分析运行中的 Python 进程
在 Java 中打印当前线程的方法栈,可以用 kill -3 命令向 JVM 发送一个 OS 信号,JVM 捕捉以后会自动 dump 出来;当然,也可以直接使用 jstack 工具完成,这些方法好几年前我在这篇性能分析的文章 中介绍过。这样的需求可以说很常见,比如定位死锁,定位一个不工作的线程到底卡在哪里,或者定位为什么 CPU 居高不下等等问题。
现在工作中我用的是 Python,需要线上问题定位的缘故,也有了类似的需求——想要知道当前的 Python 进程“在干什么”。但是没有了 JVM 的加持,原有的命令或者工具都不再适用。传统的 gdb 的 debug 大法在线上也不好操作。于是我寻找了一些别的方法,来帮助定位问题,我把它们记录在这里。
signal
在代码中,我们可以使用 signal 为进程预先注册一个信号接收器,在进程接收到特定信号的时候,可以打印方法栈:
import traceback, signal class Debugger(): def __init__(self, logger): self._logger = logger def log_stack_trace(self, sig, frame): d={'_frame':frame} d.update(frame.f_globals) d.update(frame.f_locals) messages = "Signal received. Stack trace:\n" messages += ''.join(traceback.format_stack(frame)) self._logger.warn(messages) def listen(self): signal.signal(signal.SIGUSR1, self.log_stack_trace)
通过调用上面的 listen 方法(比如 new Debug(logger).listen()),就将一个可以接收 SIGUSR1 并打印方法栈的接收器注册到当前进程了。这里是打印方法栈,但是实际上可以做任何事,因为方法执行的当前,上下文已经跑到进程里面了。
那么怎么向进程发送信号呢?和 JVM 的方法类似,可以通过操作系统命令来发送:
kill -30 pid
这里的信号为什么是 30?这是因为 SIGUSR1 被当前操作系统定义成 30(请注意不同的操作系统这个映射表是可能不同的),这点可以通过 man signal 查看:
No Name Default Action Description 1 SIGHUP terminate process terminal line hangup 2 SIGINT terminate process interrupt program 3 SIGQUIT create core image quit program 4 SIGILL create core image illegal instruction 5 SIGTRAP create core image trace trap 6 SIGABRT create core image abort program (formerly SIGIOT) 7 SIGEMT create core image emulate instruction executed 8 SIGFPE create core image floating-point exception 9 SIGKILL terminate process kill program 10 SIGBUS create core image bus error 11 SIGSEGV create core image segmentation violation 12 SIGSYS create core image non-existent system call invoked 13 SIGPIPE terminate process write on a pipe with no reader 14 SIGALRM terminate process real-time timer expired 15 SIGTERM terminate process software termination signal 16 SIGURG discard signal urgent condition present on socket 17 SIGSTOP stop process stop (cannot be caught or ignored) 18 SIGTSTP stop process stop signal generated from keyboard 19 SIGCONT discard signal continue after stop 20 SIGCHLD discard signal child status has changed 21 SIGTTIN stop process background read attempted from control terminal 22 SIGTTOU stop process background write attempted to control terminal 23 SIGIO discard signal I/O is possible on a descriptor (see fcntl(2)) 24 SIGXCPU terminate process cpu time limit exceeded (see setrlimit(2)) 25 SIGXFSZ terminate process file size limit exceeded (see setrlimit(2)) 26 SIGVTALRM terminate process virtual time alarm (see setitimer(2)) 27 SIGPROF terminate process profiling timer alarm (see setitimer(2)) 28 SIGWINCH discard signal Window size change 29 SIGINFO discard signal status request from keyboard 30 SIGUSR1 terminate process User defined signal 1 31 SIGUSR2 terminate process User defined signal 2
当然,也可以写一点点 python 脚本来发送这个信号:
import os, signal os.kill($PID, signal.SIGUSR1)
原理是一样的。
strace
如果进程已经无响应了,或者上面的信号接收器没有注册,那么就要考虑别的方法来或者“进程在干什么”这件事情了。其中,一个有用的命令是 strace:
strace -p pid
比如,我自己写了一个测试脚本 t.py,使用 python 执行,然后调用 sleep,再给它发送一个 SIGUSR1 的消息,它打印方法栈并退出。这整个过程,我使用 strace 可以得到这样的结果:
strace -p 9157 strace: Process 9157 attached select(0, NULL, NULL, NULL, {9999943, 62231}) = ? ERESTARTNOHAND (To be restarted if no handler) --- SIGUSR1 {si_signo=SIGUSR1, si_code=SI_USER, si_pid=9273, si_uid=9007} --- rt_sigreturn({mask=[]}) = -1 EINTR (Interrupted system call) stat("t.py", {st_mode=S_IFREG|0644, st_size=1281, ...}) = 0 open("t.py", O_RDONLY) = 3 fstat(3, {st_mode=S_IFREG|0644, st_size=1281, ...}) = 0 fstat(3, {st_mode=S_IFREG|0644, st_size=1281, ...}) = 0 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f631e866000 read(3, "import traceback, signal, time\n "..., 8192) = 1281 read(3, "", 4096) = 0 close(3) = 0 munmap(0x7f631e866000, 4096) = 0 stat("t.py", {st_mode=S_IFREG|0644, st_size=1281, ...}) = 0 write(1, "Signal received. Stack trace:\n "..., 134) = 134 write(1, "\n", 1) = 1 rt_sigaction(SIGINT, {SIG_DFL, [], SA_RESTORER, 0x7f631e06f5d0}, {0x7f631e392680, [], SA_RESTORER, 0x7f631e06f5d0}, 8) = 0 rt_sigaction(SIGUSR1, {SIG_DFL, [], SA_RESTORER, 0x7f631e06f5d0}, {0x7f631e392680, [], SA_RESTORER, 0x7f631e06f5d0}, 8) = 0 exit_group(0) = ? +++ exited with 0 +++
可以看到从 strace attached 开始,到进程退出,所有重要的调用都被打印出来了。
在 iOS 下,没有 strace,但是可以使用类似的(更好的)命令 dtruss。
lsof
lsof 可以打印某进程打开的文件,而 Linux 下面一切都是文件,因此查看打开的文件列表有时可以获取很多额外的信息。比如,打开前面提到的这个测试进程:
lsof -p 16872 COMMAND PID USER FD TYPE DEVICE SIZE/OFF NODE NAME Python 16872 xxx cwd DIR 1,5 2688 1113586 /Users/xxx Python 16872 xxx txt REG 1,5 51744 10627527 /System/Library/Frameworks/Python.framework/Versions/2.7/Resources/Python.app/Contents/MacOS/Python Python 16872 xxx txt REG 1,5 52768 10631046 /System/Library/Frameworks/Python.framework/Versions/2.7/lib/python2.7/lib-dynload/_locale.so Python 16872 xxx txt REG 1,5 65952 10631134 /System/Library/Frameworks/Python.framework/Versions/2.7/lib/python2.7/lib-dynload/time.so Python 16872 xxx txt REG 1,5 841440 10690598 /usr/lib/dyld Python 16872 xxx txt REG 1,5 1170079744 10705794 /private/var/db/dyld/dyld_shared_cache_x86_64h Python 16872 xxx 0u CHR 16,2 0t39990 649 /dev/ttys002 Python 16872 xxx 1u CHR 16,2 0t39990 649 /dev/ttys002 Python 16872 xxx 2u CHR 16,2 0t39990 649 /dev/ttys002
它有几个参数很常用,比如-i,用来指定网络文件(如果是“-i: 端口号”这样的形式还可以指定端口)。