高并发性能调试经验分享

引文

4 月份的时候看到一道面试题，据说是腾讯校招面试官提的：在多线程和高并发环境下，如果有一个平均运行一百万次才出现一次的 bug，你如何调试这个 bug？知乎原贴地址如下：腾讯实习生面试，这两道题目该怎么回答？ – 编程

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

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

项目背景

我们针对 nginx 事件框架和 openssl 协议栈进行了一些深度改造，以提升 nginx 的 HTTPS 完全握手计算性能。

由于原生 nginx 使用本地 CPU 做 RSA 计算，ECDHE_RSA 算法的单核处理能力只有 400 qps 左右。前期测试时的并发性能很低，就算开了 24 核，性能也无法超过 1 万。

核心功能在去年底就完成了开发，线下测试也没有发现问题。经过优化后的性能提升几倍，为了测试最大性能，使用了很多客户端并发测试 https 性能。很快就遇到了一些问题：

 

1.第一个问题是 nginx 有极低概率（亿分之一）在不同地方 core dump。白天线下压力测试 2W qps 一般都要两三个小时才出一次 core。每次晚上睡觉之前都会将最新的调试代码编译好并启动测试，到早上醒来第一眼就会去查看机器并祈祷不要出 core，不幸的是，一般都会有几个到几十个 core，并且会发现经常是在一个时间点集中 core dump。线上灰度测试运行了 6 天，在第 6 天的早上才集中 core dump 了几十次。这样算来，这个 core dump 的概率至少是亿分之一了。 不过和面试题目中多线程不同的是，nginx 采用的是多进程 + 全异步事件驱动的编程模式（目前也支持了多线程，但只是针对 IO 的优化，核心机制还是多进程加异步）。在 webserver 的实现背景下，多进程异步相比多线程的优点是性能高，没有太多线程间的切换，而且内存空间独立，省去线程间锁的竞争。当然也有缺点，就是异步模式编程非常复杂，将一些逻辑上连续的事件从空间和时间切割，不符合人的正常思考习惯，出了问题后比较难追查。另外异步事件对网络和操作系统的底层知识要求较高，稍不小心就容易挖坑。

2.第二个问题是高并发时 nginx 存在内存泄漏。在流量低的时候没有问题，加大测试流量就会出现内存泄漏。

3.第三个问题，因为我们对 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 的真正原因

这时候强大的 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，另外数据显示也不是很方便。

nginx 的测试用法： wrk -t500 -c2000 -d30s https://127.0.0.1:8443/index.html

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

由于是 HTTPS 请求，使用 ECDHE_RSA 密钥交换算法时，客户端的计算消耗也比较大，单机也就 10000 多 qps。也就是说如果 server 的性能有 3W qps，那么一台客户端是无法发送这么大的压力的，所以需要构建一个多机的分布式测试系统，即通过中控机同时控制多台测试机客户端启动和停止测试。

之前也提到了，调试效率太低，整个测试过程需要能够自动化运行，比如晚上睡觉前，可以控制多台机器在不同的协议，不同的端口，不同的 cipher suite 运行整个晚上。白天因为一直在盯着，运行几分钟就需要查看结果。 这个系统有如下功能：

• 并发控制多台测试客户端的启停，最后汇总输出总的测试结果。

• 支持 https，http 协议测试，支持 webserver 及 revers proxy 性能测试。

• 支持配置不同的测试时间、端口、URL。

• 根据端口选择不同的 SSL 协议版本，不同的 cipher suite。

• 根据 URL 选择 webserver、revers proxy 模式。

异常测试请求的构造

压力测试工具和系统都准备好了，还是不能准确复现 core dump 的环境。接下来还要完成异常请求的构造。构造哪些异常请求呢？由于新增的功能代码主要是和 SSL 握手相关，这个过程是紧接着 TCP 握手发生的，所以异常也主要发生在这个阶段。于是我考虑构造了如下三种异常情形：

• 异常的 tcp 连接。即在客户端 tcp connent 系统调用时，10% 概率直接 close 这个 socket。

• 异常的 ssl 连接。考虑两种情况，full handshake 第一阶段时，即发送 client hello 时，客户端 10% 概率直接 close 连接。full handshake 第二阶段时，即发送 clientKeyExchange 时，客户端 10% 概率直接直接关闭 TCP 连接。

• 异常的 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。

内存泄漏

虽然解决了 core dump，但是另外一个问题又浮出了水面，就是 ** 高并发测试时，会出现内存泄漏，大概一个小时 500M 的样子。

valgrind 的缺点

出现内存泄漏或者内存问题，大家第一时间都会想到 valgrind。valgrind 是一款非常优秀的软件，不需要重新编译程序就能够直接测试。功能也非常强大，能够检测常见的内存错误包括内存初始化、越界访问、内存溢出、free 错误等都能够检测出来。推荐大家使用。

valgrind 运行的基本原理是：待测程序运行在 valgrind 提供的模拟 CPU 上，valgrind 会纪录内存访问及计算值，最后进行比较和错误输出。我通过 valgrind 测试 nginx 也发现了一些内存方面的错误，简单分享下 valgrind 测试 nginx 的经验：

• nginx 通常都是使用 master fork 子进程的方式运行，使用–trace-children=yes 来追踪子进程的信息

• 测试 nginx + openssl 时，在使用 rand 函数的地方会提示很多内存错误。比如 Conditional jump or move depends on uninitialised value，Uninitialised value was created by a heap allocation 等。这是由于 rand 数据需要一些熵，未初始化是正常的。如果需要去掉 valgrind 提示错误，编译时需要加一个选项：-DPURIFY

• 如果 nginx 进程较多，比如超过 4 个时，会导致 valgrind 的错误日志打印混乱，尽量减小 nginx 工作进程, 保持为 1 个。因为一般的内存错误其实和进程数目都是没有关系的。

上面说了 valgrind 的功能和使用经验，但是 valgrind 也有一个非常大的缺点，就是它会显著降低程序的性能，官方文档说使用 memcheck 工具时，降低 10-50 倍。也就是说，如果 nginx 完全握手性能是 20000 qps, 那么使用 valgrind 测试，性能就只有 400 qps 左右。对于一般的内存问题，降低性能没啥影响，但是我这次的内存泄漏是在大压力测试时才可能遇到的，如果性能降低这么明显，内存泄漏的错误根本检测不出来。

AddressSanitizer 的优点

address sanitizer（简称 asan）是一个用来检测 c/c++ 程序的快速内存检测工具。相比 valgrind 的优点就是速度快，官方文档介绍对程序性能的降低只有 2 倍。对 Asan 原理有兴趣的同学可以参考 asan 的算法这篇文章，它的实现原理就是在程序代码中插入一些自定义代码，如下：

和 valgrind 明显不同的是，asan 需要添加编译开关重新编译程序，好在不需要自己修改代码。而 valgrind 不需要编程程序就能直接运行。

  address sanitizer 集成在了 clang 编译器中，GCC 4.8 版本以上才支持。我们线上程序默认都是使用 gcc4.3 编译，于是我测试时直接使用 clang 重新编译 nginx：

由于 AddressSanitizer 对 nginx 的影响较小，所以大压力测试时也能达到上万的并发，内存泄漏的问题很容易就定位了。这里就不详细介绍内存泄漏的原因了，因为跟 openssl 的错误处理逻辑有关，是我自己实现的，没有普遍的参考意义。最重要的是，知道 valgrind 和 asan 的使用场景和方法，遇到内存方面的问题能够快速修复。

性能热点分析

到此，经过改造的 nginx 程序没有 core dump 和内存泄漏方面的风险了。但这显然不是我们最关心的结果（因为代码本该如此），我们最关心的问题是：

• 代码优化前，程序的瓶颈在哪里？能够优化到什么程度？

• 代码优化后，优化是否彻底？会出现哪些新的性能热点和瓶颈？

       这个时候我们就需要一些工具来检测程序的性能热点。

perf，oprofile，gprof，systemtap

linux 世界有许多非常好用的性能分析工具，我挑选几款最常用的简单介绍下：

•  [perf](Perf Wiki) 应该是最全面最方便的一个性能检测工具。由 linux 内核携带并且同步更新，基本能满足日常使用。** 推荐大家使用 **。

• oprofile，我觉得是一个较过时的性能检测工具了，基本被 perf 取代，命令使用起来也不太方便。比如 opcontrol –no-vmlinux , opcontrol –init 等命令启动，然后是 opcontrol –start， opcontrol –dump， opcontrol -h 停止，opreport 查看结果等，一大串命令和参数。有时候使用还容易忘记初始化，数据就是空的。

•  gprof主要是针对应用层程序的性能分析工具，缺点是需要重新编译程序，而且对程序性能有一些影响。不支持内核层面的一些统计，优点就是应用层的函数性能统计比较精细，接近我们对日常性能的理解，比如各个函数时间的运行时间，，函数的调用次数等，很人性易读。

• systemtap 其实是一个运行时程序或者系统信息采集框架，主要用于动态追踪，当然也能用做性能分析，功能最强大，同时使用也相对复杂。不是一个简单的工具，可以说是一门动态追踪语言。如果程序出现非常麻烦的性能问题时，推荐使用 systemtap。

这里再多介绍一下 perf 命令，tlinux 系统上默认都有安装，比如通过 perf top 就能列举出当前系统或者进程的热点事件，函数的排序。

      perf record 能够纪录和保存系统或者进程的性能事件，用于后面的分析，比如接下去要介绍的火焰图。

火焰图 flame graph

perf 有一个缺点就是不直观。火焰图就是为了解决这个问题。它能够以矢量图形化的方式显示事件热点及函数调用关系。比如我通过如下几条命令就能绘制出原生 nginx 在 ecdhe_rsa cipher suite 下的性能热点：

1.perf record -F 99 -p PID -g — sleep 10

2.erf script | ./stackcollapse-perf.pl > out.perf-folded

3../flamegraph.pl out.perf-folded>ou.svg

 

直接通过火焰图就能看到各个函数占用的百分比，比如上图就能清楚地知道 rsaz_1024_mul_avx2 和 rsaz_1024_sqr_avx2 函数占用了 75% 的采样比例。那我们要优化的对象也就非常清楚了，能不能避免这两个函数的计算？或者使用非本地 CPU 方案实现它们的计算？

当然是可以的，我们的异步代理计算方案正是为了解决这个问题，

心态

为了解决上面提到的 core dump 和内存泄漏问题，花了大概三周左右时间。压力很大，精神高度紧张， 说实话有些狼狈，看似几个很简单的问题，搞了这么长时间。心里当然不是很爽，会有些着急，特别是项目的关键上线期。但即使这样，整个过程我还是非常自信并且斗志昂扬。我一直在告诉自己：

1.调试 BUG 是一次非常难得的学习机会，不要把它看成是负担。不管是线上还是线下，能够主动地，高效地追查 BUG 特别是有难度的 BUG，对自己来说一次非常宝贵的学习机会。面对这么好的学习机会，自然要充满热情，要如饥似渴，回首一看，如果不是因为这个 BUG，我也不会对一些工具有更深入地了解和使用，也就不会有这篇文档的产生。

2.不管什么样的 BUG，随着时间的推移，肯定是能够解决的。这样想想，其实会轻松很多，特别是接手新项目，改造复杂工程时，由于对代码，对业务一开始并不是很熟悉，需要一个过渡期。但关键是，你要把这些问题放在心上。白天上班有很多事情干扰，上下班路上，晚上睡觉前，大脑反而会更加清醒，思路也会更加清晰。特别是白天上班时容易思维定势，陷入一个长时间的误区，在那里调试了半天，结果大脑一片混沌。睡觉前或者上下班路上一个人时，反而能想出一些新的思路和办法。

3.开放地讨论。遇到问题不要不好意思，不管多简单，多低级，只要这个问题不是你 google 一下就能得到的结论，大胆地，认真地和组内同事讨论。这次 BUG 调试，有几次关键的讨论给了我很大的启发，特别是最后 reusable 的问题，也是组内同事的讨论才激发了我的灵感。谢谢大家的帮助。

 

本来来源于：http://mp.weixin.qq.com/s?__biz=MzI5NjAxODQyMg==&mid=2676478541&idx=1&sn=60537ca932bc3577cc9a1118eaecdc4e&scene=0#rd