Monday, October 25, 2021

[SOLVED] Cant initialise replica set on debian (open/create failed in createPrivateMap)

Issue

I try to setup MongoDB on my new virtual Server running with Debian 7.3. If a try to configurate the replica set with

hosts = {
   "_id" : "rs0",
   "version" : 1,
   "members" : [
      {
         "_id" : 0,
         "host" : "localhost:27017"
      }
   ]
}

rs.initiate(hosts);

MongoDB crashes with following exceptions:

Tue Jan 21 00:10:24.599 [initandlisten] MongoDB starting : pid=3616 port=27017 dbpath=/var/lib/mongodb 64-bit host=lvps176-28-17-95.dedicated.hosteurope.de
Tue Jan 21 00:10:24.599 [initandlisten]
Tue Jan 21 00:10:24.600 [initandlisten] ** WARNING: You are running in OpenVZ. This is known to be broken!!!
Tue Jan 21 00:10:24.600 [initandlisten]
Tue Jan 21 00:10:24.600 [initandlisten] db version v2.4.7
Tue Jan 21 00:10:24.600 [initandlisten] git version: 0161738abf06c1f067b56a465b706efd6f4bf2aa
Tue Jan 21 00:10:24.600 [initandlisten] build info: Linux ip-10-2-29-40 2.6.21.7-2.ec2.v1.2.fc8xen #1 SMP Fri Nov 20 17:48:28 EST 2009 x86_64 BOOST_LIB_VERSION=1_49
Tue Jan 21 00:10:24.600 [initandlisten] allocator: tcmalloc
Tue Jan 21 00:10:24.600 [initandlisten] options: { config: "/etc/mongodb.conf", dbpath: "/var/lib/mongodb", logappend: "true", logpath: "/var/log/mongodb/mongodb.log", replSet: "rs0" }
Tue Jan 21 00:10:24.609 [initandlisten] journal dir=/var/lib/mongodb/journal
Tue Jan 21 00:10:24.609 [initandlisten] recover : no journal files present, no recovery needed
Tue Jan 21 00:10:24.740 [initandlisten] preallocateIsFaster=true 2.38
Tue Jan 21 00:10:24.780 [initandlisten] waiting for connections on port 27017
Tue Jan 21 00:10:24.780 [websvr] admin web console waiting for connections on port 28017
Tue Jan 21 00:10:24.786 [rsStart] replSet can't get local.system.replset config from self or any seed (EMPTYCONFIG)
Tue Jan 21 00:10:24.786 [rsStart] replSet info you may need to run replSetInitiate -- rs.initiate() in the shell -- if that is not already done
Tue Jan 21 00:10:27.429 [initandlisten] connection accepted from 127.0.0.1:50602 #1 (1 connection now open)
Tue Jan 21 00:10:34.786 [rsStart] replSet can't get local.system.replset config from self or any seed (EMPTYCONFIG)
Tue Jan 21 00:10:40.160 [conn1] replSet replSetInitiate admin command received from client
Tue Jan 21 00:10:40.163 [conn1] replSet replSetInitiate config object parses ok, 1 members specified
Tue Jan 21 00:10:40.164 [conn1] replSet replSetInitiate all members seem up
Tue Jan 21 00:10:40.164 [conn1] ******
Tue Jan 21 00:10:40.164 [conn1] creating replication oplog of size: 24630MB...

Tue Jan 21 00:10:40.165 [FileAllocator] allocating new datafile /var/lib/mongodb/local.1, filling with zeroes...
Tue Jan 21 00:10:40.165 [FileAllocator] creating directory /var/lib/mongodb/_tmp
Tue Jan 21 00:10:40.205 [FileAllocator] done allocating datafile /var/lib/mongodb/local.1, size: 2047MB,  took 0.036 secs
Tue Jan 21 00:10:40.206 [FileAllocator] allocating new datafile /var/lib/mongodb/local.2, filling with zeroes...
Tue Jan 21 00:10:40.233 [FileAllocator] done allocating datafile /var/lib/mongodb/local.2, size: 2047MB,  took 0.027 secs
Tue Jan 21 00:10:40.234 [FileAllocator] allocating new datafile /var/lib/mongodb/local.3, filling with zeroes...
Tue Jan 21 00:10:40.255 [FileAllocator] done allocating datafile /var/lib/mongodb/local.3, size: 2047MB,  took 0.02 secs
Tue Jan 21 00:10:40.256 [FileAllocator] allocating new datafile /var/lib/mongodb/local.4, filling with zeroes...
Tue Jan 21 00:10:40.275 [FileAllocator] done allocating datafile /var/lib/mongodb/local.4, size: 2047MB,  took 0.019 secs
Tue Jan 21 00:10:40.276 [FileAllocator] allocating new datafile /var/lib/mongodb/local.5, filling with zeroes...
Tue Jan 21 00:10:40.355 [FileAllocator] done allocating datafile /var/lib/mongodb/local.5, size: 2047MB,  took 0.079 secs
Tue Jan 21 00:10:40.356 [FileAllocator] allocating new datafile /var/lib/mongodb/local.6, filling with zeroes...
Tue Jan 21 00:10:40.372 [FileAllocator] done allocating datafile /var/lib/mongodb/local.6, size: 2047MB,  took 0.014 secs
Tue Jan 21 00:10:40.372 [FileAllocator] allocating new datafile /var/lib/mongodb/local.7, filling with zeroes...
Tue Jan 21 00:10:40.498 [FileAllocator] done allocating datafile /var/lib/mongodb/local.7, size: 2047MB,  took 0.121 secs
Tue Jan 21 00:10:40.499 [FileAllocator] allocating new datafile /var/lib/mongodb/local.8, filling with zeroes...
Tue Jan 21 00:10:40.546 [FileAllocator] done allocating datafile /var/lib/mongodb/local.8, size: 2047MB,  took 0.046 secs
Tue Jan 21 00:10:40.546 [conn1] ERROR: mmap private failed with out of memory. (64 bit build)
Tue Jan 21 00:10:40.546 [conn1] Assertion: 13636:file /var/lib/mongodb/local.8 open/create failed in createPrivateMap (look in log for more information)
0xde0151 0xda188b 0xda1dcc 0xa5a63b 0xa5af9a 0xaba3b1 0x8d518d 0x8d5698 0x8d577f 0x8d5a1e 0xabbb00 0xac1429 0xa75908 0xc10af1 0x8dd4da 0x8de04d 0x8df582 0xa81f00 0xa867cc 0x9fa469
 /usr/bin/mongod(_ZN5mongo15printStackTraceERSo+0x21) [0xde0151]
 /usr/bin/mongod(_ZN5mongo11msgassertedEiPKc+0x9b) [0xda188b]
 /usr/bin/mongod() [0xda1dcc]
 /usr/bin/mongod(_ZN5mongo8MongoMMF13finishOpeningEv+0x1fb) [0xa5a63b]
 /usr/bin/mongod(_ZN5mongo8MongoMMF6createERKSsRyb+0x5a) [0xa5af9a]
 /usr/bin/mongod(_ZN5mongo13MongoDataFile4openEPKcib+0x141) [0xaba3b1]
 /usr/bin/mongod(_ZN5mongo8Database7getFileEiib+0xbd) [0x8d518d]
 /usr/bin/mongod(_ZN5mongo8Database8addAFileEib+0x38) [0x8d5698]
 /usr/bin/mongod(_ZN5mongo8Database12suitableFileEPKcibb+0xaf) [0x8d577f]
 /usr/bin/mongod(_ZN5mongo8Database11allocExtentEPKcibb+0x9e) [0x8d5a1e]
 /usr/bin/mongod(_ZN5mongo13_userCreateNSEPKcRKNS_7BSONObjERSsPb+0x7a0) [0xabbb00]
 /usr/bin/mongod(_ZN5mongo12userCreateNSEPKcNS_7BSONObjERSsbPb+0x2b9) [0xac1429]
 /usr/bin/mongod(_ZN5mongo11createOplogEv+0xa78) [0xa75908]
 /usr/bin/mongod(_ZN5mongo18CmdReplSetInitiate3runERKSsRNS_7BSONObjEiRSsRNS_14BSONObjBuilderEb+0x1da1) [0xc10af1]
 /usr/bin/mongod(_ZN5mongo12_execCommandEPNS_7CommandERKSsRNS_7BSONObjEiRSsRNS_14BSONObjBuilderEb+0x3a) [0x8dd4da]
 /usr/bin/mongod(_ZN5mongo7Command11execCommandEPS0_RNS_6ClientEiPKcRNS_7BSONObjERNS_14BSONObjBuilderEb+0x71d) [0x8de04d]
 /usr/bin/mongod(_ZN5mongo12_runCommandsEPKcRNS_7BSONObjERNS_11_BufBuilderINS_16TrivialAllocatorEEERNS_14BSONObjBuilderEbi+0x5f2) [0x8df582]
 /usr/bin/mongod(_ZN5mongo11runCommandsEPKcRNS_7BSONObjERNS_5CurOpERNS_11_BufBuilderINS_16TrivialAllocatorEEERNS_14BSONObjBuilderEbi+0x40) [0xa81f00]
 /usr/bin/mongod(_ZN5mongo8runQueryERNS_7MessageERNS_12QueryMessageERNS_5CurOpES1_+0xd7c) [0xa867cc]
 /usr/bin/mongod() [0x9fa469]
Tue Jan 21 00:10:40.563 [conn1] replSet replSetInitiate exception: file /var/lib/mongodb/local.8 open/create failed in createPrivateMap (look in log for more information)
Tue Jan 21 00:10:40.563 [conn1] command admin.$cmd command: { replSetInitiate: { _id: "rs0", version: 1.0, members: [ { _id: 0.0, host: "localhost:27017" } ] } } ntoreturn:1 keyUpdates:0 locks(micros) W:401$
Tue Jan 21 00:10:44.787 [rsStart] replSet can't get local.system.replset config from self or any seed (EMPTYCONFIG)
Tue Jan 21 00:10:53.835 [conn1] replSet replSetInitiate admin command received from client
Tue Jan 21 00:10:53.835 [conn1] replSet replSetInitiate config object parses ok, 1 members specified
Tue Jan 21 00:10:53.835 [conn1] replSet replSetInitiate all members seem up
Tue Jan 21 00:10:53.835 [conn1] replSet info saving a newer config version to local.system.replset
Tue Jan 21 00:10:54.564 Invalid access at address: 0x18 from thread: conn1

Tue Jan 21 00:10:54.564 Got signal: 11 (Segmentation fault).

Why MongoDB tries to create 8 files a 2GB? My machine run with 16GB ram, may that is the problem? Because in one line the error "[conn1] ERROR: mmap private failed with out of memory. (64 bit build)" looks like my machine run out of memory. But i only create a replica set with one member and an empty database. Sombody know that bug?


Solution

It's not RAM but disk space that is the problem, it's not a bug either.

Tue Jan 21 00:10:40.164 [conn1] creating replication oplog of size: 24630MB...

From MongoDB docs:

The oplog (operations log) is a special capped collection that keeps a rolling record of all operations that modify the data stored in your databases. MongoDB applies database operations on the primary and then records the operations on the primary’s oplog. The secondary members then copy and apply these operations in an asynchronous process. All replica set members contain a copy of the oplog, allowing them to maintain the current state of the database.

For 64-bit Linux, Solaris, FreeBSD, and Windows systems, MongoDB allocates 5% of the available free disk space to the oplog. If this amount is smaller than a gigabyte, then MongoDB allocates 1 gigabyte of space.

Above via http://docs.mongodb.org/manual/core/replica-set-oplog/

Oplog is needed for replication (It's a capped collection of a fixed size) and this is created automatically when you create replica set. oplogSize can be set via configuration options (if you would like to just experiment with the setup and can't free up some more disk space). Here's a doc on it: http://docs.mongodb.org/manual/reference/configuration-options/#oplogSize

However:

Once the mongod has created the oplog for the first time, changing oplogSize will not affect the size of the oplog.

via http://docs.mongodb.org/manual/reference/configuration-options/#oplogSize

If you would like to change oplogSize after it has been already created you could use this tutorial: http://docs.mongodb.org/manual/tutorial/change-oplog-size/

However if this is your "playground" installation, it better to delete content of your old MongoDB data directory (/var/lib/mongodb), change config file /etc/mongodb.conf (or pass --oplogSize param to mongo when it starts) and just have a "fresh start" with smaller oplog or point your MongoDB dbpath directory to a place where it has more disk space.



Answered By - Michal Gasek