[SERVER-72427] Stuck creating index with "Index Build: draining writes received during build" Created: 29/Dec/22 Updated: 02/Jan/23 Resolved: 02/Jan/23 |
|
| Status: | Closed |
| Project: | Core Server |
| Component/s: | None |
| Affects Version/s: | 5.0.14 |
| Fix Version/s: | None |
| Type: | Bug | Priority: | Major - P3 |
| Reporter: | Snir David | Assignee: | Chris Kelly |
| Resolution: | Done | Votes: | 0 |
| Labels: | cluster, index, indexes, indexing | ||
| Remaining Estimate: | Not Specified | ||
| Time Spent: | Not Specified | ||
| Original Estimate: | Not Specified | ||
| Operating System: | ALL |
| Participants: |
| Description |
|
I have checked out the previous issues: https://jira.mongodb.org/browse/SERVER-50665 and https://jira.mongodb.org/browse/SERVER-48516 I have ensured a keyfile exists, and I then stopped and started the servers again (in the recommended order, first stop secondaries then master, etc.) None of this helped and I have no idea what to do. Mongo version 5.0.14
The `op` output for example: ``` ] }, , , }, } ,"s":"I", "c":"INDEX", "id":20689, "ctx":"IndexBuildsCoordinatorMongod-1","msg":"Index build: drained side writes","attr":{"index":"store_id_1_name_1_timestamp_1","collectionUUID":{"uuid":{"$uuid":"8e1e6c02-1f20-4645-a3b2-1e1fb32ea7f5"}},"namespace":"captainup.actions","numApplied":534,"totalInserted":534,"totalDeleted":0,"durationMillis":2}} {"t":\{"$date":"2022-12-29T16:17:12.706+00:00"},"s":"I", "c":"INDEX", "id":20689, "ctx":"IndexBuildsCoordinatorMongod-0","msg":"Index build: drained side writes","attr":{"index":"timestamp_1","collectionUUID":{"uuid":{"$uuid":"8e1e6c02-1f20-4645-a3b2-1e1fb32ea7f5"}},"namespace":"captainup.actions","numApplied":529,"totalInserted":529,"totalDeleted":0,"durationMillis":24}} {"t":\{"$date":"2022-12-29T16:17:13.127+00:00"},"s":"I", "c":"INDEX", "id":20689, "ctx":"IndexBuildsCoordinatorMongod-1","msg":"Index build: drained side writes","attr":{"index":"store_id_1_name_1_timestamp_1","collectionUUID":{"uuid":{"$uuid":"8e1e6c02-1f20-4645-a3b2-1e1fb32ea7f5"}},"namespace":"captainup.actions","numApplied":547,"totalInserted":547,"totalDeleted":0,"durationMillis":2}} {"t":\{"$date":"2022-12-29T16:17:13.709+00:00"},"s":"I", "c":"INDEX", "id":20689, "ctx":"IndexBuildsCoordinatorMongod-0","msg":"Index build: drained side writes","attr":{"index":"timestamp_1","collectionUUID":{"uuid":{"$uuid":"8e1e6c02-1f20-4645-a3b2-1e1fb32ea7f5"}},"namespace":"captainup.actions","numApplied":534,"totalInserted":534,"totalDeleted":0,"durationMillis":2}} {"t":\{"$date":"2022-12-29T16:17:14.131+00:00"},"s":"I", "c":"INDEX", "id":20689, "ctx":"IndexBuildsCoordinatorMongod-1","msg":"Index build: drained side writes","attr":{"index":"store_id_1_name_1_timestamp_1","collectionUUID":{"uuid":{"$uuid":"8e1e6c02-1f20-4645-a3b2-1e1fb32ea7f5"}},"namespace":"captainup.actions","numApplied":511,"totalInserted":511,"totalDeleted":0,"durationMillis":2}} {"t":\{"$date":"2022-12-29T16:17:14.712+00:00"},"s":"I", "c":"INDEX", "id":20689, "ctx":"IndexBuildsCoordinatorMongod-0","msg":"Index build: drained side writes","attr":{"index":"timestamp_1","collectionUUID":{"uuid":{"$uuid":"8e1e6c02-1f20-4645-a3b2-1e1fb32ea7f5"}},"namespace":"captainup.actions","numApplied":523,"totalInserted":523,"totalDeleted":0,"durationMillis":1}} {"t":\{"$date":"2022-12-29T16:17:15.135+00:00"},"s":"I", "c":"INDEX", "id":20689, "ctx":"IndexBuildsCoordinatorMongod-1","msg":"Index build: drained side writes","attr":{"index":"store_id_1_name_1_timestamp_1","collectionUUID":{"uuid":{"$uuid":"8e1e6c02-1f20-4645-a3b2-1e1fb32ea7f5"}},"namespace":"captainup.actions","numApplied":528,"totalInserted":528,"totalDeleted":0,"durationMillis":2}} {"t":\{"$date":"2022-12-29T16:17:15.715+00:00"},"s":"I", "c":"INDEX", "id":20689, "ctx":"IndexBuildsCoordinatorMongod-0","msg":"Index build: drained side writes","attr":{"index":"timestamp_1","collectionUUID":{"uuid":{"$uuid":"8e1e6c02-1f20-4645-a3b2-1e1fb32ea7f5"}},"namespace":"captainup.actions","numApplied":498,"totalInserted":498,"totalDeleted":0,"durationMillis":2}} {"t":\{"$date":"2022-12-29T16:17:16.138+00:00"},"s":"I", "c":"INDEX", "id":20689, "ctx":"IndexBuildsCoordinatorMongod-1","msg":"Index build: drained side writes","attr":{"index":"store_id_1_name_1_timestamp_1","collectionUUID":{"uuid":{"$uuid":"8e1e6c02-1f20-4645-a3b2-1e1fb32ea7f5"}},"namespace":"captainup.actions","numApplied":515,"totalInserted":515,"totalDeleted":0,"durationMillis":2}} {"t":\{"$date":"2022-12-29T16:17:16.717+00:00"},"s":"I", "c":"INDEX", "id":20689, "ctx":"IndexBuildsCoordinatorMongod-0","msg":"Index build: drained side writes","attr":{"index":"timestamp_1","collectionUUID":{"uuid":{"$uuid":"8e1e6c02-1f20-4645-a3b2-1e1fb32ea7f5"}},"namespace":"captainup.actions","numApplied":519,"totalInserted":519,"totalDeleted":0,"durationMillis":1}} {"t":\{"$date":"2022-12-29T16:17:17.142+00:00"},"s":"I", "c":"INDEX", "id":20689, "ctx":"IndexBuildsCoordinatorMongod-1","msg":"Index build: drained side writes","attr":{"index":"store_id_1_name_1_timestamp_1","collectionUUID":{"uuid":{"$uuid":"8e1e6c02-1f20-4645-a3b2-1e1fb32ea7f5"}},"namespace":"captainup.actions","numApplied":517,"totalInserted":517,"totalDeleted":0,"durationMillis":2}} {"t":\{"$date":"2022-12-29T16:17:17.720+00:00"},"s":"I", "c":"INDEX", "id":20689, "ctx":"IndexBuildsCoordinatorMongod-0","msg":"Index build: drained side writes","attr":{"index":"timestamp_1","collectionUUID":{"uuid":{"$uuid":"8e1e6c02-1f20-4645-a3b2-1e1fb32ea7f5"}},"namespace":"captainup.actions","numApplied":536,"totalInserted":536,"totalDeleted":0,"durationMillis":1}} {"t":\{"$date":"2022-12-29T16:17:18.145+00:00"},"s":"I", "c":"INDEX", "id":20689, "ctx":"IndexBuildsCoordinatorMongod-1","msg":"Index build: drained side writes","attr":{"index":"store_id_1_name_1_timestamp_1","collectionUUID":{"uuid":{"$uuid":"8e1e6c02-1f20-4645-a3b2-1e1fb32ea7f5"}},"namespace":"captainup.actions","numApplied":527,"totalInserted":527,"totalDeleted":0,"durationMillis":2}} {"t":\{"$date":"2022-12-29T16:17:18.722+00:00"},"s":"I", "c":"INDEX", "id":20689, "ctx":"IndexBuildsCoordinatorMongod-0","msg":"Index build: drained side writes","attr":{"index":"timestamp_1","collectionUUID":{"uuid":{"$uuid":"8e1e6c02-1f20-4645-a3b2-1e1fb32ea7f5"}},"namespace":"captainup.actions","numApplied":471,"totalInserted":471,"totalDeleted":0,"durationMillis":1}} {"t":\{"$date":"2022-12-29T16:17:19.148+00:00"},"s":"I", "c":"INDEX", "id":20689, "ctx":"IndexBuildsCoordinatorMongod-1","msg":"Index build: drained side writes","attr":{"index":"store_id_1_name_1_timestamp_1","collectionUUID":{"uuid":{"$uuid":"8e1e6c02-1f20-4645-a3b2-1e1fb32ea7f5"}},"namespace":"captainup.actions","numApplied":413,"totalInserted":413,"totalDeleted":0,"durationMillis":1}} {"t":\{"$date":"2022-12-29T16:17:19.725+00:00"},"s":"I", "c":"INDEX", "id":20689, "ctx":"IndexBuildsCoordinatorMongod-0","msg":"Index build: drained side writes","attr":{"index":"timestamp_1","collectionUUID":{"uuid":{"$uuid":"8e1e6c02-1f20-4645-a3b2-1e1fb32ea7f5"}},"namespace":"captainup.actions","numApplied":433,"totalInserted":433,"totalDeleted":0,"durationMillis":1}} {"t":\{"$date":"2022-12-29T16:17:20.152+00:00"},"s":"I", "c":"INDEX", "id":20689, "ctx":"IndexBuildsCoordinatorMongod-1","msg":"Index build: drained side writes","attr":{"index":"store_id_1_name_1_timestamp_1","collectionUUID":{"uuid":{"$uuid":"8e1e6c02-1f20-4645-a3b2-1e1fb32ea7f5"}},"namespace":"captainup.actions","numApplied":542,"totalInserted":542,"totalDeleted":0,"durationMillis":2}} {"t":\{"$date":"2022-12-29T16:17:20.727+00:00"},"s":"I", "c":"INDEX", "id":20689, "ctx":"IndexBuildsCoordinatorMongod-0","msg":"Index build: drained side writes","attr":{"index":"timestamp_1","collectionUUID":{"uuid":{"$uuid":"8e1e6c02-1f20-4645-a3b2-1e1fb32ea7f5"}},"namespace":"captainup.actions","numApplied":533,"totalInserted":533,"totalDeleted":0,"durationMillis":1}} {"t":\{"$date":"2022-12-29T16:17:21.155+00:00"},"s":"I", "c":"INDEX", "id":20689, "ctx":"IndexBuildsCoordinatorMongod-1","msg":"Index build: drained side writes","attr":{"index":"store_id_1_name_1_timestamp_1","collectionUUID":{"uuid":{"$uuid":"8e1e6c02-1f20-4645-a3b2-1e1fb32ea7f5"}},"namespace":"captainup.actions","numApplied":486,"totalInserted":486,"totalDeleted":0,"durationMillis":2}} {"t":\{"$date":"2022-12-29T16:17:21.729+00:00"},"s":"I", "c":"INDEX", "id":20689, "ctx":"IndexBuildsCoordinatorMongod-0","msg":"Index build: drained side writes","attr":{"index":"timestamp_1","collectionUUID":{"uuid":{"$uuid":"8e1e6c02-1f20-4645-a3b2-1e1fb32ea7f5"}},"namespace":"captainup.actions","numApplied":500,"totalInserted":500,"totalDeleted":0,"durationMillis":1}} {"t":\{"$date":"2022-12-29T16:17:22.158+00:00"},"s":"I", "c":"INDEX", "id":20689, "ctx":"IndexBuildsCoordinatorMongod-1","msg":"Index build: drained side writes","attr":{"index":"store_id_1_name_1_timestamp_1","collectionUUID":{"uuid":{"$uuid":"8e1e6c02-1f20-4645-a3b2-1e1fb32ea7f5"}},"namespace":"captainup.actions","numApplied":492,"totalInserted":492,"totalDeleted":0,"durationMillis":2}} |
| Comments |
| Comment by Chris Kelly [ 02/Jan/23 ] |
|
Thanks for dropping a comment to let us know it's resolved! I'll go ahead and close the ticket. |
| Comment by Snir David [ 29/Dec/22 ] |
|
Resolved. One node was at "RECOVERY" mode - a hard reset (by force deleting all the internal wt files) got it out of this recovery loop. |