diff options
Diffstat (limited to 'jstests/replsets/initial_sync_fetch_from_oldest_active_transaction_timestamp.js')
| -rw-r--r-- | jstests/replsets/initial_sync_fetch_from_oldest_active_transaction_timestamp.js | 378 |
1 files changed, 190 insertions, 188 deletions
diff --git a/jstests/replsets/initial_sync_fetch_from_oldest_active_transaction_timestamp.js b/jstests/replsets/initial_sync_fetch_from_oldest_active_transaction_timestamp.js index a15f5290ea6..eea0ebfab20 100644 --- a/jstests/replsets/initial_sync_fetch_from_oldest_active_transaction_timestamp.js +++ b/jstests/replsets/initial_sync_fetch_from_oldest_active_transaction_timestamp.js @@ -14,192 +14,194 @@ */ (function() { - "use strict"; - - load("jstests/libs/check_log.js"); - load("jstests/core/txns/libs/prepare_helpers.js"); - - const replTest = new ReplSetTest({nodes: 2}); - replTest.startSet(); - - const config = replTest.getReplSetConfig(); - // Increase the election timeout so that we do not accidentally trigger an election while the - // secondary is restarting. - config.settings = {"electionTimeoutMillis": 12 * 60 * 60 * 1000}; - replTest.initiate(config); - - const primary = replTest.getPrimary(); - let secondary = replTest.getSecondary(); - - const dbName = "test"; - const collName = "initial_sync_fetch_from_oldest_active_transaction_timestamp"; - let testDB = primary.getDB(dbName); - let testColl = testDB.getCollection(collName); - - assert.commandWorked(testColl.insert({_id: 1})); - - jsTestLog("Preparing a transaction that will later be committed"); - - const session1 = primary.startSession(); - const sessionDB1 = session1.getDatabase(dbName); - const sessionColl1 = sessionDB1.getCollection(collName); - session1.startTransaction(); - assert.commandWorked(sessionColl1.insert({_id: 2})); - const prepareTimestamp1 = PrepareHelpers.prepareTransaction(session1); - - jsTestLog("Preparing a transaction that will later be the oldest active transaction"); - - // Prepare a transaction so that there is an active transaction with an oplog entry. The - // timestamp of the first oplog entry of this transaction will become the beginFetchingTimestamp - // during initial sync. - let session2 = primary.startSession(); - let sessionDB2 = session2.getDatabase(dbName); - const sessionColl2 = sessionDB2.getCollection(collName); - session2.startTransaction(); - assert.commandWorked(sessionColl2.update({_id: 1}, {_id: 1, a: 1})); - let prepareTimestamp2 = PrepareHelpers.prepareTransaction(session2); - - const lsid2 = session2.getSessionId(); - const txnNumber2 = session2.getTxnNumber_forTesting(); - - const oplog = primary.getDB("local").getCollection("oplog.rs"); - const txnNum = session2.getTxnNumber_forTesting(); - const op = oplog.findOne({"txnNumber": txnNum, "lsid.id": session2.getSessionId().id}); - assert.neq(op, null); - const beginFetchingTs = op.ts; - jsTestLog("Expected beginFetchingTimestamp: " + beginFetchingTs); - - // Commit the first transaction so that we have an operation that is fetched during initial sync - // but should not be applied. If this is applied, initial sync will fail because while trying to - // apply the commitTransaction oplog entry, it will fail to get the prepare oplog - // entry since its optime is before the beginFetchingTimestamp. Doing another operation will - // also cause the beginApplyingTimestamp to be different from the beginFetchingTimestamp. Note - // that since the beginApplyingTimestamp is the timestamp after which operations are applied - // during initial sync, this commitTransaction will not be applied. - const beginApplyingTimestamp = - assert.commandWorked(PrepareHelpers.commitTransaction(session1, prepareTimestamp1)) - .operationTime; - - jsTestLog("beginApplyingTimestamp: " + beginApplyingTimestamp); - - // Restart the secondary with startClean set to true so that it goes through initial sync. Also - // restart the node with a failpoint turned on that will pause initial sync after the secondary - // has copied {_id: 1} and {_id: 2}. This way we can insert more documents when initial sync is - // paused and know that they won't be copied during collection cloning but instead must be - // applied during oplog application. - replTest.stop(secondary, - // signal - undefined, - // Validation would encounter a prepare conflict on the open transaction. - {skipValidation: true}); - secondary = replTest.start( - secondary, - { - startClean: true, - setParameter: { - 'failpoint.initialSyncHangDuringCollectionClone': tojson( - {mode: 'alwaysOn', data: {namespace: testColl.getFullName(), numDocsToClone: 2}}), - 'numInitialSyncAttempts': 1 - } - }, - true /* wait */); - - jsTestLog("Secondary was restarted"); - - // Wait for failpoint to be reached so we know that collection cloning is paused. - checkLog.contains(secondary, "initialSyncHangDuringCollectionClone fail point enabled"); - - jsTestLog("Running operations while collection cloning is paused"); - - // Run some operations on the sync source while collection cloning is paused so that we know - // they must be applied during the oplog application stage of initial sync. This will also make - // sure that the beginApplyingTimestamp and the stopTimestamp in initial sync are different. The - // stopTimestamp is the timestamp of the oplog entry that was last applied on the sync source - // when the oplog application phase of initial sync begins. - const stopTimestamp = - assert.commandWorked(testColl.runCommand("insert", {documents: [{_id: 4}]})).operationTime; - - jsTestLog("stopTimestamp: " + stopTimestamp); - - // Resume initial sync. - assert.commandWorked(secondary.adminCommand( - {configureFailPoint: "initialSyncHangDuringCollectionClone", mode: "off"})); - - jsTestLog("Initial sync resumed"); - - // Wait for the secondary to complete initial sync. - replTest.waitForState(secondary, ReplSetTest.State.SECONDARY); - replTest.awaitReplication(); - - jsTestLog("Initial sync completed"); - - // Make sure the secondary fetched enough transaction oplog entries. - secondary.setSlaveOk(); - const secondaryOplog = secondary.getDB("local").getCollection("oplog.rs"); - assert.eq(secondaryOplog.find({"ts": beginFetchingTs}).itcount(), 1); - - // Make sure the first transaction committed properly and is reflected after the initial sync. - let res = secondary.getDB(dbName).getCollection(collName).findOne({_id: 2}); - assert.docEq(res, {_id: 2}, res); - - jsTestLog("Stepping up the secondary"); - - // Step up the secondary after initial sync is done and make sure the transaction is properly - // prepared. - replTest.stepUp(secondary); - replTest.waitForState(secondary, ReplSetTest.State.PRIMARY); - const newPrimary = replTest.getPrimary(); - testDB = newPrimary.getDB(dbName); - testColl = testDB.getCollection(collName); - - // Force the second session to use the same lsid and txnNumber as from before the restart. This - // ensures that we're working with the same session and transaction. - session2 = PrepareHelpers.createSessionWithGivenId(newPrimary, lsid2); - session2.setTxnNumber_forTesting(txnNumber2); - sessionDB2 = session2.getDatabase(dbName); - - jsTestLog("Checking that the second transaction is properly prepared"); - - // Make sure that we can't read changes to the document from the second prepared transaction - // after initial sync. - assert.eq(testColl.find({_id: 1}).toArray(), [{_id: 1}]); - - // Make sure that another write on the same document from the second transaction causes a write - // conflict. - assert.commandFailedWithCode( - testDB.runCommand( - {update: collName, updates: [{q: {_id: 1}, u: {$set: {a: 2}}}], maxTimeMS: 5 * 1000}), - ErrorCodes.MaxTimeMSExpired); - - // Make sure that we cannot add other operations to the second transaction since it is prepared. - assert.commandFailedWithCode(sessionDB2.runCommand({ - insert: collName, - documents: [{_id: 3}], - txnNumber: NumberLong(txnNumber2), - stmtId: NumberInt(2), - autocommit: false - }), - ErrorCodes.PreparedTransactionInProgress); - - jsTestLog("Committing the second transaction"); - - // Make sure we can successfully commit the second transaction after recovery. - assert.commandWorked(sessionDB2.adminCommand({ - commitTransaction: 1, - commitTimestamp: prepareTimestamp2, - txnNumber: NumberLong(txnNumber2), - autocommit: false - })); - assert.eq(testColl.find({_id: 1}).toArray(), [{_id: 1, a: 1}]); - - jsTestLog("Attempting to run another transaction"); - - // Make sure that we can run another conflicting transaction without any problems. - session2.startTransaction(); - assert.commandWorked(sessionDB2[collName].update({_id: 1}, {_id: 1, a: 2})); - prepareTimestamp2 = PrepareHelpers.prepareTransaction(session2); - assert.commandWorked(PrepareHelpers.commitTransaction(session2, prepareTimestamp2)); - assert.eq(testColl.findOne({_id: 1}), {_id: 1, a: 2}); - - replTest.stopSet(); +"use strict"; + +load("jstests/libs/check_log.js"); +load("jstests/core/txns/libs/prepare_helpers.js"); + +const replTest = new ReplSetTest({nodes: 2}); +replTest.startSet(); + +const config = replTest.getReplSetConfig(); +// Increase the election timeout so that we do not accidentally trigger an election while the +// secondary is restarting. +config.settings = { + "electionTimeoutMillis": 12 * 60 * 60 * 1000 +}; +replTest.initiate(config); + +const primary = replTest.getPrimary(); +let secondary = replTest.getSecondary(); + +const dbName = "test"; +const collName = "initial_sync_fetch_from_oldest_active_transaction_timestamp"; +let testDB = primary.getDB(dbName); +let testColl = testDB.getCollection(collName); + +assert.commandWorked(testColl.insert({_id: 1})); + +jsTestLog("Preparing a transaction that will later be committed"); + +const session1 = primary.startSession(); +const sessionDB1 = session1.getDatabase(dbName); +const sessionColl1 = sessionDB1.getCollection(collName); +session1.startTransaction(); +assert.commandWorked(sessionColl1.insert({_id: 2})); +const prepareTimestamp1 = PrepareHelpers.prepareTransaction(session1); + +jsTestLog("Preparing a transaction that will later be the oldest active transaction"); + +// Prepare a transaction so that there is an active transaction with an oplog entry. The +// timestamp of the first oplog entry of this transaction will become the beginFetchingTimestamp +// during initial sync. +let session2 = primary.startSession(); +let sessionDB2 = session2.getDatabase(dbName); +const sessionColl2 = sessionDB2.getCollection(collName); +session2.startTransaction(); +assert.commandWorked(sessionColl2.update({_id: 1}, {_id: 1, a: 1})); +let prepareTimestamp2 = PrepareHelpers.prepareTransaction(session2); + +const lsid2 = session2.getSessionId(); +const txnNumber2 = session2.getTxnNumber_forTesting(); + +const oplog = primary.getDB("local").getCollection("oplog.rs"); +const txnNum = session2.getTxnNumber_forTesting(); +const op = oplog.findOne({"txnNumber": txnNum, "lsid.id": session2.getSessionId().id}); +assert.neq(op, null); +const beginFetchingTs = op.ts; +jsTestLog("Expected beginFetchingTimestamp: " + beginFetchingTs); + +// Commit the first transaction so that we have an operation that is fetched during initial sync +// but should not be applied. If this is applied, initial sync will fail because while trying to +// apply the commitTransaction oplog entry, it will fail to get the prepare oplog +// entry since its optime is before the beginFetchingTimestamp. Doing another operation will +// also cause the beginApplyingTimestamp to be different from the beginFetchingTimestamp. Note +// that since the beginApplyingTimestamp is the timestamp after which operations are applied +// during initial sync, this commitTransaction will not be applied. +const beginApplyingTimestamp = + assert.commandWorked(PrepareHelpers.commitTransaction(session1, prepareTimestamp1)) + .operationTime; + +jsTestLog("beginApplyingTimestamp: " + beginApplyingTimestamp); + +// Restart the secondary with startClean set to true so that it goes through initial sync. Also +// restart the node with a failpoint turned on that will pause initial sync after the secondary +// has copied {_id: 1} and {_id: 2}. This way we can insert more documents when initial sync is +// paused and know that they won't be copied during collection cloning but instead must be +// applied during oplog application. +replTest.stop(secondary, + // signal + undefined, + // Validation would encounter a prepare conflict on the open transaction. + {skipValidation: true}); +secondary = replTest.start( + secondary, + { + startClean: true, + setParameter: { + 'failpoint.initialSyncHangDuringCollectionClone': tojson( + {mode: 'alwaysOn', data: {namespace: testColl.getFullName(), numDocsToClone: 2}}), + 'numInitialSyncAttempts': 1 + } + }, + true /* wait */); + +jsTestLog("Secondary was restarted"); + +// Wait for failpoint to be reached so we know that collection cloning is paused. +checkLog.contains(secondary, "initialSyncHangDuringCollectionClone fail point enabled"); + +jsTestLog("Running operations while collection cloning is paused"); + +// Run some operations on the sync source while collection cloning is paused so that we know +// they must be applied during the oplog application stage of initial sync. This will also make +// sure that the beginApplyingTimestamp and the stopTimestamp in initial sync are different. The +// stopTimestamp is the timestamp of the oplog entry that was last applied on the sync source +// when the oplog application phase of initial sync begins. +const stopTimestamp = + assert.commandWorked(testColl.runCommand("insert", {documents: [{_id: 4}]})).operationTime; + +jsTestLog("stopTimestamp: " + stopTimestamp); + +// Resume initial sync. +assert.commandWorked(secondary.adminCommand( + {configureFailPoint: "initialSyncHangDuringCollectionClone", mode: "off"})); + +jsTestLog("Initial sync resumed"); + +// Wait for the secondary to complete initial sync. +replTest.waitForState(secondary, ReplSetTest.State.SECONDARY); +replTest.awaitReplication(); + +jsTestLog("Initial sync completed"); + +// Make sure the secondary fetched enough transaction oplog entries. +secondary.setSlaveOk(); +const secondaryOplog = secondary.getDB("local").getCollection("oplog.rs"); +assert.eq(secondaryOplog.find({"ts": beginFetchingTs}).itcount(), 1); + +// Make sure the first transaction committed properly and is reflected after the initial sync. +let res = secondary.getDB(dbName).getCollection(collName).findOne({_id: 2}); +assert.docEq(res, {_id: 2}, res); + +jsTestLog("Stepping up the secondary"); + +// Step up the secondary after initial sync is done and make sure the transaction is properly +// prepared. +replTest.stepUp(secondary); +replTest.waitForState(secondary, ReplSetTest.State.PRIMARY); +const newPrimary = replTest.getPrimary(); +testDB = newPrimary.getDB(dbName); +testColl = testDB.getCollection(collName); + +// Force the second session to use the same lsid and txnNumber as from before the restart. This +// ensures that we're working with the same session and transaction. +session2 = PrepareHelpers.createSessionWithGivenId(newPrimary, lsid2); +session2.setTxnNumber_forTesting(txnNumber2); +sessionDB2 = session2.getDatabase(dbName); + +jsTestLog("Checking that the second transaction is properly prepared"); + +// Make sure that we can't read changes to the document from the second prepared transaction +// after initial sync. +assert.eq(testColl.find({_id: 1}).toArray(), [{_id: 1}]); + +// Make sure that another write on the same document from the second transaction causes a write +// conflict. +assert.commandFailedWithCode( + testDB.runCommand( + {update: collName, updates: [{q: {_id: 1}, u: {$set: {a: 2}}}], maxTimeMS: 5 * 1000}), + ErrorCodes.MaxTimeMSExpired); + +// Make sure that we cannot add other operations to the second transaction since it is prepared. +assert.commandFailedWithCode(sessionDB2.runCommand({ + insert: collName, + documents: [{_id: 3}], + txnNumber: NumberLong(txnNumber2), + stmtId: NumberInt(2), + autocommit: false +}), + ErrorCodes.PreparedTransactionInProgress); + +jsTestLog("Committing the second transaction"); + +// Make sure we can successfully commit the second transaction after recovery. +assert.commandWorked(sessionDB2.adminCommand({ + commitTransaction: 1, + commitTimestamp: prepareTimestamp2, + txnNumber: NumberLong(txnNumber2), + autocommit: false +})); +assert.eq(testColl.find({_id: 1}).toArray(), [{_id: 1, a: 1}]); + +jsTestLog("Attempting to run another transaction"); + +// Make sure that we can run another conflicting transaction without any problems. +session2.startTransaction(); +assert.commandWorked(sessionDB2[collName].update({_id: 1}, {_id: 1, a: 2})); +prepareTimestamp2 = PrepareHelpers.prepareTransaction(session2); +assert.commandWorked(PrepareHelpers.commitTransaction(session2, prepareTimestamp2)); +assert.eq(testColl.findOne({_id: 1}), {_id: 1, a: 2}); + +replTest.stopSet(); })(); |