[SERVER-23021] Mongorestore hans? Created: 09/Mar/16  Updated: 11/Mar/16  Resolved: 11/Mar/16

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

Type: Bug Priority: Major - P3
Reporter: Feng Yu Assignee: Unassigned
Resolution: Done Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Operating System: ALL
Participants:

 Description   

I want to restore a 10GB collection to a db. So I use mongorestore to do this.

mongorestore -d aricareRealtimeDB aircareRealtimeDB/

After a long time:

2016-03-08T15:36:51.888+0800    [........................]  arcareRealtimeDB.equipment.rtdata  6.8 MB/10.8 GB  (0.1%)
2016-03-08T15:36:54.888+0800    [........................]  arcareRealtimeDB.equipment.rtdata  6.8 MB/10.8 GB  (0.1%)
2016-03-08T15:36:57.888+0800    [........................]  arcareRealtimeDB.equipment.rtdata  6.8 MB/10.8 GB  (0.1%)
2016-03-08T15:37:00.888+0800    [........................]  arcareRealtimeDB.equipment.rtdata  6.8 MB/10.8 GB  (0.1%)
2016-03-08T15:37:03.888+0800    [........................]  arcareRealtimeDB.equipment.rtdata  6.8 MB/10.8 GB  (0.1%)
2016-03-08T15:37:06.888+0800    [........................]  arcareRealtimeDB.equipment.rtdata  6.8 MB/10.8 GB  (0.1%)
2016-03-08T15:37:09.888+0800    [........................]  arcareRealtimeDB.equipment.rtdata  6.8 MB/10.8 GB  (0.1%)
2016-03-08T15:37:12.888+0800    [........................]  arcareRealtimeDB.equipment.rtdata  6.8 MB/10.8 GB  (0.1%)
2016-03-08T15:37:15.888+0800    [........................]  arcareRealtimeDB.equipment.rtdata  6.8 MB/10.8 GB  (0.1%)
2016-03-08T15:37:18.888+0800    [........................]  arcareRealtimeDB.equipment.rtdata  6.8 MB/10.8 GB  (0.1%)
2016-03-08T15:37:21.888+0800    [........................]  arcareRealtimeDB.equipment.rtdata  6.8 MB/10.8 GB  (0.1%)
2016-03-08T15:37:24.888+0800    [........................]  arcareRealtimeDB.equipment.rtdata  6.8 MB/10.8 GB  (0.1%)
2016-03-08T15:37:27.888+0800    [........................]  arcareRealtimeDB.equipment.rtdata  6.8 MB/10.8 GB  (0.1%)
2016-03-08T15:37:30.888+0800    [........................]  arcareRealtimeDB.equipment.rtdata  6.8 MB/10.8 GB  (0.1%)
2016-03-08T15:37:33.888+0800    [........................]  arcareRealtimeDB.equipment.rtdata  6.8 MB/10.8 GB  (0.1%)
2016-03-08T15:37:36.888+0800    [........................]  arcareRealtimeDB.equipment.rtdata  6.8 MB/10.8 GB  (0.1%)
2016-03-08T15:37:39.888+0800    [........................]  arcareRealtimeDB.equipment.rtdata  6.8 MB/10.8 GB  (0.1%)
2016-03-08T15:37:42.888+0800    [........................]  arcareRealtimeDB.equipment.rtdata  6.8 MB/10.8 GB  (0.1%)
2016-03-08T15:37:45.888+0800    [........................]  arcareRealtimeDB.equipment.rtdata  6.8 MB/10.8 GB  (0.1%)
2016-03-08T15:37:48.888+0800    [........................]  arcareRealtimeDB.equipment.rtdata  6.8 MB/10.8 GB  (0.1%)
2016-03-08T15:37:51.888+0800    [........................]  arcareRealtimeDB.equipment.rtdata  6.8 MB/10.8 GB  (0.1%)
2016-03-08T15:37:54.888+0800    [........................]  arcareRealtimeDB.equipment.rtdata  6.8 MB/10.8 GB  (0.1%)
2016-03-08T15:37:57.888+0800    [........................]  arcareRealtimeDB.equipment.rtdata  6.8 MB/10.8 GB  (0.1%)
2016-03-08T15:38:00.888+0800    [........................]  arcareRealtimeDB.equipment.rtdata  6.8 MB/10.8 GB  (0.1%)
2016-03-08T15:38:03.888+0800    [........................]  arcareRealtimeDB.equipment.rtdata  6.8 MB/10.8 GB  (0.1%)
2016-03-08T15:38:06.888+0800    [........................]  arcareRealtimeDB.equipment.rtdata  6.8 MB/10.8 GB  (0.1%)
2016-03-08T15:38:09.888+0800    [........................]  arcareRealtimeDB.equipment.rtdata  6.8 MB/10.8 GB  (0.1%)
2016-03-08T15:38:12.888+0800    [........................]  arcareRealtimeDB.equipment.rtdata  6.8 MB/10.8 GB  (0.1%)
2016-03-08T15:38:15.888+0800    [........................]  arcareRealtimeDB.equipment.rtdata  6.8 MB/10.8 GB  (0.1%)
2016-03-08T15:38:18.888+0800    [........................]  arcareRealtimeDB.equipment.rtdata  6.8 MB/10.8 GB  (0.1%)
2016-03-08T15:38:21.888+0800    [........................]  arcareRealtimeDB.equipment.rtdata  6.8 MB/10.8 GB  (0.1%)
2016-03-08T15:38:24.888+0800    [........................]  arcareRealtimeDB.equipment.rtdata  6.8 MB/10.8 GB  (0.1%)
2016-03-08T15:38:27.888+0800    [........................]  arcareRealtimeDB.equipment.rtdata  6.8 MB/10.8 GB  (0.1%)
2016-03-08T15:38:30.888+0800    [........................]  arcareRealtimeDB.equipment.rtdata  6.8 MB/10.8 GB  (0.1%)
2016-03-08T15:38:33.888+0800    [........................]  arcareRealtimeDB.equipment.rtdata  6.8 MB/10.8 GB  (0.1%)
2016-03-08T15:38:36.888+0800    [........................]  arcareRealtimeDB.equipment.rtdata  6.8 MB/10.8 GB  (0.1%)
2016-03-08T15:38:39.888+0800    [........................]  arcareRealtimeDB.equipment.rtdata  6.8 MB/10.8 GB  (0.1%)
2016-03-08T15:38:42.888+0800    [........................]  arcareRealtimeDB.equipment.rtdata  6.8 MB/10.8 GB  (0.1%)
2016-03-08T15:38:45.888+0800    [........................]  arcareRealtimeDB.equipment.rtdata  6.8 MB/10.8 GB  (0.1%)
2016-03-08T15:38:48.888+0800    [........................]  arcareRealtimeDB.equipment.rtdata  6.8 MB/10.8 GB  (0.1%)
2016-03-08T15:38:51.888+0800    [........................]  arcareRealtimeDB.equipment.rtdata  6.8 MB/10.8 GB  (0.1%)
2016-03-08T15:38:54.888+0800    [........................]  arcareRealtimeDB.equipment.rtdata  6.8 MB/10.8 GB  (0.1%)
2016-03-08T15:38:57.888+0800    [........................]  arcareRealtimeDB.equipment.rtdata  6.8 MB/10.8 GB  (0.1%)
2016-03-08T15:39:00.888+0800    [........................]  arcareRealtimeDB.equipment.rtdata  6.8 MB/10.8 GB  (0.1%)
2016-03-08T15:39:03.888+0800    [........................]  arcareRealtimeDB.equipment.rtdata  6.8 MB/10.8 GB  (0.1%)
2016-03-08T15:39:06.888+0800    [........................]  arcareRealtimeDB.equipment.rtdata  6.8 MB/10.8 GB  (0.1%)
2016-03-08T15:39:09.888+0800    [........................]  arcareRealtimeDB.equipment.rtdata  6.8 MB/10.8 GB  (0.1%)
2016-03-08T15:39:12.888+0800    [........................]  arcareRealtimeDB.equipment.rtdata  6.8 MB/10.8 GB  (0.1%)
2016-03-08T15:39:15.888+0800    [........................]  arcareRealtimeDB.equipment.rtdata  6.8 MB/10.8 GB  (0.1%)

Not restoring at all. I don't know what happened.

Here is my config:

# cat /etc/mongod.conf
systemLog:
   destination: file
   path: "/var/log/mongodb/mongod.log"
   logAppend: true
   logRotate: reopen
storage:
   journal:
      enabled: true
   dbPath: "/mnt/mongodb_wt"
   engine: wiredTiger
   wiredTiger.engineConfig.cacheSizeGB: 1
operationProfiling:
   slowOpThresholdMs: 500
   mode: off
replication.replSetName: shifudaoRs

And here is the db.currentOP() output:

shifudaoRs:PRIMARY> db.currentOp()
{
	"inprog" : [
		{
			"desc" : "conn236063",
			"threadId" : "0x2ee55ba0",
			"connectionId" : 236063,
			"opid" : 85475446,
			"active" : true,
			"secs_running" : 1324,
			"microsecs_running" : NumberLong(1324206791),
			"op" : "query",
			"ns" : "arcareRealtimeDB.$cmd",
			"query" : {
				"$msg" : "query not recording (too large)"
			},
			"client" : "127.0.0.1:56287",
			"msg" : "waiting for write concern",
			"numYields" : 0,
			"locks" : {
				
			},
			"waitingForLock" : false,
			"lockStats" : {
				"Global" : {
					"acquireCount" : {
						"r" : NumberLong(1011),
						"w" : NumberLong(1011)
					}
				},
				"Database" : {
					"acquireCount" : {
						"w" : NumberLong(1010),
						"W" : NumberLong(1)
					}
				},
				"Collection" : {
					"acquireCount" : {
						"w" : NumberLong(8),
						"W" : NumberLong(1)
					}
				},
				"oplog" : {
					"acquireCount" : {
						"w" : NumberLong(1001)
					}
				}
			}
		},
		{
			"desc" : "conn236039",
			"threadId" : "0x321941a0",
			"connectionId" : 236039,
			"opid" : 85463785,
			"active" : true,
			"secs_running" : 1644,
			"microsecs_running" : NumberLong(1644883225),
			"op" : "query",
			"ns" : "rcareRealtimeDB.$cmd",
			"query" : {
				"$msg" : "query not recording (too large)"
			},
			"client" : "127.0.0.1:56000",
			"msg" : "waiting for write concern",
			"numYields" : 0,
			"locks" : {
				
			},
			"waitingForLock" : false,
			"lockStats" : {
				"Global" : {
					"acquireCount" : {
						"r" : NumberLong(1011),
						"w" : NumberLong(1011)
					}
				},
				"Database" : {
					"acquireCount" : {
						"w" : NumberLong(1010),
						"W" : NumberLong(1)
					}
				},
				"Collection" : {
					"acquireCount" : {
						"w" : NumberLong(8),
						"W" : NumberLong(1)
					}
				},
				"oplog" : {
					"acquireCount" : {
						"w" : NumberLong(1001)
					}
				}
			}
		},
		{
			"desc" : "conn235999",
			"threadId" : "0x215f3a80",
			"connectionId" : 235999,
			"opid" : 85443542,
			"active" : true,
			"secs_running" : 2241,
			"microsecs_running" : NumberLong("2241782158"),
			"op" : "query",
			"ns" : "aircareRealtimeDB.$cmd",
			"query" : {
				"$msg" : "query not recording (too large)"
			},
			"client" : "127.0.0.1:53000",
			"msg" : "waiting for write concern",
			"numYields" : 0,
			"locks" : {
				
			},
			"waitingForLock" : false,
			"lockStats" : {
				"Global" : {
					"acquireCount" : {
						"r" : NumberLong(1010),
						"w" : NumberLong(1010)
					}
				},
				"Database" : {
					"acquireCount" : {
						"w" : NumberLong(1010)
					},
					"acquireWaitCount" : {
						"w" : NumberLong(3)
					},
					"timeAcquiringMicros" : {
						"w" : NumberLong(236)
					}
				},
				"Collection" : {
					"acquireCount" : {
						"w" : NumberLong(10)
					}
				},
				"oplog" : {
					"acquireCount" : {
						"w" : NumberLong(1000)
					}
				}
			}
		},
		{
			"desc" : "conn235808",
			"threadId" : "0x3069d6c0",
			"connectionId" : 235808,
			"opid" : 85358646,
			"active" : true,
			"secs_running" : 4935,
			"microsecs_running" : NumberLong("4935759787"),
			"op" : "query",
			"ns" : "aircareRealtimeDB.$cmd",
			"query" : {
				"$msg" : "query not recording (too large)"
			},
			"client" : "127.0.0.1:53013",
			"msg" : "waiting for write concern",
			"numYields" : 0,
			"locks" : {
				
			},
			"waitingForLock" : false,
			"lockStats" : {
				"Global" : {
					"acquireCount" : {
						"r" : NumberLong(1010),
						"w" : NumberLong(1010)
					}
				},
				"Database" : {
					"acquireCount" : {
						"w" : NumberLong(1010)
					},
					"acquireWaitCount" : {
						"w" : NumberLong(3)
					},
					"timeAcquiringMicros" : {
						"w" : NumberLong(236)
					}
				},
				"Collection" : {
					"acquireCount" : {
						"w" : NumberLong(10)
					}
				},
				"oplog" : {
					"acquireCount" : {
						"w" : NumberLong(1000)
					}
				}
			}
		}
	]
}



 Comments   
Comment by Ramon Fernandez Marina [ 11/Mar/16 ]

Thanks for the update abcfy2, glad to hear you can use mongorestore successfully.

Please note that the SERVER project is for reporting bugs or feature suggestions for the MongoDB server. For MongoDB-related support discussion please post on the mongodb-user group or Stack Overflow with the mongodb tag, where your question will reach a larger audience. In the future, a question like this would be best posted on the mongodb-user group. See also our Technical Support page for additional support resources.

Regards,
Ramón.

Comment by Feng Yu [ 09/Mar/16 ]

I've been solved by myself. Because my secondary set "delay", so restore could not receive from secondary right now, but delay a very long time.

And I see the "write concern" in currentop(), so I read about the docs. Now I know that mongorestore write concern default is "majority", so I change to disable write concern, and it works.

mongorestore --writeConcern '{w:0}' -d aircareRealtimeDB aircareRealtimeDB

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