用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
1
2
3

继续用strace -p 27678跟踪，发现卡在read，文件描述符是14

root@localhost:/# strace -p 27678      
Process 27678 attached
read(14,
1
2
3

接着我们cd /proc/27678/，在这里我们可以查看进程状态

root@localhost:/proc/27678# cat status 
Name:   python
State:  S (sleeping)
Tgid:   27678
Ngid:   0
Pid:    27678
PPid:   27677
1
2
3
4
5
6
7

查看进程的内核堆栈的调试信息，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
1
2
3
4
5
6
7
8
9
10

现在我们查看一下进程打开的文件描述符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]
1
2
3
4
5
6
7
8
9

我们已经可以确定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
1
2
3
4
5
6
7
8

也可以直接查看进程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
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17