[SERVER-27036] WT takes longer to start than MMAPv1 on EBS volumes that have not been intialized Created: 15/Nov/16  Updated: 17/Jun/19  Resolved: 21/Nov/16

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

Type: Bug Priority: Major - P3
Reporter: Yoni Douek Assignee: Unassigned
Resolution: Done Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Attachments: HTML File log     Zip Archive tmp.zip    
Issue Links:
Related
related to DOCS-12807 Using a snapshot restore from AWS EBS... Closed
related to SERVER-41790 Report progress during oplog sampling... Closed
Backwards Compatibility: Fully Compatible
Operating System: ALL
Participants:
Case:

 Description   

Hey,

We recently upgraded from MMAP to WT. For the same data amount (~500GB), on an AWS EBS volume which is "cold" (restored from a snapshot) - size 2TB -
MMAP took ~5 minutes to start
WT takes 50 minutes, log mentioning this:

Taking 1005 samples and assuming that each section of oplog contains approximately 5672862 records totaling to 1073741955 bytes

It apparently scans the oplog (we've set its size to 100GB) - and we see the iowait on 100%. But still, 50 minutes is a lot...

Anything we can do to speed things up?



 Comments   
Comment by Michael Cahill (Inactive) [ 21/Nov/16 ]

yonido, as explained above, MongoDB 3.2 samples the oplog to optimize truncation with WiredTiger. This process isn't inherently slow, but happens during startup so you may notice it more than slow reads via MMAPv1.

I'm going to close this now, the issue with slow reads from EBS is understood and documented by AWS, there isn't much we can do about it in MongoDB.

Comment by Yoni Douek [ 21/Nov/16 ]

Yep, this will be a workaround. But I though you guys might be interested to see why it's x10 slower than mmap.

Comment by Michael Cahill (Inactive) [ 21/Nov/16 ]

yoni@appsee.com, if a warmup of the full EBS volume is too slow, one thing you could consider is following the AWS instructions to sequentially read through just the files in the database path for MongoDB.

In fact, if you get the filename from the wiredtiger.uri collection stats for the oplog, you could just fault in that file before starting MongoDB to avoid waiting on EBS.

Comment by Yoni Douek [ 17/Nov/16 ]

Thanks.
Attached. In this example it took ~15 min but sometimes it takes much more.

The EBS warm up process was taken into consideration when opening this ticket - we are aware that this affects the performance drastically. But when comparing cold disks in WT vs mmap - this is 10x slower. We are sure that pre-warming the EBS drive will help, but unfortunately this process make take several hours on large disks.

Comment by Michael Cahill (Inactive) [ 16/Nov/16 ]

Also, one cause of very slow I/O when starting MongoDB on an EBS volume created from a snapshot is described in the AWS docs Initialising Amazon EBS Volumes,

For a new volume created from a snapshot, you should read all the blocks that have data before using the volume.

If this applies to you, please try one of the steps recommended by AWS in the link above to see if that resolves the slow I/O.

Comment by Michael Cahill (Inactive) [ 16/Nov/16 ]

yoni@appsee.com, sorry to hear that you are experiencing this problem.

During this part of startup, MongoDB takes samples of the oplog, which involves random lookups in the WiredTiger btree that contains the oplog. Each lookup usually results in reading a single leaf page, so here that would mean about 1005 page reads. Even with slow spinning disks, that is not expected to take more than about 10 seconds.

Can you please attach the mongod log file (at least the section covering startup until this process is complete) and an archive of the diagnostic.data directory from your database path? That is a log of statistics that should help us understand whether there is something we can change in MongoDB to make this process faster.

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