-
Type:
Bug
-
Resolution: Incomplete
-
Priority:
Minor - P4
-
None
-
Affects Version/s: 3.2.9
-
Component/s: mongorestore
-
Labels:None
Mongo Ver: 3.2.9 w/ WiredTiger
We are trying to restore a relatively small database, but the mongorestore process keeps eating up all the system RAM and getting itself (or the mongod process) killed by the system OOM kiiler. There are no errors, the process just gets killed and then mongod restarts and shows the results of an unclean shutdown (see log below)
We tried with the options "--noIndexRestore --numParallelCollections=1" but got the same behavior.
This machine has ~30gig of free memory and almost 7gig of swap. Here you can see the RAM being used by mongorestore:
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
8177 root 20 0 25.817g 0.023t 0.009g S 6.3 73.6 0:54.79 mongorestore
13804 mongo 20 0 1.897g 1.172g 0.000g S 47.6 3.7 7:31.92 mongod
We also tried increasing the TigerCache to 10gig, but the restore behaved exactly the same...just a little faster.
Looks like it is typically the mongorestore that gets killed, but mongod a few times...
kern :err : [Mon Dec 11 10:53:41 2017] Out of memory: Kill process 1554 (mongorestore) score 524 or sacrifice child kern :err : [Mon Dec 11 10:53:41 2017] Out of memory: Kill process 12481 (mongod) score 30 or sacrifice child kern :err : [Mon Dec 11 14:09:10 2017] Out of memory: Kill process 9444 (mongorestore) score 503 or sacrifice child kern :err : [Mon Dec 11 14:09:10 2017] Out of memory: Kill process 7571 (mongod) score 33 or sacrifice child kern :err : [Mon Dec 11 15:04:31 2017] Out of memory: Kill process 7667 (mongorestore) score 499 or sacrifice child kern :err : [Mon Dec 11 15:04:32 2017] Out of memory: Kill process 7676 (mongorestore) score 499 or sacrifice child kern :err : [Mon Dec 11 15:17:28 2017] Out of memory: Kill process 14470 (mongorestore) score 508 or sacrifice child kern :err : [Mon Dec 11 16:15:30 2017] Out of memory: Kill process 8177 (mongorestore) score 913 or sacrifice child kern :err : [Mon Dec 11 16:58:53 2017] Out of memory: Kill process 15930 (mongorestore) score 807 or sacrifice child kern :err : [Mon Dec 11 16:58:53 2017] Out of memory: Kill process 15689 (mongod) score 135 or sacrifice child
This is the size of the DB that we are trying to restore:
mongodb_sigmadraconis:PRIMARY> db.stats(1048576)
{
"db" : "SigmaDraconis",
"collections" : 14,
"objects" : 528,105,
"avgObjSize" : 140,983.90503024968,
"dataSize" : 71,005.15858268738, meg
"storageSize" : 24,746.1640625, meg
"numExtents" : 0,
"indexes" : 30,
"indexSize" : 11.69921875, meg
"ok" : 1
}
So... it's not huge... Ideas?
----- mongod logfile
2017-12-11T14:09:08.347-0500 I COMMAND [conn194] command SigmaDraconis.medusa_private.chunks command: insert { insert: "medusa_private.chunks", documents: 1000, writeConcern: { getLastError: 1, w: "majority" }, ordered: false } ninserted:1000 keyUpdates:0 writeConflicts:0 numYields:0 reslen:100 locks:{ Global: { acquireCount: { r: 1022, w: 1022 } }, Database: { acquireCount: { w: 1022 } }, Collection: { acquireCount: { w: 22 } }, Metadata: { acquireCount: { w: 1000 } }, oplog: { acquireCount: { w: 1000 } } } protocol:op_query 1964ms
2017-12-11T14:10:09.094-0500 I CONTROL [main] ***** SERVER RESTARTED *****
2017-12-11T14:10:09.110-0500 I CONTROL [initandlisten] MongoDB starting : pid=13804 port=27020 dbpath=/data/mongodb_sigmadraconis 64-bit host=vc2crtp1295588n
2017-12-11T14:10:09.110-0500 I CONTROL [initandlisten] db version v3.2.9
2017-12-11T14:10:09.110-0500 I CONTROL [initandlisten] git version: 22ec9e93b40c85fc7cae7d56e7d6a02fd811088c
2017-12-11T14:10:09.110-0500 I CONTROL [initandlisten] allocator: tcmalloc
2017-12-11T14:10:09.110-0500 I CONTROL [initandlisten] modules: none
2017-12-11T14:10:09.110-0500 I CONTROL [initandlisten] build environment:
2017-12-11T14:10:09.110-0500 I CONTROL [initandlisten] distarch: x86_64
2017-12-11T14:10:09.110-0500 I CONTROL [initandlisten] target_arch: x86_64
2017-12-11T14:10:09.110-0500 I CONTROL [initandlisten] options: { config: "/usr/local/mongodb_sigmadraconis/mongodb-linux-x86_64-3.2.9/conf/mongodb_sigmadraconis.conf", cpu: true, net: { http: { RESTInterfaceEnabled: true, enabled: true }, port: 27020 }, processManagement: { fork: true, pidFilePath: "/var/run/mongodb_sigmadraconis.pid" }, replication: { oplogSizeMB: 10240, replSet: "mongodb_sigmadraconis" }, storage: { dbPath: "/data/mongodb_sigmadraconis", mmapv1: { nsSize: 1024 }, wiredTiger: { engineConfig: { cacheSizeGB: 1 } } }, systemLog: { destination: "file", logAppend: true, path: "/var/log/mongodb_sigmadraconis/mongodb_sigmadraconis.log" } }
2017-12-11T14:10:09.137-0500 I - [initandlisten] Detected data files in /data/mongodb_sigmadraconis created by the 'wiredTiger' storage engine, so setting the active storage engine to 'wiredTiger'.
2017-12-11T14:10:09.138-0500 W - [initandlisten] Detected unclean shutdown - /data/mongodb_sigmadraconis/mongod.lock is not empty.
2017-12-11T14:10:09.138-0500 W STORAGE [initandlisten] Recovering data from the last clean checkpoint.
----- mongorestore stdout
2017-12-11T14:09:07.310-0500 [#.......................] SigmaDraconis.download_store.chunks 1.62GB/37.6GB (4.3%) 2017-12-11T14:09:07.310-0500 [##......................] SigmaDraconis.model_store.chunks 1.66GB/14.4GB (11.6%) 2017-12-11T14:09:07.310-0500 [##......................] SigmaDraconis.datasink.chunks 1.43GB/16.3GB (8.8%) 2017-12-11T14:09:07.310-0500 [#######################.] SigmaDraconis.medusa_private.chunks 336MB/348MB (96.6%) 2017-12-11T14:09:07.310-0500 2017-12-11T14:09:10.261-0500 [#.......................] SigmaDraconis.download_store.chunks 1.62GB/37.6GB (4.3%) 2017-12-11T14:09:10.261-0500 [##......................] SigmaDraconis.model_store.chunks 1.66GB/14.4GB (11.6%) 2017-12-11T14:09:10.261-0500 [##......................] SigmaDraconis.datasink.chunks 1.43GB/16.3GB (8.8%) 2017-12-11T14:09:10.261-0500 [#######################.] SigmaDraconis.medusa_private.chunks 338MB/348MB (97.0%) 2017-12-11T14:09:10.261-0500 Killed