[j0:prim] | 2021-03-22T05:32:52.262+00:00 I  INDEX    20438   [conn2606] "Index build: registering","attr":{"buildUUID":{"uuid":{"$uuid":"27843eda-2d02-4e1d-9292-983dcd05e571"}},"namespace":"access_collection_in_transaction_after_catalog_changes_ddl_db.ddl_coll","collectionUUID":{"uuid":{"$uuid":"5a334853-b30f-49d8-864e-6bc841e78a90"}},"indexes":1,"firstIndex":{"name":"x_1"}}
[j0:prim] | 2021-03-22T05:32:52.341+00:00 I  INDEX    20384   [IndexBuildsCoordinatorMongod-3] "Index build: starting","attr":{"buildUUID":{"uuid":{"$uuid":"27843eda-2d02-4e1d-9292-983dcd05e571"}},"collectionUUID":{"uuid":{"$uuid":"5a334853-b30f-49d8-864e-6bc841e78a90"}},"namespace":"access_collection_in_transaction_after_catalog_changes_ddl_db.ddl_coll","properties":{"v":2,"key":{"x":1},"name":"x_1"},"method":"Hybrid","maxTemporaryMemoryUsageMB":200}
[j0:prim] | 2021-03-22T05:32:52.396+00:00 I  INDEX    20346   [IndexBuildsCoordinatorMongod-3] "Index build: initialized","attr":{"buildUUID":{"uuid":{"$uuid":"27843eda-2d02-4e1d-9292-983dcd05e571"}},"collectionUUID":{"uuid":{"$uuid":"5a334853-b30f-49d8-864e-6bc841e78a90"}},"namespace":"access_collection_in_transaction_after_catalog_changes_ddl_db.ddl_coll","initializationTimestamp":{"$timestamp":{"t":1616391172,"i":32}}}
[j0:prim] | 2021-03-22T05:32:52.405+00:00 I  STORAGE  4847600 [IndexBuildsCoordinatorMongod-3] "Index build: waiting for last optime before interceptors to be majority committed","attr":{"buildUUID":{"uuid":{"$uuid":"27843eda-2d02-4e1d-9292-983dcd05e571"}},"collectionUUID":{"uuid":{"$uuid":"5a334853-b30f-49d8-864e-6bc841e78a90"}},"deadline":{"$date":"2021-03-22T05:33:02.403Z"},"timeoutMillis":10000,"lastOpTime":{"ts":{"$timestamp":{"t":1616391172,"i":36}},"t":1}}
[j0:prim] | 2021-03-22T05:32:52.409+00:00 I  INDEX    20440   [conn2606] "Index build: waiting for index build to complete","attr":{"buildUUID":{"uuid":{"$uuid":"27843eda-2d02-4e1d-9292-983dcd05e571"}},"deadline":{"$date":{"$numberLong":"9223372036854775807"}}}
[j0:prim] | 2021-03-22T05:32:52.547+00:00 I  INDEX    20391   [IndexBuildsCoordinatorMongod-3] "Index build: collection scan done","attr":{"buildUUID":{"uuid":{"$uuid":"27843eda-2d02-4e1d-9292-983dcd05e571"}},"collectionUUID":{"uuid":{"$uuid":"5a334853-b30f-49d8-864e-6bc841e78a90"}},"namespace":"access_collection_in_transaction_after_catalog_changes_ddl_db.ddl_coll","totalRecords":3,"readSource":"kMajorityCommitted","durationMillis":0}
[j0:prim] | 2021-03-22T05:32:52.557+00:00 I  INDEX    20685   [IndexBuildsCoordinatorMongod-3] "Index build: inserted keys from external sorter into index","attr":{"namespace":"access_collection_in_transaction_after_catalog_changes_ddl_db.ddl_coll","index":"x_1","keysInserted":3,"durationMillis":0}
[j0:prim] | 2021-03-22T05:32:52.671+00:00 I  INDEX    20689   [IndexBuildsCoordinatorMongod-3] "Index build: drained side writes","attr":{"index":"x_1","collectionUUID":{"uuid":{"$uuid":"5a334853-b30f-49d8-864e-6bc841e78a90"}},"namespace":"access_collection_in_transaction_after_catalog_changes_ddl_db.ddl_coll","numApplied":3,"totalInserted":2,"totalDeleted":1,"durationMillis":11}
[j0:prim] | 2021-03-22T05:32:52.688+00:00 I  COMMAND  51803   [conn757] "Slow query","attr":{"type":"command","ns":"config.system.indexBuilds","command":{"voteCommitIndexBuild":{"$uuid":"27843eda-2d02-4e1d-9292-983dcd05e571"},"hostAndPort":"localhost:20001","writeConcern":{"w":"majority"},"$clusterTime":{"clusterTime":{"$timestamp":{"t":1616391172,"i":43}},"signature":{"hash":{"$binary":{"base64":"beyCKo+9ofpUqhygO466WT8MBIk=","subType":"0"}},"keyId":6942345262778024000}},"$db":"admin"},"numYields":0,"reslen":163,"locks":{"ReplicationStateTransition":{"acquireCount":{"w":3}},"Global":{"acquireCount":{"r":2,"w":1}},"Database":{"acquireCount":{"r":2,"w":1}},"Collection":{"acquireCount":{"r":2,"w":1}},"Mutex":{"acquireCount":{"r":5}}},"flowControl":{"acquireCount":1,"timeAcquiringMicros":20},"writeConcern":{"w":"majority","wtimeout":0,"provenance":"clientSupplied"},"storage":{},"remote":"127.0.0.1:53174","protocol":"op_msg","durationMillis":171}
[j0:prim] | 2021-03-22T05:32:52.695+00:00 I  STORAGE  23879   [conn2608] "About to abort all index builders","attr":{"namespace":"access_collection_in_transaction_after_catalog_changes_ddl_db.ddl_coll","uuid":{"uuid":{"$uuid":"5a334853-b30f-49d8-864e-6bc841e78a90"}},"reason":"Collection access_collection_in_transaction_after_catalog_changes_ddl_db.ddl_coll(5a334853-b30f-49d8-864e-6bc841e78a90) is being dropped"}
[j0:prim] | 2021-03-22T05:32:52.696+00:00 I  STORAGE  4656010 [conn2608] "Attempting to abort index build","attr":{"buildUUID":{"uuid":{"$uuid":"27843eda-2d02-4e1d-9292-983dcd05e571"}}}
[j0:prim] | 2021-03-22T05:32:52.696+00:00 I  STORAGE  4656003 [conn2608] "Aborting index build","attr":{"buildUUID":{"uuid":{"$uuid":"27843eda-2d02-4e1d-9292-983dcd05e571"}},"error":"Collection access_collection_in_transaction_after_catalog_changes_ddl_db.ddl_coll(5a334853-b30f-49d8-864e-6bc841e78a90) is being dropped"}
[j0:prim] | 2021-03-22T05:32:52.705+00:00 I  STORAGE  465611  [conn2608] "Cleaned up index build after abort. ","attr":{"buildUUID":{"uuid":{"$uuid":"27843eda-2d02-4e1d-9292-983dcd05e571"}}}
[j0:prim] | 2021-03-22T05:32:53.056+00:00 I  STORAGE  20655   [conn2608] "Index build: joined after abort","attr":{"buildUUID":{"uuid":{"$uuid":"27843eda-2d02-4e1d-9292-983dcd05e571"}},"waitResult":{"code":0,"codeName":"OK"},"status":{"code":47,"codeName":"NoMatchingDocument","errmsg":"failed to get commit quorum before committing index build: 27843eda-2d02-4e1d-9292-983dcd05e571 :: caused by :: No matching IndexBuildEntry found with indexBuildUUID: 27843eda-2d02-4e1d-9292-983dcd05e571"}}
[j0:prim] | 2021-03-22T05:32:53.077+00:00 I  INDEX    20449   [conn2606] "Index build: failed","attr":{"buildUUID":{"uuid":{"$uuid":"27843eda-2d02-4e1d-9292-983dcd05e571"}},"error":{"code":47,"codeName":"NoMatchingDocument","errmsg":"failed to get commit quorum before committing index build: 27843eda-2d02-4e1d-9292-983dcd05e571 :: caused by :: No matching IndexBuildEntry found with indexBuildUUID: 27843eda-2d02-4e1d-9292-983dcd05e571"}}