52 | 案例篇:服务吞吐量下降很厉害,怎么分析?
下载APP
关闭
渠道合作
推荐作者
52 | 案例篇:服务吞吐量下降很厉害,怎么分析?
2019-03-25 倪朋飞 来自北京
《Linux性能优化实战》
课程介绍
讲述:冯永吉
时长16:45大小15.30M
你好,我是倪朋飞。
上一节,我们一起学习了怎么使用动态追踪来观察应用程序和内核的行为。先简单来回顾一下。
所谓动态追踪,就是在系统或者应用程序还在正常运行的时候,通过内核中提供的探针,来动态追踪它们的行为,从而辅助排查出性能问题的瓶颈。
使用动态追踪,便可以在不修改代码也不重启服务的情况下,动态了解应用程序或者内核的行为。这对排查线上的问题、特别是不容易重现的问题尤其有效。
在 Linux 系统中,常见的动态追踪方法包括 ftrace、perf、eBPF/BCC 以及 SystemTap 等。
使用 perf 配合火焰图寻找热点函数,是一个比较通用的性能定位方法,在很多场景中都可以使用。
如果这仍满足不了你的要求,那么在新版的内核中,eBPF 和 BCC 是最灵活的动态追踪方法。
而在旧版本内核,特别是在 RHEL 系统中,由于 eBPF 支持受限,SystemTap 和 ftrace 往往是更好的选择。
其实,除了延迟问题外,网络请求的吞吐量下降,是另一个常见的性能问题。那么,针对这种吞吐量下降问题,我们又该如何进行分析呢?
接下来,我就以最常用的反向代理服务器 Nginx 为例,带你一起看看,如何分析服务吞吐量下降的问题。
案例准备
今天的案例需要用到两台虚拟机,还是基于 Ubuntu 18.04,同样适用于其他的 Linux 系统。我使用的案例环境如下所示:
机器配置:2 CPU,8GB 内存。
预先安装 docker、curl、wrk、perf、FlameGraph 等工具,比如
这些工具,我们在前面的案例中已经多次使用,这儿就不再重复。你可以打开两个终端,分别登录到这两台虚拟机中,并安装上述工具。
注意,以下所有命令都默认以 root 用户运行,如果你用普通用户身份登陆系统,请运行 sudo su root 命令切换到 root 用户。
到这里,准备工作就完成了。接下来,我们正式进入操作环节。
案例分析
我们今天要分析的案例是一个 Nginx + PHP 应用,它们的关系如下图所示:
其中,wrk 和 curl 是 Nginx 的客户端,而 PHP 应用则是一个简单的 Hello World:
为了方便你运行,我已经把案例应用打包成了两个 Docker 镜像,并推送到 Docker Hub 中。你可以直接按照下面的步骤来运行它。
同时,为了分析方便,这两个容器都将运行在 host network 模式中。这样,我们就不用切换到容器的网络命名空间,而可以直接观察它们的套接字状态。
我们先在终端一中,执行下面的命令,启动 Nginx 应用,并监听在 80 端口。如果一切正常,你应该可以看到如下的输出:
然后,执行 docker ps 命令,查询容器的状态,你会发现,容器已经处于运行状态(Up)了:
不过,从 docker ps 的输出,我们只能知道容器处于运行状态。至于 Nginx 能不能正常处理外部的请求,还需要我们进一步确认。
接着,切换到终端二中,执行下面的 curl 命令,进一步验证 Nginx 能否正常访问。如果你看到 “Hello World!” 的输出,说明 Nginx+PHP 的应用已经正常启动了:
提示:如果你看到不一样的结果,可以再次执行 docker ps -a 确认容器的状态,并执行 docker logs < 容器名 > 来查看容器日志,从而找出原因。
接下来,我们就来测试一下,案例中 Nginx 的吞吐量。
我们继续在终端二中,执行 wrk 命令,来测试 Nginx 的性能:
从 wrk 的结果中,你可以看到吞吐量(也就是每秒请求数)只有 189,并且所有 1910 个请求收到的都是异常响应(非 2xx 或 3xx)。这些数据显然表明,吞吐量太低了,并且请求处理都失败了。这是怎么回事呢?
根据 wrk 输出的统计结果,我们可以看到,总共传输的数据量只有 573 KB,那就肯定不会是带宽受限导致的。所以,我们应该从请求数的角度来分析。
分析请求数,特别是 HTTP 的请求数,有什么好思路吗?当然就要从 TCP 连接数入手。
连接数优化
要查看 TCP 连接数的汇总情况,首选工具自然是 ss 命令。为了观察 wrk 测试时发生的问题,我们在终端二中再次启动 wrk,并且把总的测试时间延长到 30 分钟:
然后,回到终端一中,观察 TCP 连接数:
从这里看出,wrk 并发 1000 请求时,建立连接数只有 5,而 closed 和 timewait 状态的连接则有 1100 多 。其实从这儿你就可以发现两个问题:
一个是建立连接数太少了;
另一个是 timewait 状态连接太多了。
分析问题,自然要先从相对简单的下手。我们先来看第二个关于 timewait 的问题。在之前的 NAT 案例中,我已经提到过,内核中的连接跟踪模块,有可能会导致 timewait 问题。我们今天的案例还是基于 Docker 运行,而 Docker 使用的 iptables ,就会使用连接跟踪模块来管理 NAT。那么,怎么确认是不是连接跟踪导致的问题呢?
其实,最简单的方法,就是通过 dmesg 查看系统日志,如果有连接跟踪出了问题,应该会看到 nf_conntrack 相关的日志。
我们可以继续在终端一中,运行下面的命令,查看系统日志:
从日志中,你可以看到 nf_conntrack: table full, dropping packet 的错误日志。这说明,正是连接跟踪导致的问题。
这种情况下,我们应该想起前面学过的两个内核选项——连接跟踪数的最大限制 nf_conntrack_max ,以及当前的连接跟踪数 nf_conntrack_count。执行下面的命令,你就可以查询这两个选项:
这次的输出中,你可以看到最大的连接跟踪限制只有 200,并且全部被占用了。200 的限制显然太小,不过相应的优化也很简单,调大就可以了。
我们执行下面的命令,将 nf_conntrack_max 增大:
连接跟踪限制增大后,对 Nginx 吞吐量的优化效果如何呢?我们不妨再来测试一下。你可以切换到终端二中,按下 Ctrl+C ;然后执行下面的 wrk 命令,重新测试 Nginx 的性能:
从 wrk 的输出中,你可以看到,连接跟踪的优化效果非常好,吞吐量已经从刚才的 189 增大到了 5382。看起来性能提升了将近 30 倍,
不过,这是不是就能说明,我们已经把 Nginx 的性能优化好了呢?
别急,我们再来看看 wrk 汇报的其他数据。果然,10s 内的总请求数虽然增大到了 5 万,但是有 4 万多响应异常,说白了,真正成功的只有 8000 多个(54221-45577=8644)。
很明显,大部分请求的响应都是异常的。那么,该怎么分析响应异常的问题呢?
工作进程优化
由于这些响应并非 Socket error,说明 Nginx 已经收到了请求,只不过,响应的状态码并不是我们期望的 2xx (表示成功)或 3xx(表示重定向)。所以,这种情况下,搞清楚 Nginx 真正的响应就很重要了。
不过这也不难,我们切换回终端一,执行下面的 docker 命令,查询 Nginx 容器日志就知道了:
从 Nginx 的日志中,我们可以看到,响应状态码为 499。
499 并非标准的 HTTP 状态码,而是由 Nginx 扩展而来,表示服务器端还没来得及响应时,客户端就已经关闭连接了。换句话说,问题在于服务器端处理太慢,客户端因为超时(wrk 超时时间为 2s),主动断开了连接。
既然问题出在了服务器端处理慢,而案例本身是 Nginx+PHP 的应用,那是不是可以猜测,是因为 PHP 处理过慢呢?
我么可以在终端中,执行下面的 docker 命令,查询 PHP 容器日志:
从这个日志中,我们可以看到两条警告信息,server reached max_children setting (5),并建议增大 max_children。
max_children 表示 php-fpm 子进程的最大数量,当然是数值越大,可以同时处理的请求数就越多。不过由于这是进程问题,数量增大,也会导致更多的内存和 CPU 占用。所以,我们还不能设置得过大。
一般来说,每个 php-fpm 子进程可能会占用 20 MB 左右的内存。所以,你可以根据内存和 CPU 个数,估算一个合理的值。这儿我把它设置成了 20,并将优化后的配置重新打包成了 Docker 镜像。你可以执行下面的命令来执行它:
然后我们切换到终端二,再次执行下面的 wrk 命令,重新测试 Nginx 的性能:
从 wrk 的输出中,可以看到,虽然吞吐量只有 4683,比刚才的 5382 少了一些;但是测试期间成功的请求数却多了不少,从原来的 8000,增长到了 15000(47210-31692=15518)。
不过,虽然性能有所提升,可 4000 多的吞吐量显然还是比较差的,并且大部分请求的响应依然还是异常。接下来,该怎么去进一步提升 Nginx 的吞吐量呢?
套接字优化
回想一下网络性能的分析套路,以及 Linux 协议栈的原理,我们可以从从套接字、TCP 协议等逐层分析。而分析的第一步,自然还是要观察有没有发生丢包现象。
我们切换到终端二中,重新运行测试,这次还是要用 -d 参数延长测试时间,以便模拟性能瓶颈的现场:
然后回到终端一中,观察有没有发生套接字的丢包现象:
根据两次统计结果中 socket overflowed 和 sockets dropped 的变化,你可以看到,有大量的套接字丢包,并且丢包都是套接字队列溢出导致的。所以,接下来,我们应该分析连接队列的大小是不是有异常。
你可以执行下面的命令,查看套接字的队列大小:
这次可以看到,Nginx 和 php-fpm 的监听队列 (Send-Q)只有 10,而 nginx 的当前监听队列长度 (Recv-Q)已经达到了最大值,php-fpm 也已经接近了最大值。很明显,套接字监听队列的长度太小了,需要增大。
关于套接字监听队列长度的设置,既可以在应用程序中,通过套接字接口调整,也支持通过内核选项来配置。我们继续在终端一中,执行下面的命令,分别查询 Nginx 和内核选项对监听队列长度的配置:
从输出中可以看到,Nginx 和 somaxconn 的配置都是 10,而 php-fpm 的配置也只有 511,显然都太小了。那么,优化方法就是增大这三个配置,比如,可以把 Nginx 和 php-fpm 的队列长度增大到 8192,而把 somaxconn 增大到 65536。
同样地,我也把这些优化后的 Nginx ,重新打包成了两个 Docker 镜像,你可以执行下面的命令来运行它:
然后,切换到终端二中,重新测试 Nginx 的性能:
现在的吞吐量已经增大到了 6185,并且在测试的时候,如果你在终端一中重新执行 netstat -s | grep socket,还会发现,现在已经没有套接字丢包问题了。
不过,这次 Nginx 的响应,再一次全部失败了,都是 Non-2xx or 3xx。这是怎么回事呢?我们再去终端一中,查看 Nginx 日志:
你可以看到,Nginx 报出了无法连接 fastcgi 的错误,错误消息是 Connect 时, Cannot assign requested address。这个错误消息对应的错误代码为 EADDRNOTAVAIL,表示 IP 地址或者端口号不可用。
在这里,显然只能是端口号的问题。接下来,我们就来分析端口号的情况。
端口号优化
根据网络套接字的原理,当客户端连接服务器端时,需要分配一个临时端口号,而 Nginx 正是 PHP-FPM 的客户端。端口号的范围并不是无限的,最多也只有 6 万多。
我们执行下面的命令,就可以查询系统配置的临时端口号范围:
你可以看到,临时端口的范围只有 50 个,显然太小了 。优化方法很容易想到,增大这个范围就可以了。比如,你可以执行下面的命令,把端口号范围扩展为 “10000 65535”:
优化完成后,我们再次切换到终端二中,测试性能:
这次,异常的响应少多了 ,不过,吞吐量也下降到了 3208。并且,这次还出现了很多 Socket read errors。显然,还得进一步优化。
火焰图
前面我们已经优化了很多配置。这些配置在优化网络的同时,却也会带来其他资源使用的上升。这样来看,是不是说明其他资源遇到瓶颈了呢?
我们不妨在终端二中,执行下面的命令,重新启动长时间测试:
然后,切换回终端一中,执行 top ,观察 CPU 和内存的使用:
从 top 的结果中可以看到,可用内存还是很充足的,但系统 CPU 使用率(sy)比较高,两个 CPU 的系统 CPU 使用率都接近 50%,且空闲 CPU 使用率只有 2%。再看进程部分,CPU 主要被两个 Nginx 进程和两个 docker 相关的进程占用,使用率都是 30% 左右。
CPU 使用率上升了,该怎么进行分析呢?我想,你已经还记得我们多次用到的 perf,再配合前两节讲过的火焰图,很容易就能找到系统中的热点函数。
我们保持终端二中的 wrk 继续运行;在终端一中,执行 perf 和 flamegraph 脚本,生成火焰图:
然后,使用浏览器打开生成的 nginx.svg ,你就可以看到下面的火焰图:
根据我们讲过的火焰图原理,这个图应该从下往上、沿着调用栈中最宽的函数,来分析执行次数最多的函数。
这儿中间的 do_syscall_64、tcp_v4_connect、inet_hash_connect 这个堆栈,很明显就是最需要关注的地方。inet_hash_connect() 是 Linux 内核中负责分配临时端口号的函数。所以,这个瓶颈应该还在临时端口的分配上。
在上一步的“端口号”优化中,临时端口号的范围,已经优化成了 “10000 65535”。这显然是一个非常大的范围,那么,端口号的分配为什么又成了瓶颈呢?
一时想不到也没关系,我们可以暂且放下,先看看其他因素的影响。再顺着 inet_hash_connect 往堆栈上面查看,下一个热点是 __init_check_established 函数。而这个函数的目的,是检查端口号是否可用。结合这一点,你应该可以想到,如果有大量连接占用着端口,那么检查端口号可用的函数,不就会消耗更多的 CPU 吗?
实际是否如此呢?我们可以继续在终端一中运行 ss 命令, 查看连接状态统计:
这回可以看到,有大量连接(这儿是 32768)处于 timewait 状态,而 timewait 状态的连接,本身会继续占用端口号。如果这些端口号可以重用,那么自然就可以缩短 __init_check_established 的过程。而 Linux 内核中,恰好有一个 tcp_tw_reuse 选项,用来控制端口号的重用。
我们在终端一中,运行下面的命令,查询它的配置:
你可以看到,tcp_tw_reuse 是 0,也就是禁止状态。其实看到这里,我们就能理解,为什么临时端口号的分配会是系统运行的热点了。当然,优化方法也很容易,把它设置成 1 就可以开启了。
我把优化后的应用,也打包成了两个 Docker 镜像,你可以执行下面的命令来运行:
容器启动后,切换到终端二中,再次测试优化后的效果:
现在的吞吐量已经达到了 5000 多,并且只有少量的 Socket errors,也不再有 Non-2xx or 3xx 的响应了。说明一切终于正常了。
案例的最后,不要忘记执行下面的命令,删除案例应用:
小结
今天,我带你一起学习了服务吞吐量下降后的分析方法。其实,从这个案例你也可以看出,性能问题的分析,总是离不开系统和应用程序的原理。
实际上,分析性能瓶颈,最核心的也正是掌握运用这些原理。
首先,利用各种性能工具,收集想要的性能指标,从而清楚系统和应用程序的运行状态;
其次,拿目前状态跟系统原理进行比较,不一致的地方,就是我们要重点分析的对象。
从这个角度出发,再进一步借助 perf、火焰图、bcc 等动态追踪工具,找出热点函数,就可以定位瓶颈的来源,确定相应的优化方法。
思考
最后,我想邀请你一起来聊聊,你碰到过的吞吐量下降问题。你是怎么分析它们的根源?又是怎么解决的?你可以结合我的讲述,总结自己的思路。
欢迎在留言区和我讨论,也欢迎把这篇文章分享给你的同事、朋友。我们一起在实战中演练,在交流中进步。
分享给需要的人,Ta购买本课程,你将得20元
生成海报并分享
赞 14
提建议
© 版权归极客邦科技所有,未经许可不得传播售卖。 页面已增加防盗追踪,如有侵权极客邦将依法追究其法律责任。
上一篇
51 | 案例篇:动态追踪怎么用?(下)
下一篇
53 | 套路篇:系统监控的综合思路
精选留言(31)
- 我来也2019-03-26[D52打卡] 哈哈,看专栏的同时,也在生产环境中执行下查看套接字的命令. 居然还发现了一个高并发时的隐患. `ss -ltnp` 有些监听端口半链接队列的值偏小,只有32.而有些都是128. 赶紧查看程序源码,发现是调用框架的接口时未传递backlog的值,导致使用框架默认的值32. 哈哈,这个程序是专门处理客户端连接的,虽然目前Recv-Q都为0,但也确实是一个隐患吧. `ss -s` 看到的连接数和各状态数还正常. `netstat -s | grep -wE "socket|listen"` 结果还比较稳定. 像 sysctl 相关的配置,由于没有权限,就无缘查看了. 不得不说,综合案例篇的内容真不错.老师也是够狠,设置了这么多的坑.填了一个一个又一个. 1.内核连接数限制 nf_conntrack. 2.php程序的工作进程数量 3.半链接队列偏小,导致高并发时的丢包. 4.系统分配的临时端口号范围. 5.系统的端口复用参数配置. 调优过程中,有时甚至是一波未平一波又起,很是惊险刺激.展开36
- 2xshu2019-03-25老师,有个疑问。 套接字优化部分,你用ss -s输出的两个队列,根据“关于 Linux 网络,你必须知道这些(下)”你讲的内容,当链接处于listening状态是,Send-Q和Recv-Q都是半链接队列,但是你这里却都是调的全连接队列啊?不是应该调整tcp_max_syn_backlog吗?
作者回复: 嗯,谢谢指出,是文中的步骤不严谨了。实际上应该再加上两步 1. 查看调优 tcp_max_syn_backlog 2. 观察全连接的状况之后再调优全连接队列
15 - ninuxer2019-03-25打卡day55 缺乏由现象联想到可能原因的系统性思维~
作者回复: 还是需要加强原理的理解
共 3 条评论5 - xfan2019-03-28内核选项 tcp_tw_reuse,不是直接修改内核参数就好了么,为什么还有修改后的tag:3 ,这里不太清楚
作者回复: 嗯 也可以的。打包成镜像的是最后优化的结果
共 2 条评论4 - 泡泡2019-03-26wrk命令-c参数用来模拟连接数为1000, 为什么输出中的连接数有1910,不理解
作者回复: -c是并发数,输出中是每秒请求数,不是一回事
4 - Maxwell2019-03-25在公司局域网下做性能测试,如何判断网络会不会成为压测的瓶颈呢?也就是说如果开了500线程进行压测,会不会因为网络瓶颈,导致请求无法发送到服务器端?
作者回复: 可以在测试的时候同时观察一下网络吞吐和丢包(比如使用sar)
4 - Lane2019-03-25一天看2篇,终于追上进度了3
- jorin@zou2020-06-12这个案例很强1
- burner2019-08-13老师,系统cpu只用了一半,但是就出现502和499的请求错误,是否意味这应用服务已经过载,还是系统连接数过载,查看netstat发现有28万失败的连接尝试,
作者回复: 应用过载了
1 - 腾达2019-04-15net.ipv4.tcp_tw_reuse = 1 这里是影响到socket的客户端(nginx作为一个客户端连接php的服务端)的行为吗? 不是影响到服务端的time_wait数量? 我弄了个tomcat,用ab压测,tw_use=1, 用ss -s看time_wait 还很高啊,1万多。
作者回复: 嗯 用在客户端上
共 2 条评论1 - 夜空中最亮的星2019-03-26报个到1
- moooofly2022-11-10 来自上海虽然这么“曲折”的案例是刻意创造出来的,不过作为示例还是不错的~
- 儿戏2020-10-23老师,请问下 nginx 用wrk 进行压测的时候报[error] 7696#0: *3730171 no live upstreams while connecting to upstream这个错误,用您教的方法都已经优化过了,还是没找到这个问题原因,nginx 连接后端的服务还是Nginx,为了保证后端服务没问题才用nginx。 针对这个问题,我应该如何排除呢?
- 子杨2020-07-22服务端端口号不是近似无限的吗,这里怎么又有限制了。
作者回复: 端口号是16位的,自然有最大限制。你从哪里看到端口号无限?
共 2 条评论 - 星之所在2020-04-27老师我的一台8G内存的虚拟机这个nf_conntrack_max最大值能调整多大,太大了貌似也没用对吧
- 初音未来2020-04-07老师问一个关于docker的问题,修改docker内的应用配置后必须保存新的镜像,然后再启动新镜像吗,这个的话生产环境怎么办
- 丁乐洪2020-03-28~最近碰到个问题,Rest接口访问返回404,是不是可以用动态跟踪来排查
- 董皋2020-03-21打卡
- Geek_b04b122020-02-16我的ubuntu系统为什么没有nf_conntrack_count 等一些参数,提示找不到。。共 1 条评论
- 陳先森2019-05-06打下卡。