systemd之導致內核 crash


本文主要講解linux kernel panic系列其中一種情況:

Attempted to kill init! exitcode=0x0000000b

背景:linux kernel 的panic ,在日常的kernel維護中比較常見,不同的

kernel panic 有不同的背景,而這些背景的觸發則有其一些類似的

處理思想。

下面列一下我們是怎么排查並解決這個問題的。

一、故障現象

oppo雲內核團隊接到連通性告警報障,發現機器復位:

      KERNEL: /usr/lib/debug/lib/modules/3.10.0-1062.18.1.el7.x86_64/vmlinux
    DUMPFILE: vmcore  [PARTIAL DUMP]
        CPUS: 72
LOAD AVERAGE: 0.11, 0.07, 0.15
       TASKS: 2229
     RELEASE: 3.10.0-1062.18.1.el7.x86_64
     VERSION: #1 SMP Tue Mar 17 23:49:17 UTC 2020
     MACHINE: x86_64  (3100 Mhz)
       PANIC: "Kernel panic - not syncing: Attempted to kill init! exitcode=0x0000000b"
         PID: 1
     COMMAND: "systemd"------進程名稱,這個進程比較特殊
        TASK: ffff8ca429570000  [THREAD_INFO: ffff8ca429578000]
         CPU: 20
       STATE:  (PANIC)

crash> bt
PID: 1      TASK: ffff8ca429570000  CPU: 20  COMMAND: "systemd"
 #0 [ffff8ca42957bb30] machine_kexec at ffffffff8c665b34
 #1 [ffff8ca42957bb90] __crash_kexec at ffffffff8c722592
 #2 [ffff8ca42957bc60] panic at ffffffff8cd74a16
 #3 [ffff8ca42957bce0] do_exit at ffffffff8c6a28e6
 #4 [ffff8ca42957bd78] do_group_exit at ffffffff8c6a296f
 #5 [ffff8ca42957bda8] get_signal_to_deliver at ffffffff8c6b377e
 #6 [ffff8ca42957be40] do_signal at ffffffff8c62c527
 #7 [ffff8ca42957bf30] do_notify_resume at ffffffff8c62cc32
 #8 [ffff8ca42957bf50] retint_signal at ffffffff8cd8457c
    RIP: 00005653070bb420  RSP: 00007ffc3b683438  RFLAGS: 00010202
    RAX: 0000000000000000  RBX: 000000000000000e  RCX: ffffffffffffffff
    RDX: 00007ffc3b683440  RSI: 00007ffc3b683570  RDI: 0000000000000007
    RBP: 000056530719e920   R8: 0000000000000001   R9: 00005653085048a0
    R10: 00000000ffffff00  R11: 0000000000000206  R12: 0000000000000009
    R13: 0000565308389ab0  R14: 0000000000000004  R15: 0000565308389ab0
    ORIG_RAX: ffffffffffffffff  CS: 0033  SS: 002b
          

從堆棧看,我們的1號進程因為收到了退出信號,內核出於對1號進程退出的保護,
會根據情況觸發panic,保存當前堆棧。

二、故障現象分析

1、理論知識:
我們了解到0號進程是系統所有進程的先祖,是一個靜態構造task_struct
而運行的進程,
0號進程創建1號進程的方式如下:
kernel_thread(kernel_init, NULL, CLONE_FS);
由0號進程創建1號進程(內核態),1號內核線程負責執行內核的部分初始化工作及進行系統配置
之后,調用 try_to_run_init_process 來選擇對應的用戶態程序,然后
調用do_execve運行可執行程序init,並從內核態線程演變成用戶態1號進程,即init進程

static int __ref kernel_init(void *unused)
{
  ...
	if (!try_to_run_init_process("/sbin/init") ||
	    !try_to_run_init_process("/etc/init") ||
	    !try_to_run_init_process("/bin/init") ||
	    !try_to_run_init_process("/bin/sh"))
		return 0;
  ...

}
而當前系統的/sbin/init 則是 systemd
# file /sbin/init
/sbin/init: symbolic link to `../lib/systemd/systemd'

1號用戶態進程慢慢從 sysvinit,upstart,演進到 systemd,提高了啟動速度,此為后話。

2、實戰分析:
查看當前系統狀態,當前屬於restart狀態。

crash> p system_state

system_state = $1 = SYSTEM_RESTART

根據調用堆棧,代碼分析如下:
對應的調用鏈為:


do_group_exit-->do_exit-->exit_notify-->forget_original_parent-->find_new_reaper

    592 static struct task_struct *find_new_reaper(struct task_struct *father)
    593         __releases(&tasklist_lock)----內核常見寫法,會有檢查獲取鎖的順序
    594         __acquires(&tasklist_lock)
    595 {
      ....
    607 
    608         if (unlikely(pid_ns->child_reaper == father)) {
    609                 qwrite_unlock_irq(&tasklist_lock);
    610                 if (unlikely(pid_ns == &init_pid_ns)) {//caq:進入這個流程產生panic
    611                         panic("Attempted to kill init! exitcode=0x%08x\n",
    612                                 father->signal->group_exit_code ?:
    613                                         father->exit_code);
    614                 }
    ...}

分析的數據為:

crash> task_struct.signal,exit_signal ffff8ca429570000
  signal = 0xffff8cb3a9ed8000
  exit_signal = 17
crash> signal_struct.flags 0xffff8cb3a9ed8000
  flags = 4---這個信號下面有


#define SIGNAL_STOP_STOPPED 0x00000001 /* job control stop in effect */
#define SIGNAL_STOP_CONTINUED   0x00000002 /* SIGCONT since WCONTINUED reap */
#define SIGNAL_GROUP_EXIT   0x00000004 /* group exit in progress */----------------------------------------4就是退出標志
#define SIGNAL_GROUP_COREDUMP   0x00000008 /* coredump in progress */

當前1號進程是收到什么信號導致退出的呢?最近有些同事會問到一些基本的x86匯編
的棧操作,在此描述一下,這些屬於匯編的基本功。

crash> dis -l get_signal_to_deliver|grep do_group_exit -B 5
/usr/src/debug/kernel-3.10.0-1062.18.1.el7/linux-3.10.0-1062.18.1.el7.x86_64/kernel/signal.c: 2386
0xffffffff8c6b376d <get_signal_to_deliver+445>:	mov    %r12,%rdi
0xffffffff8c6b3770 <get_signal_to_deliver+448>:	callq  0xffffffff8c8b54a0 <do_coredump>
/usr/src/debug/kernel-3.10.0-1062.18.1.el7/linux-3.10.0-1062.18.1.el7.x86_64/kernel/signal.c: 2392
0xffffffff8c6b3775 <get_signal_to_deliver+453>:	mov    (%r12),%edi-----入參
0xffffffff8c6b3779 <get_signal_to_deliver+457>:	callq  0xffffffff8c6a2930 <do_group_exit>


crash> dis -l do_group_exit |head -10
/usr/src/debug/kernel-3.10.0-1062.18.1.el7/linux-3.10.0-1062.18.1.el7.x86_64/kernel/exit.c: 991
0xffffffff8c6a2930 <do_group_exit>:	nopl   0x0(%rax,%rax,1) [FTRACE NOP]
0xffffffff8c6a2935 <do_group_exit+5>:	push   %rbp
0xffffffff8c6a2936 <do_group_exit+6>:	mov    %rsp,%rbp
0xffffffff8c6a2939 <do_group_exit+9>:	push   %r14
0xffffffff8c6a293b <do_group_exit+11>:	push   %r13
/usr/src/debug/kernel-3.10.0-1062.18.1.el7/linux-3.10.0-1062.18.1.el7.x86_64/arch/x86/include/asm/current.h: 14
0xffffffff8c6a293d <do_group_exit+13>:	mov    %gs:0x10e80,%r13
/usr/src/debug/kernel-3.10.0-1062.18.1.el7/linux-3.10.0-1062.18.1.el7.x86_64/kernel/exit.c: 991
0xffffffff8c6a2946 <do_group_exit+22>:	push   %r12---------上一個棧的入參壓棧在此

我們看到,r12是在rbp,r14,r13之后壓棧的,所以能取出它的值來:

 #3 [ffff8ca42957bce0] do_exit at ffffffff8c6a28e6
    ffff8ca42957bce8: ffff8ca429570804 000000012957bf58 
    ffff8ca42957bcf8: 0000000000000000 0000000000000000 
    ffff8ca42957bd08: 00000000000200cd ffff8cbe89ef90e0 
    ffff8ca42957bd18: ffff8ca42957bd30 ffffffff8c6b03c3 
    ffff8ca42957bd28: ffff8ca429570558 ffff8ca42957bd30 
    ffff8ca42957bd38: ffff8ca42957bd30 00000000b1625208 
    ffff8ca42957bd48: ffff8cb3a9ed8000 000000000000000b 
    ffff8ca42957bd58: ffff8ca429570000 ffff8cc2fb710140 
    ffff8ca42957bd68: ffff8cc2fb710148 ffff8ca42957bda0 
    ffff8ca42957bd78: ffffffff8c6a296f 
 #4 [ffff8ca42957bd78] do_group_exit at ffffffff8c6a296f
    ffff8ca42957bd80: 000000000000000b ffff8ca42957be70 ------------r12壓棧在此
                                          r12
    ffff8ca42957bd90: ffff8ca429570000 ffff8cc2fb710140 
                        r13               r14
    ffff8ca42957bda0: ffff8ca42957be38 ffffffff8c6b377e 
                         rbp
 #5 [ffff8ca42957bda8] get_signal_to_deliver at ffffffff8c6b377e

那取出對應的信號分析:

crash> siginfo_t ffff8ca42957be70
struct siginfo_t {
 si_signo = 11, ---------------信號
 si_errno = 0, 
 si_code = 128, 

好的,到目前為止,我們知道了1號進程是收到了段錯誤信號,也就是11信號,那么
正常情況下,我們給1號進程發送11號信號,會出現這個panic么?

三、故障復現

操作如下:

#kill -11 1

Broadcast message from systemd-journald@centos7 (觸發時間):

systemd[1]: Caught <SEGV>, dumped core as pid 17969.


Broadcast message from systemd-journald@centos7 (觸發時間):

systemd[1]: Freezing execution.-------------對應的就是 log_emergency("Freezing execution.");

如上,我們發現如果使用kill 11 去殺死1號進程,並不能觸發當前的crash,那么,
到底是什么原因觸發了crash呢?

首先,發送完11信號之后,我們看下1號進程處於什么狀態,
此時systemd的狀態為:

(gdb) bt
#0  0x00007efede1fdb80 in waitid () from /lib64/libc.so.6
#1  0x000055759d6ace8e in freeze ()
#2  0x000055759d636528 in crash ()
#3  <signal handler called>--------------注意這個,信號處理狀態
#4  0x00007efede237483 in epoll_wait () from /lib64/libc.so.6
#5  0x000055759d6dda69 in sd_event_wait ()
#6  0x000055759d6de57d in sd_event_run ()
#7  0x000055759d63f0c3 in manager_loop ()
#8  0x000055759d6335fb in main ()

也就是說,雖然我們kill 11信號沒有能夠殺死1號進程並產生crash,但其實
當前1號進程的狀態也不太對,還處於信號處理的堆棧中,正常工作狀態應該是:

# cat /proc/1/stack
[<0000000000000000>] ep_poll+0x23e/0x360
[<0000000000000000>] SyS_epoll_wait+0xed/0x120
[<0000000000000000>] system_call_fastpath+0x22/0x27
[<0000000000000000>] 0xffffffffffffffff

(gdb) bt
#0  0x00007f2e12bb7643 in epoll_wait () at ../sysdeps/unix/syscall-template.S:81
#1  0x0000560bf6913ee9 in sd_event_wait ()
#2  0x0000560bf69149fd in sd_event_run ()
#3  0x0000560bf68742e3 in manager_loop ()
#4  0x0000560bf686872b in main ()

關注到這個細節之后,我們來看一下1號進程的信號處理函數:

正常的其他機器上的systemd 1號進程的信號處理:
crash> sig 1
PID: 1      TASK: ffff886eadff0000  CPU: 14  COMMAND: "systemd"
SIGNAL_STRUCT: ffff886ead848000  NR_THREADS: 1
 SIG    SIGACTION        HANDLER       MASK       FLAGS           
...
[11] ffff88794dad8148 55568fde1420 0000000000000000 44000000 (SA_RESTORER|SA_NODEFER)---注意比較

而我們當前crash進程的信號處理函數為:

crash> sig 1
PID: 1      TASK: ffff8ca429570000  CPU: 20  COMMAND: "systemd"
SIGNAL_STRUCT: ffff8cb3a9ed8000  NR_THREADS: 1
 SIG    SIGACTION        HANDLER       MASK       FLAGS           
...
[11] ffff8cc2fb710148    SIG_DFL 0000000000000000 44000000 (SA_RESTORER|SA_NODEFER)--注意比較

我們發現,當前出現crash的1號進程對11號信號的處理函數是 SIG_DFL,而正常的並不是。

我們查看systemd的信號處理函數源碼:

#define SIGNALS_CRASH_HANDLER SIGSEGV,SIGILL,SIGFPE,SIGBUS,SIGQUIT,SIGABRT
static void install_crash_handler(void) {
        static const struct sigaction sa = {
                .sa_handler = crash,
                .sa_flags = SA_NODEFER, /* So that we can raise the signal again from the signal handler */
        };
        int r;

        /* We ignore the return value here, since, we don't mind if we
         * cannot set up a crash handler */
        r = sigaction_many(&sa, SIGNALS_CRASH_HANDLER, -1);

所以可以看出,crash函數負責處理SIGSEGV,SIGILL,SIGFPE,SIGBUS,SIGQUIT,SIGABRT 這些信號,
也就是包含11號信號:

220 _noreturn_ static void crash(int sig) {
    221         struct sigaction sa;
    222         pid_t pid;
    223 
    224         if (getpid_cached() != 1)
    225                 /* Pass this on immediately, if this is not PID 1 */
    226                 (void) raise(sig);
    227         else if (!arg_dump_core)
    228                 log_emergency("Caught <%s>, not dumping core.", signal_to_string(sig));
    229         else {
    230                 sa = (struct sigaction) {
    231                         .sa_handler = nop_signal_handler,
    232                         .sa_flags = SA_NOCLDSTOP|SA_RESTART,
    233                 };
    234 
    235                 /* We want to wait for the core process, hence let's enable SIGCHLD */
    236                 (void) sigaction(SIGCHLD, &sa, NULL);
    237 
    238                 pid = raw_clone(SIGCHLD);
    239                 if (pid < 0)
    240                         log_emergency_errno(errno, "Caught <%s>, cannot fork for core dump: %m", signal_to_string(sig));
    241                 else if (pid == 0) {--------子進程
    242                         /* Enable default signal handler for core dump */
    243 
    244                         sa = (struct sigaction) {
    245                                 .sa_handler = SIG_DFL,
    246                         };
    247                         (void) sigaction(sig, &sa, NULL);
........
    255                         /* Raise the signal again */
    256                         pid = raw_getpid();
    257                         (void) kill(pid, sig); --------------自己發送信號給自己
    258 
    259                         assert_not_reached("We shouldn't be here...");
    260                         _exit(EXIT_EXCEPTION);
    261                 } else {--------父進程
    262                         siginfo_t status;
    263                         int r;
  ......
    266                         r = wait_for_terminate(pid, &status);
    267                         if (r < 0)
    268                                 log_emergency_errno(r, "Caught <%s>, waitpid() failed: %m", signal_to_string(sig));
    269                         else if (status.si_code != CLD_DUMPED) {
    270                                 const char *s = status.si_code == CLD_EXITED
    271                                         ? exit_status_to_string(status.si_status, EXIT_STATUS_LIBC)

因為雲安卓虛擬化項目的緣故,最近也看了一些安卓的資料,如果有對安卓比較熟悉的朋友,
可以看到上面的代碼與crash_dump進程的代碼有異曲同工之妙:

 pid_t forkpid = fork();
  if (forkpid == -1) {
    PLOG(FATAL) << "fork failed";
  } else if (forkpid == 0) {
    fork_exit_read.reset();
  } else {
    // We need the pseudothread to live until we get around to verifying the vm pid against it.
    // The last thing it does is block on a waitpid on us, so wait until our child tells us to die.
    fork_exit_write.reset();
    char buf;
    TEMP_FAILURE_RETRY(read(fork_exit_read.get(), &buf, sizeof(buf)));
    _exit(0);
  }

如果仔細研究了一下上面信號處理的代碼,就應該知道怎么復現當前的crash堆棧了,比如你連續
兩次:

kill -11 1

kill -11 1

或者其他類似的信號,比如:

# gdb -p 1
GNU gdb (GDB) Red Hat Enterprise Linux 7.6.1-114.el7
.....
(gdb) bt
#0  0x00007f15138ca483 in epoll_wait () from /lib64/libc.so.6
#1  0x00005588a7b44a69 in sd_event_wait ()
#2  0x00005588a7b4557d in sd_event_run ()
#3  0x00005588a7aa60c3 in manager_loop ()
#4  0x00005588a7a9a5fb in main ()
(gdb) c
Continuing.
^C

上面的操作,就是gdb 1號進程,之后continue運行,然后再按ctrl +c ,
都會有類似的結果,注意,不要在線上環境做類似動作,高度風險。

四、故障規避或解決

可能的解決方案是:

嘗試修改systemd對應的信號處理函數,或者,什么都不做,畢竟觸發的概率也不是很高。

五、作者簡介

陳安慶,目前在oppo混合雲負責linux內核及容器,虛擬機等虛擬化方面的工作,

聯系方式:微信與手機同號:18752035557。


免責聲明!

本站轉載的文章為個人學習借鑒使用,本站對版權不負任何法律責任。如果侵犯了您的隱私權益,請聯系本站郵箱yoyou2525@163.com刪除。



 
粵ICP備18138465號   © 2018-2025 CODEPRJ.COM