[SERVER-48428] createIndexes should wait for user provided write concern even when returning failure Created: 27/May/20  Updated: 29/Oct/23  Resolved: 23/Jul/20

Status: Closed
Project: Core Server
Component/s: Index Maintenance
Affects Version/s: None
Fix Version/s: 4.7.0

Type: Bug Priority: Major - P3
Reporter: Justin Seyster Assignee: Eric Milkie
Resolution: Fixed Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Issue Links:
Backports
Depends
Problem/Incident
causes SERVER-61601 Determine if global lock upgrade is n... Closed
Related
is related to SERVER-48878 Remove admin X-lock promotion Closed
Backwards Compatibility: Fully Compatible
Operating System: ALL
Backport Requested:
v4.4
Sprint: Execution Team 2020-06-15, Execution Team 2020-06-29, Execution Team 2020-07-13, Execution Team 2020-07-27
Participants:
Linked BF Score: 10

 Description   

When an index build fails (for example, because the index is a "2dsphere" index and the collection contains invalid geometry), it can return the failure before the startIndexBuilds oplog entry is majority committed.

A stepdown at just the right moment can make it appear that the index is still being built (according to the listIndexes command), even though the client has already observed the failure code.

Waiting for majority commit in the failure case should stop this from happening.



 Comments   
Comment by Benety Goh [ 16/Sep/20 ]

This change is not safe to back port to 4.4 without further modification because it relies on SERVER-48878, which is in 4.7+.

Comment by Githook User [ 16/Sep/20 ]

Author:

{'name': 'Benety Goh', 'email': 'benety@mongodb.com', 'username': 'benety'}

Message: Revert "SERVER-48428 do not acquire IX locks in createIndexes if not doing any writes; this will avoid it being killed by stepDown"

This reverts commit 81d5259fb84897191e01114f623050c29b760523.
Branch: v4.4
https://github.com/mongodb/mongo/commit/8a70f5128af22e6f9da80e47a9484ea50332d064

Comment by Githook User [ 09/Sep/20 ]

Author:

{'name': 'Eric Milkie', 'email': 'milkie@10gen.com', 'username': 'milkie'}

Message: SERVER-48428 do not acquire IX locks in createIndexes if not doing any writes; this will avoid it being killed by stepDown

(cherry picked from commit 475fcc6ebd04767fbbbe3231c516e70b9be7d90e)
Branch: v4.4
https://github.com/mongodb/mongo/commit/81d5259fb84897191e01114f623050c29b760523

Comment by Githook User [ 23/Jul/20 ]

Author:

{'name': 'Eric Milkie', 'email': 'milkie@10gen.com', 'username': 'milkie'}

Message: SERVER-48428 do not acquire IX locks in createIndexes if not doing any writes; this will avoid it being killed by stepDown
Branch: master
https://github.com/mongodb/mongo/commit/475fcc6ebd04767fbbbe3231c516e70b9be7d90e

Comment by Eric Milkie [ 16/Jul/20 ]

In the BF, it appears that waiting for write concern got interrupted by the stepdown itself and thus didn't wait long enough:

[ReplicaSetFixture:job0:node1] | 2020-05-12T07:07:50.916+00:00 I  INDEX    20449   [conn268] "Index build failed","attr":{"buildUUID":{"uuid":{"$uuid":"4cda93b9-8890-4fe7-9b69-8f5c96047729"}},"ex":{"code":16755,"codeName":"Location16755","errmsg":"Can't extract geo keys: { _id: ObjectId('5eba4b4645d00c1f8be556ee'), p: { type: \"Polygon\", coordinates: [ [ [ 9.0, 9.0 ], [ 9.0, 11.0 ], [ 11.0, 11.0 ], [ 11.0, 9.0 ], [ 9.0, 9.0 ] ], [ [ 0.0, 0.0 ], [ 0.0, 1.0 ], [ 1.0, 1.0 ], [ 1.0, 0.0 ], [ 0.0, 0.0 ] ] ] } }  Secondary loops not contained by first exterior loop - secondary loops must be holes: [ [ 0.0, 0.0 ], [ 0.0, 1.0 ], [ 1.0, 1.0 ], [ 1.0, 0.0 ], [ 0.0, 0.0 ] ] first loop: [ [ 9.0, 9.0 ], [ 9.0, 11.0 ], [ 11.0, 11.0 ], [ 11.0, 9.0 ], [ 9.0, 9.0 ] ]"}}
[ReplicaSetFixture:job0:node1] | 2020-05-12T07:07:50.942+00:00 I  REPL     21339   [conn268] "Replication failed for write concern","attr":{"writeConcern":{"w":"majority","j":true,"wtimeout":300321,"provenance":"clientSupplied"},"opTime":{"ts":{"$timestamp":{"t":1589267270,"i":14}},"t":5},"opID":4337,"allDurable":{"$timestamp":{"t":1589267270,"i":14}},"progress":{"lastCommittedOpTime":{"ts":{"$timestamp":{"t":1589267270,"i":11}},"t":5},"currentCommittedSnapshotOpTime":{"ts":{"$timestamp":{"t":1589267270,"i":11}},"t":5},"replicationProgress":[{"host":"localhost:20000","optime":{"ts":{"$timestamp":{"t":1589267270,"i":10}},"t":5},"lastAppliedOpTime":{"ts":{"$timestamp":{"t":1589267270,"i":10}},"t":5},"heartbeatAppliedOpTime":{"ts":{"$timestamp":{"t":1589267269,"i":11}},"t":5},"heartbeatDurableOpTime":{"ts":{"$timestamp":{"t":1589267269,"i":11}},"t":5},"memberId":0},{"host":"localhost:20001","optime":{"ts":{"$timestamp":{"t":1589267270,"i":14}},"t":5},"lastAppliedOpTime":{"ts":{"$timestamp":{"t":1589267270,"i":14}},"t":5},"heartbeatAppliedOpTime":{"ts":{"$timestamp":{"t":0,"i":0}},"t":-1},"heartbeatDurableOpTime":{"ts":{"$timestamp":{"t":0,"i":0}},"t":-1},"memberId":1},{"host":"localhost:20002","optime":{"ts":{"$timestamp":{"t":1589267270,"i":11}},"t":5},"lastAppliedOpTime":{"ts":{"$timestamp":{"t":1589267270,"i":11}},"t":5},"heartbeatAppliedOpTime":{"ts":{"$timestamp":{"t":1589267269,"i":11}},"t":5},"heartbeatDurableOpTime":{"ts":{"$timestamp":{"t":1589267269,"i":11}},"t":5},"memberId":2}]}}

I'm not sure if there will be a way to avoid having the write concern wait be interrupted by stepdown.

Comment by Eric Milkie [ 28/May/20 ]

After further investigation, we do need to do this work to solve the build failure.

Comment by Justin Seyster [ 27/May/20 ]

daniel.gottlieb Good question! I checked the logs, and unfortunately, I can't find any entries that include the operationTime for the startIndexBuild oplog entry. I can't reproduce this failure scenario, unfortunately, so I don't have any other way to get that data.

I think the next step is to build a test case that uses fail points to force the interleaving I described, so we can verify it's actually possible and have a way to test any potential fixes.

Comment by Daniel Gottlieb (Inactive) [ 27/May/20 ]

Curious, in this failure case, what's the relationship to the index build failure response's operationTime with the startIndexBuild oplog entry? Do they match? Does the failure response have an earlier value?

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