Mongodb restore stuck

mongo --version
MongoDB shell version v5.0.11
Build Info: {
“version”: “5.0.11”,
“gitVersion”: “d08c3c41c105cde798ca934e3ac3426ac11b57c3”,
“openSSLVersion”: “OpenSSL 1.1.1f 31 Mar 2020”,
“modules”: ,
“allocator”: “tcmalloc”,
“environment”: {
“distmod”: “ubuntu2004”,
“distarch”: “x86_64”,
“target_arch”: “x86_64”
}
}

We have taken backup using mongodump
mongodump --host=myhost.com --port=1801 --out=/data/backup

Backup was done successfully.

Restore started more than 6 hrs ago and it looks like it restored all databases but mongorestore process still not finish. Process is running using nohup
mongorestore --authenticationDatabase=“admin” --username=“myuser” --password=“mypassword” – /data/backup &

nohup log has not been updated since last 5 hrs or so

last few lines

|2023-02-27T20:51:14.562+0000|index: &idx.IndexDocument{Options:primitive.M{name:rs_id_1, ns:rsid.rsid_metadata, v:1}, Key:primitive.D{primitive.E{Key:rs_id, Value:1}}, PartialFilterExpression:primitive.D(nil)}|
|---|---|
|2023-02-27T20:51:14.562+0000|no indexes to restore for collection rsid.rsid_metadata_bkp_1116|
|2023-02-27T20:51:14.562+0000|no indexes to restore for collection rsid.samplestations|
|2023-02-27T20:51:14.562+0000|no indexes to restore for collection rsid.bkp_sample_0807|
|2023-02-27T20:51:14.562+0000|no indexes to restore for collection rsid.bkp_sample_1106|
|2023-02-27T20:51:14.562+0000|restoring indexes for collection image.image from metadata|
|2023-02-27T20:51:14.562+0000|index: &idx.IndexDocument{Options:primitive.M{name:image_id_1_resolution_1, ns:image.image, v:1}, Key:primitive.D{primitive.E{Key:image_id, Value:1}, primitive.E{Key:resolution, Value:1}}, PartialFilterExpression:primitive.D(nil)}|
|2023-02-27T20:51:14.562+0000|no indexes to restore for collection rsid.samplestations_auto|
|2023-02-27T20:51:14.562+0000|restoring indexes for collection image.cds_image from metadata|
|2023-02-27T20:51:14.562+0000|index: &idx.IndexDocument{Options:primitive.M{name:cds_id_1, ns:image.cds_image, v:1}, Key:primitive.D{primitive.E{Key:cds_id, Value:1}}, PartialFilterExpression:primitive.D(nil)}|
|2023-02-27T20:51:14.562+0000|index: &idx.IndexDocument{Options:primitive.M{expireAfterSeconds:3.1536e+07, name:createdAt_1, ns:image.cds_image, v:1}, Key:primitive.D{primitive.E{Key:createdAt, Value:1}}, PartialFilterExpression:primitive.D(nil)}|
|2023-02-27T20:51:14.562+0000|no indexes to restore for collection rsid.rsid_metadata_sbt_model|
|2023-02-27T20:51:14.562+0000|no indexes to restore for collection cayenne.tvstation|
|2023-02-27T20:51:14.562+0000|restoring indexes for collection fingerprint.fingerprint from metadata|
|2023-02-27T20:51:14.562+0000|index: &idx.IndexDocument{Options:primitive.M{name:fp_id_1, ns:fingerprint.fingerprint, v:1}, Key:primitive.D{primitive.E{Key:fp_id, Value:1}}, PartialFilterExpression:primitive.D(nil)}|

date
Tue 28 Feb 2023 02:05:30 AM GMT

mongodb log files does not show any progress about mongorestore, I see some checkpoint info

{"t":{"$date":"2023-02-28T02:05:36.204+00:00"},"s":"W",  "c":"ACCESS",   "id":5626700, "ctx":"conn41","msg":"Client has attempted to reauthenticate as a single user","attr":{"user":{"user":"__system","db":"local"}}}
{"t":{"$date":"2023-02-28T02:05:36.204+00:00"},"s":"I",  "c":"ACCESS",   "id":20250,   "ctx":"conn41","msg":"Authentication succeeded","attr":{"mechanism":"SCRAM-SHA-256","speculative":false,"principalName":"__system","authenticationDatabase":"local","remote":"10.61.128.37:57644","extraInfo":{}}}
{"t":{"$date":"2023-02-28T02:05:44.078+00:00"},"s":"I",  "c":"STORAGE",  "id":22430,   "ctx":"Checkpointer","msg":"WiredTiger message","attr":{"message":"[1677549944:78358][1524094:0x7f650f7dd700], WT_SESSION.checkpoint: [WT_VERB_CHECKPOINT_PROGRESS] saving checkpoint snapshot min: 560123, snapshot max: 560123 snapshot count: 0, oldest timestamp: (1677549641, 1) , meta checkpoint timestamp: (1677549941, 1) base write gen: 10399739"}}

I do see
db.currentOp(), there is process name mongorestore and command is createindex but if index is getting created , isn’t mongo log file should have some progress info as well.

Any idea how to check what is going on with mongorestore and how to check status of index getting created.

db.currentOp(true).inprog.forEach(function(op){ if(op.msg!==undefined) print(op.msg) })
Index Build: draining writes received during build
Index Build: draining writes received during build
Index Build: draining writes received during build

Looks like one replica node was in recovering mode so I have dropped and recreating it. Will update about progress.

That was my issue. One of my replica set went into recovering state and that’s what causing issues with mongo restore. After I removed replica set and added back again. It synced up in couple hrs and mongorestore also finished.

I don’t get your solution. Can you elaborate more? why a recovering node will make the restore hang forever?

It did cause issue.
Look this issue. I got resolution and direction from here.
https://jira.mongodb.org/browse/SERVER-72427?jql=labels%20%3D%20indexes

This topic was automatically closed 5 days after the last reply. New replies are no longer allowed.