专栏首页架构说案例篇:服务吞吐量下降很厉害,怎么分析?

案例篇:服务吞吐量下降很厉害,怎么分析?

回顾

在 Linux 系统中,常见的动态追踪方法包括 ftrace、perf、eBPF/BCC 以及 SystemTap 等。

  • 使用 perf 配合火焰图寻找热点函数,是一个比较通用的性能定位方法,在很多场景中都可以使用。
  • 如果这仍满足不了你的要求,那么在新版的内核中,eBPF 和 BCC 是最灵活的动态追踪方法。

而在旧版本内核,特别是在 RHEL 系统中,由于 eBPF 支持受限,

SystemTap 和 ftrace 往往是更好的选择

画外音:

perf教程 请参考 http://www.brendangregg.com/perf.html

开始

Python

# 安装必备docker、curl和perf
$ apt-get install -y docker.io curl build-essential linux-tools-common
# 安装火焰图工具
$ git clone https://github.com/brendangregg/FlameGraph
# 安装wrk
$ git clone https://github.com/wg/wrk
$ cd wrk && make && sudo cp wrk /usr/local/bin/

Shell

$ docker run --name nginx --network host --privileged -itd feisky/nginx-tp
6477c607c13b37943234755a14987ffb3a31c33a7f04f75bb1c190e710bce19e
$ docker run --name phpfpm --network host --privileged -itd feisky/php-fpm-tp
09e0255159f0c8a647e22cd68bd097bec7efc48b21e5d91618ff29b882fa7c1f

Python

$ curl http://192.168.0.30
Hello World!

测试命令

C

# 默认测试时间为10s,请求超时2s
$ wrk --latency -c 1000 http://192.168.0.30
Running 10s test @ http://192.168.0.30
  2 threads and 1000 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency    14.82ms   42.47ms 874.96ms   98.43%
    Req/Sec   550.55      1.36k    5.70k    93.10%
  Latency Distribution
     50%   11.03ms
     75%   15.90ms
     90%   23.65ms
     99%  215.03ms
  1910 requests in 10.10s, 573.56KB read
  Non-2xx or 3xx responses: 1910
Requests/sec:    189.10
Transfer/sec:     56.78KB

从 wrk 的结果中,你可以看到吞吐量(也就是每秒请求数)只有 189,并且所有 1910 个请求收到的都是异常响应(非 2xx 或 3xx)。

这些数据显然表明,吞吐量太低了,并且请求处理都失败了。这是怎么回事呢?

根据 wrk 输出的统计结果,我们可以看到,总共传输的数据量只有 573 KB,那就肯定不会是带宽受限导致的。

所以,我们应该从请求数的角度来分析。

画外音:

分析请求数,特别是 HTTP 的请求数,有什么好思路吗?

当然就要从 TCP 连接数入手

连接数优化

  • 观察tcp连接数

Shell

# 测试时间30分钟
$ wrk --latency -c 1000 -d 1800 http://192.168.0.30
$ ss -s
Total: 177 (kernel 1565)
TCP:   1193 (estab 5, closed 1178, orphaned 0, synrecv 0, timewait 1178/0), ports 0
Transport Total     IP        IPv6
*    1565      -         -
RAW    1         0         1
UDP    2         2         0
TCP    15        12        3
INET    18        14        4
FRAG    0         0         0
  -s, --summary
              Print  summary  statistics.
$ dmesg | tail
[88356.354329] nf_conntrack: nf_conntrack: table full, dropping packet
[88356.354374] nf_conntrack: nf_conntrack: table full, dropping packet

从这里看出,wrk 并发 1000 请求时,建立连接数只有 5,而 closed 和 timewait 状态的连接则有 1100 多 。

其实从这儿你就可以发现两个问题:一个是建立连接数太少了;另一个是 timewait 状态连接太多了。

Plain Text

$ dmesg | tail
[88356.354329] nf_conntrack: nf_conntrack: table full, dropping packet
[88356.354374] nf_conntrack: nf_conntrack: table full, dropping packet
possible SYN flooding on port 80. Sending cookies.
  • 解决办法: centos没有找到该命令

两个内核选项——连接跟踪数的最大限制

C++

$ sysctl net.netfilter.nf_conntrack_max
net.netfilter.nf_conntrack_max = 200
$ sysctl net.netfilter.nf_conntrack_count
net.netfilter.nf_conntrack_count = 200
# 将连接跟踪限制增大到1048576
$ sysctl -w net.netfilter.nf_conntrack_max=1048576
# 默认测试时间为10s,请求超时2s
$ wrk --latency -c 1000 http://192.168.0.30
...
  54221 requests in 10.07s, 15.16MB read
  Socket errors: connect 0, read 7, write 0, timeout 110
  Non-2xx or 3xx responses: 45577
Requests/sec:   5382.21
Transfer/sec:      1.50MB

画外音:

吞吐量已经从刚才的 189 增大到了 5382。看起来性能提升了将近 30 倍,

大部分请求的响应都是异常的。那么,该怎么分析响应异常的问题呢?

工作进程优化

主要多线程 多进程参数调整。

套接字优化

  • 分析的第一步,自然还是要观察有没有发生丢包现象。

Go

# 测试时间30分钟
$ wrk --latency -c 1000 -d 1800 http://192.168.0.30
  这次还是要用 -d 参数延长测试时间,以便模拟性能瓶颈的现场:
# 只关注套接字统计
$ netstat -s | grep socket
    73 resets received for embryonic SYN_RECV sockets
    308582 TCP sockets finished time wait in fast timer
    8 delayed acks further delayed because of locked socket
    290566 times the listen queue of a socket overflowed
    290566 SYNs to LISTEN sockets dropped
# 稍等一会,再次运行
$ netstat -s | grep socket
    73 resets received for embryonic SYN_RECV sockets
    314722 TCP sockets finished time wait in fast timer
    8 delayed acks further delayed because of locked socket
    344440 times the listen queue of a socket overflowed
    344440 SYNs to LISTEN sockets dropped
$ ss -ltnp
State     Recv-Q     Send-Q            Local Address:Port            Peer Address:Port
LISTEN    10         10                      0.0.0.0:80                   0.0.0.0:*         users:(("nginx",pid=10491,fd=6),("nginx",pid=10490,fd=6),("nginx",pid=10487,fd=6))
LISTEN  
-t, --tcp
              Display TCP sockets.
   -l, --listening
              Display only listening sockets (these are omitted by default).
  1. 这次可以看到,Nginx 和 php-fpm 的监听队列 (Send-Q)只有 10,而 nginx 的当前监听队列长度 (Recv-Q)已经达到了最大值,php-fpm 也已经接近了最大值。很明显,套接字监听队列的长度太小了,需要增大。
  2. 根据两次统计结果中 socket overflowed 和 sockets dropped 的变化,你可以看到,有大量的套接字丢包,并且丢包都是套接字队列溢出导致的。所以,接下来,我们应该分析连接队列的大小是不是有异常。

如果短时间内存在大量的这种恶意连接,对服务端来说压力就会很大,这就是所谓的 SYN FLOOD 攻击。

http://jaseywang.me/2014/07/20/tcp-queue-%E7%9A%84%E4%B8%80%E4%BA%9B%E9%97%AE%E9%A2%98/

https://blog.csdn.net/plokmju88/article/details/103884145

补充Recv-Q/Send-Q 理解

Plain Text

可以看到,整个 TCP stack 有如下的两个 queue:
1. 一个是 half open(syn queue) queue(max(tcp_max_syn_backlog, 64)),用来保存 SYN_SENT 以及 SYN_RECV 的信息。
2. 另外一个是 accept queue(min(somaxconn, backlog)),保存 ESTAB 的状态,但是调用 accept()。
注意,之前我对 Recv-Q/Send-Q 的理解有些误差,
使用 ss 获取到的 Recv-Q/Send-Q 在 LISTEN 状态以及非 LISTEN 状态所表达的含义是不同的。
从 tcp_diag.c 源码中可以看到二者的区别:
LISTEN 状态: Recv-Q 表示的当前等待服务端调用 accept 完成三次握手的 listen backlog 数值
也就是说,当客户端通过 connect() 去连接正在 listen() 的服务端时,
这些连接会一直处于这个 queue 里面直到被服务端 accept();Send-Q 表示的则是最大的 listen backlog 数值,这就就是上面提到的 min(backlog, somaxconn) 的值。
其余状态:
非 LISTEN 状态之前理解的没有问题。Recv-Q 表示 receive queue 中的 bytes 数量;
Send-Q 表示 send queue 中的 bytes 数值
通过 "SYNs to LISTEN sockets dropped" 以及 "times the listen queue of a socket overflowed" 这两个 netstat -s 获取到的 TCP 状态,可以很快的发现系统存在的一些问题。
任何一个包含 "dropped" 或者 "overflowed" 并且数值一直居高不下的 metric 从字面含义理解来看,都不是一个好现象。
对于 Nginx 来说,backlog 的默认值为 511,这个可以通过 ss/netstat 的 Send-Q 确认:
State      Recv-Q Send-Q        Local Address:Port          Peer Address:Port
LISTEN     0      511                       *:80                       *:*
可以通过适当的增大 nginx 的 backlog 以及 somaxconn 来增大队列:
listen 80 backlog=1638
  • 解决办法:

从输出中可以看到,Nginx 和 somaxconn 的配置都是 10,而 php-fpm 的配置也只有 511,显然都太小了。

那么,优化方法就是增大这三个配置,比如,可以把 Nginx 和 php-fpm 的队列长度增大到 8192,而把 somaxconn 增大到 65536。

Shell

# 查询nginx监听队列长度配置
$ docker exec nginx cat /etc/nginx/nginx.conf | grep backlog
        listen       80  backlog=10;
# 查询php-fpm监听队列长度
$ docker exec phpfpm cat /opt/bitnami/php/etc/php-fpm.d/www.conf | grep backlog
; Set listen(2) backlog.
;listen.backlog = 511
# somaxconn是系统级套接字监听队列上限
$ sysctl net.core.somaxconn
net.core.somaxconn = 10
补充:somaxconn

cat /proc/sys/net/core/somaxconn

128

Specifies the maximum listen backlog.

socket tcp的backlog的上限是min(backlog,somaxconn),

其中backlog是应用程序中传递给listen系统调用的参数值,somaxconn是内核规定的最大连接数。

accept() call is used by a server to accept a connection request from a client.

端口号优化

  • 问题:

可以看到,Nginx 报出了无法连接 fastcgi 的错误,错误消息是 Connect 时, Cannot assign requested address。

这个错误消息对应的错误代码为 EADDRNOTAVAIL,表示 IP 地址或者端口号不可用。

  • 解决办法:

当客户端连接服务器端时,需要分配一个临时端口号,而 Nginx 正是 PHP-FPM 的客户端。

端口号的范围并不是无限的,最多也只有 6 万多

Go

$ sysctl net.ipv4.ip_local_port_range
net.ipv4.ip_local_port_range=20000 20050
$
sysctl -w net.ipv4.ip_local_port_range="10000 65535"
net.ipv4.ip_local_port_range = 10000 65535

火焰图

  • 问题:

Shell

$ top
...
%Cpu0  : 30.7 us, 48.7 sy,  0.0 ni,  2.3 id,  0.0 wa,  0.0 hi, 18.3 si,  0.0 st
%Cpu1  : 28.2 us, 46.5 sy,  0.0 ni,  2.0 id,  0.0 wa,  0.0 hi, 23.3 si,  0.0 st
KiB Mem :  8167020 total,  5867788 free,   490400 used,  1808832 buff/cache
KiB Swap:        0 total,        0 free,        0 used.  7361172 avail Mem
  PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND
20379 systemd+  20   0   38068   8692   2392 R  36.1  0.1   0:28.86 nginx
20381 systemd+  20   0   38024   8700   2392 S  33.8  0.1   0:29.29 nginx
 1558 root      20   0 1118172  85868  39044 S  32.8  1.1  22:55.79 dockerd
20313 root      20   0   11024   5968   3956 S  27.2  0.1   0:22.78 docker-containe
13730 root      20   0       0      0      0 I   4.0  0.0   0:10.07 kworker/u4:0-ev

从 top 的结果中可以看到,可用内存还是很充足的,但系统 CPU 使用率(sy)比较高,两个 CPU 的系统 CPU 使用率都接近 50%,且空闲 CPU 使用率只有 2%。

再看进程部分,CPU 主要被两个 Nginx 进程和两个 docker 相关的进程占用,使用率都是 30% 左右。

  • 解决

C

# 执行perf记录事件3
$ perf record -g
# 切换到FlameGraph安装路径执行下面的命令生成火焰图
$ perf script -i ~/perf.data | ./stackcollapse-perf.pl --all | ./flamegraph.pl > nginx.svg

这儿中间的 dosyscall64、tcpv4connect、inethashconnect 这个堆栈,很明显就是最需要关注的地方。inethashconnect() 是 Linux 内核中负责分配临时端口号的函数。

所以,这个瓶颈应该还在临时端口的分配上。在上一步的“端口号”优化中,临时端口号的范围,已经优化成了 “10000 65535”。这显然是一个非常大的范围,那么,端口号的分配为什么又成了瓶颈呢?

一时想不到也没关系,我们可以暂且放下,先看看其他因素的影响。再顺着 inethashconnect 往堆栈上面查看,下一个热点是 _initcheck_established 函数。而这个函数的目的,是检查端口号是否可用。结合这一点,你应该可以想到,如果有大量连接占用着端口,

下一个热点是 _initcheck_established 函数。

而这个函数的目的,是检查端口号是否可用。

结合这一点,你应该可以想到,如果有大量连接占用着端口,那么检查端口号可用的函数,不就会消耗更多的 CPU 吗?

Shell

$ ss -s
TCP:   32775 (estab 1, closed 32768, orphaned 0, synrecv 0, timewait 32768/0), ports 0
...
$ sysctl net.ipv4.tcp_tw_reuse
net.ipv4.tcp_tw_reuse = 0

你可以看到,tcp_tw_reuse 是 0,也就是禁止状态。 其实看到这里, 我们就能理解,为什么临时端口号的分配会是系统运行的热点了。 当然,优化方法也很容易,把它设置成 1 就可以开启了。

本文分享自微信公众号 - 架构说(JiaGouS),作者:王传义

原文出处及转载信息见文内详细说明,如有侵权,请联系 yunjia_community@tencent.com 删除。

原始发表时间:2020-06-24

本文参与腾讯云自媒体分享计划,欢迎正在阅读的你也加入,一起分享。

我来说两句

0 条评论
登录 后参与评论

相关文章

  • 大流量Web系统性能优化实践

    系统性能优化一般方法 1 通过工具寻找瓶颈 2 水平扩展机器 这遇到很多问题 分布式事务和cache问题等 需要调整架构和组件 ? ? ? ? ?...

    程序员小王
  • c++系列之一构造函数

    这里有三个类,其中A,C类是B的父类,然后在Main函数中声明一个B类型的变量,然后程序的输出是这样的:

    程序员小王
  • 关于linux进程间的close-on-exec机制

    待我们仔细分析流量已经用netstat查看具体的连接数,离我们设置的上限还差很远。这个时候开始怀疑我们的程序是不是有bug导致文件描述符泄露了。

    程序员小王
  • Redux 入坑进阶 - 源码解析

    通过这样函数之间的组合,可以大大增加可读性,效果远大于嵌套一大堆的函数调用,并且我们可以随意更改函数的调用顺序

    前端博客 : alili.tech
  • Python2.x设置命令执行的超时时间

    kongxx
  • 百页课程笔记,统计物理视角下的深度学习

    近日,哥德堡大学物理系 Bernhard Mehlig 教授在 arXiv 上发布了他的一本「新书」《Artifical Neural Networks》。这本...

    机器之心
  • shedlock源码解析

    shedlock-core-0.16.1-sources.jar!/net/javacrumbs/shedlock/core/LockProvider.java

    codecraft
  • 发展至今的机器学习到底对我们的就业和社会产生了哪些影响?

    镁客网
  • OpenFlow 1.3 学习笔记

    因为7、8月我跟小伙伴们在备战今年的全国大学生SDN大赛,9月在全身心投入准备特殊人才保研的专家答辩,所以好久没有新文章跟大家见面啦。现在一切尘埃落定,继续卯足...

    SDNLAB
  • Windows 7 开启远程桌面及远程桌面端口号修改

    魏晓蕾

扫码关注云+社区

领取腾讯云代金券