用GDB排查Python程序故障

标题: MISC系列(43)–用GDB排查Python程序故障

创建: 2015-09-21 16:40

更新:

某Team在用Python开发一些代码,涉及子进程以及设法消除僵尸进程的需求。实践中他们碰上Python程序非预期退出的现象。最初他们决定用GDB调试Python解释器,查看exit()的源头。我听了之后,觉得这个问题应该用别的调试思路。帮他们排查这次程序故障时,除去原始问题,还衍生了其他问题。

这次的问题相比西安研发中心曾经碰上的Python信号处理问题,有不少基础知识、先验知识是共用的,此处不做再普及,感兴趣的同学可以翻看我以前发过的文章。

下文是一次具体的调试、分析记录。为了简化现场、方便调试,已将原始问题、衍生问题浓缩成DebugPythonWithGDB_6.py、DebugPythonWithGDB_7.py。

$ vi DebugPythonWithGDB_6.py

流程进入on_SIGCHLD(),但os.waitpid()抛出OSError异常。帮助里写的是,如果系统调用waitpid()返回-1,就抛出异常: An OSError is raised with the value of errno when the syscall returns -1. 10245号子进程在on_SIGCHLD()里waitpid()成功,(10245, 9)中的9表示该进程是被SIGKILL干掉的,符合预期。 10246号子进程是do_more()里的os.system()产生的shell进程,它结束时向10244号父进程投递了SIGCHLD信号。on_SIGCHLD()里waitpid()时,已经在别处wait*()过,10246号子进程已经彻底消失,系统调用waitpid()返回-1,Python函数os.waitpid()抛出异常。 整个过程非常复杂,用伪代码描述如下:

整个过程之所以如此复杂,主要是因为Python的信号处理机制比较复杂,让已经非常复杂的Linux信号机制再添变数。参看:

就本例而言,为了确保DebugPythonWithGDB_6.py不因OSError异常而终止,只需在on_SIGCHLD()中调用os.waitpid()时捕捉OSError异常:

前述观点有些是动态调试得到,有些是静态分析得到。有人可能问了,为什么不拦截Python进程的C级信号句柄,查看SIGCHLD信号源,以此确认10246号子进程可能被回收两次?其实我最初也想这么干来着,但这是行不通的,因为Python的C级信号句柄signal_handler()是那种最原始的单形参信号句柄,不是高大上的三形参信号句柄。 用GDB调试Python解释器:

查看#4的system.c:161,这个位置已经在waitpid( pid, &status, 0 )之后: sigprocmask( SIG_SETMASK, &omask, (sigset_t *)NULL ) 其作用是取消对SIGCHLD的屏蔽(阻塞)。 此时内存布局如下:

因为是单形参信号句柄,没有siginfo,无法在用户态获知信号源。但我分析此时的信号源不是10289号子进程,而是10288号子进程。10288产生SIGCHLD时,SIGCHLD信号已被屏蔽(阻塞),只能保持在内核态的未决信号链上。之后待10289产生SIGCHLD时,sigpending.signal中相应位已经置位,10289产生的SIGCHLD被丢弃,不会进入内核态的未决信号链。SIGCHLD信号的屏蔽(阻塞)被取消后,从内核态的未决信号链上取出10288产生的SIGCHLD进行处理。于是断点命中。 如果完全理解了前述实验结果及分析,就会发现DebugPythonWithGDB_6.py存在竞争条件。subprocess.Popen()对应的子进程投递SIGCHLD信号时,父进程有两种可能:

情况1)会触发OSError异常,情况2)不会触发OSError异常。执行: $ python DebugPythonWithGDB_6.py ‘python -c “import time;time.sleep(3600)”‘ 有时会因OSError异常而终止,有时就一直循环执行下去。出现这种差异,正是竞争环境的表征。 小结一下: 假设针对SIGCHLD安装了Python级信号句柄,其调用os.waitpid( -1, os.WNOHANG )回收子进程。如果别处会调用os.system(),则必须在os.waitpid()外侧捕捉OSError异常。不建议这种方式的混用。 对waitpid()的分析到此就结束了,说点调试过程中出现的其他问题。 意外地发现Ctrl-C无法终止情况2),而我已经调用: signal.signal( signal.SIGINT, signal.SIG_DFL ) 这是因为do_system()中一上来就调用了:

导致Ctrl-C暂时失效,直至do_system()结束。假设DebugPythonWithGDB_6.py已经出 现情况2),查看它的信号处理方式:

上面显示SIGINT的处理方式是ignored,其实是ignored、default交叉出现,但我们 基本上不可能看到default。 $ vi DebugPythonWithGDB_7.py

$ python DebugPythonWithGDB_7.py ‘python -c “import time;time.sleep(3600)”‘ DebugPythonWithGDB_7.py没有显式调用wait(),它一直循环执行下去。我以为subprocess.Popen()会生成一堆僵尸进程。从另一个终端查看相关进程,发现始终只有一个僵尸进程,很快就被回收了。这个现象挺奇特,只能假设有隐式wait()存在。

调用栈回溯表明:

捕获

查看: /usr/lib/python2.7/subprocess.py:1363

考虑这种情形,调用subprocess.Popen()之前做过如下动作之一:

_internal_poll()调用_waitpid()时,在外侧捕捉了_os_error异常,就是对付上述可能。subprocess.Popen()不是built-in函数,对应很多条PVM指令,不像os.system()是built-in函数,对应单条PVM指令。前者执行过程中,Python级信号句柄on_SIGCHLD()有很大机会得到执行,_internal_poll()调用_waitpid(),遭遇_os_error异常的可能性不低。 Popen()对象的析构函数自动调用wait*(),于是Popen()对象离开作用域时自动回收子进程。 Python能够改变变量作用域的是def、class、lamda、global。下面这些并不涉及作用域变更:

DebugPythonWithGDB_7.py中Popen()对象的作用域是main()。尽管没有离开作用域,但对child变量的重新赋值会触发对前一个Popen()对象的析构。这就解释了为什么始终只有一个僵尸进程。 回顾原始问题与衍生问题,再次表明,掌握对Python解释器的调试技术可以快速排查众多看似神秘实则基础的程序故障。

发表评论