用strace查找进程卡死的原因分析
作者：SoulNov23
这篇文章主要介绍了用strace查找进程卡死的原因分析，具有很好的参考价值，希望对大家有所帮助。如有错误或未考虑完全的地方，望不吝赐教
用strace查找进程卡死原因
最近遇到进程卡死的情况，但是自己调试的过程中并不一定能复现，都是需要运行一段时间某些条件下才会触发，对于这种运行着不能破坏现场的情况，我们可以使用gdb -p和strace -p来跟踪。
首先我们用ps auxf
查看我们的进程执行到了哪一步：
可以看到执行到了docker exec -i 178.20.1.229_0115034556 ls然后就卡死了
然后我们进一步通过
strace查看执行这个操作死在哪个系统回调了：
这里可以看到死在了系统回调read这里
描述符19的具体意义我们可以进入/proc/pid/fd再查看一下：
我们可以发现，19代表的是pipe，我们这里是死在了读pipe上面。
/************************************************/
分割线，后面再次出现这个问题
我们先用ps auxf查看进程号和进程执行到了哪一步，可以看到进程号是27678，卡在docker exec
root 27678 0.3 0.4 512172 16500 Sl python /wns/cloud/app/com_host/main.pyc root 25011 0.0 0.0 4332 652 S \_ /bin/sh -c docker exec -i mongo_docker_master ls root 25014 0.0 0.2 136592 10600 Sl \_ docker exec -i mongo_docker_master ls
继续用strace -p 27678跟踪
发现卡在read，文件描述符是14
root@localhost:/# strace -p 27678 Process 27678 attached read(14,
接着我们cd /proc/27678/
在这里我们可以查看进程状态
root@localhost:/proc/27678# cat status Name: python State: S (sleeping) Tgid: 27678 Ngid: 0 Pid: 27678 PPid: 27677
查看进程的内核堆栈的调试信息
wchan表示导致进程睡眠或者等待的函数
root@localhost:/proc/27678# cat stack [<ffffffff811a91ab>] pipe_wait+0x6b/0x90 [<ffffffff811a9c04>] pipe_read+0x344/0x4f0 [<ffffffff811a00bf>] do_sync_read+0x7f/0xb0 [<ffffffff811a0681>] vfs_read+0xb1/0x130 [<ffffffff811a1110>] SyS_read+0x80/0xe0 [<ffffffff818d4c49>] system_call_fastpath+0x16/0x1b [<ffffffffffffffff>] 0xffffffffffffffff root@localhost:/proc/27678# cat wchan pipe_wait
现在我们查看一下进程打开的文件描述符14代表什么
pipe文件
root@localhost:/proc/27678# ls -l ./fd total 0 lr-x------ 1 root root 64 Mar 26 17:19 0 -> pipe:[30690124] l-wx------ 1 root root 64 Mar 26 17:19 1 -> pipe:[30690125] lrwx------ 1 root root 64 Mar 26 17:19 10 -> socket:[30691732] lr-x------ 1 root root 64 Mar 26 17:19 11 -> /dev/urandom lrwx------ 1 root root 64 Mar 26 17:19 12 -> socket:[30719611] lrwx------ 1 root root 64 Mar 26 17:19 13 -> socket:[30719610] lr-x------ 1 root root 64 Mar 26 17:19 14 -> pipe:[38483750]
我们已经可以确定main创建子进程执行shell命令docker exec -i mongo_docker_master ls，同时通过pipe和子进程通信，结果卡在了read pipe上。
其实在这里我们也可以使用lsof来定位
可以看到进程27678打开的FD 14是pipe，这里u代表可读可写，r代表可读
sangfor ~ # lsof -d 14 COMMAND PID USER FD TYPE DEVICE SIZE/OFF NODE NAME mongod 1907 root 14u REG 251,0 36864 130683 /wns/data/mongodb/db/collection-7--588642557116981989.wt syslog-ng 3446 root 14u unix 0xffff88012227d800 0t0 40557736 /dev/log dockerd 4025 root 14u unix 0xffff8800b8d5d800 0t0 13941 /run/docker/libnetwork/a73bd949b5fbb89c2b8bec3b4ac6af0a948a944958c8b037d9e6c9b324b44331.sock docker-co 9382 root 14u 0000 0,9 0 9553 anon_inode docker-co 21204 root 14u 0000 0,9 0 9553 anon_inode python 27678 root 14r FIFO 0,8 0t0 38483750 pipe
也可以直接查看进程27678打开的
可以看到14是pipe
sangfor ~ # lsof -p 27678 COMMAND PID USER FD TYPE DEVICE SIZE/OFF NODE NAME python 27678 root 0r FIFO 0,8 0t0 30690124 pipe python 27678 root 1w FIFO 0,8 0t0 30690125 pipe python 27678 root 2w FIFO 0,8 0t0 30690126 pipe python 27678 root 3u 0000 0,9 0 9553 anon_inode python 27678 root 4u 0000 0,9 0 9553 anon_inode python 27678 root 5u pack 30691718 0t0 unknown type=SOCK_RAW python 27678 root 6w REG 251,0 76106652 130565 /wns/data/com_host/etc/config/err.log python 27678 root 7u IPv4 30691716 0t0 TCP Sangfor:53102->Sangfor:42457 (ESTABLISHED) python 27678 root 8u IPv4 30691717 0t0 TCP Sangfor:42457->Sangfor:53102 (ESTABLISHED) python 27678 root 9u IPv4 30691731 0t0 TCP db.sdwan:54072->sdwan.io:27017 (ESTABLISHED) python 27678 root 10u IPv4 30691732 0t0 TCP db.sdwan:54074->sdwan.io:27017 (ESTABLISHED) python 27678 root 11r CHR 1,9 0t0 30690329 /dev/urandom python 27678 root 12u IPv4 30719611 0t0 TCP db.sdwan:51404->db.sdwan:37017 (ESTABLISHED) python 27678 root 13u IPv4 30719610 0t0 TCP db.sdwan:47124->db.sdwan:27017 (ESTABLISHED) python 27678 root 14r FIFO 0,8 0t0 38483750 pipe
总结
以上为个人经验，希望能给大家一个参考，也希望大家多多支持脚本之家。