专业的网站建设企业,wordpress 制作微信小程序,临沂seo网站管理,网络策划营销[deadlock]死锁导致的设备登录无响应问题 一、问题现象二、初步观察三、继续深挖查看netlink相关信息查看warnd进程栈 四、再接再厉查看warnd 用户栈 后记 一、问题现象
实验室一台压力测试设备突然无法登录#xff0c;无论web页面#xff0c;ssh或者telnet登录#xff0c;… [deadlock]死锁导致的设备登录无响应问题 一、问题现象二、初步观察三、继续深挖查看netlink相关信息查看warnd进程栈 四、再接再厉查看warnd 用户栈 后记 一、问题现象
实验室一台压力测试设备突然无法登录无论web页面ssh或者telnet登录都是输入用户名密码后卡在哪里无法进入管理页面。 如果这样子的话根本无法调试。幸运的是有个之前就打开的shell窗口可以使用。这给我们分析调试提供了方便。
二、初步观察
在shell中查看现存和hang住的命令行进程看看有什么线索。
/var/log# ps | grep cli2812 root 720m S cli admin 1 admin telnet(10.10.20.11)
15126 root 720m S cli admin 1 admin telnet(10.10.20.11)
15264 root 720m S cli admin 0 admin console
21947 root 16448 S grep cli这里有3个cli进程有除了2812是我们当前在使用的剩下两个都是无响应的。查看进程的内核栈信息。
/var/log# cat /proc/15264/stack
[ffffffff8080a819] netlink_attachskb0x189/0x1d0
[ffffffff8080a991] netlink_unicast0xa1/0x1f0
[ffffffff8080ad81] netlink_sendmsg0x1c1/0x3e0
[ffffffff80799b8a] sock_sendmsg0x1a/0x30
[ffffffff8079a376] ___sys_sendmsg0x1e6/0x200
[ffffffff8079b404] SyS_sendmsg0x44/0x80
[ffffffff802016d5] do_syscall_640x75/0x2c0
[ffffffff80c0008d] entry_SYSCALL_64_after_hwframe0x59/0xbe
[ffffffffffffffff] 0xffffffffffffffff
/var/log# cat /proc/15126/stack
[ffffffff8080a819] netlink_attachskb0x189/0x1d0
[ffffffff8080a991] netlink_unicast0xa1/0x1f0
[ffffffff8080ad81] netlink_sendmsg0x1c1/0x3e0
[ffffffff80799b8a] sock_sendmsg0x1a/0x30
[ffffffff8079a376] ___sys_sendmsg0x1e6/0x200
[ffffffff8079b404] SyS_sendmsg0x44/0x80
[ffffffff802016d5] do_syscall_640x75/0x2c0
[ffffffff80c0008d] entry_SYSCALL_64_after_hwframe0x59/0xbe
[ffffffffffffffff] 0xffffffffffffffff
/var/log# cat /proc/2812/stack
[ffffffff80255f6a] do_wait0x1aa/0x210
[ffffffff802570f7] kernel_wait40x97/0x120
[ffffffff802571ef] SyS_wait40x6f/0x80
[ffffffff802016d5] do_syscall_640x75/0x2c0
[ffffffff80c0008d] entry_SYSCALL_64_after_hwframe0x59/0xbe
[ffffffffffffffff] 0xffffffffffffffff可以发现 15126和15264进程都卡在了 netlink发送等待上。怀疑netlink socket收包队列有积压导致发送端处于等待发送状态。
三、继续深挖
查看netlink相关信息
/var/log# cat /proc/net/netlink
sk Eth Pid Groups Rmem Wmem Dump Locks Drops Inode
ffff88880b2cb000 0 2851 00000000 0 0 0 2 0 12002
ffff888806d6e800 0 2707076566 00000000 0 0 0 2 0 12784
ffff888806d6a000 0 3780 00000551 0 0 0 2 0 12810
ffff88885a980000 0 0 00000000 0 0 0 2 0 3
ffff88880a1b6000 0 2825818928 00000111 0 0 0 2 0 20919
ffff888806d6d800 0 3498 00000111 0 0 0 2 0 12783
ffff88880c210000 0 3410172620 00000000 0 0 0 2 0 12811
ffff88880b2cb800 0 2855 00000001 0 0 0 2 0 11851
ffff88880a5bf800 15 10000038 00000000 33557184 0 0 27 0 1652 --问题socket
//省略部分无关socket发现socket ffff88880a5bf800 存在大量积压基本确认是积压导致。
根据Eth 15 和Pid 10000038 对照代码发现是发送和接收告警信息的socket负责接收处理的进程是warnd。
查看warnd进程栈
/var/log# ps | grep warnd2849 root 2325m S /bin/warnd
22135 root 16448 S grep warnd
/var/log# cat /proc/2849/stack
[ffffffff802bfe03] futex_wait_queue_me0xc3/0x120
[ffffffff802c01e2] futex_wait0x102/0x230
[ffffffff802c275e] do_futex0x14e/0xc30
[ffffffff802c32ab] SyS_futex0x6b/0x140
[ffffffff802016d5] do_syscall_640x75/0x2c0
[ffffffff80c0008d] entry_SYSCALL_64_a发现warnd在等待futex 锁是那个操作导致的呢这就需要查看用户态的调用栈了。
四、再接再厉
查看warnd 用户栈
用gdb attach上warnd进程查看当前栈
/var/log# gdb
GNU gdb (GDB) 11.2
Copyright (C) 2022 Free Software Foundation, Inc.
//省略无关部分
For help, type help.
Type apropos word to search for commands related to word.
(gdb) attach 2849
Attaching to process 2849
[New LWP 2945]
[New LWP 2946]
[New LWP 2947]
//省略无关部分
[Thread debugging using libthread_db enabled]
Using host libthread_db library /lib/libthread_db.so.1.
0x00007fcab97e4059 in ?? () from /lib/libc.so.6
(gdb) info threadId Target Id Frame
* 1 Thread 0x7fcab8929800 (LWP 2849) warnd 0x00007fcab97e4059 in ?? () from /lib/libc.so.62 Thread 0x7fcab8924640 (LWP 2945) warnd 0x00007fcab97e4059 in ?? () from /lib/libc.so.63 Thread 0x7fcab8123640 (LWP 2946) warnd 0x00007fcab97e4059 in ?? () from /lib/libc.so.64 Thread 0x7fcab7922640 (LWP 2947) warnd 0x00007fcab97e4059 in ?? () from /lib/libc.so.6
//省略无关部分34 Thread 0x7fcaa802b640 (LWP 8217) warnd 0x00007fcab97e4059 in ?? () from /lib/libc.so.635 Thread 0x7fcaa782a640 (LWP 8238) warnd 0x00007fcab9868add in sendmsg () from /lib/libc.so.636 Thread 0x7fcaa7029640 (LWP 8245) warnd 0x00007fcab97e4059 in ?? () from /lib/libc.so.637 Thread 0x7fcaa611f640 (LWP 8260) warnd 0x00007fcab97e4059 in ?? () from /lib/libc.so.638 Thread 0x7fcaa590d640 (LWP 8267) warnd 0x00007fcab97e4059 in ?? () from /lib/libc.so.639 Thread 0x7fcaa510c640 (LWP 8268) warnd 0x00007fcab9867196 in epoll_wait () from /lib/libc.so.6除了线程35和39外其他线程全部卡在相同的位置。
查看线程1可以知道系统调用线程读写锁的写锁时因为得不到调度进入了休眠。那么这个锁被那个线程占有了呢
(gdb) thread 1
[Switching to thread 1 (Thread 0x7fcab8929800 (LWP 2849))]
#0 0x00007fcab97e4059 in ?? () from /lib/libc.so.6
(gdb) bt full
#0 0x00007fcab97e4059 in ?? () from /lib/libc.so.6
No symbol table info available.
#1 0x00007fcab97ed4f1 in pthread_rwlock_wrlock () from /lib/libc.so.6
No symbol table info available.
#2 0x000000000040d5d3 in ?? ()
No symbol table info available.
#3 0x0000000000404ad9 in ?? ()
No symbol table info available.
#4 0x00007fcab978b1f7 in ?? () from /lib/libc.so.6
No symbol table info available.
#5 0x00007fcab978b2ac in __libc_start_main () from /lib/libc.so.6
No symbol table info available.
#6 0x0000000000404b01 in ?? ()
No symbol table info available.我们再查看看35线程。通过查看代码发现在sendmsg之前线程已经持通过pthread_rwlock_wrlock 持有了写锁。也就是其他线程都在等待35线程释放写锁。那么35线程为什么不释放写锁呢 (gdb) thread 35
[Switching to thread 35 (Thread 0x7fcaa782a640 (LWP 8238))]
#0 0x00007fcab9868add in sendmsg () from /lib/libc.so.6
(gdb) bt full
#0 0x00007fcab9868add in sendmsg () from /lib/libc.so.6
No symbol table info available.
#1 0x00007fcab967f81d in fun_nl_sendto0 () from /lib/libfun_nl_ipc.so
No symbol table info available.
#2 0x00007fcab9b2a61a in send_warn () from /lib/libwarnapi.so
No symbol table info available.
#3 0x00000000004159d0 in ?? ()
No symbol table info available.
#4 0x0000000000415dbc in ?? ()
No symbol table info available.
#5 0x000000000040c9c5 in ?? ()
No symbol table info available.
#6 0x00007fcab9b62067 in ?? () from /lib/libevent.so
No symbol table info available.
#7 0x00007fcab9b62314 in ?? () from /lib/libevent.so
No symbol table info available.
#8 0x00007fcab9b62568 in ?? () from /lib/libevent.so
No symbol table info available.
#9 0x000000000040ca8e in ?? ()
No symbol table info available.
#10 0x00007fcab97e731a in ?? () from /lib/libc.so.6
No symbol table info available.
#11 0x00007fcab9866db0 in clone () from /lib/libc.so.6查代码发现35线程sendmsg就是向 已经积压的netlink socket 发送warn消息。因为netlink socket积压导致35线程进入休眠等待。
分析到这里基本逻辑差不多通顺了。
压力测试导致netlink socket积压35线程获取写锁后向netlink socket发送消息。因为积压导致休眠。其他线程包括netlink socket消息接受处理的线程因为获取不到写锁导致休眠。此时线程35发送消息持有写锁等待netlink socket buffer空闲。处理netlink socket消息的线程等待写锁。–根因cli命令行进程会向warnd发送netlink消息因为netlink socket消息积压(消息没有得到及时处理)导致发送进程进入等待休眠。
后记
warnd进程主要处理其他进程发来的warn消息自己也发送warn消息。在锁的处理上不够完善导致压力测试下socket接收队列打满后形成了死锁。
