call stack是什么错误_一次调试段错误(segmentation fault)的经验

最新推荐文章于 2023-06-29 18:53:33 发布

weixin_39758956

最新推荐文章于 2023-06-29 18:53:33 发布

阅读量864

点赞数

文章标签： call stack是什么错误

本文首发于微信公众号「Python之美」: https:// mp.weixin.qq.com/s/na1W k3hZii-792IFprkV5Q

段错误(segmentation fault)的发生是由于C模块试图访问无法访问的内存。如果没有尝鲜最新的CPython或者类库或者编写C/C++扩展，段错误对Python开发者来说可以说可遇不可求，因为CPython和主流第三方类库的测试完善且社区活跃所以很难看到，即便看到了往往也已经被修复了。

昨天恰好遇到一个，所以把整个调试解决过程整理成本文。

问题

我准备在博客应用lyanna的v3.0版本时支持Python 3.8最新的海象运算符，所以拉取了最新的CPython源码并编译，在lyanna项目中使用它创建虚拟环境并安装依赖。问题就出在安装依赖过程中:

❯ virtualenv venv --python=python3.8
❯ source venv/bin/activate
❯ pip install -r requirements.txt
...
Installing collected packages: aiomcache
  Running setup.py develop for aiomcache
    ERROR: Command errored out with exit status -11:
     command: /Users/dongweiming/lyanna/venv/bin/python3.8 -c 'import sys, setuptools, tokenize; sys.argv[0] = '"'"'/Users/dongweiming/lyanna/venv/src/aiomcache/setup.py'"'"'; __file__='"'"'/Users/dongweiming/lyanna/venv/src/aiomcache/setup.py'"'"';f=getattr(tokenize, '"'"'open'"'"', open)(__file__);code=f.read().replace('"'"'rn'"'"', '"'"'n'"'"');f.close();exec(compile(code, __file__, '"'"'exec'"'"'))' develop --no-deps
         cwd: /Users/dongweiming/lyanna/venv/src/aiomcache/
    Complete output (10 lines):
    running develop
    running egg_info
    writing aiomcache.egg-info/PKG-INFO
    writing dependency_links to aiomcache.egg-info/dependency_links.txt
    writing top-level names to aiomcache.egg-info/top_level.txt
    reading manifest file 'aiomcache.egg-info/SOURCES.txt'
    reading manifest template 'MANIFEST.in'
    warning: no previously-included files matching '*.pyc' found anywhere in distribution
    warning: no previously-included files matching '*.swp' found anywhere in distribution
    writing manifest file 'aiomcache.egg-info/SOURCES.txt'
...

这里并没有抛出段错误，输出还是很让人困惑的，我查了下退出码11(延伸阅读链接1)表示段错误，当然还可以直接执行复现:

❯ python /Users/dongweiming/lyanna/venv/src/aiomcache/setup.py develop
...
[1]    93545 segmentation fault  python3.8 /Users/dongweiming/lyanna/venv/src/aiomcache/setup.py develop

和Python代码报错有详细的堆栈不一样，段错误的输出不带任何有帮助的信息，不能确定是哪行代码引起的。

faulthandler模块

看到错误立刻想起来之前看过的faulthandler模块，它是Python 3.3加入的，我尝试通过它获得堆栈。首先把下面代码写入setup.py头部:

import faulthandler; faulthandler.enable()
# 下面是原来的代码
import codecs
...

然后运行它：

❯ python -Xfaulthandler /Users/dongweiming/lyanna/venv/src/aiomcache/setup.py develop
# 或者: PYTHONFAULTHANDLER=1 /Users/dongweiming/lyanna/venv/src/aiomcache/setup.py develop
...
Fatal Python error: Segmentation fault

Current thread 0x000000010fe73dc0 (most recent call first):
  File "<frozen importlib._bootstrap>", line 219 in _call_with_frames_removed
  File "<frozen importlib._bootstrap_external>", line 1109 in exec_module
  File "<frozen importlib._bootstrap>", line 671 in _load_unlocked
  File "<frozen importlib._bootstrap>", line 975 in _find_and_load_unlocked
  File "<frozen importlib._bootstrap>", line 991 in _find_and_load
  File "/Users/dongweiming/lyanna/venv/lib/python3.8/site-packages/Cython/Compiler/Main.py", line 28 in <module>
  File "<frozen importlib._bootstrap>", line 219 in _call_with_frames_removed
  File "<frozen importlib._bootstrap_external>", line 783 in exec_module
  File "<frozen importlib._bootstrap>", line 671 in _load_unlocked
  File "<frozen importlib._bootstrap>", line 975 in _find_and_load_unlocked
  ...

这次的输出可谓详细了很多，注意堆栈顺序和Python代码的相反: 引起错误的在顶部。

看了下importlib._bootstrap的代码没看出来有问题，而且堆栈提到的这些是Python代码的应该不是它。不过这次的堆栈之后要考，大家看看能不能联想到什么？其实这里已经隐隐的显示了问题。

怀疑aiomcache代码兼容性问题

接着想到的第一个搜索点就是aiomcache，但是翻了下aiomcache代码，它和其依赖中没有C扩展，那应该不是，另外试了下install没有问题:

❯ python /Users/dongweiming/lyanna/venv/src/aiomcache/setup.py install
... # 正常
Installed /Users/dongweiming/lyanna/venv/lib/python3.8/site-packages/aiomcache-0.6.0-py3.8.egg
Processing dependencies for aiomcache==0.6.0
Finished processing dependencies for aiomcache==0.6.0

那可以确定不是aiomemcache，这个时候我想到:

是setuptools(在setup.py中会用到)及其依赖中的C扩展(在Python3.8下)问题
最新的CPython代码问题

怀疑最新的CPython代码问题

等大家看完全文会发现这里偏了，因为按照几率来说肯定是第三方的库更不靠谱一点... 不过也是合理的，想尝鲜就是非常可能遇到各种还没有人踩到的坑。此时我心中一怔，顺便给CPython改C代码的机会来的，激动！！

由于这种心情的撺掇，调试方向的天平倾向了CPython而不是看setuptools依赖链。

接着我加了DEBUG标记重新编译了CPython:

❯ ./configure CFLAGS='-DPy_DEBUG' --with-pydebug && make && make install

这次最终没有抛段错误，执行正常，很奇怪。接着我不带标记重新编译，上面的错误又重现了，不过我在调试过程发现直接用CPython源码目录下编译好的python执行正常:

❯ ~/cpython/python.exe /Users/dongweiming/lyanna/venv/src/aiomcache/setup.py develop

也就是说用什么都没做的裸Python正常，但是在虚拟环境中的Python本来也正常，但是安装了一堆依赖后就不正常

直观上，我已经觉得和CPython 3.8的源码无关了(＃￣～￣＃)，但谁引起的段错误还不清楚。

https://appv72m4Msi7516.h5.xiaoeknow.com (二维码自动识别)

GDB大法

对于调试Python代码，我基本上都会用print，连pdb也用的很少。如果是C接口有问题，就需要使用gdb了。另外gdb也可以用于调试正在运行的Python进程。

在macOS下使用Homebrew安装gdb:

❯ brew install gdb

不过此时GDB只有基本的Python支持，如果你自己编译GDB记得加上--with-python选项。接着我们要把CPython项目中的libpython.py里面提供的命令加进来:

❯ gdb python3
GNU gdb (GDB) 8.3
...
(gdb) python  # Python解释器
>import sys  # 和写Python代码一样
>sys.path.insert(0, '/Users/dongweiming/cpython/Tools/gdb')  # 把包含libpython.py文件的目录加到sys.path里
>import libpython  # 导入
>end  # 结束Python
(gdb) py  # 按Tab就可以看到支持多个py-开头的命令了
py-bt               py-down             py-locals           py-up               python-interactive
py-bt-full          py-list             py-print            python

导入libpython的缺点是每次进入gdb都得执行一次，另外一个方法是写入到GDB初始化文件.gdbinit中:

source ~/cpython/Tools/gdb/libpython.py

libpython的作用是让PyObject*的输出更容易理解，另外新加了上面看到的命令具体用法可以看延伸阅读链接2。

另外CPython官方也维护了一个Misc/gdbinit文件(见延伸阅读链接3)，其中提供了pystack、pyframe、lineno等命令，它们是针对gdb 7之前的版本，我安装的是当前最新的GDB 8.3，就不需要了

这里要注意一个细节，加了配置后抛段错误前会卡住，需要在.gdbinit里面加这么一句:

set startup-with-shell off

Ok, 配置已经完成了，现在运行这个有问题的命令:

❯ gdb python3
(gdb) run /Users/dongweiming/lyanna/venv/src/aiomcache/setup.py develop
Starting program: /Users/dongweiming/lyanna/venv/bin/python3 /Users/dongweiming/lyanna/venv/src/aiomcache/setup.py develop
Unable to find Mach task port for process-id 8888: (os/kern) failure (0x5).
 (please check gdb is codesigned - see taskgated(8))

这是由于权限问题，需要给gdb签一个证书。步骤如下(也可以参考延伸阅读链接5里的内容):

启动Keychain Access应用程序
从菜单选择Certificate Assistant -> Create a Certificate
新加一个证书，名字就叫gdbcert(之后还要用到)，身份类型self-signed root，证书类型Code Signing，「Let me override defaults」不用勾，然后create
创建一个XML文件(gdb.xml)，内容如下:

<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE plist PUBLIC "-//Apple//DTD PLIST 1.0//EN" "http://www.apple.com/DTDs/PropertyList-1.0.dtd">
<plist version="1.0">
<dict>
    <key>com.apple.security.cs.debugger</key>
    <true/>
</dict>
</plist>

更新代码签名: codesign --entitlements gdb.xml -fs gdbcert /usr/local/bin/gdb

现在就可以正常使用了:

❯ cd ~/cpython
(gdb) run /Users/dongweiming/lyanna/venv/src/aiomcache/setup.py develop
Starting program: /Users/dongweiming/lyanna/venv/bin/python3 /Users/dongweiming/lyanna/venv/src/aiomcache/setup.py develop
[New Thread 0x1a03 of process 35316]
[New Thread 0x2603 of process 35316]
warning: unhandled dyld version (16)
...

Thread 2 received signal SIGSEGV, Segmentation fault.
0x0000000100026c04 in PyCode_NewWithPosOnlyArgs (argcount=1, posonlyargcount=0, kwonlyargcount=0,
    nlocals=0, stacksize=1, flags=0, code=<unknown at remote 0x3>, consts=b'', names=(), varnames=(),
    freevars=('self',), cellvars=(), filename=(), name='Cython/Compiler/Scanning.py',
    firstlineno=28646256, lnotab=<unknown at remote 0x42>) at Objects/codeobject.c:121
121         code == NULL || !PyBytes_Check(code) ||   # 可以看到是这里引起的段错误
(gdb) bt  #  回溯堆栈。frame0是栈顶，id越大顺序越靠前，也就是说PyCode_New里面调用了PyCode_NewWithPosOnlyArgs最终引发段错误
#0  0x0000000100026c04 in PyCode_NewWithPosOnlyArgs (argcount=1, posonlyargcount=0, kwonlyargcount=0,
    nlocals=0, stacksize=1, flags=0, code=<unknown at remote 0x3>, consts=b'', names=(), varnames=(),
    freevars=('self',), cellvars=(), filename=(), name='Cython/Compiler/Scanning.py',
    firstlineno=28646256, lnotab=<unknown at remote 0x42>) at Objects/codeobject.c:121
#1  0x00000001000273f7 in PyCode_New (argcount=1, kwonlyargcount=3, nlocals=25499040, stacksize=1,
    flags=0, code=0x0, consts=b'', names=(), varnames=(), freevars=('self',), cellvars=(), filename=(),
    name='Cython/Compiler/Scanning.py', firstlineno=28646256, lnotab=<unknown at remote 0x42>)
    at Objects/codeobject.c:253
#2  0x0000000103b84fe2 in ?? ()
#3  0x00000001018515a0 in ?? ()
#4  0x00000001004b6040 in ?? ()
#5  0x00000001004b6040 in ?? ()
#6  0x0000000103b4c070 in ?? ()
...
(gdb) frame 0  # 切换到栈顶
...
(gdb) list  # 查看栈顶的代码，注意121行
116
117     /* Check argument types */
118     if (argcount < posonlyargcount || posonlyargcount < 0 ||
119         kwonlyargcount < 0 || nlocals < 0 ||
120         stacksize < 0 || flags < 0 ||
121         code == NULL || !PyBytes_Check(code) ||  相关的是code这个参数
122         consts == NULL || !PyTuple_Check(consts) ||
123         names == NULL || !PyTuple_Check(names) ||
124         varnames == NULL || !PyTuple_Check(varnames) ||
125         freevars == NULL || !PyTuple_Check(freevars) ||
(gdb) frame 0  # 切回栈顶，这个输出内容很多，由于libpython的作用，参数的值更明确了
#0  0x0000000100026c04 in PyCode_NewWithPosOnlyArgs (argcount=1, posonlyargcount=0, kwonlyargcount=0,
    nlocals=0, stacksize=1, flags=0, code=<unknown at remote 0x3>, consts=b'', names=(), varnames=(),
    freevars=('self',), cellvars=(), filename=(), name='Cython/Compiler/Scanning.py',
    firstlineno=28646256, lnotab=<unknown at remote 0x42>) at Objects/codeobject.c:121
121         code == NULL || !PyBytes_Check(code) ||
(gdb) p code
$1 = <unknown at remote 0x3>
# 可以看到大部分参数是Python对象，但是要注意其中code的参数看起来是一个很怪的内存地址，看一下下个栈:
(gdb) up
#1  0x00000001000273f7 in PyCode_New (argcount=1, kwonlyargcount=3, nlocals=25499040, stacksize=1,
    flags=0, code=0x0, consts=b'', names=(), varnames=(), freevars=('self',), cellvars=(), filename=(),
    name='Cython/Compiler/Scanning.py', firstlineno=28646256, lnotab=<unknown at remote 0x42>)
    at Objects/codeobject.c:253
253     return PyCode_NewWithPosOnlyArgs(argcount, 0, kwonlyargcount, nlocals,
# 注意code的值0x0，应该是这个内存地址有问题。

注意code的值0x0，应该是这个内存地址有问题，因为它不像stacksize、flags、consts等参数那样可读。不过到这里卡住了，我循着frame又向前看了一遍，没看出来CPython的问题

sys.settrace

既然CPython这方面没有收获，换个思路，用sys.settrace试试把整个执行代码的过程都打印出来。在setup.py里面加入下面代码:

import sys

def trace(frame, event, arg):
    print("%s, %s:%d" % (event, frame.f_code.co_filename, frame.f_lineno))
    return trace

sys.settrace(trace)
# 下面是原来的代码
import codecs  #
...

然后执行:

❯ python /Users/dongweiming/lyanna/venv/src/aiomcache/setup.py develop  # 执行时间略长，等1分钟
... # 输出非常长，省略
line, /Users/dongweiming/lyanna/venv/lib/python3.8/site-packages/Cython/Compiler/Main.py:28
...
line, <frozen importlib._bootstrap>:671
call, <frozen importlib._bootstrap_external>:1107
line, <frozen importlib._bootstrap_external>:1109
call, <frozen importlib._bootstrap>:211
line, <frozen importlib._bootstrap>:219
[1]    7125 segmentation fault  python /Users/dongweiming/lyanna/venv/src/aiomcache/setup.py develop

大家还记得一开始用faulthandler模块输出的堆栈么？这个要具体的多，不过我由捕捉到了Cython这部分，这是出现错误前最后一个出现的和C有关的模块。

我突然来了灵感: 「是不是什么Python 3.8的修改对Cython的逻辑有影响？」Python3.8已经上了一段时间，相信有别人已经用了一段时间了，不过去Cython项目下没找到对应issue，因为这个不能明确的对应到是Cython引起的。我就顺手升级下Cython试试:

❯ pip freeze |grep -i cython
Cython==0.29.13

❯ pip install -U cython
...
Successfully installed cython-0.29.14

从0.29.13升到了0.29.14，去掉sys.settrace部分代码再试一下:

❯ python /Users/dongweiming/lyanna/venv/src/aiomcache/setup.py develop
...
Finished processing dependencies for aiomcache==0.6.0

Emm, 正常了 O(∩_∩)O！之后我翻了下这次cython更新的改变，但由于改动太多还是没有找到具体的问题，另外一个让我疑惑的是，用另外一个电脑没有过问题。不过问题算是解决了，先这样。

别急，还有后续

现在依赖都装好了，启动应用:

❯ python app.py
[1]    10396 segmentation fault  python app.py

心情down到了谷底。用gdb看还是类似的错误，不过换用faulthandler后看到了新的问题:

❯ python app.py
Fatal Python error: Segmentation fault

Current thread 0x000000010b4e3dc0 (most recent call first):
...
File "/Users/dongweiming/lyanna/venv/lib/python3.8/site-packages/yaml/cyaml.py", line 7 in <module>
...
[1]    12363 segmentation fault  python app.py

也就是yaml有问题了。按之前的套路，先升级看看:

❯ pip freeze |grep -i yaml
PyYAML==5.1.2

❯ pip install -U PyYAML
...
Successfully installed PyYAML-5.2

再启动:

❯ python app.py
[2019-12-11 13:19:03 +0800] [14690] [DEBUG]

                 Sanic
         Build Fast. Run Fast.


[2019-12-11 13:19:03 +0800] [14690] [INFO] Goin' Fast @ http://0.0.0.0:8000

还没有结束

2个段错误都以升级包而解决，不过这也太巧了吧？此时我怀疑是pip cache引起的，很早前我就在编译安装Python3.8，所以我在想是不是由于pip缓存的缘故，使用了之前编译的包，而距离上次编译之后Python3.8又做了不兼容的修改？所以我做了如下尝试:

❯ pip install cython==0.29.13  # 安装回之前有问题的包
Processing /Users/dongweiming/Library/Caches/pip/wheels/5b/1e/17/15dd6d435ec0644967eb8e1493af09ae28cd94184c6f416d02/Cython-0.29.13-cp38-cp38-macosx_10_14_x86_64.whl  # 注意这句，用了缓存
❯ python /Users/dongweiming/lyanna/venv/src/aiomcache/setup.py develop  # 还是会抛出段错误
...
[1]    33909 segmentation fault  python /Users/dongweiming/lyanna/venv/src/aiomcache/setup.py develop
❯ rm /Users/dongweiming/Library/Caches/pip/wheels/5b/1e/17/15dd6d435ec0644967eb8e1493af09ae28cd94184c6f416d02/Cython-0.29.13-cp38-cp38-macosx_10_14_x86_64.whl  # 删除本地编译好的包
❯ pip uninstall cython  # 卸载Cython-0.29.13
❯ pip install cython==0.29.13  # 重新安装
❯ python /Users/dongweiming/lyanna/venv/src/aiomcache/setup.py develop
...
Finished processing dependencies for aiomcache==0.6.0

这次一切正常，猜对了，这也解释了为什么用另外一个电脑不能复现。不过等等，我突然意识到了问题:

❯ sw_vers -productVersion
10.15.1

什么意思呢？我最近升级了系统到Catalina 10.15.1，但是安装包时会使用10.14时编译的包

搜了下本地有错误的whl包:

❯ find /Users/dongweiming/Library/Caches/pip/wheels -name "*cp38-cp38-macosx_10_14_x86_64.whl"
/Users/dongweiming/Library/Caches/pip/wheels/3b/13/4a/e6b972b23b1d7fca074f2ef681b3c819123b842cf1b4de8627/ciso8601-2.1.2-cp38-cp38-macosx_10_14_x86_64.whl
/Users/dongweiming/Library/Caches/pip/wheels/f2/aa/04/0edf07a1b8a5f5f1aed7580fffb69ce8972edc16a505916a77/MarkupSafe-1.1.1-cp38-cp38-macosx_10_14_x86_64.whl
/Users/dongweiming/Library/Caches/pip/wheels/28/77/e4/0311145b9c2e2f01470e744855131f9e34d6919687550f87d1/ujson-1.35-cp38-cp38-macosx_10_14_x86_64.whl

虽然这次没因为他们抛出段错误，不过正好可以当做调试pip的badcase 罒ω罒

虽然没给CPython贡献代码，给pip贡献一下也好，具体PR是: https://github.com/pypa/pip/pull/7466

更新

给pip提了PR后，维护者说编译的包应该是向前兼容的，所以这不是pip的问题。emm，等我有时间帮助复现一下~