MongoDB线上案例：一个参数提升16倍写入速度

时间：2022-09-19 21:20:26人气：次作者：快盘下载我要评论

01、问题背景

今天在线上遇到了一个MongoDB的性能问题，经过排查和参数调优，最终解决，还是很有收获，这里记录下整个问题排查过程以及思路，如果你不是搞MongoDB数据库的，那看看也无妨，这个排查问题的思路，后续会对你排查其他数据库有帮助。

问题描述：接到业务反馈线上的一个MongoDB副本集环境写入很慢，存在很多超时报警。设定的报警阈值是2s，一旦查询或者写入超过2s，就会触发报警，而本次报警的内容基本上都是写入报警，查询上面的报警较少。

02、基本的分析排查思路

通常情况下，一个业务请求从客户端发出，到客户端受到请求的反馈，需要经过一下的链路：

MongoDB线上案例：一个参数提升16倍写入速度

这个链路分为客户端、网络链路、服务器三个部分，任何一个环节出了差错，都会导致访问慢的问题，例如客户端部署的服务器负载高、网络链路带宽跑满、服务器上的慢查询等等问题，都可能表现为响应超时，所以，这里想说的是，如果你是一个开发，发现数据库返回时间超时了，请同时检查客户端和网络层面的问题，而不要直接把问题都丢给DBA。

这里给出我的排查思路

1、分析响应慢的问题

那么我们目前面临的问题是写入慢，而读取速度正常，通常情况下，跟网络关系就不太明显，因为网络如果慢，那么读写都会慢，看起来，更像是数据库服务器端的问题，那么我们的重点就是关注MongoDB数据库服务层面的问题。

首先，写入比较慢，我们可以通过查看mongodb的log，来查看写入慢的那些语句的具体执行时间，通常情况下，MongoDB默认会记录所有的查询语句，如果你想要的记录的内容更加丰富，可以使用db.setLogLevel的命令来设置mongodb的log等级。我们可以看到，log中的内容如下(省略了记录)：

2021-08-03T10:17:41.912+0800 I COMMAND  [conn2005245099] command fs.xxx command: insert { xxx }   protocol:op_query 16169ms
2021-08-03T10:17:41.913+0800 I COMMAND  [conn2005245095] command fs.xxx command: insert { xxx }   protocol:op_query 16165ms
2021-08-03T10:17:41.913+0800 I COMMAND  [conn2005245101] command fs.xxx command: insert { xxx }   protocol:op_query 16161ms
2021-08-03T10:17:41.913+0800 I COMMAND  [conn2005245107] command fs.xxx command: insert { xxx }   protocol:op_query 16148ms
2021-08-03T10:17:41.913+0800 I COMMAND  [conn2005245106] command fs.xxx command: insert { xxx }   protocol:op_query 16146ms
2021-08-03T10:17:41.915+0800 I COMMAND  [conn2005245148] command fs.xxx command: insert { xxx }   protocol:op_query 16078ms
2021-08-03T10:17:41.915+0800 I COMMAND  [conn2005245138] command fs.xxx command: insert { xxx }   protocol:op_query 16090ms

可以看到，每行的最后面，都有执行时间，日志里面大量的insert语句，执行时间都是16s左右，这代表仅仅在MongoDB层面，一个insert语句，就需要执行16s，加上网络层面的开销，业务感知到的插入语句返回时间大概在20s左右，好在这个业务主要是保存图片信息的，每次插入对于时间不是特别敏感，但是最多能容忍2s的返回时间，这20s看起来，确实有点夸张了。

2、服务器级别分析

因为插入都是在MongoDB副本集的Primary节点来进行的，那么我们只需要分析Primary节点所在Linux服务器的基本情况，就可以从全局上对这个问题有一个总体的了解，分析服务器的指标包含但不限于CPU使用率、负载、内存、磁盘容量、TCP连接数等。

能够看到，除了TCP连接数有主键增多的趋势外，其他的指标没有特别明显的异常。TCP连接数增多，主要是业务的响应迟迟得不到返回，重新发起连接导致的，TCP的报警趋势图如下：

对应的，我们使用db.serverStatus().connections采集一下当前Primary节点所在服务器的连接数，可以发现，基本一致，都在7600左右，会有小幅抖动：

+------+----------+---+-------+-----------+-----------+--------+---------+
|TYPE  |STATE     |LAG|VERSION|node_CONF  |CONNECTIONS|MEM_USED|DISK_USED|
+------+----------+---+-------+-----------+-----------+--------+---------+
|mongod|          |   |       |           |           |        |         |
|      |PRIMARY   |0  |3.2.8  |P:1;D:0;H:0|7691/10000 |15.6GB  |1.3T     |
|      |SECONDARY |25 |3.2.8  |P:1;D:0;H:0|4599/10000 |11.3GB  |1.3T     |
|      |SECONDARY |17 |3.2.8  |P:1;D:0;H:0|4563/10000 |27.8GB  |1.3T     |
|      |SECONDARY |17 |3.2.8  |P:1;D:0;H:0|2984/10000 |12.2GB  |1.4T     |
|      |RECOVERING|   |3.2.8  |P:0;D:1;H:1|7/10000    |22.6GB  |1.4T     |
+------+----------+---+-------+-----------+-----------+--------+---------+

3、查看当前写入的表的基本情况

通常情况下，如果我们写入某个数据库中的集合比较慢，我们可以通过查看集合的基本情况来了解一些基本信息。

例如，集合的数据量和索引情况，在数据量比较大而索引较多的时候，每一个记录的插入，都需要维护集合上面的索引信息，那么这个插入问题肯定会被放大，耗时肯定比较长。MongoDB也类似mysql一样，采用插件式存储引擎架构，底层的WiredTiger存储引擎还可以支持B-Tree和LSM两种结构组织数据,但MongoDB在使用WiredTiger作为存储引擎时，目前默认配置是使用了B-Tree结构，B-Tree结构的话，索引原理大家就比较熟悉了，插入的时候肯定要产生数据页的裂变等维护开销，自然，索引和数据量对插入性能影响就很大

这个表的基本情况是：32亿条数据，6个索引。到这里，就能够解释为什么业务的阈值设置是2s了，因为正常情况下，如果根据自己生成的_id乱序插入的话，维护索引的时间代价就很大，如此大的数据量，达到秒级别，自然不稀奇。但是，一个插入20s，似乎还是说不过去。

这肯定不是主要原因，接着看。

4、查看当前数据库上是否有慢查询

如果当前这个数据库上存在其他操作持有排它锁，或者其他一些耗费巨额资源的查询操作，那么会导致数据库整体响应变慢。

对于MongoDB的慢查询，我一般喜欢使用currentOp这个命令看，这个命令类似于MySQL服务器中的show processlist，能够看到数据库目前在干什么事情，执行了多长时间，一个常用的命令如下：

db.currentOp({"secs_running":{"$gt":3600}})

这个命令表示，查看当前数据库耗时超过3600s的操作。

执行的结果是：没有类似的操作，我把阈值设置成100s，还是没有结果。

这个结果表示，当前数据库上没有其他耗费资源的操作。

5、使用MongoDB的性能分析工具mongostat查看数据库状态

mongostat对这个副本集的Primary节点进行了分析，注意，因为插入只能在Primary节点操作，所以对Primary节点进行分析：

[11:20:18]insert query update delete getmore command % dirty % used flushes vsize   res  qr|qw  ar|aw netIn netOut  conn        set repl                      time
[11:20:18]   262    34     *0     *0       2  2462|0     6.1   96.0       0 44.8G 15.4G  0|483  1|128  987k   604k  3639 comos_temp  PRI 2021-08-03T11:20:19+08:00
[11:20:19]   299    32     *0     *0       0  2668|0     6.1   96.0       0 45.3G 15.4G  0|790 15|128  990k   607k  4141 comos_temp  PRI 2021-08-03T11:20:20+08:00
[11:20:20]   250    28     *0     *0       4  2271|0     6.1   96.0       0 45.6G 15.4G  0|926 13|128  945k   732k  4397 comos_temp  PRI 2021-08-03T11:20:21+08:00
[11:20:21]   303    26     *0     *0       0  2706|0     6.1   96.0       0 46.0G 15.4G 0|1226 13|128    1m   600k  4841 comos_temp  PRI 2021-08-03T11:20:22+08:00
[11:20:22]   297    51     *0     *0       0  2570|0     4.8   96.0       1 46.4G 15.4G 0|1548 32|128  980k   558k  5231 comos_temp  PRI 2021-08-03T11:20:23+08:00
[11:20:23]   306    32     *0     *0       0  2453|0     4.3   96.0       0 46.7G 15.4G 0|1815  9|128  901k   582k  5537 comos_temp  PRI 2021-08-03T11:20:24+08:00
[11:20:25]   309    34     *0     *0       0  2608|0     3.3   96.0       0 47.0G 15.4G 0|2149 14|128  982k   577k  5842 comos_temp  PRI 2021-08-03T11:20:25+08:00
[11:20:26]   353    26     *0     *0       0  2959|0     1.3   96.0       0 47.5G 15.4G 0|2516 24|128    1m   657k  6339 comos_temp  PRI 2021-08-03T11:20:26+08:00
[11:20:27]   325    47     *0     *0       0  2821|0     0.5   96.0       0 48.0G 15.4G 0|2884 26|128  999k   679k  6875 comos_temp  PRI 2021-08-03T11:20:27+08:00
[11:20:28]   325    32     *0     *0       0  2759|0     0.2   96.0       0 48.4G 15.4G 0|3242 10|128  992k   658k  7267 comos_temp  PRI 2021-08-03T11:20:28+08:00

对mongostat性能分析工具的结果进行分析：

前面4个列分别代表每秒增删改查操作的次数；getmore代表游标信息，command代表mongod副本集之间的交互命令，dirty是一个关键参数，代表的是mongodb内存中被更新的脏数据占比，它有两个临界值，5%和20%。这些脏数据需要落在磁盘上，如果占比不超过5%，那么MongoDB会每分钟刷盘，如果超过5%，MongoDB会启动主动刷盘，尽量让这个数字不超过5%，如果写入太快，导致dirty的值超过20%，MongoDB就会阻塞新请求，全力以赴的刷盘。used另一个关键参数，它代表系统分配给MongoDB的内存中，已经被占用的内存比例，MongoDB默认情况下，最大会占用系统内存的60%，例如我们在100G内存中，MongoDB默认最大可以占用60G内存，而当used值为50%的时候，代表此时分配给MongoDB的内存已经被占用了30G。它也有2个临界值80%和95%，在低于80%的时候，MongoDB会认为当前分配的内存还没有被完全使用，不会做太多干预；如果高于80%了，MongoDB会认为内存冗余量不足，就会触发内存数据清理动作，清理策略是依据LRU算法的，旧数据会被踢出内存；一旦高于95%，那么代表MongoDB数据库承受着巨大的写入压力，就会阻塞其他操作，全力以赴淘汰内存中的数据。qr和qw，代表目前正在排队(queue)的read和write请求数量。ar和aw，代表目前活跃(active)的read和write请求conn，代表连接数。

其他参数不重要，这里不赘述。

有了上述参数的基础，我们可以看到，我们的检测结果中，used值已经达到了96%，而qw的值高达1k~2k，这说明当前分配给MongoDB的内存几乎耗尽，MongoDB承受巨大的写入压力，在努力淘汰内存中的数据。

到这里，整个分析过程就结束了，接下来就是对症治疗了。

03、解决方案及改善效果

分析出来问题所在之后，解决方案就很容易能够提出来了，我们查看服务器上的剩余内存，发现剩余内存比较充裕，那么给MongoDB分配更多的内存，就能够缓解这个问题。

要加内存，就得知道MongoDB中，哪个参数控制内存的分配，MongoDB 3.2 及以后，默认使用 WiredTiger 存储引擎，可通过 cacheSizeGB 选项配置 WiredTiger 引擎使用内存的上限，一般建议配置在系统可用内存的60%左右。

接下来就是扩大内存的命令了，我们把内存从15G扩容到40G：

db.adminCommand({setParameter: 1, wiredTigerEngineRuntimeConfig: "cache_size=40G"})

官方文档也给出了修改wiredTiger存储引擎其他参数的命令：

SQL

详细可以查看：https://docs.mongodb.com/v4.2/reference/parameters/index.html

接下来我们看看效果，

1、首先来看mongostat性能分析的输出变化，重点关注used列和qw列（排队等待的写入）：

[11:21:00]insert query update delete getmore command % dirty % used flushes vsize   res  qr|qw  ar|aw netIn netOut  conn        set repl                      time
[11:21:00]    39     7     *0     *0       0   949|0     2.6   96.0       0 51.1G 15.5G 0|5309  2|128  161k   412k 10000 comos_temp  PRI 2021-08-03T11:21:00+08:00
[11:21:01]   104    14     *0     *0       0  1224|0     2.7   96.0       0 51.1G 15.5G 1|5129  0|128  337k   510k 10000 comos_temp  PRI 2021-08-03T11:21:01+08:00
[11:21:02]   488    31     *0     *0       0  3544|0     3.1   96.0       0 51.1G 15.5G 0|4764  0|128    1m     1m 10000 comos_temp  PRI 2021-08-03T11:21:02+08:00
[11:21:03]   527    35     *0     *0       0  4164|0     3.4   96.0       0 51.1G 15.5G 0|4403  8|128    1m     1m  9999 comos_temp  PRI 2021-08-03T11:21:03+08:00
[11:21:04]   305    27     *0     *0       0  1964|0     3.4   96.0       0 51.1G 15.5G 0|4536  6|128  445k   696k 10000 comos_temp  PRI 2021-08-03T11:21:04+08:00
[11:21:05]   214    20     *0     *0       0  1645|0     3.5   96.0       0 51.1G 15.5G 0|4337  8|128  566k   620k 10000 comos_temp  PRI 2021-08-03T11:21:05+08:00
[11:21:06]   155    19     *0     *0       0  2312|0     3.5   96.0       0 51.1G 15.5G 0|4497  1|128  910k   552k 10000 comos_temp  PRI 2021-08-03T11:21:06+08:00
[11:21:07]   137    14     *0     *0       0  2103|0     3.6   96.0       0 51.1G 15.5G 0|4463  4|128  908k   513k 10000 comos_temp  PRI 2021-08-03T11:21:08+08:00
[11:21:08]   127    11     *0     *0       0  2090|0     3.6   96.0       0 51.1G 15.5G 0|4428  5|128  902k   515k 10000 comos_temp  PRI 2021-08-03T11:21:09+08:00
[11:21:09]   120    17     *0     *0       0  2261|0     3.6   96.0       0 51.2G 15.5G 0|4297  4|128  976k   597k 10000 comos_temp  PRI 2021-08-03T11:21:10+08:00
[11:21:10]insert query update delete getmore command % dirty % used flushes vsize   res  qr|qw  ar|aw netIn netOut  conn        set repl                      time
[11:21:10]   736    44     *0     *0       1  5314|0     1.3   32.3       1 50.2G 15.5G 0|2966  1|128    3m     2m  9109 comos_temp  PRI 2021-08-03T11:21:11+08:00
[11:21:11]   587    44     *0     *0      54  4655|0     1.3   32.7       0 46.9G 15.4G    0|1    0|1    3m    11m  5652 comos_temp  PRI 2021-08-03T11:21:12+08:00
[11:21:12]   433    38     *0     *0     349  3237|0     1.7   33.0       0 46.6G 15.4G    0|0    0|1    1m     3m  5402 comos_temp  PRI 2021-08-03T11:21:13+08:00
[11:21:13]   324    41     *0     *0     389  3112|0     1.5   33.3       0 46.5G 15.4G    0|0    0|2    1m     3m  5354 comos_temp  PRI 2021-08-03T11:21:14+08:00
[11:21:14]   328    46     *0     *0     463  3278|0     1.2   33.6       0 46.5G 15.4G    0|0    0|1    2m    11m  5268 comos_temp  PRI 2021-08-03T11:21:15+08:00
[11:21:15]   331    39     *0     *0     640  3172|0     1.1   33.8       0 46.4G 15.4G    0|0    2|1    2m     4m  5222 comos_temp  PRI 2021-08-03T11:21:16+08:00
[11:21:16]   343    37     *0     *0     661  3489|0     1.1   34.0       0 46.4G 15.4G    1|0    0|3    2m     4m  5206 comos_temp  PRI 2021-08-03T11:21:17+08:00
[11:21:17]   359    29     *0     *0     619  3364|0     1.3   34.2       0 46.4G 15.4G    0|0    0|4    2m     3m  5177 comos_temp  PRI 2021-08-03T11:21:18+08:00
[11:21:19]   332    45      2     *0     637  3771|0     1.5   34.5       0 46.4G 15.4G    0|0    0|2    2m     3m  5185 comos_temp  PRI 2021-08-03T11:21:19+08:00
[11:21:20]   297    25     *0     *0     636  3849|0     1.7   34.7       0 46.4G 15.4G    0|0    0|2    2m     3m  5203 comos_temp  PRI 2021-08-03T11:21:20+08:00

--------------省略若干行---------

[11:25:04]insert query update delete getmore command % dirty % used flushes vsize   res  qr|qw  ar|aw netIn netOut  conn        set repl                      time
[11:25:04]   354    24     *0     *0     631  2417|0    15.7   77.7       0 43.0G 26.6G    0|1    0|1    1m     5m  1735 comos_temp  PRI 2021-08-03T11:25:05+08:00
[11:25:05]   365    40      1     *0     636  2404|0    16.1   78.0       0 43.0G 26.7G    0|0    0|3    1m     4m  1730 comos_temp  PRI 2021-08-03T11:25:06+08:00
[11:25:06]   438    25      1     *0     635  2491|0    16.5   78.2       0 43.0G 26.8G    0|0    0|2    1m     4m  1675 comos_temp  PRI 2021-08-03T11:25:07+08:00
[11:25:07]   346    39     *0     *0     661  2692|0    16.9   78.5       0 42.9G 26.8G    0|0    0|1    1m     4m  1689 comos_temp  PRI 2021-08-03T11:25:08+08:00
[11:25:08]   359    27     *0     *0     673  2735|0    17.3   78.7       0 43.0G 26.9G    0|0    0|2    1m     4m  1697 comos_temp  PRI 2021-08-03T11:25:09+08:00
[11:25:09]   375    33     *0     *0     686  2622|0    17.7   79.0       0 43.0G 27.0G    0|0    0|1    1m     4m  1678 comos_temp  PRI 2021-08-03T11:25:10+08:00
[11:25:10]   264    18     *0     *0     697  2144|0    18.0   79.2       0 43.0G 27.0G    0|0    1|2    1m     4m  1706 comos_temp  PRI 2021-08-03T11:25:11+08:00
[11:25:11]   356    28     *0     *0     717  2435|0    18.5   79.4       0 43.0G 27.1G    0|0    0|1    1m     4m  1670 comos_temp  PRI 2021-08-03T11:25:12+08:00
[11:25:12]   286    30     *0     *0     711  2222|0    19.0   79.6       0 43.0G 27.2G    2|0    0|3    1m     4m  1687 comos_temp  PRI 2021-08-03T11:25:13+08:00
[11:25:13]   267    32     *0     *0     727  2556|0    19.3   79.8       0 43.0G 27.2G    0|0    0|1    1m     4m  1703 comos_temp  PRI 2021-08-03T11:25:14+08:00
[11:25:14]insert query update delete getmore command % dirty % used flushes vsize   res  qr|qw  ar|aw netIn netOut  conn        set repl                      time
[11:25:14]   300    30     *0     *0     706  2598|0    19.8   80.1       0 43.0G 27.3G    0|1    0|1    1m     5m  1682 comos_temp  PRI 2021-08-03T11:25:15+08:00
[11:25:15]   400    40     *0     *0     692  2508|0    20.3   79.9       0 42.9G 27.3G    0|0    0|2    1m     6m  1658 comos_temp  PRI 2021-08-03T11:25:16+08:00
[11:25:16]   289    17     *0     *0     715  1892|0    20.7   79.9       0 42.9G 27.4G    0|0    0|2  895k     5m  1671 comos_temp  PRI 2021-08-03T11:25:17+08:00
[11:25:17]   272    28     *0     *0     596  1534|0    20.8   80.0       0 42.9G 27.4G    0|0    0|0  581k     2m  1636 comos_temp  PRI 2021-08-03T11:25:18+08:00
[11:25:18]   272    27     *0      1     657  1521|0    21.1   80.1       0 42.9G 27.4G    0|0    1|2  597k     3m  1650 comos_temp  PRI 2021-08-03T11:25:19+08:00
[11:25:19]   293    25      1     *0     719  1696|0    21.4   80.0       0 42.9G 27.5G    0|0    0|1  653k     4m  1649 comos_temp  PRI 2021-08-03T11:25:20+08:00
[11:25:20]   244    36      1     *0     773  1455|0    21.8   80.1       0 42.9G 27.5G    0|0    0|1  587k     5m  1627 comos_temp  PRI 2021-08-03T11:25:21+08:00
[11:25:21]   313    33     *0     *0     757  1798|0    22.1   80.2       0 42.9G 27.5G    0|0    0|1  694k     5m  1624 comos_temp  PRI 2021-08-03T11:25:22+08:00
[11:25:22]   302    13     *0     *0     738  1798|0    22.5   80.2       0 42.9G 27.5G    0|1    0|1  717k     5m  1613 comos_temp  PRI 2021-08-03T11:25:23+08:00
[11:25:23]   300    30     *0     *0     756  2023|0    22.5   80.2       1 42.9G 27.6G    1|0    0|1  977k     5m  1611 comos_temp  PRI 2021-08-03T11:25:24+08:00
[11:25:24]insert query update delete getmore command % dirty % used flushes vsize   res  qr|qw  ar|aw netIn netOut  conn        set repl                      time
[11:25:24]   247    28     *0     *0     772  2257|0    22.1   80.1       0 42.9G 27.6G    0|0    0|1    1m     5m  1605 comos_temp  PRI 2021-08-03T11:25:25+08:00
[11:25:25]   244    20     *0     *0     682  1737|0    22.0   80.1       0 42.9G 27.6G    0|1    0|1  774k     4m  1595 comos_temp  PRI 2021-08-03T11:25:26+08:00
[11:25:26]   244    21     *0     *0     753  2105|0    21.9   80.0       0 42.9G 27.6G    0|0    0|1    1m     5m  1596 comos_temp  PRI 2021-08-03T11:25:27+08:00
[11:25:27]   286    26     *0     *0     723  1612|0    21.8   80.1       0 42.8G 27.6G    0|0    0|1  797k     5m  1569 comos_temp  PRI 2021-08-03T11:25:28+08:00
[11:25:28]   250    14     *0     *0     650  1325|0    21.5   80.0       0 42.8G 27.6G    0|0    0|1  661k     5m  1571 comos_temp  PRI 2021-08-03T11:25:29+08:00
[11:25:29]   306    25     *0     *0     692  1986|0    21.3   80.0       0 42.8G 27.7G    0|0    0|1  996k     5m  1563 comos_temp  PRI 2021-08-03T11:25:30+08:00
[11:25:30]   312    23     *0     *0     682  1957|0    21.0   80.0       0 42.8G 27.7G    0|1    1|1    1m     5m  1569 comos_temp  PRI 2021-08-03T11:25:31+08:00
[11:25:31]   287    26     *0     *0     695  2193|0    20.6   80.0       0 42.8G 27.7G    0|0    0|2    1m     6m  1580 comos_temp  PRI 2021-08-03T11:25:32+08:00
[11:25:32]   340    36     *0     *0     673  2328|0    20.2   80.0       0 42.8G 27.7G    0|0    0|1    1m     6m  1564 comos_temp  PRI 2021-08-03T11:25:33+08:00
[11:25:33]   406    32     *0     *0     621  2199|0    19.8   80.1       0 42.8G 27.7G    0|0    0|1    1m     5m  1572 comos_temp  PRI 2021-08-03T11:25:34+08:00

可以发现，扩容内存为40G之后，used列从96%直接降低到32%，然后逐渐上升到80%之后，稳定下来，而qw列从2000多降低到0，也就意味着没有了排队等待写入的记录了。

同时我们可以看到，dirty的值，增加到22%之后，后续开始减小，因为触发了MongoDB的全力刷盘机制，超过20%之后，就开始全力刷盘了

2、来看内存的变化（因为我们设置的缘故，有一个明显增长）：

MongoDB

3、再来看连接数的变化：

Linux

使用db.serverStatus().connections来对比实际连接数：

扩容内存前：
+------+----------+---+-------+-----------+-----------+--------+---------+
|TYPE  |STATE     |LAG|VERSION|NODE_CONF  |CONNECTIONS|MEM_USED|DISK_USED|
+------+----------+---+-------+-----------+-----------+--------+---------+
|mongod|          |   |       |           |           |        |         |
|      |PRIMARY   |0  |3.2.8  |P:1;D:0;H:0|9691/10000 |15.6GB  |1.3T     |
|      |SECONDARY |25 |3.2.8  |P:1;D:0;H:0|4599/10000 |11.3GB  |1.3T     |
|      |SECONDARY |17 |3.2.8  |P:1;D:0;H:0|4563/10000 |27.8GB  |1.3T     |
|      |SECONDARY |17 |3.2.8  |P:1;D:0;H:0|2984/10000 |12.2GB  |1.4T     |
|      |RECOVERING|   |3.2.8  |P:0;D:1;H:1|7/15000    |22.6GB  |1.4T     |
+------+----------+---+-------+-----------+-----------+--------+---------+

扩容内存后：
+------+----------+---+-------+-----------+-----------+--------+---------+
|TYPE  |STATE     |LAG|VERSION|NODE_CONF  |CONNECTIONS|MEM_USED|DISK_USED|
+------+----------+---+-------+-----------+-----------+--------+---------+
|mongod|          |   |       |           |           |        |         |
|      |PRIMARY   |0  |3.2.8  |P:1;D:0;H:0|2744/10000 |15.4GB  |1.3T     |
|      |SECONDARY |0  |3.2.8  |P:1;D:0;H:0|1939/10000 |11.4GB  |1.3T     |
|      |SECONDARY |10 |3.2.8  |P:1;D:0;H:0|1883/10000 |27.8GB  |1.3T     |
|      |SECONDARY |11 |3.2.8  |P:1;D:0;H:0|1882/10000 |14.6GB  |1.4T     |
|      |RECOVERING|   |3.2.8  |P:0;D:1;H:1|7/15000    |22.6GB  |1.4T     |
+------+----------+---+-------+-----------+-----------+--------+---------+

4、业务侧的超时监控（可以看到，超时数量少了很多）：

数据库

5、查看慢日志中的insert执行时间

2021-08-03T11:35:13.500+0800 I COMMAND [conn2006075353] command fs.xxx command: insert {xxx} protocol:op_query 1092ms

2021-08-03T11:35:13.501+0800 I COMMAND [conn2006023287] command fs.xxx command: insert {xxx} protocol:op_query 1114ms

可以看到，从一开始的16s，降低到目前的1s左右，insert速度提升了将近16倍

04、拓展和总结

1、为什么有4个阈值？

上面讲述dirty和used的时候，我们说到了临界值的概念，WiredTiger 引擎通过tcmalloc分配的内存总量不会超过cacheSizeDB的大小。为了控制内存的使用，WiredTiger 在内存使用接近一定阈值就会开始做淘汰，避免内存使用满了阻塞用户请求。于是乎就有了这4个阈值。

dirty有2个临界值，分别是5和20，而used有2个临界值，分别是80和95，

2、这个值可以根据我们的实际需求更改吗？

答案是：可以，但不建议

其实这4个阈值，是由下面的4个参数控制的，

参数                      默认值         含义
eviction_target          80             当 cache used 超过 eviction_target，后台evict线程开始淘汰 CLEAN PAGE
eviction_trigger         95             当 cache used 超过 eviction_trigger，用户线程也开始淘汰 CLEAN PAGE
eviction_dirty_target    5              当 cache dirty 超过 eviction_dirty_target，后台evict线程开始淘汰 DIRTY PAGE
eviction_dirty_trigger   20             当 cache dirty 超过 eviction_dirty_trigger, 用户线程也开始淘汰 DIRTY PAGE

在这个规则下，一个正常运行的 MongoDB 实例，cache used 一般会在 0.8 * cacheSizeGB 及以下，偶尔超出问题不大；如果出现 used>=95% 或者 dirty>=20%，并一直持续，说明内存淘汰压力很大，用户的请求线程会阻塞参与page淘汰，请求延时就会增加，这时可以考虑「扩大内存」或者「换更快的磁盘提升IO能力」。

总结：

1、排查数据库响应慢的问题，可以从客户端、网络、数据库服务三个层面考虑；

2、如果确定是数据库服务器问题，不妨从服务器开始排查，先总览全局；

3、服务器层面没问题，查看数据库的基本信息，例如数据库容量、索引、日志等问题

4、借助第三方工具来对性能瓶颈进行分析

5、根据最终的问题结论确定解决问题的方案

6、执行后的反思和拓展

上一篇：优化SQL语句的一般步骤

下一篇：MongoDB之balancer(2)