一个历时五天的 Bug

• 2019 年 10 月 6 日
• 笔记

一个程序员在没有成长成为架构师之前，几乎都要跟 Bug为伴，程序员有很多时间都是花在了查找各种 Bug上。

我印象深刻的一个Bug, 是一个服务器网络框架无锁队列的 Bug 。那个 Bug 连续查找了五天的时间，才最后定位出来。

当时我们的分布式存储系统出现了性能瓶颈，定位后发现瓶颈是在服务器网络框架上，所以我们决定为此替换一个最新研发的网络框架。这个新的网络框架为了追求高的性能，采用了无锁队列的设计。

第一天编码测试完成后。测试环境跑，完全正常，特地搞了一堆 log 来重放请求，程序跑得特别欢快。解决了当时的性能瓶颈，感觉特别的开心，但好景不长，服务部署到现网环境，跑不到一个小时，就 coredump 了。

尝试上线了几次，每次都是跑半个多小时，就 coredump 。

当时的第一反应是新网络框架的问题，这是很直觉的反应，但很快就产生了怀疑，因为这个框架也有其它模块在用，也没产生问题，当时觉得诡异了。

仔细查看了代码的修改记录，特定检查了版本管理系统的 log, 做了代码 diff, 确定确实只有这部分的修改。凭着经验，我说服自己，这个时候应该坚信最明确的逻辑，不要走到其他歪路上去。

第二天，我把这个框架单独拎了出来，特地写了一个测试的模块，并用测试代码生成了一堆的请求数据，发送给测试模块。它疯狂的运转起来，跑了一个多小时，跑得很欢快，一切正常，啥 Bug 都没有。

开大了并发，继续压，依然没有问题。懵逼了！不知咋回事。再次小心得灰度系统上线，跑不到一个小时还是 coredump 了， 这个时候，我开始怀疑人生了，这个是咋回事了，都想砸键盘了都。

然后我冷静了下来，经验告诉我，这时应该按照正常流程完整地跑一遍测试模块。于是我把那个测试模块打包成了现网模块，切走了一台现网机器的流量，把测试模块给上线到了一台现网机器。

之后用工具往现网机器发送数据，不到一个小时，coredump 了。终于复现了这个 cordedump, 那一刻犹如哥伦布发现了新大陆，简直欣喜若狂啊。这个时候已经是第三天了。

我复现了 Bug，但依然没办法定位出具体的原因。coredump 出来的栈是全乱的，没有任何价值，接下来，就开始用 log 跟踪法了。

我依据数据的流转过程，在每个关键点，都打上 log，log 包含了所在的函数，行数，程序逻辑的编号，全部的关键数据等等。我仔细地设计了这个log，争取打得不多不少，太多容易看晕头，而且太多无效的信息，会掩盖了真正的问题；太少，信息不足，又不足以判断，所以这种情况下打 log 也是个艺术活。

通过精心设计的 log, 终于发现数据在一个特定的环节混乱后，程序就一定会 coredump。分析log , 发现数据包在最后时刻是完整的，但包似乎出现了乱序和重复。这个时候，才开始意识到可能是无锁队列的问题，因为只有队列出问题，包的进出顺序才会乱掉。

然后又花了半天的时间，专门为无锁队列写了测试用例，用数据疯狂地怼。在测试环境，依然一切安好，但上线到正式环境，压测半小后，终于挂了。终于看到了胜利的曙光！这个时候已经是第四天了！

到现在已经很明确是无锁队列的问题了。但这个数据结构的代码不到 200行。我拉了两个同事一起 review，都没发现问题。但就是 coredump 了。

奇葩了，又陷入了人生怀疑，开始怀疑内存，怀疑 cpu，结果换了机器，还是一样。

后来，仔细地对比了现网环境和测试环境的区别，机器类型，操作系统版本都一样。然后编译器？咦！编译器？上去看了一下，结果发现编译器的版本不一样！这段时间我所使用的现网编译环境升级了新的 gcc 版本，但测试编译环境，还是旧的版本的。(这个也比较坑)

当时的直觉是肯定跟编译器相关，但代码都一样，难道是编译器bug？不可能吧 ？！　后来想，不如将它们转换成汇编看看吧。于是用两个版本的编译器将C的代码各自转换成了汇编。然后diff 汇编代码，哇！发现真的有一行是不同的！

后来自己分析对比，发现是因为我们开启了gcc最高级别的代码性能优化，不同版本的 gcc 在一些没有特定依赖的语句上的优化是不同的。

说人话，就是有一段代码，如果加了锁，两个版本的编译器下，都会产生一样的汇编，如果没有加锁，代码有一行的顺序被调整了，当然，从编译器优化的角度讲是对的，是我们使用姿势不对。

但无论怎么样，终于找出了这个问题。苍天啊! 找了五天呀! 最后当然是开开心心地上线了。

查这个bug 确实花费了很多的时间，不过也是没办法，你不解决bug，就不能上线，但中间也收获不少，特别是对编译器优化有了很深的印象，也算是为自己的查 Bug 能力，又贡献了一波经验吧。

对于 Bug , 我分享下自己的一些认识和建议。

面对 Bug 的态度

只要你持续地写代码，就一定会持续的产生 Bug，所以第一个事情是要摆正对 Bug 的心态。我遇到过两个极端。

第一个极端。

遇到过一个leader，对系统质量相当重视，对我们写的代码要求很高，每次设计并写完一个新的系统，他喜欢跟你算这次的系统上线，产生了多少次故障，这半年时间产生了多少个 Bug，每个 Bug 的影响范围如何。

我们一堆人被搞得特别累，战战兢兢，到后面，大家都比较排斥去做优化，去重构代码，只求无过，不求有功了。所以，我觉得这种方式不好，对 Bug 带着一种比较包容的态度去看待，可以减少不少的心理负担。

第二个极端。

后来去了一个新的团队。新的团队很重视业务和工程迭代的速度，所以对代码质量和 Bug 的容忍度很高。如果是一个新上线的业务，是默许 Bug 存在的。

这种对质量过于松散的要求，在后面也带来不好的影响。大家对 Bug 太免疫了，以至于出现 Bug 和 故障的时候，大家都不够紧张。系统质量有一段时间出现比较大的问题，还因此被部门经理特训了一番，后面通过各种措施，才慢慢提高了整体的系统质量。

上面两种极端都不可取，应该很重视 Bug，尽量避免 Bug，但也不应该唯 Bug 多少论业绩。

具体到 Bug 的查找上，我说说我的一些经验。

Bug 的复现

我把 Bug 分为可重现的 Bug 和不可复现的 Bug 。

对于可重现的 Bug , 查找起来比较容易，比如可以用”二分查找“的方式，从模块层面开始定位起，每次折半，每次折半地缩小范围，一直到代码层面。

在代码层面，遵循一些常用的原则：比如看到内存拷贝，直觉上要想到内存越界；看到数组，就要考虑是否索引越界；看到指针，就要考虑是否正确解构；看到多线程，就要考虑是否线程安全；

对于不可重现的 Bug , 第一步就是要把它重现出来。有时候特别的难，特别是并发形态下产生的 Bug ，出现的时机和触发条件都不清楚。对于这种 Bug ，只能通过各种尝试去复现它。

比如将多并发调整为单并发的方式，看能否复现，如果可以复现，就可以转化为可复现的 Bug ，用”二分查找“的方式去排查。

如果不能复现，那极大概率是并发问题。这个时候最好先停止排查，仔细分析程序在并发状态下可能出问题的点。大部分并发问题的根源，是互斥数据没有被正确读写，或者一些共享状态被错误修改。

静态代码检查

利用coverity等代码检查工具进行代码的静态检查可以发现很多潜在的问题，而且修复的成本很低。团队后来引入了这个检查工具，确实带来了不错的效果。类似变量未初始化，疑似的内存越界等都有可能被检查出来。

编译器的 warning。有些同学一开始的时候对 warning 不重视。我们团队早期也遇到过这个情况。

那时候产品迭代的速度很快，所以大家写完代码，能够编译通过，就进行各种测试，然后准备上线了。一开始的一两个warning, 不太理会。后面发现越积越多，到最后终于成为一个不得不解决的问题。

部门还为此特地立项，来消除warning。先是在内部多次强调了这个理念，然后从基础库，基础模块开始实施，基础代码部分统一 fix warning, 然后开启编译器把 warning 当 error 的开关。完成之后，再逐步地推业务模块进行修改。反正折腾了好一段时间。

工欲善其事必先利其器

代码 Bug 出现的时候，善用一些排查工具可以极大得提升效率。比如对于C/C++ 的 gdb 调试，内存泄漏时候 valgrind 的检测，linux 下面用 perf top 来析 cpu 的消耗等。

一开始的时候，我对这些工具不重视，老是觉得真正使用的时候，去查文档就行。后面才发现，用工具查着问题时候，遇到不会用的命令或功能，再去查文档，是个痛苦的事情，来回切换的开销也使得效率低下。

后面就对这些辅助工具的使用重视了起来。，专门花时间去学习和练习使用，反而提升了不少的效率

打 log 的艺术

很多时候，出现一个 Bug，未能定位出来，需要打上更多额外的 log 来辅助排查。一开始的时候，是想到一点，打一个 log，后面发现这么做没有章法，逻辑不清晰, 排查效率低下。

后来学会了，遇到 Bug 后，先在脑子里面分析一番，然后花一两个小时详细地设计 log 的格式和打 log 的位置。发现这种方式对查问题的效率提升很大。

所以遇到 Bug 的时候不要急躁，先静下来心来分析，在脑海里尽力重现出完整的运行逻辑，然后仔细地进行 log 设计，包括 log 包含的字段，打 log 的点等。这样能极大的提升排查问题的效率。

结语

Bug 是程序员最不愿意用面对，但又经常出现的一个 “诡异生物“。对待Bug 要有正确的心态，最好不要跟业绩强绑定，也不能太过于疏忽。Bug 的排查是个很复杂的事情，每个人都有自己的方式和做法，如果你有好的做法和建议，也欢迎在留言区分享给大家！