处理一次系统假死工作纪实
本文转载自微信公众号「相遇Linux」，作者JeffXie 。转载本文请联系相遇Linux公众号。 最近碰到客户反馈一个问题，系统hang了,ssh登录不上，但是可以ping通，通过串口登录进去之后，敲有些命令会卡住，查看cpu负载内存都很正常，手动触发kdump之后看不出死锁/softlockup/hardlockup等异常状态.而且重要的是已经影响到客户几十亿的业务了。 我能拿到的只有客户提供的vmcore,为了生活而奔波的人儿赶紧分析起来： 系统(SUSE 11SP1) #crash ./vmcore ./vmlinux-2.6.32.59-0.19-default ./vmlinux-2.6.32.59-0.19-default.gz crash>foreach IN bt > inbt 任意找到一个IN(可中断睡眠)的进程 12813 查看堆栈: crash>bt12813 PID:12813TASK:ffff880262eda140CPU:8COMMAND:"sshd" #0[ffff880f98e1ba58]scheduleatffffffff8139d2a4 #1[ffff880f98e1bb10]schedule_timeoutatffffffff8139d935 #2[ffff880f98e1bba0]unix_wait_for_peeratffffffff81376e27 #3[ffff880f98e1bc00]unix_dgram_sendmsgatffffffff813785c2 #4[ffff880f98e1bcb0]sock_sendmsgatffffffff812e8ddc #5[ffff880f98e1be50]sys_sendtoatffffffff812e9318 #6[ffff880f98e1bf80]system_call_fastpathatffffffff81002f7b 汇编unix_dgram_sendmsg() crash>disunix_dgram_sendmsg ... 2410xffffffff813785b7<unix_dgram_sendmsg+1143>:mov%r13,%rsi 2420xffffffff813785ba<unix_dgram_sendmsg+1146>:mov%rbp,%rdi(key1) rdi代表unix_wait_for_peer函数的第一个参数 2430xffffffff813785bd<unix_dgram_sendmsg+1149>:callq0xffffffff81376da0<unix_wait_for_peer> 进程12813 unix_wait_for_peer() 函数的堆栈数据: crash>rd-SSffff880f98e1bba0-effff880f98e1bc00 ffff880f98e1bba0:unix_wait_for_peer+1350000000000000001 ffff880f98e1bbb0:[ffff880262eda140:task_struct]autoremove_wake_function ffff880f98e1bbc0:ffff88021ea8bbc0ffff880238315bc0 ffff880f98e1bbd0:memcpy_fromiovec+87[ffff880238514980:UNIX] ffff880f98e1bbe0:[ffff880238514c30:UNIX][ffff880238514980:UNIX] ffff880f98e1bbf0:[ffff880ff708b630:UNIX]7fffffffffffffff 汇编unix_wait_for_peer() crash>disunix_wait_for_peer 0xffffffff81376da0<unix_wait_for_peer>:sub$0x58,%rsp 0xffffffff81376da4<unix_wait_for_peer+4>:mov$0x1,%edx 0xffffffff81376da9<unix_wait_for_peer+9>:mov%r13,0x50(%rsp) 0xffffffff81376dae<unix_wait_for_peer+14>:lea0x2b8(%rdi),%r13 0xffffffff81376db5<unix_wait_for_peer+21>:mov%rbx,0x38(%rsp) 0xffffffff81376dba<unix_wait_for_peer+26>:mov%gs:0xa580,%rax 0xffffffff81376dc3<unix_wait_for_peer+35>:mov%rax,0x8(%rsp) 0xffffffff81376dc8<unix_wait_for_peer+40>:lea0x18(%rsp),%rax 0xffffffff81376dcd<unix_wait_for_peer+45>:mov%rbp,0x40(%rsp)(key2) rbp压入堆栈(0x58-0x40)处，正好是unix_wait_for_peer堆栈中ffff880f98e1bbe8处，即( [ffff880238514980:UNIX]) 0xffffffff81376dd2<unix_wait_for_peer+50>:mov%rdi,%rbx 0xffffffff81376dd5<unix_wait_for_peer+53>:mov%rsi,%rbp 0xffffffff81376dd8<unix_wait_for_peer+56>:mov%r13,%rdi 查看unix_wait_for_peer()函数源码: 1005staticlongunix_wait_for_peer(structsock*other,longtimeo)(key3) 1006{ 1007structunix_sock*u=unix_sk(other); 1008intsched; 1009DEFINE_WAIT(wait); 1011prepare_to_wait_exclusive(&u->peer_wait,&wait,TASK_INTERRUPTIBLE); .. 1019if(sched) 1020timeo=schedule_timeout(timeo); 1021 1022finish_wait(&u->peer_wait,&wait); 1023returntimeo; 1024} 根据s(key1)(key2)(key3)可以知道12813进程在等待unix_sock(ffff880238514980) crash>structunix_sockffff880238514980|greppeer_wait-A10 peer_wait={ lock={ raw_lock={ slock=3369322707 } }, task_list={ next=0xffff880173427bc0, prev=0xffff8801877a7bc0 } } 查询出这个unix_sock是系统中的/dev/log文件(由syslog-ng创建，系统中大量需要记录log的进程需要通过这个unix_sock与syslog-ng通信,可以参考mansyslog-ng 和/etc/syslog-ng/syslog-ng.conf 配置文件) crash>structunix_sockffff880238514980 ... dentry=0xffff880e7634b9c0, ... crash>structdentry0xffff880e7634b9c0 ... name=0xffff880e7634ba60"log" ... 遍历这个unix_sock的所有等待队列， 说明有645个进程正在等待这个unix_sock(ffff880238514980/dev/log) crash>list__wait_queue.task_list-s__wait_queue.private-H0xffff880173427bc0|grep-iprivate|wc-l 645 所有等待unix_sock的进程重定向到一个wait_unix_sock_process文件 crash>list__wait_queue.task_list-s__wait_queue.private-H0xffff880173427bc0|grep-iprivate>wait_unix_sock_process 查询所有的sshd进程 crash>ps|grepsshd 709716ffff880244cae5c0IN0.0540881392sshd 1281370978ffff880262eda140IN0.0601482900sshd 1905570972ffff880ff74c4200IN0.0601482900sshd 2164270971ffff880262fb4340IN0.0601482904sshd 2195870971ffff880ffab501c0IN0.0601482900sshd 2245970976ffff880ff1ed4100IN0.012105210272sshd 22476224590ffff88022d11a500IN0.01213524552sshd 2333470972ffff880174b04640IN0.0601482900sshd sshd进程大部分都在wait_unix_sock_process文件中，所以ssh登录之后会卡住 查看syslog-ng进程堆栈 crash>bt15232 PID:15232TASK:ffff8801aba90680CPU:6COMMAND:"syslog-ng" #0[ffff88021ea8ba58]scheduleatffffffff8139d2a4 #1[ffff88021ea8bb10]schedule_timeoutatffffffff8139d935 #2[ffff88021ea8bba0]unix_wait_for_peeratffffffff81376e27 #3[ffff88021ea8bc00]unix_dgram_sendmsgatffffffff813785c2 #4[ffff88021ea8bcb0]sock_sendmsgatffffffff812e8ddc #5[ffff88021ea8be50]sys_sendtoatffffffff812e9318 #6[ffff88021ea8bf80]system_call_fastpathatffffffff81002f7b 查看 unix_wait_for_peer()堆栈数据: crash>rd-SSffff88021ea8bba0-effff88021ea8bc00 ffff88021ea8bba0:unix_wait_for_peer+1350000000000000001 ffff88021ea8bbb0:[ffff8801aba90680:task_struct]autoremove_wake_function ffff88021ea8bbc0:ffff880fce8dfbc0ffff880f98e1bbc0 ffff88021ea8bbd0:memcpy_fromiovec+87[ffff880238514980:UNIX] ffff88021ea8bbe0:[ffff880238514c30:UNIX][ffff880238514980:UNIX]（key4） ffff88021ea8bbf0:[ffff88104c1c3930:UNIX]7fffffffffffffff 由(key4)可知syslog-ng也是在等待ffff880238514980 unix_sock 所以系统中大量的进程,包括sshd cron等其他的645个进程都在等待unix_sock(/dev/log)(/dev/log由syslog-ng创建),syslog-ng卡住在等这个unix_sock之后，系统中大量的进程都会卡住，包括sshd cron进程等. 但是syslog-ng为什么卡住从vmcore根本看不出来，很可能进程在用户层锁住了. 通过查看客户系统中最近安装的软件发现，他们最近安装了两个定制软件，卸载之后系统恢复正常。 #/bin/rpm-qa--last CARKpam-11.01-1.19TueJun922:49:222020 CARKaim-11.01-1.5TueJun922:38:482020
