[SERVER-52623] Aborting in-progress transactions on step-up with eMRC=off can set the stable timestamp ahead of the all durable timestamp Created: 04/Nov/20  Updated: 06/Dec/22

Status: Blocked
Project: Core Server
Component/s: Replication
Affects Version/s: None
Fix Version/s: None

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

Issue Links:
Depends
Related
related to SERVER-52956 Add storage debug method to dump syst... Closed
related to SERVER-51387 Assert that the stable timestamp is n... Closed
Assigned Teams:
Replication
Operating System: ALL
Participants:

 Description   

While working on SERVER-51387, to assert that the stable timestamp is never set higher than the all durable timestamp, I ran into a problem with aborting in-progress transactions on step-up with eMRC=off on this test.

While aborting the in-progress transactions, the stable timestamp is always being set higher than the all durable timestamp by one.

TXN      [OplogApplier-0] Aborting in-progress transactions on stepup.
TXN      [OplogApplier-0] New transaction started {"txnNumber":0,"lsid":{"uuid":{"$uuid":"b7c9b1d4-1883-46c5-b73d-d235c3d41623"}}}
TXN      [OplogApplier-0] Aborting transaction {"sessionId":{"id":{"$uuid":"b7c9b1d4-1883-46c5-b73d-d235c3d41623"},"uid":{"$binary":{"base64":"47DEQpj8HBSa+/TImW+5JCeuQeRkm5NMpJWZG3hSuFU=","subType":"0"}}},"txnNumber":0}
TXN      [OplogApplier-0] transaction {"parameters":{"lsid":{"id":{"$uuid":"b7c9b1d4-1883-46c5-b73d-d235c3d41623"},"uid":{"$binary":{"base64":"47DEQpj8HBSa+/TImW+5JCeuQeRkm5NMpJWZG3hSuFU=","subType":"0"}}},"txnNumber":0,"autocommit":false,"readConcern":{"provenance":"clientSupplied"}},"readTimestamp":"Timestamp(0, 0)","terminationCause":"aborted","timeActiveMicros":0,"timeInactiveMicros":379,"numYields":0,"locks":{"ParallelBatchWriterMode":{"acquireCount":{"r":3}},"ReplicationStateTransition":{"acquireCount":{"w":4,"W":1}},"Global":{"acquireCount":{"r":1,"w":3}},"Database":{"acquireCount":{"r":1,"W":1}},"Collection":{"acquireCount":{"r":1}},"Mutex":{"acquireCount":{"r":2}}},"storage":{},"wasPrepared":false,"durationMillis":0}
REPL     [OplogApplier-0] Setting replication's stable optime {"stableOpTime":{"ts":{"$timestamp":{"t":1604518513,"i":4}},"t":2}}
STORAGE  [OplogApplier-0] The stable timestamp was greater than the all durable timestamp {"stableTimestamp":{"$timestamp":{"t":1604518513,"i":4}},"allDurableTimestamp":{"$timestamp":{"t":1604518513,"i":3}}}
-        [OplogApplier-0] Fatal assertion {"msgid":5138700,"file":"src/mongo/db/storage/wiredtiger/wiredtiger_kv_engine.cpp","line":1925}

I see that when we recalculate the stable timestamp, we only take the all durable timestamp into consideration if the node canAcceptNonLocalWrites(). However, because the node is still stepping up the canAcceptNonLocalWrites() flag wasn't updated yet. That flag gets updated once the state transition is complete.

I believe this works for eMRC=on today because we use the commit point instead of the last applied, which in my testing was less than the all durable timestamp.
 

 



 Comments   
Comment by Gregory Wlodarek [ 05/Nov/20 ]

judah.schvimer I ran the patch against the v4.4 branch and the same failures occur, so I don't think PM-1713 introduced this bug. I haven't looked into the potential risks associated with this behaviour yet.

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