[SERVER-22642] WiredTiger engine resync stalls with a lot of tables/indexes Created: 16/Feb/16  Updated: 18/Apr/16  Resolved: 18/Apr/16

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

Type: Bug Priority: Major - P3
Reporter: Bob Potter Assignee: Kelsey Schubert
Resolution: Duplicate Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Attachments: File diagnostic.data.tar.gz     File diagnostic.data_3.2.4-105-g73290d0.tar.bz2     Text File mongo_32_perf.txt     File perf_report_3.2.4-105-g73290d0.txt.gz    
Issue Links:
Duplicate
duplicates SERVER-22209 Collection creation during final phas... Closed
Related
is related to SERVER-17675 Support file per database for WiredTiger Closed
Operating System: ALL
Participants:

 Description   

We are trying to upgrade a replica set with many collections and indexes to WiredTiger. The replica set has 30k collections and 14 indexes per collection.

The initial data sync and index build works fine but the server makes very little progress once it starts to apply the replication log. It seems to make no progress for ~15 minutes during this time it consumes a full core of CPU and does very little I/O. It will does a burst of I/O for a minute or so before falling back to consuming a lot of CPU.

Based on the attached perf profile it looks like most of the CPU is being consumed by the eviction thread. (Possibly during a checkpoint?)

Let me know if there is any additional information I can provide to help track this down.



 Comments   
Comment by Kelsey Schubert [ 18/Apr/16 ]

Hi bpot,

Thank you for uploading the diagnostic.data. I have confirmed that the original issue appears to have been resolved by SERVER-22209 / WT-2346, so I will be closing this ticket as a duplicate.

The new behavior that you are observing may be explained by SERVER-22906. However, if this is still an issue for you, please open a new ticket and we will continue to investigate.

Thank you,
Thomas

Comment by Bob Potter [ 14/Apr/16 ]

Hi Thomas,

By dropping the cache size from the default of 17GB to 8GB I've been able to avoid the out of memory errors (for now at least! – it's still slowly growing). But, it looks like replication is still having trouble catching up with the primary. I've uploaded the diagnostic data and also a cpu profile I created using `perf`. It still seems to be using a lot of cpu during checkpointing but the profile looks different.

Thanks for looking at this.

Comment by Kelsey Schubert [ 12/Apr/16 ]

Hi bpot,

I'm sorry you are still encountering issues. Please upload the diagnostic.data and so we can investigate this new behavior. After we have a chance to examine the diagnostic.data, we can determine whether a new ticket would be appropriate.

Thank you for your help,
Thomas

Comment by Bob Potter [ 11/Apr/16 ]

Hi Thomas,

I've tried a couple syncs with a recent nightly build (3.2.4-105-g73290d0). I think I'm seeing a different problem now. Once the initial sync+index build process finishes the mongod process starts using a lot of memory and either brings down the instance or is killed by OOM. Would it be helpful if I uploaded a copy of diagnostic.data from that failed syncs? Should I open a new issue for this?

It's unclear if this issue is fixed or not.

Thanks,
Bob

Comment by Kelsey Schubert [ 05/Apr/16 ]

Hi bpot,

Thank you for uploading the log. From our analysis, it appears that WiredTiger checkpoints are completing very slowly once the server starts to apply the replication log. In MongoDB 3.2.4, WiredTiger holds a lock for much of the time it is doing a checkpoint, and any collection create or drop also needs the same lock. So long running checkpoints will make any workload that creates or drops collections or indexes stall. A recent improvement have been made to WiredTiger so a checkpoint doesn't take the lock needed to create/drop tables (WT-2346). This improvement will be included in MongoDB 3.2.5.

Please upgrade to MongoDB 3.2.5 when it is released and report back if the issue persists.

Kind regards,
Thomas

Comment by Bob Potter [ 07/Mar/16 ]

I've uploaded the logs to the private upload portal. I ran the fruitsalad script on it and removed all lines which contained 'failed to apply update' since they still included some of the update commands unredacted.

Comment by Kelsey Schubert [ 03/Mar/16 ]

Hi bpot,

We will need the complete log covering the sync attempt. As Ramon mentioned, these files will be only visible to MongoDB employees investigating this issue and are routinely deleted after some time.

If you are unable to provide these logs because of sensitive customer data, we will wait for the redacted logs. You may find this script useful to redact customer data.

Thank you,
Thomas

Comment by Ramon Fernandez Marina [ 29/Feb/16 ]

bpot, I've created a private upload portal so any data you upload will only be visible to MongoDB engineers. Will discuss with Thomas later and see what pieces we'll need first.

Comment by Bob Potter [ 29/Feb/16 ]

Hi Thomas,

I'm looking at the logs and they contain private customer information. Most notably from 'failed to apply update' log records. So I can't share them in total. I could try to strip log entries but it is 200MB worth of logs.

Is there log information from a particular subsystem that would be most useful?

Thanks,
Bob

Comment by Kelsey Schubert [ 22/Feb/16 ]

Hi bpot,

We are examining the diagnostic data you have uploaded. So we can get a better idea of what is going on here, can you please upload the logs covering the duration of sync attempt as well?

Thank you,
Thomas

Comment by Bob Potter [ 22/Feb/16 ]

Ramon,

I've added the diagnostic data for the most recent sync attempt on 3.2.1.

Yeah, we're away that our model may not be a great fit for WiredTiger.

Thanks,
Bob

Comment by Ramon Fernandez Marina [ 17/Feb/16 ]

bpot, if the affected secondary is running 3.2.1, can you please upload the contents of the diagnostic.data directory in your dbpath to this ticket? That should help us investigate this issue.

Please note that your data distribution will require over 400k files when using WiredTiger, so this may cause other issues as well.

Thanks,
Ramón.

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