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

abortIndexBuild oplog entry has no effect when run with --recoverFromOplogAsStandalone

    • Type: Icon: Bug Bug
    • Resolution: Fixed
    • Priority: Icon: Major - P3 Major - P3
    • 4.4.14, 5.0.8, 6.0.0-rc0
    • Affects Version/s: None
    • Component/s: None
    • Labels:
      None
    • Fully Compatible
    • ALL
    • v5.0, v4.4
    • Execution Team 2022-03-21, Execution Team 2022-04-04
    • 155

      Unfinished index builds are not restarted in standalone mode and are in a frozen state.

      [js_test:selective_backup_restore_e2e] d20528| 2022-03-15T14:15:37.801+00:00 I  STORAGE  22253   [initandlisten] "Found index from unfinished build","attr":{"namespace":"test0_fsmdb0.system.buckets.find_cmd_with_indexes_timeseries_fsmcoll0","uuid":{"uuid":{"$uuid":"29d89578-b82a-4f2b-9aa7-74c68f51a953"}},"index":"tm_1","buildUUID":{"uuid":{"$uuid":"b1db6c04-ed04-4b91-94f1-0e95d0b1dc9b"}}}
      ...
      [js_test:selective_backup_restore_e2e] d20528| 2022-03-15T14:15:37.802+00:00 I  STORAGE  21005   [initandlisten] "Not restarting unfinished index builds because we are in standalone mode"
      

      When using --recoverFromOplogAsStandalone, the abortIndexBuild oplog entry will fail to apply. This is because there are no active index build threads to abort.

      [js_test:selective_backup_restore_e2e] d20528| 2022-03-15T14:15:38.030+00:00 I  STORAGE  20656   [ReplWriterWorker-0] "Ignoring error while aborting index build","attr":{"buildUUID":{"uuid":{"$uuid":"b1db6c04-ed04-4b91-94f1-0e95d0b1dc9b"}},"error":{"code":4,"codeName":"NoSuchKey","errmsg":"No index build with UUID: b1db6c04-ed04-4b91-94f1-0e95d0b1dc9b"}}
      [js_test:selective_backup_restore_e2e] d20528| 2022-03-15T14:15:38.031+00:00 I  STORAGE  5010504 [ReplWriterWorker-0] "Index build: failed to abort index build while applying abortIndexBuild operation","attr":{"buildUUID":{"uuid":{"$uuid":"b1db6c04-ed04-4b91-94f1-0e95d0b1dc9b"}},"namespace":"test0_fsmdb0.system.buckets.find_cmd_with_indexes_timeseries_fsmcoll0","collectionUUID":{"uuid":{"$uuid":"29d89578-b82a-4f2b-9aa7-74c68f51a953"}},"cause":{"code":276,"codeName":"IndexBuildAborted","errmsg":"dropIndexes command"}}
      

      When replaying a startIndexBuild oplog entry later with an identical index specification, an exception is thrown.

      [js_test:selective_backup_restore_e2e] d20528| 2022-03-15T14:15:38.052+00:00 F  REPL     21235   [initandlisten] "Failed to apply batch of operations","attr":{"numOperationsInBatch":1,"firstOperation":{"oplogEntry":{"op":"c","ns":"test0_fsmdb0.$cmd","ui":{"$uuid":"29d89578-b82a-4f2b-9aa7-74c68f51a953"},"o":{"startIndexBuild":"system.buckets.find_cmd_with_indexes_timeseries_fsmcoll0","indexBuildUUID":{"$uuid":"16af40f5-bc5d-4150-ad1a-e0e300470b90"},"indexes":[{"v":2,"key":{"control.min.tm":1,"control.max.tm":1},"name":"tm_1"}]},"ts":{"$timestamp":{"t":1647353717,"i":5}},"t":1,"v":2,"wall":{"$date":"2022-03-15T14:15:17.007Z"}}},"lastOperation":{"oplogEntry":{"op":"c","ns":"test0_fsmdb0.$cmd","ui":{"$uuid":"29d89578-b82a-4f2b-9aa7-74c68f51a953"},"o":{"startIndexBuild":"system.buckets.find_cmd_with_indexes_timeseries_fsmcoll0","indexBuildUUID":{"$uuid":"16af40f5-bc5d-4150-ad1a-e0e300470b90"},"indexes":[{"v":2,"key":{"control.min.tm":1,"control.max.tm":1},"name":"tm_1"}]},"ts":{"$timestamp":{"t":1647353717,"i":5}},"t":1,"v":2,"wall":{"$date":"2022-03-15T14:15:17.007Z"}}},"failedWriterThread":5,"error":"CannotCreateIndex: An identical, unfinished index 'tm_1' already exists. Must drop before recreating. Spec: { v: 2, key: { control.min.tm: 1.0, control.max.tm: 1.0 }, name: \"tm_1\" }"}
      [js_test:selective_backup_restore_e2e] d20528| 2022-03-15T14:15:38.054+00:00 F  REPL     21570   [initandlisten] "Caught exception during replication recovery","attr":{"error":{"code":67,"codeName":"CannotCreateIndex","errmsg":"An identical, unfinished index 'tm_1' already exists. Must drop before recreating. Spec: { v: 2, key: { control.min.tm: 1.0, control.max.tm: 1.0 }, name: \"tm_1\" }"}}
      [js_test:selective_backup_restore_e2e] d20528| 2022-03-15T14:15:38.054+00:00 F  CONTROL  4757800 [initandlisten] "Writing fatal message","attr":{"message":"terminate() called. An exception is active; attempting to gather more information"}
      [js_test:selective_backup_restore_e2e] d20528| 2022-03-15T14:15:38.054+00:00 F  CONTROL  4757800 [initandlisten] "Writing fatal message","attr":{"message":"DBException::toString(): CannotCreateIndex: An identical, unfinished index 'tm_1' already exists. Must drop before recreating. Spec: { v: 2, key: { control.min.tm: 1.0, control.max.tm: 1.0 }, name: \"tm_1\" }\nActual exception type: mongo::error_details::ExceptionForImpl<(mongo::ErrorCodes::Error)67, mongo::AssertionException>\n"}
      

      The logic for the abortIndexBuild oplog entry should drop unfinished, frozen indexes to prevent this.

            Assignee:
            gregory.wlodarek@mongodb.com Gregory Wlodarek
            Reporter:
            gregory.wlodarek@mongodb.com Gregory Wlodarek
            Votes:
            0 Vote for this issue
            Watchers:
            5 Start watching this issue

              Created:
              Updated:
              Resolved: