当前位置: 首页 > 科技观察

处理系统假死工作纪实

时间:2023-03-19 16:32:16 科技观察

本文转载自微信公众号《邂逅Linux》,作者JeffXie。转载本文请联系邂逅Linux公众号。最近,一位客户报告了一个问题。系统挂了,ssh登录不上,但是能ping通。通过串口登录后,有些命令会卡住。查看CPU负载和内存正常。手动触发kdump后,就看不到了。deadlock/softlockup/hardlockup等异常状态。重要的是,它已经影响了数十亿客户的业务。我能得到的就是客户提供的vmcore。为生活奔波的人赶紧分析一下:System(SUSE11SP1)#crash./vmcore./vmlinux-2.6.32.59-0.19-default./vmlinux-2.6.32.59-0.19-default.gzcrash>foreachINbt>inbtrandomlyfindanIN(interruptiblesleep)process12813Checkthestack:crash>bt12813PID:12813TASK:ffff880262eda140CPU:8COMMAND:"sshd"#0[ffff880f98e1ba58]scheduleatffff8ffff8139dffe81bb4#1[09]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:mov%r13,%rsi2420xffffffff813785ba:mov%rbp,%rdi(key1)rdi表示unix_wait_for_peer函数第一个参数2430xffffffff813785bd:callq0xffpeffffff813_wadat;进程12813unix_wait_for_peer()函数的堆栈数据:crash>rd-SSffff880f98e1bba0-effff880f98e1bc00ffff880f98e1bba0:unix_wait_for_peer+1350000000000000001ffff880f98e1bbb0:[ffff880262eda140:task_struct]autoremove_wake_functionffff880f98e1bbc0:ffff88021ea8bbc0ffff880238315bc0ffff880f98e1bbd0:memcpy_fromiovec+87[ffff880238514980:UNIX]ffff880f98e1bbe0:[ffff880238514c30:UNIX][ffff880238514980:UNIX]ffff880f98e1bbf0:[ffff880ff708b630:UNIX]7fffffffffffffff汇编unix_wait_for_peer()crash>disunix_wait_for_peer0xffffffff81376da0:sub$0x58,%rsp0xffffffff81376da4:mov$0x1,%edx0xffffffff81376da9:mov%r13,0x50(%rsp)0xffffffff81376dae:lea0x2b8(%rdi),%r130xffffffff81376db5:mov%rbx,0x38(%rsp)0xffffffff81376dba:mov%gs:0xa580,%rax0xffffffff81376dc3:mov%rax,0x8(%rsp)0xffffffff81376dc8:lea0x18(%rsp),%rax0xffffffff81376dcd:mov%rbp,0x40(%rsp)(key2)rbp被压入栈中(0x58-0x40),恰好是ffff880f98e1bbe8中unix_wait_for_peerstack即([ffff880238514980:UNIX])0xffffffff81376dd2:mov%rdi,%rbx0xffffffff81376dd5:mov%rsi,%rbp0xffffffff81376dd8: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,&waitRUPTIB09);)1020timeo=schedule_timeout(timeo);10211022finish_wait(&u->peer_wait,&wait);1023returntimeo;1024}根据s(key1)(key2)(key3)可以知道12813进程在等待unix_sock(ffff880238514980)crash>structunix_sockfferff880238|1ep_pe_pe_pe_pe_wat=0lock={raw_lock={slock=3369322707}},task_list={next=0xffff880173427bc0,prev=0xffff8801877a7bc0}}查询这个unix_sock是系统中的/dev/log文件(由syslog-ng创建,系统中大量需要记录日志的进程需要通过这个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)unix_sockareredirectedtoawait_unix_sock_process__wait_crash>listtask_list-s__wait_queue.private-H0xffff880173427bc0|grep-iprivate>wait_unix_sock_process查询所有的sshd进程crash>ps|grepsshd709716ffff880244cae5c0IN0.0540881392sshd1281370978ffff880262eda140IN0.0601482900sshd1905570972ffff880ff74c4200IN0.0601482900sshd2164270971ffff880262fb4340IN0.0601482904sshd2195870971ffff880ffab501c0IN0.0601482900sshd2245970976ffff880ff1ed4100IN0.012105210272sshd22476224590ffff88022d11a500IN0.01213524552sshd2333470972ffff880174b04640IN0.0601482900sshdsshd进程大部分都在wait_unix_sock_process文件中,所以ssh登录之后会卡住查看syslog-ng进程堆栈crash>bt15232PID: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-effff88021ea8bc00ffff88021ea8bba0:unix_wait_for_peer+1350000000000000001ffff88021ea8bbb0:[ffff8801aba90680:task_struct]autoremove_wake_functionffff88021ea8bbc0:ffff880fce8dfbc0ffff880f98e1bbc0ffff88021ea8bbd0:memcpy_fromiovec+87[ffff880238514980:UNIX]ffff88021ea8bbe0:[ffff880238514c30:UNIX][ffff880238514980:UNIX](key4)ffff88021ea8bbf0:[ffff88104c1c3930:UNIX]7fffffffffffffff(key4)显示syslog-ng也在等待ffff880238514980unix_sock,所以系统中大量的进程,包括sshdcron等645个进程都在等待unix_sock(/dev/log)(/dev/log是syslog-ng创建的),syslog-ng等待这个unix_sock后就卡住了,系统中大量的进程都会卡住,包括sshdcron进程等。但是为什么syslog-ng卡住了基本是从vmcore看不出来,很可能是进程被锁在了用户层。通过查看客户系统中最近安装的软件,发现他们最近安装了两个定制软件,卸载后系统恢复正常#/bin/rpm-qa--lastCARKpam-11.01-1.19TueJun922:49:222020CARKaim-11.01-1.5TueJun922:38:482020