游戏排行榜压测 ——性能的各种观测指标

乘以零
873 阅读33分钟

排行榜的实现

全服排行榜作为一个中心服，向全部游戏服提供相关接口调用，其接口又分为同步接口及异步接口两个版本，异步接口通过WebFlux实现，关于WebFlux这里不展开讨论，后面会单独出一篇文章。中心服（排行榜服）数据库采用MongoDB实现，综合 中心服在集群环境下的复杂度，稳定性及排行榜本身的吞吐量需求进行考量 ，最终决定在中心服不做二级缓存，游戏服的请求流量经过鉴权后直接涌入数据库（集群版本则增加网关做一层负载均衡）。以下贴出webFlux版本的部分实现：

领域模型:

@Data
@AllArgsConstructor
@Document
@CompoundIndexes(@CompoundIndex(name="sortIndex",def="{rid:1,value:-1;secondValue:-1,rankTime:1}"))
public class RankElement {
    @Id
    private String id;
    /**
     * 排行榜ID
     */
    private  String rid;
    /**
     * 排行值
     */
    private long value;
    /**
     * 第二排行值
     */
    private long secondValue;
    /**
     * 时间戳
     */
    private long rankTime;
    
    ....
}

服务层：

@Component
public class ReactiveRankService {
    @Autowired
    private ReactiveMongoTemplate template;
​
    public Flux<RankElement> asyncGetRankList(String rankId,int limit){
        Aggregation aggregation =Aggregation.newAggregation(Aggregation.match(Criteria.where("rid").is(rankId)),
                Aggregation.sort(Sort.by(Sort.Order.desc("value"),Sort.Order.desc("secondValue"),Sort.Order.asc("rankTime"))));
        if (limit>0){
            aggregation.getPipeine().add(Aggregation.limit(limit));
        }
        return template.aggregate(aggregation,"RankElement",RankElement.class);
    }
}

对外接口层：

@RestController
@RequestMapping("rank")
public class RankController {
    @Autowired
    private ReactiveRankService service;
​
    @PostMapping("/getRank")
    public Flux<RankElement> asyncGetRank(ServerHttpRequest request,@RequestBody RankVo vo){
        return service.asyncGetRankList(vo.getRankId(),vo.getLimit());
    }
​
}

单机测试

工具使用

压测客户端：wrk

wrk：轻量级性能测试工具;

安装简单，学习曲线基本为零，几分钟就能学会了；

基于系统自带的高性能 I/O 机制，如 epoll, kqueue, 利用异步的事件驱动框架，通过很少的线程就可以压出很大的并发量；

Linux性能分析工具：sar

sar命令可以从文件的读写情况、系统调用的使用情况、磁盘I/O、CPU效率、内存使用状况、进程活动及IPC有关的活动等方面进行报告。 sar命令是Linux下系统运行状态统计工具，它将指定的操作系统状态计数器显示到标准输出设备。sar工具将对系统当前的状态进行取样，然后通过计算数据和比例来表达系统的当前运行状态。它的特点是可以连续对系统取样，获得大量的取样数据。取样数据和分析的结果都可以存入文件，使用它时消耗的系统资源很小。

数据库监控工具：MongoStat

测试环境

压测机：xx.xx.xx.49

被测机：xx.xx.xx.216 6核 ，万兆带宽，文件句柄数65535

数据库：Mongodb4.2.3，部署在10.11.10.30，总数据量100万个文档，查询文档数100个

压测命令：

同步 ./wrk -t16 -c300 -d120s --latency xx.xx.xx.216:10000/crank/getPl…

异步 ./wrk -t16 -c300 -d120s --latency xx.xx.xx.216:10000/crank/getPl…

压测过程

CPU负载情况

空闲时：

[root@cqs_xx.xx.xx.216 ~]#sar -q 1 100
Linux 3.10.0-693.el7.x86_64 (cqs_xx.xx.xx.216)   06/06/2021      _x86_64_        (6 CPU)
​
01:11:16 PM   runq-sz  plist-sz   ldavg-1   ldavg-5  ldavg-15   blocked
01:11:17 PM         0      2212      0.41      2.11      1.85         0
01:11:18 PM         0      2212      0.41      2.11      1.85         0
01:11:19 PM         0      2212      0.41      2.11      1.85         0
01:11:20 PM         2      2212      0.41      2.11      1.85         0
01:11:21 PM         0      2213      0.41      2.11      1.85         0
​

压测时：

[root@cqs_xx.xx.xx.216 ~]#sar -q 1 100
Linux 3.10.0-693.el7.x86_64 (cqs_xx.xx.xx.216)   06/06/2021      _x86_64_        (6 CPU)
​
04:56:34 PM   runq-sz  plist-sz   ldavg-1   ldavg-5  ldavg-15   blocked
04:56:35 PM         4      2402      6.30      3.90      2.73         0
04:56:36 PM         7      2402      6.30      3.90      2.73         0
04:56:37 PM         9      2401      6.30      3.90      2.73         0
04:56:38 PM         8      2401      6.30      3.90      2.73         0
04:56:39 PM         4      2399      6.30      3.90      2.73         0
04:56:40 PM        13      2399      6.20      3.91      2.74         0
04:56:41 PM        16      2399      6.20      3.91      2.74         0
04:56:42 PM         7      2399      6.20      3.91      2.74         0
04:56:43 PM         7      2399      6.20      3.91      2.74         0
04:56:44 PM        11      2399      6.20      3.91      2.74         0
​

runq-sz：运行队列的长度（等待运行的进程数）

plist-sz：进程列表中进程（processes）和线程（threads）的数量

ldavg-1：最后1分钟的系统平均负载（Systemload average）

ldavg-5：过去5分钟的系统平均负载

ldavg-15：过去15分钟的系统平均负载

216这台机为6核CPU，单核负载为1，则总负载为6。关于负载多少才算理想，存在争议，网上找了一圈，各有各的说法。

有的认为小于内核数*2或者 *3都可以接受，但普遍认同超过内核数即过载。

通过上面的统计信息，CPU负载在6.3左右，等待进程数大于内核数，基本是超负载的状态了。

但系统load高，不能代表cpu资源不足，只是代表需要运行的队列累计过多，但队列中的任务实际可能是耗CPU的，也可能是耗i/o及其他因素的，因此我们还需要与CPU使用率结合来看。

CPU使用率

空闲时:

[root@cqs_xx.xx.xx.216 ~]#sar -u -o 1 100
Linux 3.10.0-693.el7.x86_64 (cqs_xx.xx.xx.216)   06/06/2021      _x86_64_        (6 CPU)
​
01:12:33 PM     CPU     %user     %nice   %system   %iowait    %steal     %idle
01:12:34 PM     all      3.87      0.00      0.67      0.00      0.00     95.45
01:12:35 PM     all      4.03      0.00      0.50      0.00      0.00     95.46
01:12:36 PM     all      4.03      0.00      0.50      0.00      0.00     95.46
01:12:37 PM     all      3.53      0.00      0.67      0.00      0.00     95.80
01:12:38 PM     all      3.54      0.00      0.51      0.00      0.00     95.95
01:12:39 PM     all      4.38      0.00      0.67      0.00      0.00     94.95
01:12:40 PM     all      4.24      0.00      1.02      0.00      0.00     94.75
​

压测时：

​
11:39:46 AM     CPU     %user     %nice   %system   %iowait    %steal     %idle
11:39:48 AM     all     71.57      0.00      9.70      0.00      0.00     18.73
11:39:49 AM     all     71.79      0.00      9.68      0.00      0.00     18.53
11:39:50 AM     all     65.77      0.00      9.56      0.00      0.00     24.66
11:39:51 AM     all     67.06      0.00     10.03      0.00      0.00     22.91
11:39:52 AM     all     71.21      0.00     10.44      0.00      0.00     18.35
11:39:53 AM     all     66.44      0.00      9.73      0.00      0.00     23.83
11:39:54 AM     all     66.11      0.00      9.06      0.00      0.00     24.83
11:39:55 AM     all     70.72      0.00      9.82      0.00      0.00     19.47
11:39:56 AM     all     64.66      0.00      8.38      0.00      0.00     26.97
11:39:57 AM     all     78.93      0.00     10.70      0.00      0.00     10.37
11:39:58 AM     all     76.76      0.00      9.36      0.00      0.00     13.88
11:39:59 AM     all     76.54      0.00     10.48      0.00      0.00     12.98
​

%user：显示在用户级别(application)运行使用 CPU总时间的百分比。

%nice：显示在用户级别，用于nice操作，所占用 CPU总时间的百分比。

%system：在核心级别(kernel)运行所使用 CPU总时间的百分比。

%iowait：显示用于等待I/O操作占用 CPU总时间的百分比。

%steal：管理程序(hypervisor)为另一个虚拟进程提供服务而等待虚拟CPU 的百分比。

%idle：显示 CPU空闲时间占用 CPU总时间的百分比。

从上面的数据看，%idle基本维持在基本在18左右，CPU的利用率也基本是差不多了，可见硬件上CPU确实存在瓶颈。

系统整体运行状态

空闲时：

[root@cqs_xx.xx.xx.216 ~]#vmstat 1 100
procs -----------memory---------- ---swap-- -----io---- -system-- ------cpu-----
 r  b   swpd   free   buff  cache     si   so    bi    bo   in   cs us sy id wa st
 1  0 576820 2495800      0 2499564    0    0     3     7    0    1  8  2 91  0  0
 1  0 576820 2496048      0 2499568    0    0     0     0 5935 7030  4  1 95  0  0
 1  0 576820 2496172      0 2499572    0    0     0   359 5915 6936  4  1 95  0  0
 0  0 576820 2495940      0 2499596    0    0     0   120 5956 6965  4  1 95  0  0
 0  0 576820 2495692      0 2499604    0    0     0     0 5639 6891  5  1 95  0  0
 0  0 576820 2495692      0 2499604    0    0     0     0 5437 6795  4  1 95  0  0
 0  0 576820 2495692      0 2499604    0    0     0     0 6441 7460  4  1 95  0  0
 0  0 576820 2495708      0 2499604    0    0     0     0 5673 7033  4  1 95  0  0
 0  0 576820 2495708      0 2499604    0    0     0    40 5627 6821  5  1 94  0  0
​

压测时：

​
[root@cqs_xx.xx.xx.216 ~]#vmstat 1 200
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   1032 4799576   2104 8018456    0    0     5    34  49   24   4   1 95  0  0
15  0   1032 4799840   2104 8018420    0    0     0     0 17660 5607 58  8 34  0  0
17  0   1032 4799172   2104 8018420    0    0     0     0 17872 5471 58  9 33  0  0
12  0   1032 4799208   2104 8018420    0    0     0     0 17336 5241 53  8 38  0  0
10  0   1032 4799284   2104 8018420    0    0     0     0 19477 4681 65  9 26  0  0
 1  0   1032 4799396   2104 8018428    0    0     0     0 18248 5205 61  9 30  0  0
17  0   1032 4799116   2104 8018428    0    0     0     0 16143 3249 61  9 30  0  0
15  0   1032 4799528   2104 8018428    0    0     0     8 17940 3980 68 10 22  0  0
 3  0   1032 4798860   2104 8018428    0    0     0     0 18214 4343 63  8 29  0  0
14  0   1032 4798884   2104 8018428    0    0     0     0 17161 4448 65 10 25  0  0

procs： r 表示运行和等待CPU时间片的进程数，这个值如果长期大于系统CPU个数，说明CPU不足。 b 表示等待资源的进程数，比如正在等待I/O、或者内存交换等。

memory： swpd 虚拟内存使用量。即切换到内存交换区的内存数量。如果大于0，表示机器物理内存不足。 free 空闲物理内存 buff 作为buff使用的内存 cache 作为cache使用的内存

swap： si 每秒从磁盘读入虚拟内存的大小，如果这个值大于0，表示物理内存不够或者内存泄露了，要查找耗内存进程解决掉。

so 每秒虚拟内存写入磁盘的大小，如果这个值大于0，同上。 一般情况下，si、so的值都为0，如果si、so的值长期不为0，则表示内存不足。

IO： bi 块设备每秒接收的块数量，这里的块设备是指系统上所有的磁盘和其他块设备，默认块大小是1024byte bo 块设备每秒发送的块数量 设置的bi+bo参考值为1000，如果超过1000，而且wa值较大，则表示系统磁盘IO有问题，应该考虑提高磁盘的读写性能。

system： in 每秒CPU的中断次数，包括时间中断。

cs 每秒上下文切换次数 这两个值越大，内核消耗的CPU就越多

cpu： us 用户进程消耗的CPU时间百分比，us的值比较高时，说明用户进程消耗的cpu时间多，但是如果长期大于50%，就需要考虑优化程序或算法

sy 内核进程消耗的CPU时间百分比，sy值如果太高，说明内核消耗CPU资源很多，例如是IO操作频繁。

id CPU处于空闲状态的时间百分比。

wa io等待所占用的时间百分比，wa值越高，说明IO等待越严重，根据经验，wa的参考值为20%，如果wa超过20%，说明IO等待严重，引起IO等待的 原因可能是磁盘大量随机读写造成的，也可能是磁盘或者磁盘控制器的带宽瓶颈造成的（主要是块操作）

各项指标基本处于正常状态，这里关于软中断这里做个补充： CPU 微处理器有一个中断信号位， 在每个CPU时钟周期的末尾, CPU会去检测那个中断信号位是否有中断信号到达， 如果有， 则会根据中断优先级决定是否要暂停当前执行的指令， 转而去执行处理中断的指令。 （其实就是 CPU 层级的 while 轮询）

Linux操作系统中主要采用了0和3两个特权级，分别对应的就是内核态和用户态。

用户态到内核态的切换，其实就是一个进程通过系统调用到内核的一些接口。从而实现切换。而该系统调用切换时通过软件中断来完成，该中断是程序人员自己开发出的一种正常的异常，那么在Linux下，这个异常具体就是调用int $0x80的汇编指令，这条汇编指令将产生向量为0x80的编程异常。之所以系统调用需要借助这个中断异常来实现，是因为这个异常实际上就是通过系统门陷入内核。

另一方面，我们也可以观察具体到线程的执行情况：

top -H -p+进程ID 取得该进程的各线程信息

printf "%x\n"+pid 线程ID转16进制

jstack 进程ID|grep 线程ID的16进制 -C 10（查看上下10行代码） 观察该线程的运行情况

[root@cqs_xx.xx.xx.216 ~]#jstack 8071 |grep 2976 -C 10
        at io.netty.channel.unix.FileDescriptor.readAddress(FileDescriptor.java:141)
        at io.netty.channel.epoll.AbstractEpollChannel.doReadBytes(AbstractEpollChannel.java:349)
        at io.netty.channel.epoll.AbstractEpollStreamChannel$EpollStreamUnsafe.epollInReady(AbstractEpollStreamChannel.java:781)
        at io.netty.channel.epoll.EpollEventLoop.processReady(EpollEventLoop.java:480)
        at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:378)
        at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989)
        at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
        at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
        at java.lang.Thread.run(Thread.java:748)
​
"reactor-http-epoll-2" #49 daemon prio=5 os_prio=0 tid=0x00007fd814013000 nid=0x2976 waiting on condition [0x00007fd8491bc000]
   java.lang.Thread.State: WAITING (parking)
        at sun.misc.Unsafe.park(Native Method)
        - parking to wait for  <0x000000077e048db8> (a java.util.concurrent.CountDownLatch$Sync)
        at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:836)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedInterruptibly(AbstractQueuedSynchronizer.java:997)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1304)
        at java.util.concurrent.CountDownLatch.await(CountDownLatch.java:231)
        at com.mongodb.connection.netty.NettyStream$FutureAsyncCompletionHandler.get(NettyStream.java:390)
        at com.mongodb.connection.netty.NettyStream.read(NettyStream.java:190)
​
​

多跑几次，可以看到这些线程基本都是在com.mongodb.connection.netty.NettyStream.read()进行挂起，即等待Mongo返回数据后进行latch.countDown()唤醒。

网卡流量情况

空闲时：

[root@cqs_xx.xx.xx.216 ~]#sar -n DEV 1 100
Linux 3.10.0-693.el7.x86_64 (cqs_xx.xx.xx.216)   06/06/2021      _x86_64_        (6 CPU)
​
01:09:25 PM     IFACE   rxpck/s   txpck/s    rxkB/s    txkB/s   rxcmp/s   txcmp/s  rxmcst/s
01:09:26 PM    ens192     30.00      5.00      2.94      0.63      0.00      0.00      0.00
01:09:26 PM        lo     78.00     78.00      9.86      9.86      0.00      0.00      0.00
​
01:09:26 PM     IFACE   rxpck/s   txpck/s    rxkB/s    txkB/s   rxcmp/s   txcmp/s  rxmcst/s
01:09:27 PM    ens192     44.00     12.00      3.72      1.53      0.00      0.00      5.00
01:09:27 PM        lo     68.00     68.00      6.98      6.98      0.00      0.00      0.00
​
01:09:27 PM     IFACE   rxpck/s   txpck/s    rxkB/s    txkB/s   rxcmp/s   txcmp/s  rxmcst/s
01:09:28 PM    ens192     37.00     28.00      4.79     67.47      0.00      0.00      0.00
01:09:28 PM        lo     91.00     91.00      9.06      9.06      0.00      0.00      0.00
​
01:09:28 PM     IFACE   rxpck/s   txpck/s    rxkB/s    txkB/s   rxcmp/s   txcmp/s  rxmcst/s
01:09:29 PM    ens192     25.00      7.00      3.36      0.83      0.00      0.00      0.00
01:09:29 PM        lo     58.00     58.00      7.54      7.54      0.00      0.00      0.00
​
​

压测时：

[root@cqs_xx.xx.xx.216 ~]#sar -n DEV 1 100
Linux 3.10.0-693.el7.x86_64 (cqs_xx.xx.xx.216)   06/06/2021      _x86_64_        (6 CPU)
​
01:05:59 PM     IFACE   rxpck/s   txpck/s    rxkB/s    txkB/s   rxcmp/s   txcmp/s  rxmcst/s
01:06:00 PM    ens192  10060.00   9928.00  34921.85  26883.82      0.00      0.00      0.00
01:06:00 PM        lo     76.00     76.00      8.06      8.06      0.00      0.00      0.00
​
01:06:00 PM     IFACE   rxpck/s   txpck/s    rxkB/s    txkB/s   rxcmp/s   txcmp/s  rxmcst/s
01:06:01 PM    ens192  10173.00   9983.00  35802.35  27512.99      0.00      0.00      0.00
01:06:01 PM        lo    105.00    105.00     14.68     14.68      0.00      0.00      0.00
​
01:06:01 PM     IFACE   rxpck/s   txpck/s    rxkB/s    txkB/s   rxcmp/s   txcmp/s  rxmcst/s
01:06:02 PM    ens192   9681.19   9652.48  34967.50  26923.68      0.00      0.00      0.00
01:06:02 PM        lo     67.33     67.33      7.78      7.78      0.00      0.00      0.00
​
01:06:02 PM     IFACE   rxpck/s   txpck/s    rxkB/s    txkB/s   rxcmp/s   txcmp/s  rxmcst/s
01:06:03 PM    ens192   9727.00   9730.00  35323.93  27125.50      0.00      0.00      0.00
01:06:03 PM        lo     60.00     60.00      7.77      7.77      0.00      0.00      0.00
​
01:06:03 PM     IFACE   rxpck/s   txpck/s    rxkB/s    txkB/s   rxcmp/s   txcmp/s  rxmcst/s
01:06:04 PM    ens192   7716.00   7662.00  27382.98  21179.04      0.00      0.00      0.00
01:06:04 PM        lo     48.00     48.00      4.03      4.03      0.00      0.00      0.00
​
01:06:04 PM     IFACE   rxpck/s   txpck/s    rxkB/s    txkB/s   rxcmp/s   txcmp/s  rxmcst/s
01:06:05 PM    ens192   9132.00   8872.00  30950.51  23759.11      0.00      0.00      0.00
01:06:05 PM        lo     79.00     79.00      9.34      9.34      0.00      0.00      0.00

#IFACE 本地网卡接口的名称

#rxpck/s 每秒钟接受的数据包

#txpck/s 每秒钟发送的数据包

#rxKB/S 每秒钟接受的数据包大小，单位为KB

#txKB/S 每秒钟发送的数据包大小，单位为KB

#rxcmp/s 每秒钟接受的压缩数据包

#txcmp/s 每秒钟发送的压缩包

#rxmcst/s 每秒钟接收的多播数据包

216这台机为万兆网卡（通过ethtool xxx可得），理论上能支持1280000kB/s（10000Mb/s=1280MB/s=1280000kB/s），从上面的测试情况看，收发包的吞吐率（主要看rxKB/s与txKB/s）远没达到网卡流量上限。

我们也可以用sar -n EDEV来分析是否达到网卡流量上限：

[root@cqs_xx.xx.xx.216 ~]#sar -n EDEV 1 100
Linux 3.10.0-1127.18.2.el7.x86_64 (cqs_xx.xx.xx.216)     06/01/2021      _x86_64_        (6 CPU)
​
05:15:22 PM     IFACE   rxerr/s   txerr/s    coll/s  rxdrop/s  txdrop/s  txcarr/s  rxfram/s  rxfifo/s  txfifo/s
05:15:23 PM    ens192      0.00      0.00      0.00      0.00      0.00      0.00      0.00      0.00      0.00
05:15:23 PM        lo      0.00      0.00      0.00      0.00      0.00      0.00      0.00      0.00      0.00
05:15:23 PM veth93e25d0      0.00      0.00      0.00      0.00      0.00      0.00      0.00      0.00      0.00
05:15:23 PM vethc322396      0.00      0.00      0.00      0.00      0.00      0.00      0.00      0.00      0.00
05:15:23 PM   docker0      0.00      0.00      0.00      0.00      0.00      0.00      0.00      0.00      0.00
​

通过rxdrop/s,txdrop/s指标 可以得到缓冲区满而丢掉的网络包。

TCP连接情况

300个连接压测期间，使用netstat -s |grep overflow命令查看累计值，压测前后累计值相减即这段时间丢弃的连接

[root@cqs_xx.xx.xx.216 ~]#netstat -s |grep overflow
    57414 times the listen queue of a socket overflowed
[root@cqs_xx.xx.xx.216 ~]#netstat -s |grep overflow
    57434 times the listen queue of a socket overflowed
​

可以看到，有20个连接被丢弃。

这里关于overflow做个补充：

在 TCP 三次握手的时候，Linux 内核会维护两个队列，分别是：

半连接队列，也称 SYN 队列； 全连接队列，也称 accepet 队列； 服务端收到客户端发起的 SYN 请求后， 内核会把该连接存储到半连接队列，并向客户端响应 SYN+ACK，接着客户端会返回 ACK，服务端收到第三次握手的 ACK 后， 内核会把连接从半连接队列移除，然后创建新的完全的连接，并将其添加到 accept 队列，等待进程调用 accept 函数时把连接取出来。 通过ss -lnt|grep 端口号 可拿到全连接相关信息：

​
[root@cqs_xx.xx.xx.216 ~]#ss -lnt |grep 10000 
State     Recv-Q  Send-Q    Local Address:Port       Peer Address:Port
LISTEN     0      128       [::]:10000                 [::]:*

在不同状态下，Recv-Q/Send-Q表示的含义如下：

LISTEN状态非 LISTEN 状态
Recv-Q当前全连接队列的大小，也就是当前已完成三次握手并等待服务端 accept 的 TCP 连接个数已收到但未被应用进程读取的字节数
Send-Q当前全连接最大队列长度已发送但未收到确认的字节数

当超过了 TCP 最大全连接队列，服务端则会丢掉后续进来的 TCP 连接，丢掉的 TCP 连接的个数会被统计起来，也就是我们上面的netstat -s |grep overflow采集的数据。

从上面的测试结果，可以得知， 当服务端并发处理大量请求时，如果 TCP 全连接队列过小，就容易溢出。发生 TCP 全连接队溢出的时候，后续的请求就会被丢弃，这样就会出现服务端请求数量上不去的现象。

TCP 全连接队列的最大值取决于 somaxconn 和 backlog 之间的最小值，也就是 min(somaxconn, backlog)。

#cat tcp_max_syn_backlog
65535
[root@cqs_xx.xx.xx.216 ipv4]#cat /proc/sys/net/core/somaxconn
128

我也不知道为啥运维把backlog调的这么大...不过不重要，我们只需要改somaxconn就行：

[root@cqs_xx.xx.xx.216 ~]#echo 1000|sudo dd of=/proc/sys/net/core/somaxconn
0+1 records in
0+1 records out
5 bytes (5 B) copied, 7.9866e-05 s, 62.6 kB/s
​

改完要重启服务才会生效：

​
[root@cqs_xx.xx.xx.216 ~]#ss -lnt |grep 10000
State     Recv-Q  Send-Q    Local Address:Port       Peer Address:Port
LISTEN     0      1000       [::]:10000    

再次压测看有没有连接丢失：

root@localhost:~# netstat -s|grep overflow
    4046 times the listen queue of a socket overflowed
root@localhost:~# netstat -s|grep overflow
    4046 times the listen queue of a socket overflowed
​

无。

内存及交换空间

216服（服务部署服）

[root@cqs_xx.xx.xx.216 ~]#smem --sort swap
  PID User     Command                         Swap      USS      PSS      RSS
55929 root     java -jar match-plus-1.0-SN        0  2195172  2196396  2201960
​

30服（数据库部署服）

root@localhost:~# smem --sort swap
  PID User     Command                         Swap      USS      PSS      RSS
65002 polkitd  mongod --auth --bind_ip_all      172   589456   589764   590076

RSS（Resident set size）：实际使用物理内存（包含共享库占用的内存），将各进程的RSS值相加，通常会超出整个系统的内存消耗，这是因为RSS中包含了各进程间共享的内存。

PSS（Proportional set size）所有使用某共享库的程序均分该共享库占用的内存时，每个进程占用的内存。显然所有进程的PSS之和就是系统的内存使用量。它会更准确一些，它将共享内存的大小进行平均后，再分摊到各进程上去。

USS(Unique set size )进程独自占用的内存，它是PSS中自己的部分，它只计算了进程独自占用的内存大小，不包含任何共享的部分。

关于交换区（Swap）：交换通常发生在当应用需要的内存大于实际的物理内存的时候，处理这种情况操作系统通常会配置一个相应的区域叫做交换区。交换区通常位于物理磁盘上，当物理内存内应用耗尽的时候，操作系统会将一部分内存数据暂时交换到磁盘空间上，这部分内存区域通常是访问频率最低的一块区域，而不会影响比较「忙」的内存区域；当被交换到磁盘区域的内存又被应用访问的时候，这个时候就需要从磁盘交换区将以页为单位读入内存，交换会影响应用的性能。

虚拟机的垃圾收集器在交换的时候性能非常差，因为垃圾收集器所访问的大部分区域都是不可达的，也就是垃圾收集器会引起交换活动的发生。场景是戏剧性的，如果垃圾收集的堆区域已经被交换到了磁盘空间，这个时候将会以页为单位发生交换，这样才能够被垃圾收集器所扫描到，在交换的过程中会戏剧性的引发垃圾收集器的收集时间延长，这个时候如果垃圾收集器是 「Stop The World」（使得应用响应停止）的，那么这个时间就会被延长。

我们着重注意Mongo的内存使用情况，基本也在正常范围。

Mono性能分析

索引优化

For compound indexes, this rule of thumb is helpful in deciding the order of fields in the index:

  • First, add those fields against which Equality queries are run.
  • The next fields to be indexed should reflect the Sort order of the query.
  • The last fields represent the Range of data to be accessed.

对于Mongo的符合索引有一条ESR原则，即按照Equality（等值查询）字段--Sort字段--Range字段的顺序来建立复合索引，本次测试的索引按照排行榜Id--排序字段建立，故符合要求。

Covered queries return results from an index directly without having to access the source documents, and are therefore very efficient.

对于覆盖索引，由于需要查询排行榜的全部内容，无法避免回表，故无法实现。

对于Mongo的索引官方还有其他优化建议，这里不一一列举，详情见www.mongodb.com/blog/post/p…

查询语句分析

通过命令行手敲查询语句db.RankElement.find({rid:"1_1_1"}).sort({"value":1,"secondValue":1,"rankTime":-1}).limit(100).explain(true)，使用explain命令，分析查询报告，发现其executionTimeMills（实际耗时）不到1毫秒，nReturned（返回文档数）=totalDocsExamined（扫描文档数）=100（100万个文档查询其中100个），已经是最理想的情况了，完全命中索引，故查询语句基本是没有问题的。

慢查询日志

35000次请求没有产生1个慢查询（100ms以上）

我们通过db.setProfilingLevel(1,{slowms:10})降低慢查询门槛，超过10毫秒的打印出来

dbRes1:PRIMARY> db.setProfilingLevel(1,{slowms:10})
{
        "was" : 1,
        "slowms" : 5,
        "sampleRate" : 1,
        "ok" : 1,
        "$gleStats" : {
                "lastOpTime" : Timestamp(0, 0),
                "electionId" : ObjectId("7fffffff0000000000000001")
        },
        "lastCommittedOpTime" : Timestamp(1622540805, 1),
        "$configServerState" : {
                "opTime" : {
                        "ts" : Timestamp(1622540794, 1),
                        "t" : NumberLong(1)
                }
        },
        "$clusterTime" : {
                "clusterTime" : Timestamp(1622540805, 1),
                "signature" : {
                        "hash" : BinData(0,"AAAAAAAAAAAAAAAAAAAAAAAAAAA="),
                        "keyId" : NumberLong(0)
                }
        },
        "operationTime" : Timestamp(1622540805, 1)
}
dbRes1:PRIMARY> db.getProfilingStatus()
{
        "was" : 1,
        "slowms" : 10,
        "sampleRate" : 1,
​

再次压测，产生10几个慢查询（10ms以上），可以接受。

这里补充个小tips：mongodb日志过大时，可以通过旋转日志的方法，将当前日志重命名为带日期的文件，再创建新的日志文件。具体做法：

  • ps -def|grep mongod
  • kill -SIGUSR1 mongo进程

mongostat

   insert query update delete getmore command dirty  used flushes vsize  res  qrw  arw net_in net_out conn    set repl                time
​
   *0    *0     *0     *0    5873  1950|0  0.1% 24.6%       0 9.63G 694M  0|0  1|0  2.64m   54.2m  334 dbRes1  PRI May 30 22:48:11.355
    *0    *0     *0     *0    6231  2090|0  0.1% 24.6%       0 9.63G 694M  0|0  2|0  2.81m   57.8m  334 dbRes1  PRI May 30 22:48:12.355
    *0    *0     *0     *0    6209  2074|0  0.1% 24.6%       0 9.63G 694M  0|0  2|0  2.80m   57.5m  334 dbRes1  PRI May 30 22:48:13.355
    *0     1     *0     *0    6193  2071|0  0.1% 24.6%       0 9.63G 694M  0|0  5|0  2.79m   57.2m  334 dbRes1  PRI May 30 22:48:14.355
    *0     1     *0     *0    6197  2071|0  0.1% 24.6%       0 9.63G 694M  0|0  9|0  2.79m   57.4m  334 dbRes1  PRI May 30 22:48:15.354
    *0    *0     *0     *0    6208  2071|0  0.1% 24.6%       0 9.63G 694M  0|0  5|0  2.79m   57.4m  334 dbRes1  PRI May 30 22:48:16.358
    *0    *0     *0     *0    6069  2015|0  0.1% 24.6%       0 9.63G 694M  0|0  4|0  2.73m   56.2m  334 dbRes1  PRI May 30 22:48:17.354
    *0    *0     *0     *0    5981  2004|0  0.1% 24.6%       0 9.63G 694M  3|0  3|0  2.70m   55.3m  334 dbRes1  PRI May 30 22:48:18.354
    *0    *0     *0     *0    6096  2023|0  0.1% 24.6%       0 9.63G 694M  0|0  3|0  2.74m   56.4m  334 dbRes1  PRI May 30 22:48:19.355
    *0    *0     *0     *0    6252  2077|0  0.1% 24.6%       0 9.63G 694M  0|0  2|0  2.81m   57.8m  334 dbRes1  PRI May 30 22:48:20.353
​
​

一般我们通过mongostat着重观察这几个指标：

used：WiredTiger存储引擎中使用的缓存占比

dirty：WiredTiger存储引擎中dirty数据占缓存百分比

res：物理内存使用量（MB）

qr/qw：客户端读/写队列的长度，数值太大说明到了瓶颈

netout：mongodb出去的流量（集群测试中我用它作另一个角度来判断集群的水平拓展能力）

这里补充下wiredtiger存储引擎的eviction策略：

参数名默认值说明
eviction_target80当 cache used 超过 eviction_target，后台evict线程开始淘汰 DirtyPAGE
eviction_trigger95当 cache used 超过 eviction_trigger，用户线程也开始淘汰 CLEAN PAGE
eviction_dirty_target5当 cache dirty 超过 eviction_dirty_target，后台evict线程开始淘汰 DIRTY PAGE
eviction_dirty_trigger20当 cache dirty 超过 eviction_dirty_trigger, 用户线程也开始淘汰 DIRTY PAGE

如果通过 mongostat 发现 used、dirty 持续超出eviction_trigger、eviction_dirty_trigger，这时用户的请求线程也会去干 evict的事情（开销大），会导致请求延时上升，这时基本可以判定，mongodb 已经存在资源不足的问题，但就上面的数据来看，距离达到mongo的性能瓶颈还有很长距离。

最终吞吐量结果

同步接口

  • 8线程，100连接

    root@localhost:wrk-master# ./wrk -t8 -c100 -d30s --latency  http://xx.xx.xx.216:10000/crank/getPlayerRank/1_1_50
Running 30s test @ http://xx.xx.xx.216:10000/crank/getPlayerRank/1_1_50
  8 threads and 100 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency    80.97ms    9.95ms 152.99ms   79.49%
    Req/Sec   148.61     21.99   232.00     72.35%
  Latency Distribution
     50%   79.19ms
     75%   84.85ms
     90%   91.94ms
     99%  119.76ms
  35550 requests in 30.03s, 686.81MB read
Requests/sec:   1183.88
Transfer/sec:     22.87MB
​

  • 8线程，200连接

    root@localhost:wrk-master# ./wrk -t8 -c200 -d30s --latency  http://xx.xx.xx.216:10000/crank/getPlayerRank/1_1_50
Running 30s test @ http://xx.xx.xx.216:10000/crank/getPlayerRank/1_1_50
  8 threads and 200 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency   154.29ms   14.25ms 344.59ms   87.58%
    Req/Sec   162.45     36.30   356.00     66.53%
  Latency Distribution
     50%  153.55ms
     75%  159.74ms
     90%  166.35ms
     99%  190.40ms
  38821 requests in 30.03s, 750.00MB read
Requests/sec:   1292.76
Transfer/sec:     24.98MB

异步接口

  • 8线程，100连接

    root@localhost:wrk-master# ./wrk -t8 -c100 -d30s --latency  http://xx.xx.xx.216:10000/crank/getPlayerRankAsync/1_1_50
Running 30s test @ http://xx.xx.xx.216:10000/crank/getPlayerRankAsync/1_1_50
  8 threads and 100 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency    49.45ms   20.43ms 190.99ms   71.18%
    Req/Sec   245.10     38.77   370.00     69.75%
  Latency Distribution
     50%   46.08ms
     75%   60.51ms
     90%   76.46ms
     99%  112.66ms
  58712 requests in 30.08s, 1.06GB read
Requests/sec:   1952.13
Transfer/sec:     36.08MB
​

  • 8线程，200连接

    root@localhost:wrk-master# ./wrk -t8 -c200 -d30s --latency  http://xx.xx.xx.216:10000/crank/getPlayerRankAsync/1_1_50
Running 30s test @ http://xx.xx.xx.216:10000/crank/getPlayerRankAsync/1_1_50
  8 threads and 200 connections
 Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency    47.63ms   18.77ms 189.96ms   71.27%
    Req/Sec   254.37     35.42   353.00     69.58%
  Latency Distribution
     50%   44.67ms
     75%   57.79ms
     90%   72.09ms
     99%  105.99ms
  60856 requests in 30.07s, 1.10GB read
Requests/sec:   2023.79
Transfer/sec:     37.41MB
​
​

集群测试

工具使用

nginx性能分析工具：openresty-systemtap-toolkit; stapxx

需要事先安装SystemTAP以及kernel的bebuginfo包，这里不做赘述。

在OpenResty中有两个开源项目:openresty-systemtap-toolkit和stapxx。它们是基于Systemtap封装好的工具集，用于Nginx和OpenResty的实时分析和诊断，可以覆盖onCPU 、offCPU、共享字典、垃圾回收、请求延迟、内存池、连接池、文件访问等常用功能和调试场景。

火焰图生成工具：FlameGraph

测试环境

压测机：xx.xx.xx.49 8核 万兆带宽

nginx服务器：xx.xx.xx.49

上游服务器组：

xx.xx.xx.17 16核 16G内存 万兆带宽

xx.xx.xx.216 ​6核 20G内存 万兆带

xx.xx.xx.74 4核 8G内存 万兆带宽

数据库：Mongodb4.2.3，总数据量100万个文档，查询文档数100个

部署于10.11.10.30 12核 12G内存

压测命令：

同步 ./wrk -t16 -c300 -d120s --latency http://localhost:80/crank/getPlayerRank/1_1_50

异步 ./wrk -t16 -c300 -d120s --latency http://localhost:80/crank/getPlayerRankAsync/1_1_50

压测过程

各台机单机测试结果

  • xx.xx.xx.74

    root@localhost:wrk-master# ./wrk -t16 -c300 -d30s --latency  http://xx.xx.xx.74:10000/crank/getPlayerRankAsync/1_1_50
Running 30s test @ http://xx.xx.xx.74:10000/crank/getPlayerRankAsync/1_1_50
  16 threads and 300 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency   168.61ms   30.11ms 418.15ms   72.29%
    Req/Sec   107.26     24.81   191.00     69.20%
  Latency Distribution
     50%  168.79ms
     75%  186.32ms
     90%  203.79ms
     99%  243.63ms
  51120 requests in 30.03s, 0.92GB read
Requests/sec:   1702.40
Transfer/sec:     31.47MB

  • xx.xx.xx.216

    root@localhost:wrk-master# ./wrk -t16 -c300 -d30s --latency  http://xx.xx.xx.216:10000/crank/getPlayerRankAsync/1_1_50
Running 30s test @ http://xx.xx.xx.216:10000/crank/getPlayerRankAsync/1_1_50
  16 threads and 300 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency   144.67ms   27.78ms 456.42ms   75.23%
    Req/Sec   124.80     23.99   190.00     66.23%
  Latency Distribution
     50%  144.93ms
     75%  159.49ms
     90%  174.50ms
     99%  227.56ms
  59613 requests in 30.04s, 1.08GB read
Requests/sec:   1984.68
Transfer/sec:     36.69MB
​

  • xx.xx.xx.17

    root@localhost:wrk-master# ./wrk -t16 -c300 -d30s --latency  http://xx.xx.xx.17:10000/crank/getPlayerRankAsync/1_1_50
Running 30s test @ http://xx.xx.xx.17:10000/crank/getPlayerRankAsync/1_1_50
  16 threads and 300 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency   121.32ms   45.76ms 485.47ms   74.13%
    Req/Sec   148.95     35.55   260.00     69.42%
  Latency Distribution
     50%  117.09ms
     75%  145.59ms
     90%  174.42ms
     99%  267.22ms
  71274 requests in 30.03s, 1.29GB read
Requests/sec:   2673.33
Transfer/sec:     43.87MB
​

首次测试

root@localhost:wrk-master# ./wrk -t16 -c500 -d40s --latency  http://localhost:80/crank/getPlayerRankAsync/1_1_50
Running 40s test @ http://localhost:80/crank/getPlayerRankAsync/1_1_50
  16 threads and 500 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency   136.44ms  112.89ms 849.86ms   66.91%
    Req/Sec   248.98     75.84   520.00     70.89%
  Latency Distribution
     50%  125.99ms
     75%  211.94ms
     90%  285.44ms
     99%  467.16ms
  158584 requests in 40.04s, 2.88GB read
Requests/sec:   3960.99
Transfer/sec:     73.59MB

首次测试结果尚未达到预期，我们首先分析Nginx端的性能情况：

Nginx性能分析

通过top命令看一个大致的CPU负载及使用率：

Tasks: 297 total,   2 running, 295 sleeping,   0 stopped,   0 zombie
%Cpu0  :  5.0 us,  8.4 sy,  0.0 ni, 81.3 id,  0.0 wa,  0.0 hi,  5.4 si,  0.0 st
%Cpu1  :  4.4 us,  3.7 sy,  0.0 ni, 89.9 id,  0.0 wa,  0.0 hi,  2.0 si,  0.0 st
%Cpu2  :  5.4 us,  6.7 sy,  0.0 ni, 82.6 id,  0.0 wa,  0.0 hi,  5.4 si,  0.0 st
%Cpu3  :  5.8 us,  8.2 sy,  0.0 ni, 80.6 id,  0.7 wa,  0.0 hi,  4.8 si,  0.0 st
%Cpu4  :  6.7 us,  7.4 sy,  0.0 ni, 81.1 id,  0.0 wa,  0.0 hi,  4.7 si,  0.0 st
%Cpu5  :  4.4 us,  7.7 sy,  0.0 ni, 83.2 id,  0.0 wa,  0.0 hi,  4.7 si,  0.0 st
%Cpu6  :  6.4 us,  5.7 sy,  0.0 ni, 83.4 id,  0.0 wa,  0.0 hi,  4.4 si,  0.0 st
%Cpu7  :  5.8 us,  3.8 sy,  0.0 ni, 83.2 id,  0.0 wa,  0.0 hi,  7.2 si,  0.0 st
KiB Mem : 32771584 total,  4231832 free, 10005316 used, 18534436 buff/cache
KiB Swap:  8388604 total,  8240380 free,   148224 used. 21692928 avail Mem
​

可以看到，基本上没什么压力，通过ngx-single-req-latency.sxx监控某条Worker进程，观察单次请求耗时分布：

root@localhost:samples# ./ngx-single-req-latency.sxx  -x 51561
Start tracing process 51561 (/usr/local/nginx/sbin/nginx)...
​
[1622455837141478] pid:51561 GET /crank/getPlayerRankAsync/1_1_50
    total: 48570us, accept() ~ header-read: 44us, rewrite: 7us, pre-access: 13us, access: 11us, content: 48475us
    upstream: connect=8us, time-to-first-byte=48047us, read=0us
​

可以看到绝大部分时间都花费在time-to-first-byte 即等待上游服务器初始响应所花费的时间，nginx处理请求及建立连接的时间基本可以忽略不计了。

我们尝试从另一个角度观察Nginx的性能——火焰图；

火焰图的生成分成采集数据和生成图片两个过程，这两个过程中有多种工具可选，这里我们用satpxx作为数据收集，FlameGraph生成火焰图。

用到的satpxx命令为：./sample-bt.sxx ：用于采集on-CPU时间，分析CPU的使用率；

这里用了一个脚本，自动生成火焰图：

export PATH=/usr/local/nginx-tool/stapxx-master:/usr/local/FlameGraph/FlameGraph-master:/usr/local/nginx-tool/openresty-systemtap-toolkit-master:$PATH
pid=$(ps aux |grep '/usr/local/nginx/sbin/nginx'|grep master |awk '{print $2}')
./samples/sample-bt.sxx --arg time=20 --skip-badvars -D MAXSKIPPED=100000 -D MAXMAPENTRIES=100000 --master $pid>a.bt
stackcollapse-stap.pl a.bt>a.cbt
flamegraph.pl a.cbt>a.svg
​

nginx.jpg

y 轴表示调用栈，每一层都是一个函数。调用栈越深，火焰就越高，顶部就是正在执行的函数，下方都是它的父函数。

x 轴表示抽样数，如果一个函数在 x 轴占据的宽度越宽，就表示它被抽到的次数多，即执行的时间长。注意，x 轴不代表时间，而是所有的调用栈合并后，按字母顺序排列的。

火焰图就是看顶层的哪个函数占据的宽度最大。只要有"平顶"（plateaus），就表示该函数可能存在性能问题。

图中writev/readv分别为写入/读取buffer，epoll wait即epoll机制中用于等待事件的产生，捕获所有的网络接口的读写事件。可以看到，顶层函数都是基本都是在与网络层打交道，内部的请求处理基本不占时间。

负载均衡算法调整

由于上游服务器组各自的机器性能有明显差异，所以我们不能按照默认的轮询机制进行负载均衡，需根据每台机器做出适当调整，调整的原则：使每台机器达到单机测试的极限负载。主要观察新增连接数（sar -n SOCK）、CPU1分钟负载及CPU使用率（这里主要看用户级别的使用率）。

首次测试中17服这台机子的CPU负载，差不多为单机极限测试的一半，通过不断调整权重，最终得到的最优权重比为：

  upstream match{
          least_conn;
          server xx.xx.xx.74:10000 weight=1 ;
          server xx.xx.xx.216:10000 weight=1 ;
          server xx.xx.xx.17:10000 weight=4 ;
          keepalive 1000;
    }
​

最少连接计算复杂均衡策略下，会在上游服务器组中各服务器权重的前提下将客户端请求分配给活跃连接最少的被代理服务器。

计算过程：

1.比较各个后端的活跃连接数（conns）与其权重（weight）的比值，选比值最小的分配客户端请求

2.如果上一次请求了a服务器，则当前请求将在b和c服务器中选择。

root@localhost:wrk-master# ./wrk -t16 -c500 -d30s --latency  http://localhost:80/crank/getPlayerRankAsync/1_1_50
Running 30s test @ http://localhost:80/crank/getPlayerRankAsync/1_1_50
  16 threads and 500 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency   131.78ms  162.92ms   1.95s    91.92%
    Req/Sec   308.96     75.80   636.00     71.26%
  Latency Distribution
     50%   86.44ms
     75%  147.74ms
     90%  258.26ms
     99%  936.16ms
  147646 requests in 30.10s, 2.68GB read
  Socket errors: connect 0, read 0, write 0, timeout 10
Requests/sec:   4905.67
Transfer/sec:     91.14MB
​

吞吐量也有所提升。

TIME-WAIT数量过多问题

在多次测试中发现，吞吐量会随着测试的次数逐步下降，通过上文中的单机分析流程，最终在网络监测那块定位到TIME-WAIT数量过多问题（sar -n SOCK）：

Linux 3.10.0-957.el7.x86_64 (localhost.localdomain)     05/29/2021      _x86_64_        (6 CPU)
​
11:54:00 PM    totsck    tcpsck    udpsck    rawsck   ip-frag    tcp-tw
11:54:01 PM      1871       765         0         0         0      6000
11:54:02 PM      1874       772         0         0         0      6000
11:54:03 PM      1875       769         0         0         0      6000
11:54:04 PM      1873       762         0         0         0      6000
11:54:05 PM      1875       762         0         0         0      6000
11:54:06 PM      1875       776         0         0         0      6000
11:54:07 PM      1875       765         0         0         0      6000

以上取自上游服务器中的216服，在每次压力测试结束后，TIME-WAIT数量从100多都会剧增到6000，之后逐渐回落。

这里做个补充，TIME_WAIT是TCP关闭连接中，主动关闭的一方，在接收到对方的FIN包并给出ACK应答后，会进入的一个状态。TCP是建立在不可靠网络上的可靠协议，主动方发送的ACK包可能延迟，从而触发被动方的FIN包重传，这一来一去，就是2MSL的时间，因此，必须要有这个状态，来保证TCP的可靠性。

有TIME_WAIT不奇怪，但数量不能多，大量的TIME_WAIT意味着，要么是用的短连接，要么就是服务端的连接池过小，除了连接池维护的部分连接，其余连接会不断在创建、销毁，服务端主动关闭连接，连接进入TIME_WAIT状态等待回收。

Nginx端与上游服务器默认采用的是短连接，导致每次请求处理后连接都会被服务端关闭，需在Nginx配置的server域中加入以下指令使之变为长连接：

proxy_set_header Connection "";
proxy_http_version 1.1;

再次观察连接TIME_WAIT情况：

[root@cqs_xx.xx.xx.216 ~]#sar -n SOCK 1 100
Linux 3.10.0-1127.18.2.el7.x86_64 (cqs_xx.xx.xx.216)     05/31/2021      _x86_64_        (6 CPU)
​
10:34:28 PM    totsck    tcpsck    udpsck    rawsck   ip-frag    tcp-tw
10:34:29 PM      1874        76         1         0         0        75
10:34:30 PM      1874        76         1         0         0        75
10:34:31 PM      1874        76         1         0         0        75
10:34:31 PM      1874        76         1         0         0        75
Average:         1874        76         1         0         0        75
​

上游服务器TIME_WAIT数基本稳定在75左右不再增长。

但此时另一个问题出现了，TIME-WAIT转移到了Nginx服务端。。。

​
Linux 3.10.0-957.el7.x86_64 (localhost.localdomain)     05/31/2021      _x86_64_        (8 CPU)
​
10:44:47 PM    totsck    tcpsck    udpsck    rawsck   ip-frag    tcp-tw
10:44:48 PM      2801      1668         0         0         0      6000
10:44:49 PM      2801      1668         0         0         0      6000
10:44:50 PM      2802      1669         0         0         0      6000
10:44:51 PM      2801      1672         0         0         0      6000
10:44:52 PM      2801      1670         0         0         0      5708
10:44:53 PM      2801      1668         0         0         0      6000
10:44:54 PM      2789      1665         0         0         0      6000
​
​

根据上文提到，哪边主动关连接，TIME_WAIT则出现在那边，可见是Nginx端主动关闭的连接，这时就要引出另一个参数——KeepAlive；

Activates the cache for connections to upstream servers. 激活到upstream服务器的连接缓存。

The connections parameter sets the maximum number of idle keepalive connections to upstream servers that are preserved in the cache of each worker process. When this number is exceeded, the least recently used connections are closed. connections参数设置每个worker进程在缓冲中保持的到upstream服务器的空闲keepalive连接的最大数量.当这个数量被突破时，最近使用最少的连接将被关闭。

It should be particularly noted that the keepalive directive does not limit the total number of connections to upstream servers that an nginx worker process can open. The connections parameter should be set to a number small enough to let upstream servers process new incoming connections as well. 特别提醒：keepalive指令不会限制一个nginx worker进程到upstream服务器连接的总数量。connections参数应该设置为一个足够小的数字来让upstream服务器来处理新进来的连接。

keepalive即最大空闲连接数量，默认不使用连接池，则客户端（nginx）在每次请求后都会销毁连接，那么出现大量TIME-WAIT则不奇怪了。我们在upstream域中配上Keepalive：

upstream match{
          least_conn;
          server xx.xx.xx.74:10000 weight=1 ;
          server xx.xx.xx.216:10000 weight=1 ;
          server xx.xx.xx.17:10000 weight=4 ;
          keepalive 1000;
    }
​

Linux 3.10.0-957.el7.x86_64 (localhost.localdomain)     06/01/2021      _x86_64_        (8 CPU)
​
10:31:56 AM    totsck    tcpsck    udpsck    rawsck   ip-frag    tcp-tw
10:31:57 AM      1296       172         0         0         0       126
10:31:58 AM      1296       172         0         0         0       111
10:31:59 AM      1296       172         0         0         0       111
10:32:00 AM      1299       174         0         0         0       112
10:32:01 AM      1300       174         0         0         0       116
​

TIME-WAIT不再增长。

惊群效应及accept_mutex

nginx接受请求流程：主进程首先调用listen创建监听TCP套接字，进行监听，接着调用fork创建多进程，子进程内部调用阻塞accept等待连接请求，当有TCP连接请求到达时，这些子进程全部被唤醒并抢占连接请求，抢占到的子进程会获得该连接请求并创建TCP连接，然后进行handle。抢占不到连接请求的进程会收到EAGAIN错误并在下次调用阻塞accept时再次挂起。

多个进程因为一个连接请求而被同时唤醒，称为惊群效应，在高并发情况下，大部分进程会无效地被唤醒然后因为抢占不到连接请求又重新进入睡眠，是会造成系统极大的性能损耗。

nginx缺省激活了accept_mutex，也就是说不会有惊群问题，但真的有那么严重么？实际上Nginx作者Igor Sysoev曾经给过相关的解释：

OS may wake all processes waiting on accept() and select(), this is called thundering herd problem. This is a problem if you have a lot of workers as in Apache (hundreds and more), but this insensible if you have just several workers as nginx usually has. Therefore turning accept_mutex off is as scheduling incoming connection by OS via select/kqueue/epoll/etc (but not accept()).

简单点说：Apache动辄就会启动成百上千的进程，如果发生惊群问题的话，影响相对较大；但是对Nginx而言，一般来说，worker_processes会设置成CPU个数，所以最多也就几十个，即便发生惊群问题的话，影响相对也较小。

…

假设你养了一百只小鸡，现在你有一粒粮食，那么有两种喂食方法：

你把这粒粮食直接扔到小鸡中间，一百只小鸡一起上来抢，最终只有一只小鸡能得手，其它九十九只小鸡只能铩羽而归。这就相当于关闭了accept_mutex。 你主动抓一只小鸡过来，把这粒粮食塞到它嘴里，其它九十九只小鸡对此浑然不知，该睡觉睡觉。这就相当于激活了accept_mutex。 可以看到此场景下，激活accept_mutex相对更好一些，让我们修改一下问题的场景，我不再只有一粒粮食，而是一盆粮食，怎么办？

此时如果仍然采用主动抓小鸡过来塞粮食的做法就太低效了，一盆粮食不知何年何月才能喂完，大家可以设想一下几十只小鸡排队等着喂食时那种翘首以盼的情景。此时更好的方法是把这盆粮食直接撒到小鸡中间，让它们自己去抢，虽然这可能会造成一定程度的混乱，但是整体的效率无疑大大增强了。

Nginx缺省激活了accept_mutex（最新版缺省禁用），是一种保守的选择。如果关闭了它，可能会引起一定程度的惊群问题，表现为上下文切换增多（sar -w）或者负载上升，但是如果访问量比较大，为了系统的吞吐量，还是建议大家关闭它。

——blog.huoding.com/2013/08/24

我们可以通过openresty-systemtap-toolkit-master的./ngx-req-distr -m “nginx的pid”来看请求在各个工作进程的分布情况，

Mongo性能分析

机器大体状态

[root@localhost bin]# top
top - 15:42:50 up 5 days,  4:37,  4 users,  load average: 30.48, 17.56, 10.51
Tasks: 280 total,   1 running, 279 sleeping,   0 stopped,   0 zombie
%Cpu0  : 59.4 us,  6.5 sy,  0.0 ni, 28.0 id,  0.0 wa,  0.0 hi,  6.1 si,  0.0 st
%Cpu1  : 59.3 us,  7.1 sy,  0.0 ni, 27.5 id,  0.0 wa,  0.0 hi,  6.1 si,  0.0 st
%Cpu2  : 58.6 us,  6.4 sy,  0.0 ni, 28.8 id,  0.0 wa,  0.0 hi,  6.1 si,  0.0 st
%Cpu3  : 59.3 us,  6.8 sy,  0.0 ni, 28.5 id,  0.0 wa,  0.0 hi,  5.4 si,  0.0 st
%Cpu4  : 57.2 us,  7.7 sy,  0.0 ni, 34.7 id,  0.0 wa,  0.0 hi,  0.3 si,  0.0 st
%Cpu5  : 63.6 us,  7.1 sy,  0.0 ni, 23.1 id,  0.0 wa,  0.0 hi,  6.1 si,  0.0 st
%Cpu6  : 49.5 us,  5.8 sy,  0.0 ni, 40.2 id,  0.0 wa,  0.0 hi,  4.5 si,  0.0 st
%Cpu7  : 50.0 us,  6.7 sy,  0.0 ni, 43.3 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
%Cpu8  : 53.6 us,  5.2 sy,  0.0 ni, 35.4 id,  0.0 wa,  0.0 hi,  5.8 si,  0.0 st
%Cpu9  : 47.4 us,  5.1 sy,  0.0 ni, 47.4 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
%Cpu10 : 57.9 us,  5.2 sy,  0.0 ni, 31.7 id,  0.0 wa,  0.0 hi,  5.2 si,  0.0 st
%Cpu11 : 59.8 us,  8.1 sy,  0.0 ni, 32.1 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
KiB Mem : 12119052 total,   160944 free,  5752388 used,  6205720 buff/cache
KiB Swap:  8388604 total,  6295696 free,  2092908 used.  5907880 avail Mem
​
   PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND
 49550 root      20   0    9.9g 805428   9232 S 779.7  6.6   2580:20 mongod
  2506 1000      20   0   36.9g   2.8g 666368 S   4.0 24.0 997:50.52 java
  2859 1000      20   0 9328788   1.7g   6244 S   2.0 14.5 186:07.34 java
​

12核负载最高跑到30出头，CPU使用率最高不超过70%。

一般来说CPU使用率在85%以下就可以说明CPU尚未达到瓶颈，几千TPS，CPU这个表现算是合理的。

mongostat

insert query update delete getmore command dirty  used flushes vsize  res  qrw  arw net_in net_out conn    set repl                time
    *0    *0     *0     *0   18034  6013|0  0.1% 25.1%       0 9.75G 719M  2|0  6|0  8.12m    167m  333 dbRes1  PRI Jun  1 11:57:49.485
    *0    *0     *0     *0   17208  5758|0  0.1% 25.1%       0 9.75G 719M  0|0  8|0  7.75m    159m  333 dbRes1  PRI Jun  1 11:57:50.487
    *0    *0     *0     *0   16987  5631|0  0.1% 25.1%       0 9.75G 719M  0|0  9|0  7.63m    157m  333 dbRes1  PRI Jun  1 11:57:51.486
    *0     7    764     *0   17472  5896|0  0.2% 25.1%       0 9.75G 719M  0|0 10|0  8.04m    162m  333 dbRes1  PRI Jun  1 11:57:52.486
    *0    *0     *0     *0   14945  4996|0  0.2% 25.1%       0 9.75G 719M  1|0  4|0  6.75m    138m  333 dbRes1  PRI Jun  1 11:57:53.495
    *0     5     *0     *0   14018  4656|0  0.2% 25.1%       0 9.75G 719M  0|0  4|0  6.28m    130m  333 dbRes1  PRI Jun  1 11:57:54.486
    *0    *0     *0     *0   10574  3524|0  0.2% 25.1%       0 9.75G 719M  2|0  3|0  4.76m   97.8m  333 dbRes1  PRI Jun  1 11:57:55.486
    *0    *0     *0     *0   12845  4292|0  0.2% 25.1%       0 9.75G 719M  0|0  7|0  5.78m    119m  333 dbRes1  PRI Jun  1 11:57:56.488
    *0    *0     *0     *0   14862  4939|0  0.2% 25.1%       0 9.75G 719M  1|0  4|0  6.68m    137m  333 dbRes1  PRI Jun  1 11:57:57.485
​

最终吞吐量结果

root@localhost:wrk-master# ./wrk -t16 -c400 -d40s --latency  http://localhost:80/crank/getPlayerRankAsync/1_1_50
Running 40s test @ http://localhost:80/crank/getPlayerRankAsync/1_1_50
  16 threads and 400 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency    73.38ms   54.40ms 591.28ms   75.66%
    Req/Sec   367.61     70.50   585.00     74.00%
  Latency Distribution
     50%   63.38ms
     75%  103.25ms
     90%  140.40ms
     99%  259.74ms
  234396 requests in 40.03s, 4.25GB read
Requests/sec:   5855.11
Transfer/sec:    108.69MB
​

总结

本文旨在分享性能压测下可能的观测角度，文中的各个阶段的吞吐量是 “基于特定机器下”，并无太大参考价值。排行榜也并非要用MongoDB实现，比如可以换成Redis，实际上笔者也实现过Redis版本，在这种架构上，其并未表现出比Mongo更好的性能，且实现的复杂度要高于Mongo（比如说zset实现多值排序会很妖娆）；又或者是在中心服增加二级缓存（游戏服，即客户端已有实现一级缓存），但一旦引进缓存，就会提高系统的复杂度，需要考虑缓存的实效、更新、一致性等问题，尤其是在集群环境更难把控，笔者认为如果可以通过增强CPU、IO本身的性能（比如扩展服务器的数量）来满足需要的话，那升级硬件往往是更好的解决方案。即便要多花点钱，也通常比缓存带来的风险更低。从以上的压测结果来看，也确实是硬件上，尤其是CPU存在瓶颈。

本人才疏学浅，如有纰漏，欢迎各位同行指正。

avatar
文章
阅读
粉丝