Uploaded image for project: 'Core Server'
  1. Core Server
  2. SERVER-44834

mongod block some time, dirty is very high, and do not evit data to disk, io is 0%, my disk is nvme-SSD(this disk io performance is very good)

    XMLWordPrintableJSON

Details

    • Icon: Bug Bug
    • Resolution: Community Answered
    • Icon: Major - P3 Major - P3
    • None
    • 3.6.14, 3.6.15
    • Performance, Replication
    • None
    • Fully Compatible
    • ALL
    • Hide

      dirty is very high, but do not evit to disk, disk io is 0%

       

      iostat log as following:

      11/22/2019 12:17:21 AM
      avg-cpu: %user %nice %system %iowait %steal %idle
      3.43 0.00 1.01 0.02 0.00 95.55

      Device: rrqm/s wrqm/s r/s w/s rkB/s wkB/s avgrq-sz avgqu-sz await r_await w_await svctm %util
      sda 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
      dfa 0.00 0.00 15.00 546.00 208.00 2588.00 9.97 0.00 0.01 0.00 0.01 0.01 0.30

      11/22/2019 12:17:22 AM
      avg-cpu: %user %nice %system %iowait %steal %idle
      2.90 0.00 0.56 0.00 0.00 96.54

      Device: rrqm/s wrqm/s r/s w/s rkB/s wkB/s avgrq-sz avgqu-sz await r_await w_await svctm %util
      sda 0.00 1.00 0.00 2.00 0.00 12.00 12.00 0.00 0.00 0.00 0.00 0.00 0.00
      dfa 0.00 0.00 0.00 485.00 0.00 2276.00 9.39 0.00 0.00 0.00 0.00 0.00 0.00

      11/22/2019 12:17:23 AM
      avg-cpu: %user %nice %system %iowait %steal %idle
      3.51 0.00 1.07 0.02 0.00 95.41

      Device: rrqm/s wrqm/s r/s w/s rkB/s wkB/s avgrq-sz avgqu-sz await r_await w_await svctm %util
      sda 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
      dfa 0.00 0.00 0.00 509.00 0.00 2468.00 9.70 0.00 0.00 0.00 0.00 0.00 0.10

      11/22/2019 12:17:24 AM
      avg-cpu: %user %nice %system %iowait %steal %idle
      4.20 0.00 1.79 0.00 0.00 94.00

      Device: rrqm/s wrqm/s r/s w/s rkB/s wkB/s avgrq-sz avgqu-sz await r_await w_await svctm %util
      sda 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
      dfa 0.00 0.00 0.00 531.00 0.00 2472.00 9.31 0.00 0.01 0.00 0.01 0.01 0.30

      11/22/2019 12:17:25 AM
      avg-cpu: %user %nice %system %iowait %steal %idle
      4.19 0.00 2.03 0.00 0.00 93.78

      Device: rrqm/s wrqm/s r/s w/s rkB/s wkB/s avgrq-sz avgqu-sz await r_await w_await svctm %util
      sda 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
      dfa 0.00 0.00 1.98 474.26 11.88 2249.50 9.50 0.00 0.00 0.50 0.00 0.00 0.20

      11/22/2019 12:17:26 AM
      avg-cpu: %user %nice %system %iowait %steal %idle
      1.86 0.00 1.80 0.05 0.00 96.30

      Device: rrqm/s wrqm/s r/s w/s rkB/s wkB/s avgrq-sz avgqu-sz await r_await w_await svctm %util
      sda 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
      dfa 0.00 0.00 0.00 109721.00 0.00 1053840.00 19.21 25.67 0.23 0.00 0.23 0.01 62.00

      11/22/2019 12:17:27 AM
      avg-cpu: %user %nice %system %iowait %steal %idle
      1.43 0.00 0.56 0.00 0.00 98.01

      Device: rrqm/s wrqm/s r/s w/s rkB/s wkB/s avgrq-sz avgqu-sz await r_await w_await svctm %util
      sda 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
      dfa 0.00 0.00 0.00 436.00 0.00 2076.00 9.52 0.00 0.00 0.00 0.00 0.00 0.00

      11/22/2019 12:17:28 AM
      avg-cpu: %user %nice %system %iowait %steal %idle
      1.82 0.00 0.91 0.00 0.00 97.27

      Device: rrqm/s wrqm/s r/s w/s rkB/s wkB/s avgrq-sz avgqu-sz await r_await w_await svctm %util
      sda 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
      dfa 0.00 0.00 0.00 474.00 0.00 2312.00 9.76 0.00 0.00 0.00 0.00 0.00 0.20

      Show
      dirty is very high, but do not evit to disk, disk io is 0%   iostat log as following: 11/22/2019 12:17:21 AM avg-cpu: %user %nice %system %iowait %steal %idle 3.43 0.00 1.01 0.02 0.00 95.55 Device: rrqm/s wrqm/s r/s w/s rkB/s wkB/s avgrq-sz avgqu-sz await r_await w_await svctm %util sda 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 dfa 0.00 0.00 15.00 546.00 208.00 2588.00 9.97 0.00 0.01 0.00 0.01 0.01 0.30 11/22/2019 12:17:22 AM avg-cpu: %user %nice %system %iowait %steal %idle 2.90 0.00 0.56 0.00 0.00 96.54 Device: rrqm/s wrqm/s r/s w/s rkB/s wkB/s avgrq-sz avgqu-sz await r_await w_await svctm %util sda 0.00 1.00 0.00 2.00 0.00 12.00 12.00 0.00 0.00 0.00 0.00 0.00 0.00 dfa 0.00 0.00 0.00 485.00 0.00 2276.00 9.39 0.00 0.00 0.00 0.00 0.00 0.00 11/22/2019 12:17:23 AM avg-cpu: %user %nice %system %iowait %steal %idle 3.51 0.00 1.07 0.02 0.00 95.41 Device: rrqm/s wrqm/s r/s w/s rkB/s wkB/s avgrq-sz avgqu-sz await r_await w_await svctm %util sda 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 dfa 0.00 0.00 0.00 509.00 0.00 2468.00 9.70 0.00 0.00 0.00 0.00 0.00 0.10 11/22/2019 12:17:24 AM avg-cpu: %user %nice %system %iowait %steal %idle 4.20 0.00 1.79 0.00 0.00 94.00 Device: rrqm/s wrqm/s r/s w/s rkB/s wkB/s avgrq-sz avgqu-sz await r_await w_await svctm %util sda 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 dfa 0.00 0.00 0.00 531.00 0.00 2472.00 9.31 0.00 0.01 0.00 0.01 0.01 0.30 11/22/2019 12:17:25 AM avg-cpu: %user %nice %system %iowait %steal %idle 4.19 0.00 2.03 0.00 0.00 93.78 Device: rrqm/s wrqm/s r/s w/s rkB/s wkB/s avgrq-sz avgqu-sz await r_await w_await svctm %util sda 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 dfa 0.00 0.00 1.98 474.26 11.88 2249.50 9.50 0.00 0.00 0.50 0.00 0.00 0.20 11/22/2019 12:17:26 AM avg-cpu: %user %nice %system %iowait %steal %idle 1.86 0.00 1.80 0.05 0.00 96.30 Device: rrqm/s wrqm/s r/s w/s rkB/s wkB/s avgrq-sz avgqu-sz await r_await w_await svctm %util sda 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 dfa 0.00 0.00 0.00 109721.00 0.00 1053840.00 19.21 25.67 0.23 0.00 0.23 0.01 62.00 11/22/2019 12:17:27 AM avg-cpu: %user %nice %system %iowait %steal %idle 1.43 0.00 0.56 0.00 0.00 98.01 Device: rrqm/s wrqm/s r/s w/s rkB/s wkB/s avgrq-sz avgqu-sz await r_await w_await svctm %util sda 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 dfa 0.00 0.00 0.00 436.00 0.00 2076.00 9.52 0.00 0.00 0.00 0.00 0.00 0.00 11/22/2019 12:17:28 AM avg-cpu: %user %nice %system %iowait %steal %idle 1.82 0.00 0.91 0.00 0.00 97.27 Device: rrqm/s wrqm/s r/s w/s rkB/s wkB/s avgrq-sz avgqu-sz await r_await w_await svctm %util sda 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 dfa 0.00 0.00 0.00 474.00 0.00 2312.00 9.76 0.00 0.00 0.00 0.00 0.00 0.20

    Description

      mongod block some time, dirty is very high, and do not evit data to disk, io is 0%

      dirty is very high, but do not evit to disk, disk io is 0%

      mongostat info as following:

      insert query update delete getmore command dirty used flushes vsize  res qrw arw net_in net_out conn                time
      10.37.162.223:10000 *0 *0 *0 *0 0 11|0 21.7% 95.0% 0 117G 55.9G n/a 0|0 1|1 1.57k 69.1k 1823 shard_4FC5EC6E PRI Nov 22 12:17:51.561
      10.37.162.223:10000 *0 *0 *0 *0 0 6|0 21.5% 95.0% 0 117G 55.9G n/a 0|0 1|1 1.09k 74.3k 1823 shard_4FC5EC6E PRI Nov 22 12:17:52.505
      10.37.162.223:10000 *0 *0 *0 *0 0 5|0 21.3% 95.0% 0 117G 55.9G n/a 0|0 1|1 1.03k 69.9k 1823 shard_4FC5EC6E PRI Nov 22 12:17:53.506
      10.37.162.223:10000 *0 *0 *0 *0 0 7|0 29.7% 95.0% 0 117G 55.9G n/a 0|0 2|1 1.25k 70.4k 1823 shard_4FC5EC6E PRI Nov 22 12:17:54.506
      10.37.162.223:10000 *0 *0 *0 *0 0 8|0 48.5% 95.0% 0 117G 55.9G n/a 0|0 2|1 1.59k 71.9k 1823 shard_4FC5EC6E PRI Nov 22 12:17:55.505
      10.37.162.223:10000 *0 *0 3 *0 0 5|0 58.1% 95.0% 0 117G 55.9G n/a 0|0 2|23 26.4k 69.9k 1823 shard_4FC5EC6E PRI Nov 22 12:17:56.507
      10.37.162.223:10000 *0 *0 22 *0 0 60|0 57.5% 95.0% 0 117G 55.9G n/a 0|411 2|128 80.3k 39.2k 1944 shard_4FC5EC6E PRI Nov 22 12:18:04.579
      10.37.162.223:10000 *0 *0 561 *0 0 1509|0 56.3% 94.1% 0 118G 56.0G n/a 0|691 2|128 607k 3.66m 1944 shard_4FC5EC6E PRI Nov 22 12:18:05.679
      10.37.162.223:10000 *0 *0 *0 *0 0 10|0 55.7% 94.0% 0 118G 56.0G n/a 0|691 1|128 1.31k 80.0k 1944 shard_4FC5EC6E PRI Nov 22 12:18:06.559
      10.37.162.223:10000 *0 *0 *0 *0 0 11|0 55.0% 93.9% 0 118G 56.0G n/a 0|691 1|128 2.56k 78.7k 1944 shard_4FC5EC6E PRI Nov 22 12:18:07.509
      10.37.162.223:10000 *0 *0 *0 *0 0 8|0 54.7% 93.8% 0 118G 56.0G n/a 0|691 1|128 2.56k 71.1k 1944 shard_4FC5EC6E PRI Nov 22 12:18:08.507
      10.37.162.223:10000 *0 *0 *0 *0 0 8|0 54.2% 93.3% 0 118G 56.0G n/a 0|691 1|128 2.56k 71.1k 1944 shard_4FC5EC6E PRI Nov 22 12:18:09.507
      10.37.162.223:10000 *0 *0 *0 *0 0 10|0 54.2% 93.3% 0 118G 56.0G n/a 0|691 1|128 2.67k 73.0k 1944 shard_4FC5EC6E PRI Nov 22 12:18:10.506
      10.37.162.223:10000 *0 *0 *0 *0 0 26|0 54.2% 93.3% 0 118G 56.0G n/a 0|691 2|128 7.85k 88.5k 1944 shard_4FC5EC6E PRI Nov 22 12:18:11.507
      10.37.162.223:10000 *0 *0 *0 *0 0 9|0 54.2% 93.3% 0 118G 56.0G n/a 0|691 1|128 2.84k 72.0k 1944 shard_4FC5EC6E PRI Nov 22 12:18:12.506
      10.37.162.223:10000 *0 *0 *0 *0 0 7|0 54.2% 93.2% 0 118G 56.0G n/a 0|691 1|128 2.55k 70.9k 1944 shard_4FC5EC6E PRI Nov 22 12:18:13.508
      10.37.162.223:10000 *0 *0 *0 *0 0 8|0 54.3% 93.2% 0 118G 56.0G n/a 0|691 1|128 2.56k 71.1k 1944 shard_4FC5EC6E PRI Nov 22 12:18:14.506
      10.37.162.223:10000 *0 *0 *0 *0 0 6|0 54.3% 93.2% 0 118G 55.9G n/a 0|691 1|128 1.03k 70.1k 1944 shard_4FC5EC6E PRI Nov 22 12:18:15.506
      10.37.162.223:10000 *0 *0 *0 *0 0 8|0 54.0% 92.9% 0 118G 55.9G n/a 0|691 1|128 2.77k 71.3k 1944 shard_4FC5EC6E PRI Nov 22 12:18:16.507
      10.37.162.223:10000 *0 *0 *0 *0 0 7|0 52.9% 91.9% 0 118G 55.9G n/a 0|691 1|128 2.55k 71.0k 1944 shard_4FC5EC6E PRI Nov 22 12:18:17.507
      10.37.162.223:10000 *0 *0 *0 *0 0 8|0 51.7% 91.1% 0 118G 55.9G n/a 0|691 1|128 1.59k 71.9k 1943 shard_4FC5EC6E PRI Nov 22 12:18:18.507
      10.37.162.223:10000 *0 *0 *0 *0 0 10|0 50.6% 90.2% 0 118G 55.9G n/a 0|691 1|128 1.58k 71.6k 1943 shard_4FC5EC6E PRI Nov 22 12:18:19.517
      10.37.162.223:10000 *0 *0 *0 *0 0 6|0 49.5% 89.6% 0 118G 55.9G n/a 0|691 1|128 1.04k 70.8k 1943 shard_4FC5EC6E PRI Nov 22 12:18:20.506
      10.37.162.223:10000 *0 *0 *0 *0 0 11|0 48.8% 89.3% 0 118G 55.9G n/a 0|691 1|128 1.60k 70.5k 1943 shard_4FC5EC6E PRI Nov 22 12:18:21.537
      10.37.162.223:10000 *0 *0 *0 *0 0 6|0 48.4% 89.2% 0 118G 55.9G n/a 0|691 1|128 1.06k 72.2k 1943 shard_4FC5EC6E PRI Nov 22 12:18:22.507
      10.37.162.223:10000 *0 *0 *0 *0 0 5|0 47.9% 89.1% 0 118G 55.9G n/a 0|691 1|128 1.03k 70.0k 1943 shard_4FC5EC6E PRI Nov 22 12:18:23.507
      10.37.162.223:10000 *0 *0 8 *0 0 27|0 47.3% 88.9% 0 118G 55.9G n/a 0|700 1|128 10.7k 76.0k 1951 shard_4FC5EC6E PRI Nov 22 12:18:24.606
      10.37.162.223:10000 *0 *0 93 *0 0 165|0 46.7% 88.9% 0 118G 55.9G n/a 0|843 2|128 91.7k 138k 2034 shard_4FC5EC6E PRI Nov 22 12:18:26.143
      10.37.162.223:10000 *0 *0 110 *0 0 151|0 46.3% 88.9% 0 118G 55.9G n/a 0|915 2|128 83.4k 156k 2034 shard_4FC5EC6E PRI Nov 22 12:18:26.795
      10.37.162.223:10000 *0 *0 *0 *0 0 21|0 46.0% 88.9% 0 118G 55.9G n/a 0|915 1|128 1.73k 111k 2034 shard_4FC5EC6E PRI Nov 22 12:18:27.509
      10.37.162.223:10000 *0 *0 *0 *0 0 14|0 45.6% 88.9% 0 118G 55.9G n/a 0|915 2|128 1.50k 77.8k 2034 shard_4FC5EC6E PRI Nov 22 12:18:28.508
      10.37.162.223:10000 *0 *0 *0 *0 0 6|0 45.1% 88.9% 0 118G 55.9G n/a 0|915 2|128 1.03k 70.1k 2034 shard_4FC5EC6E PRI Nov 22 12:18:29.506
      10.37.162.223:10000 *0 *0 *0 *0 0 5|0 44.7% 88.9% 0 118G 55.9G n/a 0|915 2|128 1.03k 70.0k 2034 shard_4FC5EC6E PRI Nov 22 12:18:30.507
      10.37.162.223:10000 *0 *0 *0 *0 0 6|0 44.2% 88.8% 0 118G 55.9G n/a 0|915 1|128 1.03k 70.1k 2034 shard_4FC5EC6E PRI Nov 22 12:18:31.507
      10.37.162.223:10000 *0 *0 *0 *0 0 4|0 43.1% 88.1% 0 118G 55.9G n/a 0|915 1|128 1.36k 69.1k 2034 shard_4FC5EC6E PRI Nov 22 12:18:32.508
      10.37.162.223:10000 *0 *0 *0 *0 0 6|0 42.5% 87.9% 0 118G 55.9G n/a 0|915 1|128 1.03k 70.1k 2034 shard_4FC5EC6E PRI Nov 22 12:18:33.507
      10.37.162.223:10000 *0 *0 *0 *0 0 6|0 41.4% 87.2% 0 118G 55.9G n/a 0|915 1|128 1.03k 70.1k 2034 shard_4FC5EC6E PRI Nov 22 12:18:34.507
      10.37.162.223:10000 *0 *0 *0 *0 0 233|0 40.9% 87.0% 0 118G 55.9G n/a 0|915 1|128 14.2k 288k 1660 shard_4FC5EC6E PRI Nov 22 12:18:35.508
      10.37.162.223:10000 *0 *0 *0 *0 0 153|0 40.3% 86.9% 0 118G 55.9G n/a 0|915 1|128 14.2k 206k 1634 shard_4FC5EC6E PRI Nov 22 12:18:36.528
      10.37.162.223:10000 *0 *0 *0 *0 0 14|0 39.8% 86.8% 0 118G 55.9G n/a 0|915 1|128 2.67k 73.2k 1634 shard_4FC5EC6E PRI Nov 22 12:18:37.605
      10.37.162.223:10000 *0 *0 *0 *0 0 25|0 39.3% 86.7% 0 118G 55.9G n/a 0|915 1|128 2.24k 95.7k 1634 shard_4FC5EC6E PRI Nov 22 12:18:38.507
      10.37.162.223:10000 *0 *0 *0 *0 0 16|0 38.6% 86.4% 0 118G 55.9G n/a 0|915 1|128 1.67k 80.5k 1634 shard_4FC5EC6E PRI Nov 22 12:18:39.508
      10.37.162.223:10000 *0 *0 *0 *0 0 29|0 38.1% 86.3% 0 118G 55.9G n/a 0|915 1|128 2.37k 92.2k 1634 shard_4FC5EC6E PRI Nov 22 12:18:40.507
      10.37.162.223:10000 *0 *0 *0 *0 0 30|0 37.7% 86.3% 0 118G 55.9G n/a 0|915 1|128 6.68k 93.2k 1634 shard_4FC5EC6E PRI Nov 22 12:18:41.507
      10.37.162.223:10000 *0 *0 *0 *0 0 13|0 37.3% 86.3% 0 118G 55.9G n/a 0|915 1|128 1.66k 76.8k 1634 shard_4FC5EC6E PRI Nov 22 12:18:42.506
      10.37.162.223:10000 *0 *0 *0 *0 0 7|0 36.8% 86.3% 0 118G 55.9G n/a 0|915 1|128 1.09k 71.0k 1634 shard_4FC5EC6E PRI Nov 22 12:18:43.506
      10.37.162.223:10000 *0 *0 *0 *0 0 7|0 36.3% 86.3% 0 118G 55.9G n/a 0|915 1|128 2.55k 71.0k 1634 shard_4FC5EC6E PRI Nov 22 12:18:44.507
      10.37.162.223:10000 *0 *0 *0 *0 0 7|0 35.9% 86.3% 0 118G 55.9G n/a 0|915 1|128 2.55k 71.0k 1634 shard_4FC5EC6E PRI Nov 22 12:18:45.507
      10.37.162.223:10000 *0 *0 *0 *0 0 8|0 35.4% 86.3% 0 118G 55.9G n/a 0|915 1|128 2.56k 71.1k 1634 shard_4FC5EC6E PRI Nov 22 12:18:46.507
      10.37.162.223:10000 *0 *0 *0 *0 0 8|0 34.8% 86.1% 0 118G 55.9G n/a 0|915 1|128 2.77k 71.3k 1634 shard_4FC5EC6E PRI Nov 22 12:18:47.507
      10.37.162.223:10000 *0 *0 31 *0 0 135|0 34.3% 86.0% 0 118G 55.9G n/a 0|954 1|128 40.5k 150k 1660 shard_4FC5EC6E PRI Nov 22 12:18:48.708
      

      Attachments

        1. 11111.png
          11111.png
          217 kB
        2. db.serverstats2.txt
          31 kB
        3. db.serverstatus.wiredTiger.txt
          25 kB
        4. dirty-high-disk-block.png
          dirty-high-disk-block.png
          199 kB
        5. disk-performance.png
          disk-performance.png
          45 kB
        6. iostat.log
          16 kB
        7. replSetGetConfig.txt
          4 kB

        Activity

          People

            dmitry.agranat@mongodb.com Dmitry Agranat
            1147952115@qq.com y yz
            Votes:
            0 Vote for this issue
            Watchers:
            6 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved: