记一个openwrt reboot异步信号处理死锁问题

时间:2022-11-25 20:23:48

写在前面

觉得本页面排版单调的话,可以尝试到这里看。

问题背景

openwrt 上碰到了一个偶现的 reboot 失效问题。执行 reboot 之后系统并没有重启,此时控制台还能工作。

初步排查

首先复现问题,发现复现后控制台仍可正常运行,但此时重复执行 reboot 也无效,执行 reboot -f 则可正常触发重启。

此处 reboot 是一个指向 busybox 的软链接,从 help 信息

-f	Force (don't go through init)

中可以看出 rebootreboot -f 的区别在于 reboot 会先通知 init 进程进行一系列操作,而 reboot -f 则直接调内核。

看下 busybox 源码, 如果带了 -f 则直接调用 C 库的 reboot 函数,如果没有带 -f 参数,则只会通过 kill 发信号给 1号进程

	if (!(flags & 4)) { /* no -f */
//TODO: I tend to think that signalling linuxrc is wrong
// pity original author didn't comment on it...
if (ENABLE_LINUXRC) {
/* talk to linuxrc */
/* bbox init/linuxrc assumed */
pid_t *pidlist = find_pid_by_name("linuxrc");
if (pidlist[0] > 0)
rc = kill(pidlist[0], signals[which]);
if (ENABLE_FEATURE_CLEAN_UP)
free(pidlist);
}
if (rc) {
/* talk to init */
if (!ENABLE_FEATURE_CALL_TELINIT) {
/* bbox init assumed */
rc = kill(1, signals[which]);
if (init_was_not_there())
rc = kill(1, signals[which]);
} else {
/* SysV style init assumed */
/* runlevels:
* 0 == shutdown
* 6 == reboot */
execlp(CONFIG_TELINIT_PATH,
CONFIG_TELINIT_PATH,
which == 2 ? "6" : "0",
(char *)NULL
);
bb_perror_msg_and_die("can't execute '%s'",
CONFIG_TELINIT_PATH);
}
}
} else {
rc = reboot(magic[which]);
}

目前 reboot -f 正常,那问题就出在用户空间调用 reboot() 之前的操作中了。

现场分析

既然知道了 reboot 是通过发送信号给 init 进程,那么下一步自然就是搞清楚 init 进程为什么卡住了。

出问题时控制台还能用,这是个好消息。先通过 ps 列出进程信息看下,发现 procd 处于 S 状态。

S interruptible sleep (waiting for an event to complete)`

但只知道这个没太大作用,我们需要更多信息,幸好 linux 还有 proc 文件系统

/proc 文件系统是一个虚拟文件系统, 最初开发 /proc 文件系统是为了提供有关系统中进程的信息。但是由于这个文件系统非常有用,因此内核中的很多元素也开始使用它来报告信息,或启用动态运行时配置。

知道了某个进程的 pid 号。就可以在 /proc/<pid> 目录下,获取到大量的进程相关信息。例如 cat /proc/1/status 查看状态信息 , cat /proc/1/stack 查看栈信息。

    $ cat /proc/1/stack
[<ffffff800808526c>] __switch_to+0x90/0xc4
[<ffffff80080f78c4>] futex_wait_queue_me+0xb8/0x108
[<ffffff80080f8018>] futex_wait+0xcc/0x1b4
[<ffffff80080f9728>] do_futex+0xdc/0x940
[<ffffff80080fa0c8>] SyS_futex+0x13c/0x148
[<ffffff800808325c>] __sys_trace+0x4c/0x4c
[<ffffffffffffffff>] 0xffffffffffffffff

从栈信息看,似乎在等待某个锁。

跟踪工具

情况又清晰了一点,但还不够,下一步用跟踪工具看下。

先上 stracestrace 是跟踪进程行为的利器, 可以直接用 strace 来启动一个程序,从头开始跟踪,例如 strace reboot ,也可以在程序运行过程中,通过指定 pid 动态 attach 上去,中途开始跟踪,例如目前这种情况,在 reboot 之前先运行 strace -p 1,即可观察卡住前 1号进程 都执行了什么操作。

strace 的输出,加上我自己增加的一些 log 验证,此时已经锁定到问题出在一个打印语句中,展开后是对 vsyslog 的调用。init 就卡在这个调用中,一去不复返。

记一个openwrt reboot异步信号处理死锁问题

记一个openwrt reboot异步信号处理死锁问题

如果有 gdb 那就更简单了,直接在卡住后连上去,看下 backtrace,不仅能直接看到 init 调用了 vsyslog ,还能进一步看到是 glibc 内部在 vsyslog 中又调用了 realloc,最终卡住。log 如下(本机的一些路径信息用 *** 代替了)

    (gdb) bt
#0 0x0000007f8f5948e0 in __lll_lock_wait_private () from /lib/libc.so.6
#1 0x0000007f8f543420 in realloc () from /lib/libc.so.6
#2 0x0000007f8f539108 in _IO_mem_finish () from /lib/libc.so.6
#3 0x0000007f8f5316c8 in fclose@@GLIBC_2.17 () from /lib/libc.so.6
#4 0x0000007f8f586d94 in __vsyslog_chk () from /lib/libc.so.6
#5 0x0000007f8f6a727c in vsyslog (__ap=..., __fmt=0x40c98c "- shutdown -\n",
__pri=6)
at /***-glibc/toolchain/include/bits/syslog.h:47
#6 ulog_syslog (ap=..., fmt=0x40c98c "- shutdown -\n", priority=6)
at /***/compile_dir/target/libubox-2016-02-26/ulog.c:117
#7 ulog (priority=priority@entry=6, fmt=fmt@entry=0x40c98c "- shutdown -\n")
at /***/compile_dir/target/libubox-2016-02-26/ulog.c:172
#8 0x0000000000404c84 in state_enter ()
at /***/compile_dir/target/procd-2016-02-08/state.c:155
#9 0x0000000000404314 in signal_shutdown (signal=<optimized out>,
siginfo=<optimized out>, data=<optimized out>)
at /***/compile_dir/target/procd-2016-02-08/signal.c:61
#10 <signal handler called>
---Type <return> to continue, or q <return> to quit---
#11 0x0000007f8f565070 in fork () from /lib/libc.so.6
#12 0x000000000040b19c in queue_next ()
at /***/compile_dir/target/procd-2016-02-08/plug/hotplug.c:335
#13 0x0000007f8f6a3ce0 in uloop_handle_processes ()
at /***/compile_dir/target/libubox-2016-02-26/uloop.c:545
#14 uloop_run ()
at /***/compile_dir/target/libubox-2016-02-26/uloop.c:685
#15 0x0000000000404074 in main (argc=1, argv=0x7fdf7255c8)
at /***/compile_dir/target/procd-2016-02-08/procd.c:75

分析原因

找到了卡住的点,搜索一番,问题的原因也就很明显了。这是一个异步信号安全问题。

前面说到 reboot 时是发送了一个信号给 1号进程, 而 1号进程procd 的这段出问题代码,正是在信号处理函数中被调用的。

搜下 信号处理 死锁 之类的关键词,就可以搜到很多人前仆后继地踩了这个坑。信号的到来会打断正常的执行流程,转而执行异步信号处理函数,由于不确定被打断的位置,所以异步信号处理函数的编写是很有讲究的,只能调用异步信号安全的函数。可以在 man 7 signal 中找到这个异步信号安全函数的列表。太占篇幅这里就不列了。

除了这些函数,其他的调用都不保证是安全的。本例中是调用了syslog, 里面执行了内存分配操作。此时如果信号发生时正常流程中也在执行内存分配操作,那就可能发生死锁,因为 glibc 中的内存分配操作是有锁的,正常流程中上锁之后被信号打断,信号处理函数中又去拿这个锁,就死锁了。

此处要区分好 线程安全异步信号安全。例如

lock
do something
unlock

有锁保护之后,多线程调用这段代码,任意时刻只有一个线程可拿到锁,就保证只会有一个线程在执行中间的 do something,但当某个线程拿到锁后正在执行 do something时,是可以被信号打断的。如果信号处理函数中,也尝试执行这段函数,那么信号处理函数就会卡在 lock 上一直拿不到锁。

回到问题本身,这个问题的直接原因是信号处理函数中调用了 LOG,而展开后调用了不安全的 vsyslog

但解决问题不能只是简单地注释掉这行,这样治标不治本,因为这个信号处理函数中还调用了不少其他函数,都是有风险的。

要解决这个问题,还得完全按标准来,保证信号处理函数中只调用异步信号安全的函数,才能永绝后患。

方案一

为了满足异步信号安全,在信号处理函数中编程就难免限制多多,束手束脚,申请个内存,加个打印,都有可能死锁。

一个常用的方式是将异步信号处理改成同步信号处理。思路就是将信号屏蔽掉,专门开一个线程开处理信号。

可以参考 Linux 多线程应用中如何编写安全的信号处理函数

这里贴下 man pthread_sigmask 中的例子,主线程中先屏蔽一些信号,然后创建了一个特定的线程,通过 sigwait 来检测处理这些信号。如此一来处理信号就是在正常的上下文中完成的,不必考虑线程安全问题。

EXAMPLE
The program below blocks some signals in the main thread, and then creates a dedicated thread to fetch those signals via sigwait(3).
The following shell session demonstrates its use: $ ./a.out &
[1] 5423
$ kill -QUIT %1
Signal handling thread got signal 3
$ kill -USR1 %1
Signal handling thread got signal 10
$ kill -TERM %1
[1]+ Terminated ./a.out Program source #include <pthread.h>
#include <stdio.h>
#include <stdlib.h>
#include <unistd.h>
#include <signal.h>
#include <errno.h> /* Simple error handling functions */ #define handle_error_en(en, msg) \
do { errno = en; perror(msg); exit(EXIT_FAILURE); } while (0) /* 信号处理线程 */
static void *
sig_thread(void *arg)
{
sigset_t *set = arg;
int s, sig; for (;;) {
s = sigwait(set, &sig); /* 主动等待指定的信号集 */
if (s != 0)
handle_error_en(s, "sigwait");
printf("Signal handling thread got signal %d\n", sig); /* 进行信号处理,此时不必局限于调用异步信号安全的函数 */
}
} int
main(int argc, char *argv[])
{
pthread_t thread;
sigset_t set;
int s; /* Block SIGQUIT and SIGUSR1; other threads created by main()
will inherit a copy of the signal mask. */ sigemptyset(&set); /* 创建一个空信号集 */
sigaddset(&set, SIGQUIT); /* 将SIGQUIT加入信号集 */
sigaddset(&set, SIGUSR1); /* 将SIGUSR1加入信号集 */
s = pthread_sigmask(SIG_BLOCK, &set, NULL); /* 屏蔽信号集,屏蔽后内核收到这些信号,不会触发任何异步的信号处理函数,只是登记下来 */
if (s != 0)
handle_error_en(s, "pthread_sigmask"); s = pthread_create(&thread, NULL, &sig_thread, (void *) &set); /* 创建信号处理线程,传入屏蔽的信号集,也就是要同步处理的信号集 */
if (s != 0)
handle_error_en(s, "pthread_create"); /* Main thread carries on to create other threads and/or do
other work */ pause(); /* Dummy pause so we can test program */
}

了解了这种同步信号处理模型,那目前的问题能否套用呢 ? 很遗憾不行,因为这种方式需要屏蔽信号,而信号的屏蔽是会被 fork 继承的,回到问题本身,这次的主角是 1号进程procd,整个用户空间的其他进程全是它的子进程,牵一发而动全身,信号屏蔽还是暂不考虑了。

方案二

既然不能屏蔽信号,那异步信号处理函数就还是存在。可以考虑把原来的信号处理函数做到事情挪出来,放到独立的一个线程中去做,异步信号处理函数只负责通知下这个线程干活。

怎么通知呢? man 7 signal 看看有什么异步信号安全的函数可以用,看起来 sim_post 似乎不错。

首先初始化一个 semaphore, 然后在信号处理线程中调用 sem_wait, 等到后执行实际的信号处理 , 而在异步信号处理函数中仅调用 sem_post,起到通知的作用。

这个方案的问题在于引入了多线程。本来 procd 是单线程的,其中用到的 uloop 等也并未考虑多线程下的线程安全,因此这里是有风险的,搞不好解 bug 就变成写 bug 了。

方案三

方案二的思路是没问题的,异步信号处理函数中只做最简单的事情,安全可靠,实际上的复杂操作留给正常的线程处理。

如果要避免多线程,那就得想办法在主线程中加入对信号的等待和处理,然后只在信号处理函数中进行简单操作,触发主线程处理。

具体的实现就多种多样了,例如最简单的,信号处理函数中将信号记录到全局变量中,主线程轮询。但轮询消耗资源呀,所以更好的做法是主线程阻塞在某个操作上,在信号到来打断这个阻塞操作后进行处理。

对于 procd,其循环是使用的 uloop,而 uloop 中会使用 epoll 监控指定的 fd,并调用回调函数。

看看信号安全函数列表,readwrite 都是异步信号安全的函数,由此我们可以开一个 pipe 或者 socket,一端由异步信号处理函数写入,另一端由工作在正常进程上下文中的回调函数读出并处理。

最终我们使用了方案三,具体的是使用了管道,并直接复用了 openwrtustream ,这里展开就得涉及到 procd init 的工作流程分析了,后续有机会再写吧。

有一点可以提下,方案一和二用在 procd 中还有一个问题,就是不能跟原有的 uloop 中的 epoll 顺畅配合,会导致 reboot 要做的事情堆积在队列中却触发不了处理,需要等其他事件来打断这个 epoll, 而方案三则没有这个问题。这也是 procduloop 的实现导致的,暂不展开。

其他

信号的细节还是蛮多的,例如同一信号多次发生会怎样,多个阻塞信号的到达顺序,进程级别的屏蔽处理和线程级别的屏蔽处理的差异,forkexec 时的行为等。

异步信号同步化的方式,也有很多文章阐述,例如 signalfd 等本文都没提及。

说回 procd,为什么原生的实现可以这么任性,直接在信号处理函数中调用非异步信号安全的函数呢? 这可能是 openwrt 默认 C库 是用的 musl 的原因吧。

博客:https://www.cnblogs.com/zqb-all/p/12735146.html

公众号:https://sourl.cn/iaArrv