[SERVER-57274] Capped collections can exceed limits after rollback Created: 27/May/21  Updated: 29/Oct/23  Resolved: 14/Jun/21

Status: Closed
Project: Core Server
Component/s: None
Affects Version/s: 5.0.0-rc0
Fix Version/s: 5.0.0-rc2, 5.1.0-rc0

Type: Bug Priority: Major - P3
Reporter: Gregory Wlodarek Assignee: Gregory Wlodarek
Resolution: Fixed Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Issue Links:
Backports
Depends
Backwards Compatibility: Fully Compatible
Operating System: ALL
Backport Requested:
v5.0
Sprint: Execution Team 2021-06-28
Participants:
Linked BF Score: 39

 Description   

The create_capped_collection_maxdocs.js test creates a capped collection with the maximum number of documents set to be 3. There's an assertion that the number of documents in the capped collection never exceeds 3. However, there was a build failure that showed 4 documents present in the capped collection at some point.

Since SERVER-16049, capped deletes are replicated. This means that capped deletes can be rolled back without rolling back the insert that caused the capped collection to trigger the delete. This makes it possible for the capped collection to exceed its limits temporarily until the next insert is performed.

 

This is a known and understood limit of capped collections. Tagging this test with does_not_support_stepdowns would this fix.

 

From the build failure:

The last capped insert and (triggered) delete on this capped collection was performed successfully, and the capped collection has 3 documents present upon committing:

[j0:s1:n1] {"t":{"$date":"2021-05-27T16:26:01.940+00:00"},"s":"I",  "c":"STORAGE",  "id":0,       "ctx":"conn65","msg":"XXX Enter","attr":{"ns":"test0_fsmdb0.create_capped_collection_maxdocs2_0","cappedFirstRecord":"1040","cappedLock":true,"sideTxn":false,"numRecords":4,"docsOverCap":1,"dataSize":4092,"sizeOverCap":0}}
[j0:s1:n1] {"t":{"$date":"2021-05-27T16:26:01.940+00:00"},"s":"I",  "c":"STORAGE",  "id":0,       "ctx":"conn65","msg":"XXX begin seekNear()","attr":{"ns":"test0_fsmdb0.create_capped_collection_maxdocs2_0"}}
[j0:s1:n1] {"t":{"$date":"2021-05-27T16:26:01.940+00:00"},"s":"I",  "c":"STORAGE",  "id":0,       "ctx":"conn65","msg":"XXX found record to delete","attr":{"ns":"test0_fsmdb0.create_capped_collection_maxdocs2_0","record":"1040"}}
[j0:s1:n1] {"t":{"$date":"2021-05-27T16:26:01.940+00:00"},"s":"I",  "c":"STORAGE",  "id":0,       "ctx":"conn65","msg":"XXX deleting","attr":{"ns":"test0_fsmdb0.create_capped_collection_maxdocs2_0","record":"1040","docsRemoved":1}}
[j0:s1:n1] {"t":{"$date":"2021-05-27T16:26:01.942+00:00"},"s":"I",  "c":"STORAGE",  "id":0,       "ctx":"conn65","msg":"XXX Exit","attr":{"ns":"test0_fsmdb0.create_capped_collection_maxdocs2_0","cappedFirstRecord":"1040","cappedLock":true,"sideTxn":false,"numRecords":3,"docsOverCap":1,"docsRemoved":1,"dataSize":3069,"sizeOverCap":0}}
[j0:s1:n1] {"t":{"$date":"2021-05-27T16:26:01.942+00:00"},"s":"I",  "c":"STORAGE",  "id":0,       "ctx":"conn65","msg":"XXX onCommit","attr":{"ns":"test0_fsmdb0.create_capped_collection_maxdocs2_0","oldCappedFirstRecord":"1040","newCappedFirstRecord":"1041"}}

Right after this, the primary stepped down:

[j0:s1:n1] | 2021-05-27T16:26:01.949+00:00 I  REPL     21402   [conn117] "Stepping down from primary, because a new term has begun","attr":{"term":19}
[j0:s1:n1] | 2021-05-27T16:26:01.955+00:00 I  REPL     21358   [ReplCoord-4] "Replica set state transition","attr":{"newState":"SECONDARY","oldState":"PRIMARY"}

Triggering a rollback:

[j0:s1:n1] | 2021-05-27T16:26:03.022+00:00 I  REPL     21098   [BackgroundSync] "Starting rollback due to fetcher error","attr":{"error":"OplogStartMissing: the sync source's oplog and our oplog have diverged, going into rollback. our last optime fetched: { ts: Timestamp(1622132761, 60), t: 18 }. source's GTE: { ts: Timestamp(1622132762, 1), t: 19 }","lastCommittedOpTime":{"ts":{"$timestamp":{"t":1622132761,"i":54}},"t":18}}
[j0:s1:n1] | 2021-05-27T16:26:03.023+00:00 I  REPL     21102   [BackgroundSync] "Rollback using 'recoverToStableTimestamp' method"
[j0:s1:n1] | 2021-05-27T16:26:03.023+00:00 I  ROLLBACK 21593   [BackgroundSync] "Transition to ROLLBACK"

which removed the last capped delete (but not insert)

[j0:s1:n1] | 2021-05-27T16:26:03.419+00:00 D2 ROLLBACK 21656   [BackgroundSync] "Local oplog entry to roll back","attr":{"oplogEntry":{"op":"d","ns":"test0_fsmdb0.create_capped_collection_maxdocs2_0","ui":{"$uuid":"3ed3170e-87d4-4ead-a92d-dcf3aa04820b"},"o":{"_id":{"$oid":"60afc819e7821bc338a7d711"}},"ts":{"$timestamp":{"t":1622132761,"i":59}},"t":18,"v":2,"wall":{"$date":"2021-05-27T16:26:01.940Z"}}}
[j0:s1:n1] | 2021-05-27T16:26:03.426+00:00 D2 ROLLBACK 21605   [BackgroundSync] "Setting record count for namespace after rollback","attr":{"namespace":"test0_fsmdb0.create_capped_collection_maxdocs2_0","uuid":"3ed3170e-87d4-4ead-a92d-dcf3aa04820b","oldCount":3,"newCount":4,"countDiff":1}



 Comments   
Comment by Vivian Ge (Inactive) [ 06/Oct/21 ]

Updating the fixversion since branching activities occurred yesterday. This ticket will be in rc0 when it’s been triggered. For more active release information, please keep an eye on #server-release. Thank you!

Comment by Githook User [ 16/Jun/21 ]

Author:

{'name': 'Gregory Wlodarek', 'email': 'gregory.wlodarek@mongodb.com', 'username': 'GWlodarek'}

Message: SERVER-57274 Capped collections can exceed limits after rollback
Branch: SERVER-34632
https://github.com/mongodb/mongo/commit/28f6788e4e57219bce4a98ad95d082823f6598e5

Comment by Githook User [ 14/Jun/21 ]

Author:

{'name': 'Gregory Wlodarek', 'email': 'gregory.wlodarek@mongodb.com', 'username': 'GWlodarek'}

Message: SERVER-57274 Capped collections can exceed limits after rollback

(cherry picked from commit 28f6788e4e57219bce4a98ad95d082823f6598e5)
Branch: v5.0
https://github.com/mongodb/mongo/commit/691840873290b9482ba4df9a30f8267ddcdcc021

Comment by Githook User [ 14/Jun/21 ]

Author:

{'name': 'Gregory Wlodarek', 'email': 'gregory.wlodarek@mongodb.com', 'username': 'GWlodarek'}

Message: SERVER-57274 Capped collections can exceed limits after rollback
Branch: master
https://github.com/mongodb/mongo/commit/28f6788e4e57219bce4a98ad95d082823f6598e5

Generated at Thu Feb 08 05:41:25 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.