-
Type: Bug
-
Resolution: Duplicate
-
Priority: Major - P3
-
None
-
Affects Version/s: None
-
Component/s: None
-
None
-
ALL
-
Repl 2021-10-18, Repl 2021-11-01, Replication 2021-11-15
Test jstests/replsets/rollback_waits_for_bgindex_completion.js runs an index build in the background while a transaction is waiting to be committed, leader steps down, and rollsback the txn. Test verifies that rollback should wait for the index build to be aborted but it seems from the logs that there is no wait happening--rollback proceeds immediately because abort of index build has occurred earlier. We should investigate if the current behavior makes for a correct test, and possibly introduce a delay in aborting the index build so rollback effectively waits for it.
Please refer to ticket https://jira.mongodb.org/browse/SERVER-59687 for more information.
Relevant log portion:
[js_test:rollback_waits_for_bgindex_completion] d20030| {"t":{"$date":"2021-09-22T23:06:42.609+00:00"},"s":"I", "c":"STORAGE", "id":20655, "ctx":"BackgroundSync","msg":"Index build: joined after abort","attr":{"buildUUID":{"uuid":{"$uuid":"39d281db-25d4-46c3-9f3b-20133f58bff4"}},"waitResult":{"code":0,"codeName":"OK"},"status":{"code":276,"codeName":"IndexBuildAborted","errmsg":"collection scan stopped. totalRecords: 1; durationMillis: 0ms; phase: collection scan; collectionScanPosition: RecordId(1); readSource: kMajorityCommitted :: caused by :: operation was interrupted"}}} [js_test:rollback_waits_for_bgindex_completion] d20030| {"t":{"$date":"2021-09-22T23:06:42.609+00:00"},"s":"I", "c":"STORAGE", "id":20347, "ctx":"BackgroundSync","msg":"Index build: aborted without cleanup","attr":{"buildUUID":{"uuid":{"$uuid":"39d281db-25d4-46c3-9f3b-20133f58bff4"}},"collectionUUID":{"uuid":{"$uuid":"8cec4cde-51df-432e-8bd2-2a2f8a54593d"}},"namespace":"dbWithBgIndex.coll"}} [js_test:rollback_waits_for_bgindex_completion] d20030| {"t":{"$date":"2021-09-22T23:06:42.609+00:00"},"s":"I", "c":"STORAGE", "id":4656002, "ctx":"IndexBuildsCoordinatorMongod-0","msg":"unable to log operation","attr":{"error":{"code":276,"codeName":"IndexBuildAborted","errmsg":"operation was interrupted"}}} [js_test:rollback_waits_for_bgindex_completion] d20032| {"t":{"$date":"2021-09-22T23:06:42.613+00:00"},"s":"I", "c":"REPL", "id":21079, "ctx":"BackgroundSync","msg":"bgsync - stopReplProducer fail point enabled. Blocking until fail point is disabled."} [js_test:rollback_waits_for_bgindex_completion] d20030| {"t":{"$date":"2021-09-22T23:06:42.617+00:00"},"s":"I", "c":"INDEX", "id":4841502, "ctx":"BackgroundSync","msg":"Index build: wrote resumable state to disk","attr":{"buildUUID":{"uuid":{"$uuid":"39d281db-25d4-46c3-9f3b-20133f58bff4"}},"collectionUUID":{"uuid":{"$uuid":"8cec4cde-51df-432e-8bd2-2a2f8a54593d"}},"namespace":"dbWithBgIndex.coll","details":{"_id":{"$uuid":"39d281db-25d4-46c3-9f3b-20133f58bff4"},"phase":"collection scan","collectionUUID":{"$uuid":"8cec4cde-51df-432e-8bd2-2a2f8a54593d"},"collectionScanPosition":1,"indexes":[{"fileName":"extsort-index.0-1004796179216808253","numKeys":1,"ranges":[{"startOffset":0,"endOffset":13,"checksum":4272028543}],"sideWritesTable":"internal-43--4107655658741736919","spec":{"v":2,"key":{"x":1},"name":"x_1"},"isMultikey":false,"multikeyPaths":[{"multikeyComponents":[]}]}]}}} [js_test:rollback_waits_for_bgindex_completion] d20030| {"t":{"$date":"2021-09-22T23:06:42.617+00:00"},"s":"I", "c":"ROLLBACK", "id":21595, "ctx":"BackgroundSync","msg":"Waiting for all background operations to complete before starting rollback"} [js_test:rollback_waits_for_bgindex_completion] d20030| {"t":{"$date":"2021-09-22T23:06:42.617+00:00"},"s":"I", "c":"ROLLBACK", "id":21597, "ctx":"BackgroundSync","msg":"Finished waiting for background operations to complete before rollback"}
Notice the last two lines, rollback intends to wait for indexbuild to be completed (aborted?), but the abort has already occurred, so there is nothing to wait for.
- is duplicated by
-
SERVER-60427 Investigate effectiveness of test jstests/replsets/rollback_waits_for_bgindex_completion.js
- Closed
-
SERVER-60819 remove jstests/replsets/rollback_waits_for_bgindex_completion.js
- Closed
- related to
-
SERVER-59687 Investigate failing parallel shell in jstests/replsets/rollback_waits_for_bgindex_completion.js
- Closed
-
SERVER-60819 remove jstests/replsets/rollback_waits_for_bgindex_completion.js
- Closed