Description
I try to update my Rocket Chat from version 1.0.3 to version 2.2.1. For this I have to update the mongo DB Sever also. I do this with
use admin
db.shutdownServer({force: true}
Now I try to start the new version of Rocket.Chat and it looks like that there is no data anymore, what I don’t understand. How can I get the data back?
LocalStore: store created at
LocalStore: store created at
LocalStore: store created at
Setting default file store to GridFS
{"line":"120","file":"migrations.js","message":"Migrations: Not migrating, already at version 166","time":{"$date":1574428874831},"level":"info"}
Loaded the Apps Framework and loaded a total of 0 Apps!
Using GridFS for custom sounds storage
Using GridFS for custom emoji storage
Updating process.env.MAIL_URL
➔ System ➔ startup
➔ +-----------------------------------------------+
➔ | SERVER RUNNING |
➔ +-----------------------------------------------+
➔ | |
➔ | Rocket.Chat Version: 2.2.1 |
➔ | NodeJS Version: 8.11.3 - x64 |
➔ | MongoDB Version: 3.6.15 |
➔ | MongoDB Engine: mmapv1 |
➔ | Platform: linux |
➔ | Process Port: 3002 |
➔ | Site URL: http://ultraschall.io/ |
➔ | ReplicaSet OpLog: Enabled |
➔ | Commit Hash: e7334ab4da |
➔ | Commit Branch: HEAD |
➔ | |
➔ +-----------------------------------------------+
Server Setup Information
- Version of Rocket.Chat Server:
- Operating System: ubuntu
- Deployment Method: tar
- Number of Running Instances: 1
- DB Replicaset Oplog: MONGO_OPLOG_URL=mongodb://localhost:27017/local?replSet=001-rs
- NodeJS Version: 8.11.3
- MongoDB Version: 3.6.15
- Proxy: nginx
- Firewalls involved: -
Any additional Information
This is the log form mongo DB after the update.
***aborting after invariant() failure
2019-11-21T21:15:09.972+0100 F - [initandlisten] Got signal: 6 (Aborted).
0x55ee52a23531 0x55ee52a22749 0x55ee52a22c2d 0x7f92f213d390 0x7f92f1d97428 0x7f92f1d9902a 0x55ee51136c1e 0x55ee528d8db0 0x55ee513dabb0 0x55ee528d9281 0x55ee528d5427 0x55ee511aced3 0x55ee52a1e975 0x55ee51137df7 0x55ee510d0c6c 0x55ee511b4709 0x55ee51138d49 0x7f92f1d82830 0x55ee5119cc39
----- BEGIN BACKTRACE -----
{"backtrace":[{"b":"55EE5079D000","o":"2286531","s":"_ZN5mongo15printStackTraceERSo"},{"b":"55EE5079D000","o":"2285749"},{"b":"55EE5079D000","o":"2285C2D"},{"b":"7F92F212C000","o":"11390"},{"b":"7F92F1D62000","o":"35428","s":"gsignal"},{"b":"7F92F1D62000","o":"3702A","s":"abort"},{"b":"55EE5079D000","o":"999C1E","s":"_ZN5mongo22invariantFailedWithMsgEPKcS1_S1_j"},{"b":"55EE5079D000","o":"213BDB0","s":"_ZN5mongo14ServiceContext17setPeriodicRunnerESt10unique_ptrINS_14PeriodicRunnerESt14default_deleteIS2_EE"},{"b":"55EE5079D000","o":"C3DBB0","s":"_ZN5mongo20ServiceContextMongoD9_newOpCtxEPNS_6ClientEj"},{"b":"55EE5079D000","o":"213C281","s":"_ZN5mongo14ServiceContext20makeOperationContextEPNS_6ClientE"},{"b":"55EE5079D000","o":"2138427","s":"_ZN5mongo6Client20makeOperationContextEv"},{"b":"55EE5079D000","o":"A0FED3"},{"b":"55EE5079D000","o":"2281975"},{"b":"55EE5079D000","o":"99ADF7","s":"_ZN5mongo8shutdownENS_8ExitCodeERKNS_16ShutdownTaskArgsE"},{"b":"55EE5079D000","o":"933C6C","s":"_ZZN5mongo13duration_castINS_8DurationISt5ratioILl1ELl1000EEEES2_ILl1ELl1EEEET_RKNS1_IT0_EEENKUlvE_clEv"},{"b":"55EE5079D000","o":"A17709","s":"_ZN5mongo11mongoDbMainEiPPcS1_"},{"b":"55EE5079D000","o":"99BD49","s":"main"},{"b":"7F92F1D62000","o":"20830","s":"__libc_start_main"},{"b":"55EE5079D000","o":"9FFC39","s":"_start"}],"processInfo":{ "mongodbVersion" : "3.6.15", "gitVersion" : "18934fb5c814e87895c5e38ae1515dd6cb4c00f7", "compiledModules" : [], "uname" : { "sysname" : "Linux", "release" : "4.4.0-108-generic", "version" : "#131-Ubuntu SMP Sun Jan 7 14:34:49 UTC 2018", "machine" : "x86_64" }, "somap" : [ { "b" : "55EE5079D000", "elfType" : 3, "buildId" : "9391253BC68BE750C738512655D66E98989E795E" }, { "b" : "7FFDB1FCD000", "elfType" : 3, "buildId" : "A5676B5C279512D67A7E81AC6CE94829952B811C" }, { "b" : "7F92F3322000", "path" : "/lib/x86_64-linux-gnu/libresolv.so.2", "elfType" : 3, "buildId" : "50A923F8DAFECBCD969C8573116A38C18D0E24D5" }, { "b" : "7F92F2EDD000", "path" : "/lib/x86_64-linux-gnu/libcrypto.so.1.0.0", "elfType" : 3, "buildId" : "15FFEB43278726B025F020862BF51302822A40EC" }, { "b" : "7F92F2C74000", "path" : "/lib/x86_64-linux-gnu/libssl.so.1.0.0", "elfType" : 3, "buildId" : "FF69EA60EBE05F2DD689D2B26FC85A73E5FBC3A0" }, { "b" : "7F92F2A70000", "path" : "/lib/x86_64-linux-gnu/libdl.so.2", "elfType" : 3, "buildId" : "37BFC3D8F7E3B022DAC7943B1A5FACD40CEBF0AD" }, { "b" : "7F92F2868000", "path" : "/lib/x86_64-linux-gnu/librt.so.1", "elfType" : 3, "buildId" : "69143E8B39040C964D3958490535322675F15DD3" }, { "b" : "7F92F255F000", "path" : "/lib/x86_64-linux-gnu/libm.so.6", "elfType" : 3, "buildId" : "BAD67A84E56E73D031AE507261DA066B35949D34" }, { "b" : "7F92F2349000", "path" : "/lib/x86_64-linux-gnu/libgcc_s.so.1", "elfType" : 3, "buildId" : "68220AE2C65D65C1B6AAA12FA6765A6EC2F5F434" }, { "b" : "7F92F212C000", "path" : "/lib/x86_64-linux-gnu/libpthread.so.0", "elfType" : 3, "buildId" : "B17C21299099640A6D863E423D99265824E7BB16" }, { "b" : "7F92F1D62000", "path" : "/lib/x86_64-linux-gnu/libc.so.6", "elfType" : 3, "buildId" : "1CA54A6E0D76188105B12E49FE6B8019BF08803A" }, { "b" : "7F92F353D000", "path" : "/lib64/ld-linux-x86-64.so.2", "elfType" : 3, "buildId" : "C0ADBAD6F9A33944F2B3567C078EC472A1DAE98E" } ] }}
mongod(_ZN5mongo15printStackTraceERSo+0x41) [0x55ee52a23531]
mongod(+0x2285749) [0x55ee52a22749]
mongod(+0x2285C2D) [0x55ee52a22c2d]
libpthread.so.0(+0x11390) [0x7f92f213d390]
libc.so.6(gsignal+0x38) [0x7f92f1d97428]
libc.so.6(abort+0x16A) [0x7f92f1d9902a]
mongod(_ZN5mongo22invariantFailedWithMsgEPKcS1_S1_j+0x0) [0x55ee51136c1e]
mongod(_ZN5mongo14ServiceContext17setPeriodicRunnerESt10unique_ptrINS_14PeriodicRunnerESt14default_deleteIS2_EE+0x0) [0x55ee528d8db0]
mongod(_ZN5mongo20ServiceContextMongoD9_newOpCtxEPNS_6ClientEj+0x60) [0x55ee513dabb0]
mongod(_ZN5mongo14ServiceContext20makeOperationContextEPNS_6ClientE+0x41) [0x55ee528d9281]
mongod(_ZN5mongo6Client20makeOperationContextEv+0x27) [0x55ee528d5427]
mongod(+0xA0FED3) [0x55ee511aced3]
mongod(+0x2281975) [0x55ee52a1e975]
mongod(_ZN5mongo8shutdownENS_8ExitCodeERKNS_16ShutdownTaskArgsE+0x364) [0x55ee51137df7]
mongod(_ZZN5mongo13duration_castINS_8DurationISt5ratioILl1ELl1000EEEES2_ILl1ELl1EEEET_RKNS1_IT0_EEENKUlvE_clEv+0x0) [0x55ee510d0c6c]
mongod(_ZN5mongo11mongoDbMainEiPPcS1_+0x819) [0x55ee511b4709]
mongod(main+0x9) [0x55ee51138d49]
libc.so.6(__libc_start_main+0xF0) [0x7f92f1d82830]
mongod(_start+0x29) [0x55ee5119cc39]
----- END BACKTRACE -----
2019-11-21T21:42:02.208+0100 I CONTROL [main] ***** SERVER RESTARTED *****
2019-11-21T21:42:02.211+0100 I CONTROL [initandlisten] MongoDB starting : pid=30161 port=27017 dbpath=/var/lib/mongodb 64-bit host=tokyo
2019-11-21T21:42:02.211+0100 I CONTROL [initandlisten] db version v3.6.15
2019-11-21T21:42:02.211+0100 I CONTROL [initandlisten] git version: 18934fb5c814e87895c5e38ae1515dd6cb4c00f7
2019-11-21T21:42:02.211+0100 I CONTROL [initandlisten] OpenSSL version: OpenSSL 1.0.2g 1 Mar 2016
2019-11-21T21:42:02.211+0100 I CONTROL [initandlisten] allocator: tcmalloc
2019-11-21T21:42:02.211+0100 I CONTROL [initandlisten] modules: none
2019-11-21T21:42:02.211+0100 I CONTROL [initandlisten] build environment:
2019-11-21T21:42:02.211+0100 I CONTROL [initandlisten] distmod: ubuntu1604
2019-11-21T21:42:02.211+0100 I CONTROL [initandlisten] distarch: x86_64
2019-11-21T21:42:02.211+0100 I CONTROL [initandlisten] target_arch: x86_64
2019-11-21T21:42:02.211+0100 I CONTROL [initandlisten] options: { config: "/etc/mongod.conf", net: { bindIp: "127.0.0.1", port: 27017 }, replication: { replSetName: "001-rs" }, storage: { dbPath: "/var/lib/mongodb", journal: { enabled: true } }, systemLog: { destination: "file", logAppend: true, path: "/var/log/mongodb/mongod.log", quiet: true } }
2019-11-21T21:42:02.232+0100 I - [initandlisten] Detected data files in /var/lib/mongodb created by the 'mmapv1' storage engine, so setting the active storage engine to 'mmapv1'.
2019-11-21T21:42:02.234+0100 I JOURNAL [initandlisten] journal dir=/var/lib/mongodb/journal
2019-11-21T21:42:02.234+0100 I JOURNAL [initandlisten] recover : no journal files present, no recovery needed
2019-11-21T21:42:02.401+0100 I JOURNAL [durability] Durability thread started
2019-11-21T21:42:02.401+0100 I JOURNAL [journal writer] Journal writer thread started
2019-11-21T21:42:02.457+0100 I CONTROL [initandlisten]
2019-11-21T21:42:02.457+0100 I CONTROL [initandlisten] ** WARNING: Access control is not enabled for the database.
2019-11-21T21:42:02.457+0100 I CONTROL [initandlisten] ** Read and write access to data and configuration is unrestricted.
2019-11-21T21:42:02.457+0100 I CONTROL [initandlisten]
2019-11-21T21:42:02.457+0100 I CONTROL [initandlisten]
2019-11-21T21:42:02.457+0100 I CONTROL [initandlisten] ** WARNING: /sys/kernel/mm/transparent_hugepage/enabled is 'always'.
2019-11-21T21:42:02.457+0100 I CONTROL [initandlisten] ** We suggest setting it to 'never'
2019-11-21T21:42:02.457+0100 I CONTROL [initandlisten]
2019-11-21T21:42:02.457+0100 I CONTROL [initandlisten] ** WARNING: /sys/kernel/mm/transparent_hugepage/defrag is 'always'.
2019-11-21T21:42:02.458+0100 I CONTROL [initandlisten] ** We suggest setting it to 'never'
2019-11-21T21:42:02.458+0100 I CONTROL [initandlisten]
2019-11-21T21:42:02.733+0100 I FTDC [initandlisten] Initializing full-time diagnostic data capture with directory '/var/lib/mongodb/diagnostic.data'
2019-11-21T21:42:02.733+0100 I STORAGE [initandlisten] createCollection: local.replset.minvalid with no UUID.
2019-11-21T21:42:02.734+0100 I STORAGE [initandlisten] createCollection: local.replset.election with no UUID.
2019-11-21T21:42:02.734+0100 I REPL [initandlisten] Did not find local initialized voted for document at startup.
2019-11-21T21:42:02.734+0100 I REPL [initandlisten] Did not find local Rollback ID document at startup. Creating one.
2019-11-21T21:42:02.734+0100 I STORAGE [initandlisten] createCollection: local.system.rollback.id with no UUID.
2019-11-21T21:42:02.734+0100 I REPL [initandlisten] Initialized the rollback ID to 1
2019-11-21T21:42:02.734+0100 I REPL [initandlisten] Did not find local replica set configuration document at startup; NoMatchingDocument: Did not find replica set configuration document in local.system.replset
2019-11-21T21:42:02.734+0100 I NETWORK [initandlisten] listening via socket bound to 127.0.0.1
2019-11-21T21:42:02.734+0100 I NETWORK [initandlisten] listening via socket bound to /tmp/mongodb-27017.sock
2019-11-21T21:42:02.734+0100 I NETWORK [initandlisten] waiting for connections on port 27017
2019-11-21T21:42:02.734+0100 I CONTROL [LogicalSessionCacheReap] Sessions collection is not set up; waiting until next sessions reap interval: config.system.sessions does not exist
2019-11-21T21:42:04.589+0100 I NETWORK [conn15] received client metadata from 127.0.0.1:45844 conn15: { application: { name: "MongoDB Shell" }, driver: { name: "MongoDB Internal Client", version: "3.6.15" }, os: { type: "Linux", name: "Ubuntu", architecture: "x86_64", version: "16.04" } }
2019-11-21T21:45:10.874+0100 I COMMAND [conn25] initiate : no configuration specified. Using a default configuration for the set
2019-11-21T21:45:10.874+0100 I COMMAND [conn25] created this configuration for initiation : { _id: "001-rs", version: 1, members: [ { _id: 0, host: "127.0.0.1:27017" } ] }
2019-11-21T21:45:10.874+0100 I REPL [conn25] replSetInitiate admin command received from client
2019-11-21T21:45:10.874+0100 I REPL [conn25] replSetInitiate config object with 1 members parses ok
2019-11-21T21:45:10.874+0100 I REPL [conn25] ******
2019-11-21T21:45:10.874+0100 I REPL [conn25] creating replication oplog of size: 51200MB...
2019-11-21T21:45:10.874+0100 I STORAGE [conn25] createCollection: local.oplog.rs with no UUID.
2019-11-21T21:45:10.874+0100 I STORAGE [FileAllocator] allocating new datafile /var/lib/mongodb/local.1
2019-11-21T21:45:10.874+0100 I STORAGE [FileAllocator] creating directory /var/lib/mongodb/_tmp
2019-11-21T21:45:10.965+0100 I STORAGE [FileAllocator] done allocating datafile /var/lib/mongodb/local.1, size: 2047MB, took 0.042 secs
2019-11-21T21:45:10.965+0100 I STORAGE [FileAllocator] allocating new datafile /var/lib/mongodb/local.2
2019-11-21T21:45:11.000+0100 I STORAGE [FileAllocator] done allocating datafile /var/lib/mongodb/local.2, size: 2047MB, took 0.034 secs
2019-11-21T21:45:11.000+0100 I STORAGE [FileAllocator] allocating new datafile /var/lib/mongodb/local.3
2019-11-21T21:45:11.034+0100 I STORAGE [FileAllocator] done allocating datafile /var/lib/mongodb/local.3, size: 2047MB, took 0.034 secs
2019-11-21T21:45:11.034+0100 I STORAGE [FileAllocator] allocating new datafile /var/lib/mongodb/local.4
2019-11-21T21:45:11.068+0100 I STORAGE [FileAllocator] done allocating datafile /var/lib/mongodb/local.4, size: 2047MB, took 0.033 secs
2019-11-21T21:45:11.068+0100 I STORAGE [FileAllocator] allocating new datafile /var/lib/mongodb/local.5
2019-11-21T21:45:11.102+0100 I STORAGE [FileAllocator] done allocating datafile /var/lib/mongodb/local.5, size: 2047MB, took 0.034 secs
2019-11-21T21:45:11.102+0100 I STORAGE [FileAllocator] allocating new datafile /var/lib/mongodb/local.6
2019-11-21T21:45:11.137+0100 I STORAGE [FileAllocator] done allocating datafile /var/lib/mongodb/local.6, size: 2047MB, took 0.033 secs
2019-11-21T21:45:11.137+0100 I STORAGE [FileAllocator] allocating new datafile /var/lib/mongodb/local.7
2019-11-21T21:45:11.162+0100 I STORAGE [FileAllocator] done allocating datafile /var/lib/mongodb/local.7, size: 2047MB, took 0.025 secs
2019-11-21T21:45:11.163+0100 I STORAGE [FileAllocator] allocating new datafile /var/lib/mongodb/local.8
2019-11-21T21:45:11.188+0100 I STORAGE [FileAllocator] done allocating datafile /var/lib/mongodb/local.8, size: 2047MB, took 0.025 secs
2019-11-21T21:45:11.189+0100 I STORAGE [FileAllocator] allocating new datafile /var/lib/mongodb/local.9
2019-11-21T21:45:11.223+0100 I STORAGE [FileAllocator] done allocating datafile /var/lib/mongodb/local.9, size: 2047MB, took 0.034 secs
2019-11-21T21:45:11.223+0100 I STORAGE [FileAllocator] allocating new datafile /var/lib/mongodb/local.10
2019-11-21T21:45:11.265+0100 I STORAGE [FileAllocator] done allocating datafile /var/lib/mongodb/local.10, size: 2047MB, took 0.042 secs
2019-11-21T21:45:11.265+0100 I STORAGE [FileAllocator] allocating new datafile /var/lib/mongodb/local.11
2019-11-21T21:45:11.300+0100 I STORAGE [FileAllocator] done allocating datafile /var/lib/mongodb/local.11, size: 2047MB, took 0.034 secs
2019-11-21T21:45:11.300+0100 I STORAGE [FileAllocator] allocating new datafile /var/lib/mongodb/local.12
2019-11-21T21:45:11.334+0100 I STORAGE [FileAllocator] done allocating datafile /var/lib/mongodb/local.12, size: 2047MB, took 0.034 secs
2019-11-21T21:45:11.334+0100 I STORAGE [FileAllocator] allocating new datafile /var/lib/mongodb/local.13
2019-11-21T21:45:11.369+0100 I STORAGE [FileAllocator] done allocating datafile /var/lib/mongodb/local.13, size: 2047MB, took 0.034 secs
2019-11-21T21:45:11.369+0100 I STORAGE [FileAllocator] allocating new datafile /var/lib/mongodb/local.14
2019-11-21T21:45:11.403+0100 I STORAGE [FileAllocator] done allocating datafile /var/lib/mongodb/local.14, size: 2047MB, took 0.033 secs
2019-11-21T21:45:11.403+0100 I STORAGE [FileAllocator] allocating new datafile /var/lib/mongodb/local.15
2019-11-21T21:45:11.437+0100 I STORAGE [FileAllocator] done allocating datafile /var/lib/mongodb/local.15, size: 2047MB, took 0.034 secs
2019-11-21T21:45:11.437+0100 I STORAGE [FileAllocator] allocating new datafile /var/lib/mongodb/local.16
2019-11-21T21:45:11.463+0100 I STORAGE [FileAllocator] done allocating datafile /var/lib/mongodb/local.16, size: 2047MB, took 0.025 secs
2019-11-21T21:45:11.463+0100 I STORAGE [FileAllocator] allocating new datafile /var/lib/mongodb/local.17
2019-11-21T21:45:11.518+0100 I STORAGE [FileAllocator] done allocating datafile /var/lib/mongodb/local.17, size: 2047MB, took 0.055 secs
2019-11-21T21:45:11.519+0100 I STORAGE [FileAllocator] allocating new datafile /var/lib/mongodb/local.18
2019-11-21T21:45:11.548+0100 I STORAGE [FileAllocator] done allocating datafile /var/lib/mongodb/local.18, size: 2047MB, took 0.029 secs
2019-11-21T21:45:11.548+0100 I STORAGE [FileAllocator] allocating new datafile /var/lib/mongodb/local.19
2019-11-21T21:45:11.582+0100 I STORAGE [FileAllocator] done allocating datafile /var/lib/mongodb/local.19, size: 2047MB, took 0.033 secs
2019-11-21T21:45:11.582+0100 I STORAGE [FileAllocator] allocating new datafile /var/lib/mongodb/local.20
2019-11-21T21:45:11.617+0100 I STORAGE [FileAllocator] done allocating datafile /var/lib/mongodb/local.20, size: 2047MB, took 0.034 secs
2019-11-21T21:45:11.617+0100 I STORAGE [FileAllocator] allocating new datafile /var/lib/mongodb/local.21
2019-11-21T21:45:11.643+0100 I STORAGE [FileAllocator] done allocating datafile /var/lib/mongodb/local.21, size: 2047MB, took 0.025 secs
2019-11-21T21:45:11.643+0100 I STORAGE [FileAllocator] allocating new datafile /var/lib/mongodb/local.22
2019-11-21T21:45:11.669+0100 I STORAGE [FileAllocator] done allocating datafile /var/lib/mongodb/local.22, size: 2047MB, took 0.025 secs
2019-11-21T21:45:11.669+0100 I STORAGE [FileAllocator] allocating new datafile /var/lib/mongodb/local.23
2019-11-21T21:45:11.694+0100 I STORAGE [FileAllocator] done allocating datafile /var/lib/mongodb/local.23, size: 2047MB, took 0.025 secs
2019-11-21T21:45:11.695+0100 I STORAGE [FileAllocator] allocating new datafile /var/lib/mongodb/local.24
2019-11-21T21:45:11.729+0100 I STORAGE [FileAllocator] done allocating datafile /var/lib/mongodb/local.24, size: 2047MB, took 0.033 secs
2019-11-21T21:45:11.729+0100 I STORAGE [FileAllocator] allocating new datafile /var/lib/mongodb/local.25
2019-11-21T21:45:11.763+0100 I STORAGE [FileAllocator] done allocating datafile /var/lib/mongodb/local.25, size: 2047MB, took 0.033 secs
2019-11-21T21:45:12.894+0100 I REPL [conn25] ******
2019-11-21T21:45:12.894+0100 I STORAGE [conn25] createCollection: local.system.replset with no UUID.
2019-11-21T21:45:12.894+0100 I COMMAND [conn10] command local.$cmd command: find { find: "oplog.rs", filter: { ns: /^(?:rocketchat\.|admin\.\$cmd)/, $or: [ { op: { $in: [ "i", "u", "d" ] } }, { op: "c", o.drop: { $exists: true } }, { op: "c", o.dropDatabase: 1 }, { op: "c", o.applyOps: { $exists: true } } ], ts: { $gt: Timestamp(1574368850, 1) } }, returnKey: false, showRecordId: false, tailable: true, oplogReplay: true, awaitData: true, $db: "local" } exception: Oplog collection reads are not allowed while in the rollback or startup state. code:NotMasterOrSecondary numYields:0 reslen:173 locks:{ Global: { acquireCount: { r: 2 }, acquireWaitCount: { r: 1 }, timeAcquiringMicros: { r: 1930199 } }, MMAPV1Journal: { acquireCount: { r: 1 } }, Database: { acquireCount: { r: 1 } } } protocol:op_query 1930ms
2019-11-21T21:45:12.894+0100 I STORAGE [conn25] createCollection: local.system.replset with no UUID.
2019-11-21T21:45:12.894+0100 I COMMAND [conn10] command local.$cmd command: find { find: "oplog.rs", filter: { ns: /^(?:rocketchat\.|admin\.\$cmd)/, $or: [ { op: { $in: [ "i", "u", "d" ] } }, { op: "c", o.drop: { $exists: true } }, { op: "c", o.dropDatabase: 1 }, { op: "c", o.applyOps: { $exists: true } } ], ts: { $gt: Timestamp(1574368850, 1) } }, returnKey: false, showRecordId: false, tailable: true, oplogReplay: true, awaitData: true, $db: "local" } exception: Oplog collection reads are not allowed while in the rollback or startup state. code:NotMasterOrSecondary numYields:0 reslen:173 locks:{ Global: { acquireCount: { r: 2 }, acquireWaitCount: { r: 1 }, timeAcquiringMicros: { r: 1930199 } }, MMAPV1Journal: { acquireCount: { r: 1 } }, Database: { acquireCount: { r: 1 } } } protocol:op_query 1930ms
2019-11-21T21:45:12.894+0100 I COMMAND [conn4] command local.$cmd command: find { find: "oplog.rs", filter: { ns: /^parties\./, $or: [ { op: { $in: [ "i", "u", "d" ] } }, { op: "c", o.drop: { $exists: true } }, { op: "c", o.dropDatabase: 1 } ], ts: { $gt: Timestamp(1574368851, 1) } }, tailable: true, oplogReplay: true, awaitData: true, $db: "local" } exception: Oplog collection reads are not allowed while in the rollback or startup state. code:NotMasterOrSecondary numYields:0 reslen:173 locks:{ Global: { acquireCount: { r: 2 }, acquireWaitCount: { r: 1 }, timeAcquiringMicros: { r: 1983929 } }, MMAPV1Journal: { acquireCount: { r: 1 } }, Database: { acquireCount: { r: 1 } } } protocol:op_query 1984ms
2019-11-21T21:45:12.896+0100 I COMMAND [conn25] Assigning UUID 2ce36068-9449-4554-a90e-f8970fc4bbc2 to collection local.system.rollback.id
2019-11-21T21:45:12.896+0100 I COMMAND [conn25] Assigning UUID 300ecf04-fef1-41d6-88e4-c8489d3760c1 to collection local.system.replset
2019-11-21T21:45:12.896+0100 I COMMAND [conn25] Assigning UUID 4c31a468-251a-4ccd-b35c-53c4404bb449 to collection local.me
2019-11-21T21:45:12.896+0100 I COMMAND [conn25] Assigning UUID e5d705a3-6e68-4599-9280-5c9035d96cf7 to collection local.startup_log
2019-11-21T21:45:12.896+0100 I COMMAND [conn25] Assigning UUID 0af692db-ec16-4959-a73c-9170f0c21881 to collection local.replset.minvalid
2019-11-21T21:45:12.896+0100 I COMMAND [conn25] Assigning UUID 0e458d3f-5191-42f1-a2d2-613bd68a1286 to collection local.oplog.rs
2019-11-21T21:45:12.896+0100 I COMMAND [conn25] Assigning UUID 150b0da5-0c61-49ab-935d-75dbedd9df3e to collection local.replset.election
2019-11-21T21:45:12.896+0100 I STORAGE [conn25] allocating new ns file /var/lib/mongodb/admin.ns, filling with zeroes...
2019-11-21T21:45:13.102+0100 I STORAGE [conn25] done allocating ns file /var/lib/mongodb/admin.ns, size: 16MB, took 0.206 seconds
2019-11-21T21:45:13.102+0100 I STORAGE [FileAllocator] allocating new datafile /var/lib/mongodb/admin.0
2019-11-21T21:45:13.124+0100 I STORAGE [FileAllocator] done allocating datafile /var/lib/mongodb/admin.0, size: 64MB, took 0.021 secs
2019-11-21T21:45:13.137+0100 I STORAGE [conn25] createCollection: admin.system.version with provided UUID: df80fb70-0fae-4416-af42-c858acf7cdc5
2019-11-21T21:45:13.137+0100 I COMMAND [conn25] setting featureCompatibilityVersion to 3.6
2019-11-21T21:45:13.137+0100 I NETWORK [conn25] Skip closing connection for connection # 25
2019-11-21T21:45:13.137+0100 I NETWORK [conn25] Skip closing connection for connection # 14
2019-11-21T21:45:13.137+0100 I NETWORK [conn25] Skip closing connection for connection # 13
2019-11-21T21:45:13.137+0100 I NETWORK [conn25] Skip closing connection for connection # 12
2019-11-21T21:45:13.137+0100 I NETWORK [conn25] Skip closing connection for connection # 11
2019-11-21T21:45:13.137+0100 I NETWORK [conn25] Skip closing connection for connection # 10
2019-11-21T21:45:13.137+0100 I NETWORK [conn25] Skip closing connection for connection # 9
2019-11-21T21:45:13.137+0100 I NETWORK [conn25] Skip closing connection for connection # 8
2019-11-21T21:45:13.137+0100 I NETWORK [conn25] Skip closing connection for connection # 7
2019-11-21T21:45:13.137+0100 I NETWORK [conn25] Skip closing connection for connection # 6
2019-11-21T21:45:13.137+0100 I NETWORK [conn25] Skip closing connection for connection # 5
2019-11-21T21:45:13.137+0100 I NETWORK [conn25] Skip closing connection for connection # 4
2019-11-21T21:45:13.137+0100 I NETWORK [conn25] Skip closing connection for connection # 3
2019-11-21T21:45:13.137+0100 I NETWORK [conn25] Skip closing connection for connection # 2
2019-11-21T21:45:13.137+0100 I NETWORK [conn25] Skip closing connection for connection # 1
2019-11-21T21:45:13.137+0100 I REPL [conn25] New replica set config in use: { _id: "001-rs", version: 1, protocolVersion: 1, members: [ { _id: 0, host: "127.0.0.1:27017", arbiterOnly: false, buildIndexes: true, hidden: false, priority: 1.0, tags: {}, slaveDelay: 0, votes: 1 } ], settings: { chainingAllowed: true, heartbeatIntervalMillis: 2000, heartbeatTimeoutSecs: 10, electionTimeoutMillis: 10000, catchUpTimeoutMillis: -1, catchUpTakeoverDelayMillis: 30000, getLastErrorModes: {}, getLastErrorDefaults: { w: 1, wtimeout: 0 }, replicaSetId: ObjectId('5dd6f7568933b2a00b06b0b7') } }
2019-11-21T21:45:13.137+0100 I REPL [conn25] This node is 127.0.0.1:27017 in the config
2019-11-21T21:45:13.137+0100 I REPL [conn25] transition to STARTUP2 from STARTUP
2019-11-21T21:45:13.137+0100 I REPL [conn25] Starting replication storage threads
2019-11-21T21:45:13.137+0100 I REPL [conn25] transition to RECOVERING from STARTUP2
2019-11-21T21:45:13.137+0100 I REPL [conn25] Starting replication fetcher thread
2019-11-21T21:45:13.137+0100 I REPL [conn25] Starting replication applier thread
2019-11-21T21:45:13.137+0100 I REPL [conn25] Starting replication reporter thread
2019-11-21T21:45:13.137+0100 I COMMAND [conn25] command local.system.indexes appName: "MongoDB Shell" command: replSetInitiate { replSetInitiate: undefined, lsid: { id: UUID("62f5a9eb-a840-43bc-9f7b-d6e94829c0a9") }, $db: "admin" } numYields:0 reslen:252 locks:{ Global: { acquireCount: { r: 36, w: 24, W: 2 }, acquireWaitCount: { W: 1 }, timeAcquiringMicros: { W: 122 } }, MMAPV1Journal: { acquireCount: { r: 1, w: 31 }, acquireWaitCount: { w: 1 }, timeAcquiringMicros: { w: 97 } }, Database: { acquireCount: { r: 4, w: 4, W: 20 } }, Collection: { acquireCount: { R: 2, W: 2 } }, Metadata: { acquireCount: { W: 32 } }, Mutex: { acquireCount: { r: 1, W: 54 } }, oplog: { acquireCount: { R: 2, W: 3 } } } protocol:op_msg 2263ms
2019-11-21T21:45:13.138+0100 I REPL [rsSync] transition to SECONDARY from RECOVERING
2019-11-21T21:45:13.138+0100 I REPL [rsSync] conducting a dry run election to see if we could be elected. current term: 0
2019-11-21T21:45:13.138+0100 I REPL [replexec-0] dry election run succeeded, running for election in term 1
2019-11-21T21:45:13.167+0100 I REPL [replexec-0] election succeeded, assuming primary role in term 1
2019-11-21T21:45:13.167+0100 I REPL [replexec-0] transition to PRIMARY from SECONDARY
2019-11-21T21:45:13.167+0100 I REPL [replexec-0] Resetting sync source to empty, which was :27017
2019-11-21T21:45:13.167+0100 I REPL [replexec-0] Entering primary catch-up mode.
2019-11-21T21:45:13.167+0100 I REPL [replexec-0] Exited primary catch-up mode.
2019-11-21T21:45:15.138+0100 I STORAGE [rsSync] allocating new ns file /var/lib/mongodb/config.ns, filling with zeroes...
2019-11-21T21:45:15.352+0100 I STORAGE [rsSync] done allocating ns file /var/lib/mongodb/config.ns, size: 16MB, took 0.214 seconds
2019-11-21T21:45:15.352+0100 I STORAGE [FileAllocator] allocating new datafile /var/lib/mongodb/config.0
2019-11-21T21:45:15.376+0100 I STORAGE [FileAllocator] done allocating datafile /var/lib/mongodb/config.0, size: 64MB, took 0.022 secs
2019-11-21T21:45:15.393+0100 I STORAGE [rsSync] createCollection: config.transactions with generated UUID: 7e81bf0f-9e10-4b9b-bf40-51657e7016ab
2019-11-21T21:45:15.393+0100 I COMMAND [rsSync] command config.transactions command: create { create: "transactions", $db: "config" } numYields:0 reslen:147 locks:{ Global: { acquireCount: { r: 2, w: 2 } }, MMAPV1Journal: { acquireCount: { w: 5 } }, Database: { acquireCount: { w: 1, W: 1 } }, Metadata: { acquireCount: { W: 4 } }, Mutex: { acquireCount: { W: 4 } }, oplog: { acquireCount: { W: 1 } } } protocol:op_msg 255ms
2019-11-21T21:45:15.394+0100 I REPL [rsSync] transition to primary complete; database writes are now permitted
2019-11-21T21:45:15.394+0100 I COMMAND [monitoring keys for HMAC] command admin.system.keys command: find { find: "system.keys", filter: { purpose: "HMAC", expiresAt: { $gt: Timestamp(1574369115, 1) } }, sort: { expiresAt: 1 }, $readPreference: { mode: "nearest", tags: [] }, $db: "admin" } planSummary: EOF keysExamined:0 docsExamined:0 cursorExhausted:1 numYields:0 nreturned:0 reslen:215 locks:{ Global: { acquireCount: { r: 2 }, acquireWaitCount: { r: 1 }, timeAcquiringMicros: { r: 255931 } }, MMAPV1Journal: { acquireCount: { r: 1 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { R: 1 } } } protocol:op_msg 255ms
2019-11-21T21:45:15.395+0100 I STORAGE [monitoring keys for HMAC] createCollection: admin.system.keys with generated UUID: 3ea98eb3-1494-49a7-9e37-98f57395f8e5
2019-11-21T21:45:20.113+0100 I STORAGE [conn14] allocating new ns file /var/lib/mongodb/rocketchat.ns, filling with zeroes...
2019-11-21T21:45:20.356+0100 I STORAGE [conn14] done allocating ns file /var/lib/mongodb/rocketchat.ns, size: 16MB, took 0.242 seconds
2019-11-21T21:45:20.356+0100 I STORAGE [FileAllocator] allocating new datafile /var/lib/mongodb/rocketchat.0
2019-11-21T21:45:20.380+0100 I STORAGE [FileAllocator] done allocating datafile /var/lib/mongodb/rocketchat.0, size: 64MB, took 0.023 secs
2019-11-21T21:45:20.395+0100 I STORAGE [conn14] createCollection: rocketchat.instances with generated UUID: eff61947-b43c-4a90-91eb-25e71ae7dd8c
2019-11-21T21:45:20.395+0100 I WRITE [conn14] update rocketchat.instances command: { q: { _id: "MJPxhyZKLcyy5KBSJ" }, u: { $set: { pid: 14749, name: "rocket.chat", extraInformation: { host: "undefined", port: "3002" } }, $currentDate: { _createdAt: true, _updatedAt: true } }, multi: false, upsert: true } planSummary: IDHACK keysExamined:0 docsExamined:0 nMatched:0 nModified:0 upsert:1 keysInserted:1 numYields:0 locks:{ Global: { acquireCount: { r: 5, w: 5 } }, MMAPV1Journal: { acquireCount: { w: 9 }, acquireWaitCount: { w: 1 }, timeAcquiringMicros: { w: 3686 } }, Database: { acquireCount: { w: 4, W: 1 } }, Collection: { acquireCount: { W: 2 } }, Metadata: { acquireCount: { W: 4 } }, Mutex: { acquireCount: { W: 4 } }, oplog: { acquireCount: { W: 2 } } } 282ms
2019-11-21T21:45:20.395+0100 I COMMAND [conn14] command rocketchat.$cmd command: update { update: "instances", ordered: true, $clusterTime: { clusterTime: Timestamp(1574369115, 5), signature: { hash: BinData(0, 0000000000000000000000000000000000000000), keyId: 0 } }, lsid: { id: UUID("0c2ec724-d259-4d0f-b9e8-465407e196da") }, $db: "rocketchat" } numYields:0 reslen:305 locks:{ Global: { acquireCount: { r: 5, w: 5 } }, MMAPV1Journal: { acquireCount: { w: 9 }, acquireWaitCount: { w: 1 }, timeAcquiringMicros: { w: 3686 } }, Database: { acquireCount: { w: 4, W: 1 } }, Collection: { acquireCount: { W: 2 } }, Metadata: { acquireCount: { W: 4 } }, Mutex: { acquireCount: { W: 4 } }, oplog: { acquireCount: { W: 2 } } } protocol:op_query 282ms
2019-11-21T21:45:21.280+0100 I STORAGE [conn7] allocating new ns file /var/lib/mongodb/parties.ns, filling with zeroes...
2019-11-21T21:45:21.512+0100 I STORAGE [conn7] done allocating ns file /var/lib/mongodb/parties.ns, size: 16MB, took 0.231 seconds
2019-11-21T21:45:21.512+0100 I STORAGE [FileAllocator] allocating new datafile /var/lib/mongodb/parties.0
2019-11-21T21:45:21.536+0100 I STORAGE [FileAllocator] done allocating datafile /var/lib/mongodb/parties.0, size: 64MB, took 0.024 secs
´´´
Best fairsein