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。