[SERVER-25249] High I/O load in secondary nodes with WiredTiger engine (caused by journaling) Created: 25/Jul/16  Updated: 08/Jan/21  Resolved: 19/Aug/16

Status: Closed
Project: Core Server
Component/s: WiredTiger
Affects Version/s: 3.2.7
Fix Version/s: None

Type: Bug Priority: Major - P3
Reporter: stronglee Assignee: Kelsey Schubert
Resolution: Done Votes: 0
Labels: RF
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Issue Links:
Related
related to SERVER-53667 High rate of journal flushes on secon... Closed
is related to SERVER-26040 High CPU/IOWAIT in MongoDB 3.2.9 Closed
Operating System: ALL
Steps To Reproduce:

Simply insert data heavily.

Participants:

 Description   

Hi,
I upgraded my mongodb cluster from 3.0 to 3.2.7 recently and found that the I/O load increased a lot. (abount 100% in primary nodes and 500% in secondary nodes, mainly judged by %util of iostat command).
After reading the doc, I learned that journaling behavior changed a little in 3.2 (flushes the journal every 50ms), so I tried disabling the journaling and the I/O load returned low as it was in 3.0. So I guess flushing the journal frequently is the main reason of primary nodes' I/O load going high 100%.
But I can't find out why secondaries' I/O load increased 500% in the docs. So I used strace to track the mongod thread which is in charge of flushing the journal. (strace about 10 seconds)

Primary node:

% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 58.86    3.921470      13476       291       143   futex
 40.54    2.700511      18754       144             pwrite
  0.30    0.020001      10001         2             fdatasync

Secondary node:

% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 83.04    4.272435       14682       291             fdatasync
 16.95    0.871993         998       874         9   futex
  0.01    0.000461           2       288             pwrite

From the above we know that pwrite calls in secondary node are nearly twice of primary. And fdatasync calls are as many as pwrite calls and are far more than primary's. Is this the reason why secondaries' I/O load increase 500% ? Is it a bug or a design?



 Comments   
Comment by Kelsey Schubert [ 19/Aug/16 ]

Hi strlee,

Thanks for the confirmation. We expect that that secondary would self-throttle if there was additional I/O load present.

If secondaries are falling behind and you do not see the secondaries self-throttle, please open a new ticket and we will investigate.

Kind regards,
Thomas

Comment by stronglee [ 19/Aug/16 ]

Hi Thomas Schubert,
You are right, there are no obvious adverse affects on my secondaries except for the increased I/O load.
But the reason may be that I don't have heavy query jobs on my secondaries. I wonder if when I have heavy
jobs on them, the performance would be poor because of the high I/O load.
Is it possible to make the secondaries sync the journal in a configrable interval to lower to I/O load? I think
not all systems need so high reliability. e.g. It is no problem for my system to lose data for a few seconds.

Comment by Kelsey Schubert [ 18/Aug/16 ]

Hi strlee,

Thanks for the detailed report of this behavior. It is by design that replication on secondaries will sync the journal faster than it would for the same load on a primary. The syncing is done asynchronously, and so it should not affect replication throughput unless the disk is saturated.

My understanding is that you are not observing any adverse affects as a result of the increased I/O load on the secondaries. Is this correct?

Kind regards,
Thomas

Comment by stronglee [ 27/Jul/16 ]

I tried set journalCommitInterval=500, the pwrite/fdatasync calls didn't go down too much (approximately from 300 to 200).
I also tried set cfg.protocolVersion=0, nothing happened.
I don't want to disable journaling, but the I/O load increased so much.
Is there a way to let mongodb flush journal in a certain interval?

Generated at Thu Feb 08 04:08:40 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.