问题背景
最近在配合研究部门重构ezmt，顺手把热词服务训练相关的模块进行了重构（其实接手这个服务捋清了逻辑后早就想重构了，这次正好趁机搞一下）。在联调结束后，用wrk压了一下性能，结果大跌眼镜，开了6个worker, 但是提高压测的线程数和连接数，QPS始终不见上涨， 几轮压下来QPS只有16-17左右，随着压力的上升，timeout现象非常严重。
于是单独对上游的ezmt热词训练服务压了一下，QPS在29左右
[gerrard@gerrard /home/aidu35/work/third/wrk]$ ./wrk -t 2 -c 10 -d 30s --latency -s scripts/hotword.lua http://10.12.8.19:8001
Running 30s test @ http://10.12.8.19:8001
2 threads and 10 connections
Thread Stats Avg Stdev Max +/- Stdev
Latency 341.88ms 46.86ms 520.05ms 69.14%
Req/Sec 15.19 6.48 40.00 89.67%
Latency Distribution
50% 341.40ms
75% 373.19ms
90% 403.02ms
99% 451.30ms
875 requests in 30.06s, 0.92MB read
Requests/sec: 29.10
Transfer/sec: 31.17KB
难道是重构后性能下降明显？于是我们将版本回退为重构前的版本又压测了一遍QPS还不到10
进入容器查看了一下压测时的情况，实际cpu和内存的占用都非常低，这种情况，怀疑有很大可能是网络进程中出现了阻塞调用，于是准备抓取网络进程的off-cpu火焰图。
环境准备
在抓取前需要做一些准备工作，具体参照《openresty最佳实践》中关于如何安装火焰图生成工具的步骤。
由于要排查的是网络进程阻塞，我们需要使用sample-bt-off-cpu 来绘制C代码执行过程中让出CPU 的时间（阻塞时间）的火焰图。
将热词服务的worker调成1后，我们重新进行了压测，并用下面的工具抓取了 worker进程20s的火焰图
./sample-bt-off-cpu -t 20 -p 5449 -u > out.stap
接下来使用FlameGraph生成svg
./stackcollapse-stap.pl out.stap > out.folded
./flamegraph.pl out.folded > offcpu.svg
分析和优化
从火焰图可以看到，有三处阻塞的调用，一个是posix.access接口，另外两个是语义资源训练相关的调用，主要涉及semantic.so中文件的操作，这三处操作大约占用了53%的block时间
针对这两点，我们对代码进行了优化，
- access使用了posix的unistd动态库，目的是查看文件是否存在，我们使用一个shell命令来替代它，并使用官方的lua-resty-shell来调用
- 针对semantic.so提供的API, 预期希望lua接口能返回实际的数据，将文件写入操作由单独的进程处理，已经给相关同事提了需求。短期内，先将语义训练封装到单独的lua脚本中，再利用lua-resty-shell进行调用。
这两点修改完后，我们再次抓取了off-cpu的火焰图
可以看到原先3处的阻塞调用已经消失了，接下来信心满满地再次进行压测，但是测试下来QPS仍然没有上升，这时候网络进程的CPU使用率随着连接数增加也逐渐上升了，但是随着连接数的增多明显服务的超时是错误逐步增多的。
我们抓取了CPU的火焰图
./sample-bt -p 5449 -t 20 -u > a.bt
./stackcollapse-stap.pl a.bt > a.cbt
./flamegraph.pl a.cbt > a.svg
通过CPU的火焰图可以看到，网络进程约有70%的CPU时间消耗在了lua-resty-shell的__fork中。这些shell命令大多数是执行一些io操作，查看服务的错误日志，可以看到网络进程中有大量的resty-shell执行超时。
到这里基本上可以确认是系统I/O的瓶颈，当前测试环境使用的是NFS，要提升性能，需要从磁盘入手看如何提升并发写如的性能了， 我们准备把NFS切换成本地磁盘，让训练出来的文件写到本地磁盘，再测试一下性能
[gerrard@gerrard /home/aidu35/work/third/wrk]$ ./wrk -t 4 -c 40 -d 30s --latency -s scripts/cinfo_hotword.lua http://10.12.6.199:18002
Running 30s test @ http://10.12.6.199:18002
4 threads and 40 connections
Thread Stats Avg Stdev Max +/- Stdev
Latency 1.33s 150.21ms 1.53s 93.72%
Req/Sec 13.24 9.68 40.00 68.50%
Latency Distribution
50% 1.35s
75% 1.39s
90% 1.43s
99% 1.49s
892 requests in 30.08s, 141.12KB read
Requests/sec: 29.66
Transfer/sec: 4.69KB
可以看到性能已经和测试环境的ezmt的QPS一致了， 下一步直接mock掉ezmt训练的这块的数据，再测试进行一次测试
[gerrard@gerrard /home/aidu35/work/third/wrk]$ ./wrk -t 4 -c 40 -d 30s --latency -s scripts/cinfo_hotword.lua http://10.12.6.199:18002
Running 30s test @ http://10.12.6.199:18002
4 threads and 40 connections
Thread Stats Avg Stdev Max +/- Stdev
Latency 607.42ms 116.63ms 755.61ms 81.43%
Req/Sec 28.76 23.05 101.00 67.53%
Latency Distribution
50% 638.32ms
75% 692.35ms
90% 714.52ms
99% 741.81ms
1966 requests in 30.07s, 311.03KB read
Requests/sec: 65.39
Transfer/sec: 10.35KB
采用mock的train接口后， 单worker的CPU轻松跑到了100% QPS上升到了65，我们把worker数调成和线上一直的6个，进行最终的测试
./wrk -t 6 -c 60 -d 30s --latency -s scripts/cinfo_hotword.lua http://10.12.6.199:18002
Running 30s test @ http://10.12.6.199:18002
6 threads and 60 connections
Thread Stats Avg Stdev Max +/- Stdev
Latency 198.59ms 111.60ms 819.18ms 77.58%
Req/Sec 52.73 19.63 202.00 73.75%
Latency Distribution
50% 171.61ms
75% 253.19ms
90% 344.32ms
99% 573.53ms
9406 requests in 30.10s, 1.45MB read
Requests/sec: 312.49
Transfer/sec: 49.44KB
可以看到， QPS上升到了300+， 基本按预期提升。
