[SERVER-21553] Oplog grows to 3x configured size Created: 19/Nov/15 Updated: 30/Mar/16 Resolved: 02/Dec/15 |
|
| Status: | Closed |
| Project: | Core Server |
| Component/s: | WiredTiger |
| Affects Version/s: | None |
| Fix Version/s: | 3.0.8, 3.2.0-rc6 |
| Type: | Bug | Priority: | Major - P3 |
| Reporter: | Bruce Lucas (Inactive) | Assignee: | Michael Cahill (Inactive) |
| Resolution: | Done | Votes: | 0 |
| Labels: | WTplaybook | ||
| Remaining Estimate: | Not Specified | ||
| Time Spent: | Not Specified | ||
| Original Estimate: | Not Specified | ||
| Attachments: |
|
||||||||||||||||
| Issue Links: |
|
||||||||||||||||
| Backwards Compatibility: | Fully Compatible | ||||||||||||||||
| Backport Completed: | |||||||||||||||||
| Steps To Reproduce: |
|
||||||||||||||||
| Sprint: | Build C (11/20/15) | ||||||||||||||||
| Participants: | |||||||||||||||||
| Description |
|
| Comments |
| Comment by Githook User [ 02/Dec/15 ] | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
Author: {u'username': u'michaelcahill', u'name': u'Michael Cahill', u'email': u'michael.cahill@mongodb.com'}Message: Import wiredtiger-wiredtiger-mongodb-3.2-rc4-70-g197eef0.tar.gz from wiredtiger branch mongodb-3.2 ref: 7a4f325..197eef0 bff6525 | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| Comment by Michael Cahill (Inactive) [ 02/Dec/15 ] | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
For the record, there were two underlying issues here in WiredTiger:
| ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| Comment by Githook User [ 02/Dec/15 ] | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
Author: {u'username': u'michaelcahill', u'name': u'Michael Cahill', u'email': u'michael.cahill@mongodb.com'}Message: Import wiredtiger-wiredtiger-mongodb-3.0.7-20-g27d0cbd.tar.gz from wiredtiger branch mongodb-3.0 ref: deb2d81..27d0cbd 6feaa28 | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| Comment by Githook User [ 02/Dec/15 ] | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
Author: {u'username': u'michaelcahill', u'name': u'Michael Cahill', u'email': u'michael.cahill@mongodb.com'}Message: Merge pull request #2354 from wiredtiger/server_21553_30backport
| ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| Comment by Githook User [ 02/Dec/15 ] | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
Author: {u'username': u'agorrod', u'name': u'Alex Gorrod', u'email': u'alexg@wiredtiger.com'}Message: Free the referenced block in the right place | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| Comment by Githook User [ 02/Dec/15 ] | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
Author: {u'username': u'agorrod', u'name': u'Alex Gorrod', u'email': u'alexg@wiredtiger.com'}Message: Remove redundant function I missed in merge of | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| Comment by Githook User [ 02/Dec/15 ] | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
Author: {u'username': u'agorrod', u'name': u'Alex Gorrod', u'email': u'alexander.gorrod@mongodb.com'}Message: (cherry picked from commit bff6525c8) Conflicts: | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| Comment by Githook User [ 02/Dec/15 ] | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
Author: {u'username': u'agorrod', u'name': u'Alex Gorrod', u'email': u'alexander.gorrod@mongodb.com'}Message: Merge pull request #2352 from wiredtiger/
| ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| Comment by Githook User [ 02/Dec/15 ] | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
Author: {u'username': u'agorrod', u'name': u'Alex Gorrod', u'email': u'alexander.gorrod@mongodb.com'}Message: Merge pull request #2352 from wiredtiger/
| ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| Comment by Githook User [ 02/Dec/15 ] | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
Author: {u'username': u'michaelcahill', u'name': u'Michael Cahill', u'email': u'michael.cahill@mongodb.com'}Message: Merge branch 'develop' into | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| Comment by Githook User [ 02/Dec/15 ] | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
Author: {u'username': u'michaelcahill', u'name': u'Michael Cahill', u'email': u'michael.cahill@mongodb.com'}Message: During review of this change, noticed that we are trying to free an address in | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| Comment by Githook User [ 02/Dec/15 ] | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
Author: {u'username': u'michaelcahill', u'name': u'Michael Cahill', u'email': u'michael.cahill@mongodb.com'}Message: (Note: works in conjunction with the change to LRU policy for internal pages in | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| Comment by Githook User [ 02/Dec/15 ] | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
Author: {u'username': u'michaelcahill', u'name': u'Michael Cahill', u'email': u'michael.cahill@mongodb.com'}Message: Merge branch 'develop' into | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| Comment by Githook User [ 02/Dec/15 ] | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
Author: {u'username': u'michaelcahill', u'name': u'Michael Cahill', u'email': u'michael.cahill@mongodb.com'}Message: | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| Comment by Githook User [ 02/Dec/15 ] | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
Author: {u'username': u'michaelcahill', u'name': u'Michael Cahill', u'email': u'michael.cahill@mongodb.com'}Message: | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| Comment by Githook User [ 02/Dec/15 ] | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
Author: {u'username': u'michaelcahill', u'name': u'Michael Cahill', u'email': u'michael.cahill@mongodb.com'}Message: | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| Comment by Githook User [ 02/Dec/15 ] | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
Author: {u'username': u'michaelcahill', u'name': u'Michael Cahill', u'email': u'michael.cahill@mongodb.com'}Message: | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| Comment by Keith Bostic (Inactive) [ 01/Dec/15 ] | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
What's happening is that checkpoints are starting but taking several minutes to complete (and in the case of no-journal runs, I've seen them not complete at all). That's backed up by Martin's screen-shots, too, if I'm reading it correctly, there's a 10-minute checkpoint there. | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| Comment by Keith Bostic (Inactive) [ 01/Dec/15 ] | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
I can repro this one; turning on journalling appears to resolve the problem, we top out at around 14GB instead of growing without bound. For some reason I can't read the ftdc data, so I can't verify this, but without journalling, it seems we're not checkpointing in that WiredTiger database (notice the checkpoint size : 0 lines, and no file bytes available for reuse). | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| Comment by Max Hirschhorn [ 01/Dec/15 ] | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
Per Martin's request, I reran repro_server21553.js with the latest changes from WiredTiger. With the fast path enabled for truncates, I'm seeing the oplog size db.getSiblingDB('local').oplog.rs.stats().size range from 5GB to 5.4GB (woot!), but the file size (compressed) appears to grow without bound (e.g. up to 34GB before I killed the script). Could there still be something that would prevent the pages from becoming available for reuse?
git version: 86e7b69a6c52c926d28a60d816faefa6db81eb96 | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| Comment by Githook User [ 30/Nov/15 ] | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
Author: {u'username': u'michaelcahill', u'name': u'Michael Cahill', u'email': u'michael.cahill@mongodb.com'}Message: Import wiredtiger-wiredtiger-mongodb-3.2-rc4-41-g8326df6.tar.gz from wiredtiger branch mongodb-3.2 ref: b65381f..8326df6 4c49948 | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| Comment by Githook User [ 27/Nov/15 ] | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
Author: {u'username': u'michaelcahill', u'name': u'Michael Cahill', u'email': u'michael.cahill@mongodb.com'}Message: Merge pull request #2341 from wiredtiger/
| ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| Comment by Githook User [ 27/Nov/15 ] | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
Author: {u'username': u'michaelcahill', u'name': u'Michael Cahill', u'email': u'michael.cahill@mongodb.com'}Message: Merge pull request #2341 from wiredtiger/
| ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| Comment by Githook User [ 27/Nov/15 ] | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
Author: {u'username': u'michaelcahill', u'name': u'Michael Cahill', u'email': u'michael.cahill@mongodb.com'}Message: | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| Comment by Githook User [ 27/Nov/15 ] | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
Author: {u'username': u'michaelcahill', u'name': u'Michael Cahill', u'email': u'michael.cahill@mongodb.com'}Message: Merge branch 'develop' into | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| Comment by Githook User [ 27/Nov/15 ] | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
Author: {u'username': u'michaelcahill', u'name': u'Michael Cahill', u'email': u'michael.cahill@mongodb.com'}Message: A truncate operation attempts to mark leaf pages deleted without reading them The "no overflow" flag was not being preseved across internal page splits, so Add tracking of the "no overflow" flag for in-memory page addresses so | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| Comment by Martin Bligh [ 23/Nov/15 ] | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
Was able to reproduce with script from bruce.lucas, but not mine. Turns out the key difference is that he's using random data, and I'm using something easily compressible. Might be interesting datapoint ... will try disabling snappy. Still reproduces with compression disabled. | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| Comment by Max Hirschhorn [ 23/Nov/15 ] | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
The following patch makes it so that we don't save the previous truncate point and always truncate from RecordId(0) to the lastRecord of the stone. With the patch applied I saw the oplog size db.getSiblingDB('local').oplog.rs.stats().size range from 5GB to 14GB and the file size (compressed) grow up to 34GB.
| ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| Comment by Max Hirschhorn [ 21/Nov/15 ] | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
The truncate_span.patch makes it so we truncate the RecordId span of multiple excess stones in a single WT truncate call. With the patch applied I saw the oplog size db.getSiblingDB('local').oplog.rs.stats().size range from 5GB to 18GB and the file size (compressed) grow up to 27GB. It doesn't seem like the WT truncate calls can keep up with the inserts, so we may need to add the back-pressure mechanism back in. I'm curious about the WCEs during the WT truncate call seen in the logs below when trying to truncate 13GB of oplog in one shot. Logs from the oplog reclaim thread
| ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| Comment by Martin Bligh [ 20/Nov/15 ] | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
Can we instrument the truncate range and check our stored beginning record is correct? | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| Comment by Bruce Lucas (Inactive) [ 19/Nov/15 ] | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
Just realized that these runs were without journal (problem was noticed while investigating another problem where journal was disabled). This will impose extra burden because of the frequent checkpoints, but result should not be unbounded oplog growth. | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| Comment by Bruce Lucas (Inactive) [ 19/Nov/15 ] | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
With truncate stats, on build from master just now:
| ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| Comment by Daniel Pasette (Inactive) [ 19/Nov/15 ] | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
The latest drop of WT includes statistics for named snapshots and truncation: Also, this build should have snapshot thread disabled by default ( |