被这个 Python 并发 bug 折磨了两天后,我决定把这五个排查方法写下来.
上周三晚上十一点,我盯着屏幕上的报错信息,心里只有一个念头:这破代码到底哪里出了问题?
那是一个用 Python 写的并发下载程序,功能就是把几百个文件从服务器拉下来。逻辑看起来没问题,锁也加了,线程池也调了参数。可它就是隔三差五地崩,有时候跑十分钟,有时候跑两小时。崩溃也没有固定规律,报错信息每次都不一样,有时候是 FileNotFoundError,有时候是 AttributeError,最离谱的一次报了个 KeyError,明明字典里那个键我确认过存在。
第一天我以为是网络波动,加了重试机制。没用。
第二天我觉得是文件被重复创建的问题,给每个线程单独分配了临时目录。还是崩。
到第三天凌晨,我彻底服了。泡了杯浓茶,把能想到的排查方法全过了一遍。最后发现是一个特别蠢的错误——共享变量没有做线程安全写入。就这么一行代码的疏忽,让我两天没睡好觉。
现在把排查过程写下来,希望对你有用。
方法一:加日志,加详细的日志。
很多人觉得加日志是浪费时间,其实不是。并发 bug 最难的地方在于它不可重现。你要是只靠打印几个关键节点,根本看不出问题在哪里。我当时在每个线程开始时打印了线程 ID 和当前时间,结束时也打印。中间每个操作,包括读取文件、写入缓存、更新状态,全都打上时间戳。崩溃前最后几条日志,直接暴露了两次对同一文件描述符的写操作。这就找到了突破口。
日志级别用 DEBUG,别怕多。硬盘写不坏。
方法二:缩小并发范围,逐个隔离。
这是一个笨办法,但很管用。把线程数改成 1,看崩不崩。不崩,说明是并发问题。再把线程数改成 2,如果还不崩,加到 4。这样慢慢往上加,直到问题出现。我当时发现线程数 4 以下完全正常,到 6 就开始随机崩溃。这就说明问题跟线程数量有关,不是每个线程自身的逻辑有问题。
然后下一步,只让线程执行部分操作。比如先只做下载不要写文件,看它崩不崩。我试了之后发现只下载不保存的时候一切正常。那就是保存文件这部分出问题了。
最后定位到:多个线程同时更新了一个全局状态字典,我没有加锁也没有用线程安全的类型。
方法三:用 Python 的 faulthandler 抓崩溃现场。
有些崩溃直接导致进程退出,连日志都没来得及写。这时候 faulthandler 能帮上大忙。在代码最开头加上 import faulthandler; faulthandler.enable(),之后如果发生 segfault 或者致命错误,它会自动把当前所有线程的调用栈写到一个文件里。我用了这个方法后,发现有一个线程在写入文件时,文件句柄已经被其他线程关闭了。这个错误如果只靠日志根本抓不到,因为日志本身可能没来得及刷新进程就挂了。
方法四:不要相信全局变量,哪怕你只读它。
很多人会想,我只是读一个全局变量,没写它,总安全了吧?不一定。Python 的 list.append 和 dict.update 其实都有写操作。你看着是读,底层可能改动了对象内部的状态。更隐蔽的是,当你获取一个全局列表的长度时,如果另一个线程正在往里面添加元素,你拿到的长度可能是错误的。这个问题在我的代码里没有直接表现出来,但我排查过程中发现,len(some_list) 确实在两个线程同时调用时返回过异常小的值。解决方案很简单:一律用线程安全的数据结构,或者简单粗暴加一把锁。
不要嫌加锁影响性能,出一次 bug 损失的时间远大于那点锁的开销。
方法五:在测试环境复现,生产环境不要直接改。
这个建议可能听起来很基础,但在压力下比较容易犯错。我当时崩溃了两次后,直接在生产服务器上改了代码继续跑。结果第三次崩溃的时候,日志记录因为某些原因被截断了,我在生产环境留下的调试信息根本不够用。后来我老老实实在测试机器上搭建了同样的环境,用同样的数据跑。跑了一整夜,抓到几百行日志,终于找到了规律:每当日志里出现两个线程的“开始写入”时间差距小于 0.001 秒时,接下来大概率会出现错误。
这说明锁的颗粒度不够细,或者锁使用不当。
我当初想着用 threading.Lock 保护了写操作,但是读操作没有保护。结果是:线程 A 抢到锁开始写,线程 B 在锁外面读到了一个中间状态,直接用了这个状态去执行后续代码,当然会出错。
最终修复就一句话:把读操作也放到锁里面。或者用 threading.RLock 代替普通锁,这样同一个线程可以重复进入锁区域,避免死锁。
改完之后跑了三个小时,没任何问题。跑了一天,也没问题。
说实话,这个 bug 折磨我两天的根本原因不是代码有多复杂,而是我一开始就想当然地认为“读不用加锁”。想当然害死人。如果你也遇到类似的问题,别急着怀疑是 Python 的并发机制有问题,99% 的情况是你对共享资源的访问遗漏了保护。
希望写出来的这五个方法能让你少熬两天夜。