[SERVER-29025] When index creation is requested from multiple app servers at the same time, the current ops has to finish each index build Created: 30/Apr/17  Updated: 27/Oct/23  Resolved: 05/May/17

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

Type: Bug Priority: Major - P3
Reporter: Joshua Maag Assignee: Eric Milkie
Resolution: Works as Designed Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Operating System: ALL
Participants:

 Description   

When you have multiple sources requesting the same index creation, the following occurs:

  • Since the index doesn't exist yet, each index build starts
  • Once the first index creation finishes, index now shows up
  • Remaining index builds have to complete before checking and validating that they built for nothing since the index now exists.

We saw this issue with an application requesting new index creation. After deploying un update to 50+ servers, they all made the same request on a particularly large index, which effectively took down the database servers.



 Comments   
Comment by Eric Milkie [ 05/May/17 ]

So those log lines are not the same thing as the output from a currentOp() command. The log lines you listed above here do not appear to show overlapping index build commands, so it would be hard to draw any conclusions regarding whether or not they are duplicating work. (Also your sort didn't do what you wanted I think? The lines are not sorted by time.)

Comment by Joshua Maag [ 05/May/17 ]

milkie

So the question is also around the log. I do see your point and would expect to see all the currentOp() results waiting for the one to complete, but these logs make it appear that all the indexes are building, unless I am mistaken:

grep indexName mongod.log | grep 'createIndexes: "indexName"' | sort -k 6 | grep BEAGLE819 | grep 'name: "isSynced"'
2017-04-30T10:13:03.891+0000 I COMMAND  [conn711892] command BEAGLE819_REPORTING.$cmd command: createIndexes { createIndexes: "indexName", indexes: [ { name: "isSynced", ns: "BEAGLE819_REPORTING.indexName", key: { isSynced: 1 } } ] } keyUpdates:0 writeConflicts:0 numYields:0 reslen:149 locks:{ Global: { acquireCount: { r: 1, w: 1 } }, Database: { acquireCount: { W: 1 } } } protocol:op_query 210ms
2017-04-30T10:11:09.731+0000 I COMMAND  [conn710502] command BEAGLE819_REPORTING.$cmd command: createIndexes { createIndexes: "indexName", indexes: [ { name: "isSynced", ns: "BEAGLE819_REPORTING.indexName", key: { isSynced: 1 } } ] } keyUpdates:0 writeConflicts:0 numYields:0 reslen:149 locks:{ Global: { acquireCount: { r: 1, w: 1 } }, Database: { acquireCount: { W: 1 } } } protocol:op_query 39963ms
2017-04-30T10:13:03.517+0000 I COMMAND  [conn711502] command BEAGLE819_REPORTING.$cmd command: createIndexes { createIndexes: "indexName", indexes: [ { name: "isSynced", ns: "BEAGLE819_REPORTING.indexName", key: { isSynced: 1 } } ] } keyUpdates:0 writeConflicts:0 numYields:0 reslen:149 locks:{ Global: { acquireCount: { r: 1, w: 1 } }, Database: { acquireCount: { W: 1 } } } protocol:op_query 43936ms
2017-04-30T10:11:16.559+0000 I COMMAND  [conn710407] command BEAGLE819_REPORTING.$cmd command: createIndexes { createIndexes: "indexName", indexes: [ { name: "isSynced", ns: "BEAGLE819_REPORTING.indexName", key: { isSynced: 1 } } ] } keyUpdates:0 writeConflicts:0 numYields:0 reslen:149 locks:{ Global: { acquireCount: { r: 1, w: 1 } }, Database: { acquireCount: { W: 1 }, acquireWaitCount: { W: 1 }, timeAcquiringMicros: { W: 8947 } } } protocol:op_query 4210ms

Comment by Eric Milkie [ 04/May/17 ]

A foreground index build exclusively locks the database for the duration of the build. If you issue other operations during that time, they will queue up but take no action until the foreground index build finishes and releases its lock. This is true for any operations in the database in question, including foreground index builds. All these operations will show up in currentOp() as "running", but they aren't doing anything except waiting for a database lock.
I would expect that after the foreground index build finishes, the other index builds would then complete immediately. If they do not complete immediately, that would be a bug. Is that what you are seeing here?

Generated at Thu Feb 08 04:19:43 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.