01、问题背景
今天在线上遇到了一个MongoDB的性能问题，经过排查和参数调优，最终解决，还是很有收获，这里记录下整个问题排查过程以及思路，如果你不是搞MongoDB数据库的，那看看也无妨，这个排查问题的思路，后续会对你排查其他数据库有帮助。
问题描述：接到业务反馈线上的一个MongoDB副本集环境写入很慢，存在很多超时报警。设定的报警阈值是2s，一旦查询或者写入超过2s，就会触发报警，而本次报警的内容基本上都是写入报警，查询上面的报警较少。
02、基本的分析排查思路
通常情况下，一个业务请求从客户端发出，到客户端受到请求的反馈，需要经过一下的链路：
这个链路分为客户端、网络链路、服务器三个部分，任何一个环节出了差错，都会导致访问慢的问题，例如客户端部署的服务器负载高、网络链路带宽跑满、服务器上的慢查询等等问题，都可能表现为响应超时，所以，这里想说的是，如果你是一个开发，发现数据库返回时间超时了，请同时检查客户端和网络层面的问题，而不要直接把问题都丢给DBA。
这里给出我的排查思路
1、分析响应慢的问题
那么我们目前面临的问题是写入慢，而读取速度正常，通常情况下，跟网络关系就不太明显，因为网络如果慢，那么读写都会慢，看起来，更像是数据库服务器端的问题，那么我们的重点就是关注MongoDB数据库服务层面的问题。
首先，写入比较慢，我们可以通过查看mongodb的log，来查看写入慢的那些语句的具体执行时间，通常情况下，MongoDB默认会记录所有的查询语句，如果你想要的记录的内容更加丰富，可以使用db.setLogLevel的命令来设置mongodb的log等级。我们可以看到，log中的内容如下(省略了记录)：
代码语言：javascript复制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左右，会有小幅抖动：
代码语言：javascript复制 ------ ---------- --- ------- ----------- ----------- -------- ---------
|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，能够看到数据库目前在干什么事情，执行了多长时间，一个常用的命令如下：
代码语言：javascript复制db.currentOp({"secs_running":{"$gt":3600}})这个命令表示，查看当前数据库耗时超过3600s的操作。
执行的结果是：没有类似的操作，我把阈值设置成100s，还是没有结果。
这个结果表示，当前数据库上没有其他耗费资源的操作。
5、使用MongoDB的性能分析工具mongostat查看数据库状态
mongostat对这个副本集的Primary节点进行了分析，注意，因为插入只能在Primary节点操作，所以对Primary节点进行分析：
代码语言：javascript复制[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：
代码语言：javascript复制db.adminCommand({setParameter: 1, wiredTigerEngineRuntimeConfig: "cache_size=40G"})
官方文档也给出了修改wiredTiger存储引擎其他参数的命令：
详细可以查看：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、来看内存的变化（因为我们设置的缘故，有一个明显增长）：
- 3、再来看连接数的变化：
使用db.serverStatus().connections来对比实际连接数：
代码语言：javascript复制扩容内存前：
------ ---------- --- ------- ----------- ----------- -------- ---------
|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个参数控制的，
代码语言：javascript复制参数 默认值 含义
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、执行后的反思和拓展
