Uploaded image for project: 'Core Server'
  1. Core Server
  2. SERVER-60606

Race condition during initial sync when index builds start in data cloning phase

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: Closed
    • Priority: Major - P3
    • Resolution: Fixed
    • Affects Version/s: None
    • Fix Version/s: 5.0.4, 4.4.11, 5.1.0-rc2, 5.2.0
    • Component/s: None
    • Labels:
      None
    • Backwards Compatibility:
      Fully Compatible
    • Operating System:
      ALL
    • Backport Requested:
      v5.1, v5.0, v4.4
    • Steps To Reproduce:
      Hide

      /**
       * 
       */
       
       (function() {
          'use strict';
          
          load("jstests/libs/fail_point_util.js");
          load('jstests/replsets/rslib.js');
          const basename = 'initial_sync_rename_database_before_cloning';
          
          jsTestLog('Bring up a replica set');
          const rst = new ReplSetTest({name: basename, nodes: 1});
          rst.startSet();
          rst.initiate();
          
          const dbName = "test";
          
          const primary = rst.getPrimary();
          const primaryDb = primary.getDB(dbName);
          
          jsTestLog("Create collections on primary");
          const collName = "coll";
          
          jsTestLog('Waiting for replication');
          rst.awaitReplication();
          
          jsTestLog('Bring up a new node');
          const secondary = rst.add({setParameter: 'numInitialSyncAttempts=1'});
          
          // Add a fail point that causes the secondary's initial sync to hang before
          // copying databases.
          const failPoint = configureFailPoint(secondary, 'initialSyncHangBeforeCopyingDatabases');
          
          jsTestLog('Begin initial sync on secondary');
          let conf = rst.getPrimary().getDB('admin').runCommand({replSetGetConfig: 1}).config;
          conf.members.push({_id: 1, host: secondary.host, priority: 0, votes: 0});
          conf.version++;
          assert.commandWorked(rst.getPrimary().getDB('admin').runCommand({replSetReconfig: conf}));
          assert.eq(primary, rst.getPrimary(), 'Primary changed after reconfig');
          
          // Confirm that initial sync started on the secondary node.
          jsTestLog('Waiting for initial sync to start');
          failPoint.wait();
       
          assert.commandWorked(primaryDb.getCollection(collName).insert({}));
          assert.commandWorked(primaryDb.runCommand({emptycapped: "coll"}))
          assert.commandWorked(primaryDb.getCollection(collName).insert({_id: 0, a: 1}));
          
          jsTestLog('Build index on the sync source');
          const fpIndexSrc = configureFailPoint(primary, 'hangAfterStartingIndexBuild');
          
          const awaitIndex = startParallelShell(() => {
            assert.commandWorked(db.getCollection('coll').createIndex({a: 1}));
          }, primary.port)
          
          jsTestLog('Pause index build on sync source')
          fpIndexSrc.wait();
          
          const fpIndexInit = configureFailPoint(secondary, 'hangAfterStartingIndexBuild');
          
          jsTestLog('Resume the initial sync')
          failPoint.off();
       
          jsTestLog('Pause index build on initial sync node');
          fpIndexInit.wait();
          
          jsTestLog('Resume index build on sync source to finish');
          fpIndexSrc.off();
       
          awaitIndex();
       
          jsTestLog('Resume index build on initial sync node to finish');
          fpIndexInit.off();   
          
          jsTestLog('Wait for both nodes to be up-to-date');
       
          rst.awaitSecondaryNodes();
          rst.awaitReplication();
       
          rst.checkReplicatedDataHashes();
          rst.checkOplogs();
          rst.stopSet();
          })();
      

      Show
      /** * */   (function() { 'use strict'; load("jstests/libs/fail_point_util.js"); load('jstests/replsets/rslib.js'); const basename = 'initial_sync_rename_database_before_cloning'; jsTestLog('Bring up a replica set'); const rst = new ReplSetTest({name: basename, nodes: 1}); rst.startSet(); rst.initiate(); const dbName = "test"; const primary = rst.getPrimary(); const primaryDb = primary.getDB(dbName); jsTestLog("Create collections on primary"); const collName = "coll"; jsTestLog('Waiting for replication'); rst.awaitReplication(); jsTestLog('Bring up a new node'); const secondary = rst.add({setParameter: 'numInitialSyncAttempts=1'}); // Add a fail point that causes the secondary's initial sync to hang before // copying databases. const failPoint = configureFailPoint(secondary, 'initialSyncHangBeforeCopyingDatabases'); jsTestLog('Begin initial sync on secondary'); let conf = rst.getPrimary().getDB('admin').runCommand({replSetGetConfig: 1}).config; conf.members.push({_id: 1, host: secondary.host, priority: 0, votes: 0}); conf.version++; assert.commandWorked(rst.getPrimary().getDB('admin').runCommand({replSetReconfig: conf})); assert.eq(primary, rst.getPrimary(), 'Primary changed after reconfig'); // Confirm that initial sync started on the secondary node. jsTestLog('Waiting for initial sync to start'); failPoint.wait();   assert.commandWorked(primaryDb.getCollection(collName).insert({})); assert.commandWorked(primaryDb.runCommand({emptycapped: "coll"})) assert.commandWorked(primaryDb.getCollection(collName).insert({_id: 0, a: 1})); jsTestLog('Build index on the sync source'); const fpIndexSrc = configureFailPoint(primary, 'hangAfterStartingIndexBuild'); const awaitIndex = startParallelShell(() => { assert.commandWorked(db.getCollection('coll').createIndex({a: 1})); }, primary.port) jsTestLog('Pause index build on sync source') fpIndexSrc.wait(); const fpIndexInit = configureFailPoint(secondary, 'hangAfterStartingIndexBuild'); jsTestLog('Resume the initial sync') failPoint.off();   jsTestLog('Pause index build on initial sync node'); fpIndexInit.wait(); jsTestLog('Resume index build on sync source to finish'); fpIndexSrc.off();   awaitIndex();   jsTestLog('Resume index build on initial sync node to finish'); fpIndexInit.off(); jsTestLog('Wait for both nodes to be up-to-date');   rst.awaitSecondaryNodes(); rst.awaitReplication();   rst.checkReplicatedDataHashes(); rst.checkOplogs(); rst.stopSet(); })();
    • Sprint:
      Execution Team 2021-10-18
    • Linked BF Score:
      145

      Description

      Currently we will kick off an index build on the new node if an index is observed as unfinished on the sync source. However, the new node can get stuck in this loop if:

      1. the index build on the sync source then finishes and is unregistered, AND
      2. the oplog entry before "commitIndexBuild" can get "BackgroundOperationInProgressForNamespace" when an index build is running on the collection

      It turns out we did handle this case when getting a "BackgroundOperationInProgressForNamespace" error while replaying the oplogs by aborting the conflicting index build. But we forgot to include the case for emptycapped command. Adding the case should solve the issue.

        Attachments

          Issue Links

            Activity

              People

              Assignee:
              yuhong.zhang Yuhong Zhang
              Reporter:
              yuhong.zhang Yuhong Zhang
              Participants:
              Votes:
              0 Vote for this issue
              Watchers:
              4 Start watching this issue

                Dates

                Created:
                Updated:
                Resolved: