高并发性能调试经验分享(上）

引文

4月份的时候看到一道面试题，据说是腾讯校招面试官提的：在多线程和高并发环境下，如果有一个平均运行一百万次才出现一次的bug，你如何调试这个bug？知乎原贴地址如下：
https://www.zhihu.com/question/43416744 .

遗憾的是知乎很多答案在抨击这道题本身的正确性，虽然我不是这次的面试官，但我认为这是一道非常好的面试题。当然，只是道加分题，答不上，不扣分。答得不错，说明解决问题的思路和能力要超过应届生平均水平。

之所以写上面这段，是因为我觉得大部分后台服务端开发都有可能遇到这样的BUG，即使没有遇到，这样的题目也能够激发大家不断思考和总结。非常凑巧的是，我在4月份也遇到了一个类似的而且要更加严重的BUG，这是我自己挖的一个很深的坑，不填好，整个项目就无法上线。现在已经过去了一个多月，趁着有时间，自己好好总结一下，希望里面提到的一些经验和工具能够带给大家一点帮助。

项目背景

我们针对nginx事件框架和openssl协议栈进行了一些深度改造，以提升nginx的HTTPS完全握手计算性能。
由于原生nginx使用本地CPU做RSA计算，ECDHE_RSA算法的单核处理能力只有400 qps左右。前期测试时的并发性能很低，就算开了24核，性能也无法超过1万。
核心功能在去年底就完成了开发，线下测试也没有发现问题。经过优化后的性能提升了几倍，为了测试最大性能，使用了很多客户端并发测试https性能。很快就遇到了一些问题：
第一个问题是nginx有极低概率（亿分之一）在不同地方 core dump。白天线下压力测试2W qps一般都要两三个小时才出一次core。每次晚上睡觉之前都会将最新的调试代码编译好并启动测试，到早上醒来第一眼就会去查看机器并祈祷不要出core，不幸的是，一般都会有几个到几十个core，并且会发现经常是在一个时间点集中core dump。线上灰度测试运行了6天，在第6天的早上才集中core dump了几十次。这样算来，这个core dump的概率至少是亿分之一了。
不过和面试题目中多线程不同的是，nginx采用的是多进程+全异步事件驱动的编程模式（目前也支持了多线程，但只是针对IO的优化，核心机制还是多进程加异步）。在webserver的实现背景下，多进程异步相比多线程的优点是性能高，没有太多线程间的切换，而且内存空间独立，省去线程间锁的竞争。当然也有缺点，就是异步模式编程非常复杂，将一些逻辑上连续的事件从空间和时间切割，不符合人的正常思考习惯，出了问题后比较难追查。另外异步事件对网络和操作系统的底层知识要求较高，稍不小心就容易挖坑。
第二个问题是高并发时nginx存在内存泄漏。在流量低的时候没有问题，加大测试流量就会出现内存泄漏。
第三个问题，因为我们对nginx和openssl的关键代码都做了一些改造，希望提升它的性能。那么如何找到性能热点和瓶颈并持续优化呢？
其中第一和第二个问题的背景都是，只有并发上万qps以上时才有可能出现，几百或者一两千QPS时，程序没有任何问题。

core dump的调试

首先说一下core的解决思路，主要是如下几点：
1.gdb及debug log定位，发现作用不大。
2.如何重现bug？
3.构造高并发压力测试系统。
4.构造稳定的异常请求。

gdb及debug log效率太低

因为有core dump ，所以这个问题初看很容易定位。gdb 找到core dump点，btrace就能知道基本的原因和上下文了。
core的直接原因非常简单和常见，全部都是NULL指针引用导致的。不过从函数上下文想不通为什么会出现NULL值，因为这些指针在原生nginx的事件和模块中都是这么使用的，不应该在这些地方变成NULL。由于暂时找不到根本原因，还是先解决CORE dump吧，修复办法也非常简单，直接判断指针是否NULL，如果是NULL就直接返回，不引用不就完事了，这个地方以后肯定不会出CORE了。
这样的防守式编程并不提倡，指针NULL引用如果不core dump，而是直接返回，那么这个错误很有可能会影响用户的访问，同时这样的BUG还不知道什么时候能暴露。所以CORE DUMP 在NULL处，其实是非常负责任和有效的做法。
在NULL处返回，确实避免了在这个地方的CORE，但是过几个小时又core 在了另外一个NULL指针引用上。于是我又继续加个判断并避免NULL指针的引用。悲剧的是，过了几个小时，又CORE在了其他地方，就这样过了几天，我一直在想为什么会出现一些指针为NULL的情况？为什么会CORE在不同地方？为什么我用浏览器和curl这样的命令工具访问却没有任何问题？
熟悉nginx代码的同学应该很清楚，nginx极少在函数入口及其他地方判断指针是否为NULL值。特别是一些关键数据结构，比如‘ngx_connection_t’及SSL_CTX等，在请求接收的时候就完成了初始化，所以不可能在后续正常处理过程中出现NULL的情况。
于是我更加迷惑，显然NULL值导致出CORE只是表象，真正的问题是，这些关键指针为什么会被赋值成NULL？
这个时候异步事件编程的缺点和复杂性就暴露了，好好的一个客户端的请求，从逻辑上应该是连续的，但是被读写及时间事件拆成了多个片断。虽然GDB能准确地记录core dump时的函数调用栈，但是却无法准确记录一条请求完整的事件处理栈。根本就不知道上次是哪个事件的哪些函数将这个指针赋值为NULL的,甚至都不知道这些数据结构上次被哪个事件使用了。
举个例子：客户端发送一个正常的get请求，由于网络或者客户端行为，需要发送两次才完成。服务端第一次read没有读取完全部数据，这次读事件中调用了 A，B函数，然后事件返回。第二次数据来临时，再次触发read事件，调用了A，C函数。并且core dump在了C函数中。这个时候，btrace的stack frame已经没有B函数调用的信息了。
所以通过GDB无法准确定位 core 的真正原因。

log debug的新尝试

这时候强大的GDB已经派不上用场了。怎么办？打印nginx调试日志。
但是打印日志也很郁闷，只要将nginx的日志级别调整到DEBUG，CORE就无法重现。为什么？因为DEBUG的日志信息量非常大，频繁地写磁盘严重影响了NGINX的性能，打开DEBUG后性能由几十万直线下降到几百qps。
调整到其他级别比如 INFO,性能虽然好了，但是日志信息量太少，没有帮助。尽管如此，日志却是个很好的工具，于是又尝试过以下办法：
1.针对特定客户端IP开启debug日志，比如IP是10.1.1.1就打印DEBUG，其他IP就打印最高级别的日志，nginx本身就支持这样的配置。
2.关闭DEBUG日志，自己在一些关键路径添加高级别的调试日志，将调试信息通过EMERG级别打印出来。
3.nginx只开启一个进程和少量的connection数。抽样打印连接编号（比如尾号是1）的调试日志。
总体思路依然是在不明显降低性能的前提下打印尽量详细的调试日志，遗憾的是，上述办法还是不能帮助问题定位，当然了，在不断的日志调试中，对代码和逻辑越来越熟悉。

bug如何重现？

这时候的调试效率已经很低了，几万QPS连续压力测试，几个小时才出一次CORE，然后修改代码，添加调试日志。几天过去了，毫无进展。所以必须要在线下构造出稳定的core dump环境，这样才能加快debug效率。
虽然还没有发现根本原因，但是发现了一个很可疑的地方：
出CORE比较集中，经常是在凌晨4,5点，早上7,8点的时候 dump几十个CORE。

弱网络环境的构造 traffic control

联想到夜间有很多的网络硬件调整及故障，我猜测这些core dump可能跟网络质量相关。特别是网络瞬时不稳定，很容易触发BUG导致大量的CORE DUMP。
最开始我考虑过使用TC(traffic control)工具来构造弱网络环境，但是转念一想，弱网络环境导致的结果是什么？显然是网络请求的各种异常啊,所以还不如直接构造各种异常请求来复现问题。于是准备构造测试工具和环境，需要满足两个条件：
1.并发性能强，能够同时发送数万甚至数十万级以上qps。
2.请求需要一定概率的异常。特别是TCP握手及SSL握手阶段，需要异常中止。
traffic control是一个很好的构造弱网络环境的工具，我之前用过测试SPDY协议性能。能够控制网络速率、丢包率、延时等网络环境，作为iproute工具集中的一个工具，由linux系统自带。但比较麻烦的是TC的配置规则很复杂，facebook在tc的基础上封装成了一个开源工具apc，有兴趣的可以试试。

WRK压力测试工具

由于高并发流量时才可能出core，所以首先就需要找一个性能强大的压测工具。
WRK是一款非常优秀的开源HTTP压力测试工具，采用多线程 + 异步事件驱动的框架，其中事件机制使用了redis的ae事件框架，协议解析使用了nginx的相关代码。
相比ab（apache bench）等传统压力测试工具的优点就是性能好，基本上单台机器发送几百万pqs,打满网卡都没有问题。
wrk的缺点就是只支持HTTP类协议，不支持其他协议类测试，比如protobuf，另外数据显示也不是很方便。

分布式自动测试系统的构建

由于是HTTPS请求，使用ECDHE_RSA密钥交换算法时，客户端的计算消耗也比较大，单机也就10000多qps。也就是说如果server的性能有3W qps，那么一台客户端是无法发送这么大的压力的，所以需要构建一个多机的分布式测试系统，即通过中控机同时控制多台测试机客户端启动和停止测试。
之前也提到了，调试效率太低，整个测试过程需要能够自动化运行，比如晚上睡觉前，可以控制多台机器在不同的协议，不同的端口，不同的cipher suite运行整个晚上。白天因为一直在盯着，运行几分钟就需要查看结果。
这个系统有如下功能：
1.并发控制多台测试客户端的启停，最后汇总输出总的测试结果。
2.支持https，http协议测试，支持webserver及revers proxy性能测试。
3.支持配置不同的测试时间、端口、URL。
4.根据端口选择不同的SSL协议版本，不同的cipher suite。
5.根据URL选择webserver、revers proxy模式。

异常测试请求的构造

压力测试工具和系统都准备好了，还是不能准确复现core dump的环境。接下来还要完成异常请求的构造。构造哪些异常请求呢？
由于新增的功能代码主要是和SSL握手相关，这个过程是紧接着TCP握手发生的，所以异常也主要发生在这个阶段。于是我考虑构造了如下三种异常情形：
1.异常的tcp连接。即在客户端tcp connent系统调用时，10%概率直接close这个socket。
2.异常的ssl连接。考虑两种情况，full handshake第一阶段时，即发送 client hello时，客户端10%概率直接close连接。full handshake第二阶段时，即发送clientKeyExchange时，客户端10%概率直接直接关闭TCP连接。
3.异常的HTTPS请求，客户端10%的请求使用错误的公钥加密数据，这样nginx解密时肯定会失败。

core bug fix小结

构造好了上述高并发压力异常测试系统，果然，几秒钟之内必然出CORE。有了稳定的测试环境，那bug fix的效率自然就会快很多。
虽然此时通过gdb还是不方便定位根本原因，但是测试请求已经满足了触发CORE的条件，打开debug调试日志也能触发core dump。于是可以不断地修改代码，不断地GDB调试，不断地增加日志，一步步地追踪根源，一步步地接近真相。
最终通过不断地重复上述步骤找到了core dump的根本原因。其实在写总结文档的时候，core dump的根本原因是什么已经不太重要，最重要的还是解决问题的思路和过程，这才是值得分享和总结的。很多情况下，千辛万苦排查出来的，其实是一个非常明显甚至愚蠢的错误。
比如这次core dump的主要原因是：
由于没有正确地设置non-reusable，并发量太大时，用于异步代理计算的connection结构体被nginx回收并进行了初始化，从而导致不同的事件中出现NULL指针并出CORE。