[SERVER-57065] access_collection_in_transaction_after_catalog_changes.js should expect the NoMatchingDocument error code when an index build is aborted Created: 19/May/21  Updated: 29/Oct/23  Resolved: 19/May/21

Status: Closed
Project: Core Server
Component/s: None
Affects Version/s: None
Fix Version/s: 5.0.0-rc0, 5.1.0-rc0, 4.4.20

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

Issue Links:
Backports
Depends
Related
Backwards Compatibility: Fully Compatible
Operating System: ALL
Backport Requested:
v5.0, v4.4
Sprint: Execution Team 2021-05-31
Participants:
Linked BF Score: 18

 Description   

The index builder thread was running the voteCommitIndexBuild when the collection was dropped, causing the index build to be aborted. 

 

[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"}}

The index build did get aborted cleanly but returned NoMatchingDocument instead of IndexBuildAborted. This is because we tried to read the index build entry from config.system.indexBuilds while being aborted, which removed the entry.



 Comments   
Comment by Githook User [ 27/Mar/23 ]

Author:

{'name': 'Gregory Wlodarek', 'email': 'gregory.wlodarek@mongodb.com', 'username': 'GWlodarek'}

Message: SERVER-57065 access_collection_in_transaction_after_catalog_changes.js should expect the NoMatchingDocument error code when an index build is aborted

(cherry picked from commit eef9d3863ea80c7c6663693a989b1bf803552193)
Branch: v4.4
https://github.com/mongodb/mongo/commit/404bdbe53598b477cc751c8a848636a0ce81a2de

Comment by Vivian Ge (Inactive) [ 06/Oct/21 ]

Updating the fixversion since branching activities occurred yesterday. This ticket will be in rc0 when it’s been triggered. For more active release information, please keep an eye on #server-release. Thank you!

Comment by Githook User [ 19/May/21 ]

Author:

{'name': 'Gregory Wlodarek', 'email': 'gregory.wlodarek@mongodb.com', 'username': 'GWlodarek'}

Message: SERVER-57065 access_collection_in_transaction_after_catalog_changes.js should expect the NoMatchingDocument error code when an index build is aborted

(cherry picked from commit eef9d3863ea80c7c6663693a989b1bf803552193)
Branch: v5.0
https://github.com/mongodb/mongo/commit/f4f4f89642113fdcbb2b599e90d75d630968db9e

Comment by Githook User [ 19/May/21 ]

Author:

{'name': 'Gregory Wlodarek', 'email': 'gregory.wlodarek@mongodb.com', 'username': 'GWlodarek'}

Message: SERVER-57065 access_collection_in_transaction_after_catalog_changes.js should expect the NoMatchingDocument error code when an index build is aborted
Branch: master
https://github.com/mongodb/mongo/commit/eef9d3863ea80c7c6663693a989b1bf803552193

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