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

问题背景

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

初步排查

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

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

-f Force (don't go through init)

中可以看出 reboot 和 reboot -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

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

跟踪工具

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

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

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

如果有 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，并调用回调函数。

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

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

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

其他

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

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

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