A section of MongoDB server read Data timeout story

Beijing time September 25, 2016 22:58:30 PM

Recent online production environment MongoDB is always found to read the data timeout problem, sit down this afternoon to carefully study some, the approximate process is as follows:

Business Background

The line has a pair of MongoDB master-slave server, just simple to do the MongoDB master and slave, Master-slave.

began to think that the master-slave can ensure that the data is not lost, indeed, the data did not lose the problem, but recently found that a lot of users click on certain operations to read the contents of the data inside the MONGO, to wait a long time, such a wait is unbearable.

At the beginning, thought to have done the master and slave, and then in the Tomcat Mong configuration file set up read and write separate steps can be read and write separation, but otherwise, and not as good as imagined, the actual result is no matter whether reading or writing are ruthlessly distributed to the Lord's task, so that the pressure of the Lord hated it, Causes the user to read the data, it takes a long time to wait, along this issue, we have the following

Troubleshoot the problem:

Troubleshooting: Network CARD traffic June

First use the SAR command to view the server network card traffic information, found normal:

Sar-n DEV 1 #1秒钟刷新一次网卡流量信息

23:05 26 sec     IFACE   rxpck/s   txpck/s    rxkb/s    txkb/s   rxcmp/s   txcmp/s  rxmcst/  S23 05 min 27 s        lo      0.00      0.00      0.00      0.00       0.00      0.00      0.00 23:05 27 sec      eth1    909.18    818.37      64.31     148.47      0.00      0.00      0.00

Troubleshooting: Server CPU June

After looking at the CPU, there is nothing unusual, and the CPU utilization of 8 cores is less than 1%.

Top always displays server resource information

Cpu0:57.4%us,2.6%sy,0.0%ni,32.3%ID,0.0%wa,2.6%hi,5.2%si,0.0%STCPU1:0.0%us,0.0%sy,0.0%ni,100.0%ID,0.0%wa,0.0%hi,0.0%si,0.0%STCPU2:0.6%us,0.0%sy,0.0%ni,99.4%ID,0.0%wa,0.0%hi,0.0%si,0.0%STCPU3:0.6%us,0.0%sy,0.0%ni,99.4%ID,0.0%wa,0.0%hi,0.0%si,0.0%StCpu4:0.0%us,0.0%sy,0.0%ni,100.0%ID,0.0%wa,0.0%hi,0.0%si,0.0%StCpu5:0.0%us,0.0%sy,0.0%ni,100.0%ID,0.0%wa,0.0%hi,0.0%si,0.0%StCpu6:0.0%us,0.0%sy,0.0%ni,100.0%ID,0.0%wa,0.0%hi,0.0%si,0.0%StCpu7:0.0%us,0.0%sy,0.0%ni,100.0%ID,0.0%wa,0.0%hi,0.0%si,0.0%st

Troubleshooting: Server Memory June

See memory usage, more memory available, 16GB of memory, and 5GB of usable memory

FREE-M Display Memory Information

                    Total used free            shared    buffers     cachedmem:          15950       10338       5612          0               8925-/+ buffers/cache:        1307      14642 Swap:          1023        682        341

Troubleshooting: The foreign process June

PS-EF Display System processes

It's inconvenient to turn the server on. These processes are listed here, please forgive me; The final analysis is that there is no abnormal process

This is strange, what is the problem?

At this point IO this word, in my mind wandering, I think will not be hard disk IO blocked, resulting in reading data super slow? Come on, go on.

Troubleshooting: System IO June

Iostart-x 1 Every second look at the IO usage of all disks under the system

AVG-CPU:%user% Nice%system%iowait%steal%Idle11.64    0.00    1.13    0.00    0.00   7.23DEVICE:RRQM/s wrqm/s r/sW/s rsec/s wsec/s avgrq-sz Avgqu-sz await SVCTM%UTILSDA0.00     0.00    0.00    0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00SDB0.00     7.00    0.00    5.00     0.00   104.00    20.80     0.00    0.20   0.20   99.10DM-0              0.00     0.00    0.00   12.00     0.00   104.00     8.67     0.01    0.67   0.08   0.10

Found a suspicious culprit, the disk IO waits very high, the disk is overloaded to run.

Along this train of thought, the trail, found the research and Development colleague asked the next to MongoDB did what, they calmly said, is simply increases, inquires the operation; Well, then I'll see what the MONGO is all about.

Shun Rattan mushrooms: MONGO system usage Status

Insert Query Update delete getmore command flushes mapped vsize res faults locked db idx Miss% QR|QWar|aw Netin Netout Conn REPL Time*0*0*0*0       0     2|0       031g +.7g 999m0Young0.0%0       0|0     0|0120b 3k -SLV at: +: $*0*0*0*0       0     1|0       031g +.7g 999m0Young0.0%0       0|0     0|062B 3k -SLV at: +: -*0*0*0*0       0     8|0       031g +.7g 999m0Local0.0%0       0|0     0|0468B 5k -SLV at: +: -*0*0*0*0       0     5|0       031g +.7g 999m0Young0.0%0       0|0     0|0294b 4k -SLV at: -:xx*1*0*0*0       0     6|0       031g +.7g 999m0.:0.1%0       0|0     0|0352b 4k -SLV at: -: on*0*0*0*0       0     2|0       031g +.7g 999m0Young0.0%0       0|0     0|0120b 3k -SLV at: -: Geneva

Of

A section of MongoDB server read Data timeout story