求教 nginx 作为反向代理时的性能损失问题

Daniel Qian

unread,

Feb 17, 2023, 4:40:53 AM2/17/23

to openresty

问题困惑了我两个礼拜，一直找不到原因所以在此请教，长话短说。

upstream 服务器是一个 Tomcat （这不重要）

我先用 wrk 对 Tomcat 做性能测试，得到基准数值：

./wrk -c 500 -t 4 -d 1m --latency http://<tomcat>:8080/docs/config/filter.html

Running 1m test @ http://172.18.10.210:8080/docs/config/filter.html
4 threads and 500 connections
Thread Stats Avg Stdev Max +/- Stdev
Latency 64.64ms 58.20ms 914.81ms 84.37%
Req/Sec 2.25k 429.65 3.55k 71.32%
Latency Distribution
50% 49.41ms
75% 95.27ms
90% 136.19ms
99% 269.55ms
535553 requests in 1.00m, 46.54GB read
Requests/sec: 8910.95
Transfer/sec: 792.88MB

然后对 nginx （反向代理到 Tomcat）做性能测试：

./wrk -c 500 -t 4 -d 1m --latency http://<nginx>:8080/docs/config/filter.html

Running 1m test @ http://172.18.10.211:8080/docs/config/filter.html
4 threads and 500 connections
Thread Stats Avg Stdev Max +/- Stdev
Latency 123.56ms 134.94ms 1.85s 88.98%
Req/Sec 1.27k 240.43 1.92k 73.32%
Latency Distribution
50% 104.98ms
75% 167.39ms
90% 270.04ms
99% 625.88ms
302464 requests in 1.00m, 26.29GB read
Requests/sec: 5035.75
Transfer/sec: 448.14MB

单从吞吐量上来说，性能损失居然高达 (8910-5177)/8910=41.89%，而延迟也几乎是翻倍的。实在是百思不得其解。

附件是 nginx 配置文件，systemtap oncpu 和 offcpu 的火焰图。

不用怀疑 Tomcat 的垃圾收集，我观察过一切正常。

希望有大佬能解决小弟的疑惑，先谢过了。

openresty-offcpu.svg

openresty-oncpu.svg

nginx.conf

Junlong Li

unread,

Feb 17, 2023, 6:14:51 AM2/17/23

to open...@googlegroups.com

测试的时候，wrk 和 nginx，tomcat的网络拓扑是什么关系呢？三者是在三台不同的机器上吗？

是虚拟机还是宿主机？有没有资源争抢的现象？各自的 CPU 的利用率是多少呢，有没有被打满了？

机器的规格是不是一样的呢？

网络带宽是不是瓶颈呢？

Daniel Qian <chanj...@gmail.com> 于2023年2月17日周五 17:40写道：

--
--
邮件来自列表“openresty”,专用于技术讨论!
订阅: 请发空白邮件到 openresty...@googlegroups.com
发言: 请发邮件到 open...@googlegroups.com
退订: 请发邮件至 openresty+...@googlegroups.com
归档: http://groups.google.com/group/openresty
官网: http://openresty.org/
仓库: https://github.com/agentzh/ngx_openresty
教程: http://openresty.org/download/agentzh-nginx-tutorials-zhcn.html
---
您收到此邮件是因为您订阅了Google网上论坛上的“openresty”群组。
要退订此群组并停止接收此群组的电子邮件，请发送电子邮件到openresty+...@googlegroups.com。
要在网络上查看此讨论，请访问https://groups.google.com/d/msgid/openresty/66de9f0d-6e9c-4b58-80a2-d6a4ba6bf0aen%40googlegroups.com。

Message has been deleted

Junlong Li

unread,

Feb 19, 2023, 4:59:56 AM2/19/23

to open...@googlegroups.com

从火焰图看 recv是性能瓶颈，你调整请求响应大小由明显的变化也符合网络瓶颈。或许你应该也看看内核的火焰图。

Daniel Qian <chanj...@gmail.com> 于2023年2月19日周日 17:09写道：

感谢。

3 台虚拟机，都一样，都是4c 4g，且被调度到同一个物理机上，因此流量不走物理交换机。
虚拟化平台是深信服aCloud，虚拟机网卡驱动是virtio。
操作系统是Anolis Linux 8.6 内核4.19.26。
用iperf3测试过带宽，可达到 18Gbits/s 左右，带宽不是瓶颈。

压测期间top观察过st%，在1%-2%左右。

pidstat -u 观察 nginx 的4个进程，发现 4个cpu的负载比较均匀，但是都有10-15的 wait%，这个和offcpu的分析报告能对的上。

顺便一提，我现在压的url返回的响应有91k左右，如果我压另一个url 响应尺寸在10k左右的话，吞吐量性能损失在15%左右，差距明显。

PS. 周末在家没法进机器拿报告，如果需要我周一去拉一把。

要在网络上查看此讨论，请访问https://groups.google.com/d/msgid/openresty/593025b3-e62f-4971-b6e9-052bd76e965en%40googlegroups.com。

Message has been deleted

Daniel Qian

unread,

Feb 20, 2023, 1:11:57 AM2/20/23

to openresty

感谢大佬，新采样了火焰吐（见附件），包含了内核空间的调用。

看上去的确 ngx_readv_chain 占了比较大的比例。

openresty-offcpu.svg

openresty-oncpu.svg

Daniel Qian

unread,

Feb 20, 2023, 1:24:52 AM2/20/23

to openresty

下面是压测期间对 nginx 所有进程的 pidstat 分析：

$ pidstat -G nginx -u 1

14时19分26秒 UID PID %usr %system %guest %wait %CPU CPU Command
14时19分27秒 990 34257 6.00 25.00 0.00 21.00 31.00 0 nginx
14时19分27秒 990 34258 4.00 23.00 0.00 17.00 27.00 1 nginx
14时19分27秒 990 34259 5.00 29.00 0.00 15.00 34.00 2 nginx
14时19分27秒 990 34260 6.00 33.00 0.00 12.00 39.00 3 nginx

比较奇怪的是 %wait 比较高，根据man的描述 %wait 代表 Percentage of CPU spent by the task while waiting to run.

下面是 vmstat 采集结果

$ vmstat 1

procs -----------memory---------- ---swap-- -----io---- -system-- ------cpu-----
r b swpd free buff cache si so bi bo in cs us sy id wa st
4 0 0 2394164 3324 1282388 0 0 2 3 25 28 1 2 98 0 0
7 0 0 2384076 3324 1282756 0 0 0 0 11636 9706 7 42 50 0 2
1 0 0 2399384 3324 1283128 0 0 0 1204 13944 12460 8 48 43 0 0
0 0 0 2374556 3324 1283544 0 0 0 0 14434 16267 7 42 51 0 1
0 0 0 2360732 3324 1284044 0 0 0 0 15449 17988 8 40 51 0 1
2 0 0 2359248 3324 1284548 0 0 0 0 14544 16577 8 39 51 0 1
1 0 0 2366460 3324 1285080 0 0 0 0 14664 20827 8 42 50 0 1
0 0 0 2368424 3324 1285580 0 0 0 0 15825 18571 9 46 44 0 1
4 0 0 2351812 3324 1286140 0 0 0 0 16563 21008 8 41 51 0 0
0 0 0 2344588 3324 1286736 0 0 0 0 15808 19742 8 40 52 0 1
1 0 0 2353212 3324 1287244 0 0 0 0 15717 18505 9 41 48 0 2
4 0 0 2355048 3324 1287712 0 0 0 0 14422 16859 9 42 48 0 1
2 0 0 2341792 3324 1288160 0 0 0 0 15988 17249 10 44 45 0 1

Junlong Li

unread,

Feb 20, 2023, 2:34:28 AM2/20/23

to openresty

宿主机是什么配置呢？

Daniel Qian

unread,

Feb 20, 2023, 3:05:35 AM2/20/23

to openresty

宿主机配置：

CPU 12 核 24 线程 X 2 （Intel(R) Xeon(R) Silver 4116 CPU @ 2.10GHz）
内存 256 GB

我看来看去还是觉得 epoll_wait 导致的 context_switch 比较可疑。

Junlong Li

unread,

Feb 20, 2023, 10:46:19 AM2/20/23

to openresty

wrk 降低一下线程的数量对比一下呢？

Daniel Qian

unread,

Feb 21, 2023, 1:21:04 AM2/21/23

to openresty

降低 wrk 的线程数和连接数，测试结果的确改善了，但是 nginx 的性能损失比例没有什么变化，看下面的报告。

直压 tomcat：

Running 1m test @ http://172.18.10.210:8080/docs/config/filter.html

2 threads and 20 connections

Thread Stats Avg Stdev Max +/- Stdev

Latency 3.41ms 19.37ms 298.89ms 98.71%
Req/Sec 7.04k 0.89k 8.62k 81.92%
Latency Distribution
50% 1.33ms
75% 1.63ms
90% 2.10ms
99% 78.99ms
833766 requests in 1.00m, 72.42GB read
Requests/sec: 13891.71
Transfer/sec: 1.21GB

压 nginx

Running 1m test @ http://172.18.10.211:8080/docs/config/filter.html

2 threads and 20 connections

Thread Stats Avg Stdev Max +/- Stdev

Latency 3.74ms 15.78ms 295.62ms 99.14%
Req/Sec 4.13k 548.91 4.89k 84.76%
Latency Distribution
50% 2.23ms
75% 2.72ms
90% 3.55ms
99% 9.91ms
491693 requests in 1.00m, 42.73GB read
Requests/sec: 8192.50
Transfer/sec: 729.06MB

压测期间在 nginx 服务器上用 ss 看报告，不知有什么问题（210 是 tomcat，211 是 nginx，212 是 wrk）：

$ ss -m -t

State Recv-Q Send-Q Local Address:Port Peer Address:Port Process

ESTAB 0 0 172.18.10.211:4666 172.18.10.210:8080
skmem:(r0,rb4621264,t0,tb1048576,f122880,w0,o0,bl0,d0)
ESTAB 93268 0 172.18.10.211:4672 172.18.10.210:8080
skmem:(r104704,rb2172640,t0,tb1048576,f1792,w0,o0,bl0,d0)
ESTAB 0 0 172.18.10.211:8080 172.18.10.212:48808
skmem:(r0,rb2097152,t0,tb1048576,f98304,w0,o0,bl0,d0)
ESTAB 0 0 172.18.10.211:4690 172.18.10.210:8080
skmem:(r0,rb2281272,t0,tb1048576,f118784,w0,o0,bl0,d0)
ESTAB 0 0 172.18.10.211:4668 172.18.10.210:8080
skmem:(r0,rb2172640,t0,tb1048576,f135168,w0,o0,bl0,d0)
ESTAB 0 93314 172.18.10.211:8080 172.18.10.212:48830
skmem:(r0,rb2097152,t0,tb1048576,f5678,w96722,o0,bl0,d0)
ESTAB 0 143 172.18.10.211:4684 172.18.10.210:8080
skmem:(r0,rb2172640,t0,tb1048576,f104192,w2304,o0,bl0,d0)
ESTAB 67 0 172.18.10.211:8080 172.18.10.212:48816
skmem:(r4864,rb2097152,t0,tb1048576,f93440,w0,o0,bl0,d0)
ESTAB 0 143 172.18.10.211:4662 172.18.10.210:8080
skmem:(r0,rb2166768,t0,tb1048576,f132864,w2304,o0,bl0,d0)
ESTAB 0 143 172.18.10.211:4656 172.18.10.210:8080
skmem:(r0,rb2097152,t0,tb1048576,f116480,w2304,o0,bl0,d0)
ESTAB 0 0 172.18.10.211:4686 172.18.10.210:8080
skmem:(r0,rb2097152,t0,tb1048576,f106496,w0,o0,bl0,d0)
ESTAB 0 45530 172.18.10.211:8080 172.18.10.212:48820
skmem:(r0,rb2097152,t0,tb1048576,f59686,w46810,o0,bl0,d0)
ESTAB 0 93314 172.18.10.211:8080 172.18.10.212:48828
skmem:(r0,rb2097152,t0,tb1048576,f6958,w95442,o0,bl0,d0)
ESTAB 0 0 172.18.10.211:8080 172.18.10.212:48818
skmem:(r0,rb2097152,t0,tb1048576,f98304,w0,o0,bl0,d0)
ESTAB 0 0 172.18.10.211:8080 172.18.10.212:48844
skmem:(r0,rb2097152,t0,tb1048576,f102400,w0,o0,bl0,d0)
ESTAB 0 0 172.18.10.211:4676 172.18.10.210:8080
skmem:(r0,rb4148568,t0,tb1048576,f135168,w0,o0,bl0,d0)
ESTAB 0 0 172.18.10.211:8080 172.18.10.212:48836
skmem:(r0,rb2097152,t0,tb1048576,f102400,w0,o0,bl0,d0)
ESTAB 0 93314 172.18.10.211:8080 172.18.10.212:48824
skmem:(r0,rb2097152,t0,tb1048576,f2862,w95442,o0,bl0,d0)
ESTAB 0 4142 172.18.10.211:8080 172.18.10.212:48826
skmem:(r0,rb2097152,t0,tb1048576,f97410,w4990,o0,bl0,d0)
ESTAB 0 93314 172.18.10.211:8080 172.18.10.212:48812
skmem:(r0,rb2097152,t0,tb1048576,f6958,w95442,o0,bl0,d0)
ESTAB 0 93314 172.18.10.211:8080 172.18.10.212:48806
skmem:(r0,rb2097152,t0,tb1048576,f6958,w95442,o0,bl0,d1)
ESTAB 0 143 172.18.10.211:4688 172.18.10.210:8080
skmem:(r0,rb2097152,t0,tb1048576,f104192,w2304,o0,bl0,d1)
ESTAB 0 45530 172.18.10.211:8080 172.18.10.212:48840
skmem:(r0,rb2097152,t0,tb1048576,f55590,w46810,o0,bl0,d0)
ESTAB 0 0 172.18.10.211:8080 172.18.10.212:48822
skmem:(r0,rb2097152,t0,tb1048576,f102400,w0,o0,bl0,d1)
ESTAB 0 0 172.18.10.211:4660 172.18.10.210:8080
skmem:(r0,rb2166768,t0,tb1048576,f110592,w0,o0,bl0,d0)
ESTAB 0 0 172.18.10.211:4678 172.18.10.210:8080
skmem:(r0,rb2166768,t0,tb1048576,f118784,w0,o0,bl0,d0)
ESTAB 0 143 172.18.10.211:4658 172.18.10.210:8080
skmem:(r0,rb4621264,t0,tb1048576,f124672,w2304,o0,bl0,d0)
ESTAB 0 0 172.18.10.211:4682 172.18.10.210:8080
skmem:(r0,rb2172640,t0,tb1048576,f126976,w0,o0,bl0,d0)
ESTAB 0 93314 172.18.10.211:8080 172.18.10.212:48842
skmem:(r0,rb2097152,t0,tb1048576,f2862,w95442,o0,bl0,d0)
ESTAB 0 0 172.18.10.211:4680 172.18.10.210:8080
skmem:(r0,rb2116856,t0,tb1048576,f114688,w0,o0,bl0,d0)
ESTAB 0 36 172.18.10.211:ssh 172.18.12.2:48690
skmem:(r0,rb131072,t0,tb87040,f1792,w2304,o0,bl0,d0)
ESTAB 0 0 172.18.10.211:8080 172.18.10.212:48810
skmem:(r0,rb2097152,t0,tb1048576,f98304,w0,o0,bl0,d1)
ESTAB 93067 0 172.18.10.211:4654 172.18.10.210:8080
skmem:(r100096,rb2166768,t0,tb1048576,f10496,w0,o0,bl0,d1)
ESTAB 0 0 172.18.10.211:8080 172.18.10.212:48814
skmem:(r0,rb2097152,t0,tb1048576,f98304,w0,o0,bl0,d0)
ESTAB 67 0 172.18.10.211:8080 172.18.10.212:48832
skmem:(r4864,rb2097152,t0,tb1048576,f97536,w0,o0,bl0,d0)
ESTAB 0 0 172.18.10.211:8080 172.18.10.212:48834
skmem:(r0,rb2097152,t0,tb1048576,f98304,w0,o0,bl0,d0)
ESTAB 0 0 172.18.10.211:4670 172.18.10.210:8080
skmem:(r0,rb2166768,t0,tb1048576,f118784,w0,o0,bl0,d0)
ESTAB 0 0 172.18.10.211:4674 172.18.10.210:8080
skmem:(r0,rb2097152,t0,tb1048576,f110592,w0,o0,bl0,d0)
ESTAB 0 0 172.18.10.211:8080 172.18.10.212:48838
skmem:(r0,rb2097152,t0,tb1048576,f106496,w0,o0,bl0,d0)

Daniel Qian

unread,

Feb 22, 2023, 1:13:01 AM2/22/23

to openresty

问题解决了，希望能对以后遇到相同问题的同学一些帮助。

问题的关键在于 pidstat 发现的 %wait 比较高有关系，这是一个线索，用 bcc offcputime 工具分析会发现 epoll_wait 导致的 off cpu 时间比较多，在 30s 里有 ~15s 的off cpu。

之前一直没有想明白就忽略了，直到我修改了宿主机对于网络流量转发使用的 CPU 核数的配置，原先是 1 核独占，改成 4 核独占后，性能有巨大提升。

具体的信息我总结在博客里了：https://chanjarster.github.io/post/network/few-cores-cause-net-throughput/

所以，问题在外部（宿主机），而不是虚拟机或者 Nginx 上。

Reply all

Reply to author

Forward