Description
After performing a mongodb restore using a backup from 2am same day. observed error when restarting rocketchat. In the same VM, using mongoshell - is able to connect to mongodb.
Appreciate help/advise. thanks
Server Setup Information
- Version of Rocket.Chat Server: 4.8.0
- Operating System: Ubuntu 20.04 TLS
- Deployment Method: tar
- Number of Running Instances: 1
- DB Replicaset Oplog:
- NodeJS Version: 14.19.3
- MongoDB Version: 4.4.17
- Proxy:
- Firewalls involved:
Any additional Information
Errors as below:
Jan 4 07:12:47 vm405 rocketchat[37994]: LocalStore: store created at
Jan 4 07:12:47 vm405 rocketchat[37994]: message repeated 2 times: [ LocalStore: store created at]
Jan 4 07:12:48 vm405 rocketchat[37994]: MessageType.render is deprecated. Use MessageType.message instead. livechat_webrtc_video_call
Jan 4 07:12:48 vm405 rocketchat[37994]: {“level”:40,“time”:“2023-01-04T07:12:48.447Z”,“pid”:37994,“hostname”:"vm405 ",“name”:“VoIPService”,“msg”:“Voip is not enabled.
Cant start the service”}
Jan 4 07:12:54 vm405 rocketchat[37994]: Browserslist: caniuse-lite is outdated. Please run:
Jan 4 07:12:54 vm405 rocketchat[37994]: npx browserslist@latest --update-db
Jan 4 07:12:54 vm405 rocketchat[37994]: Why you should do it regularly: GitHub - browserslist/browserslist: 🦔 Share target browsers between different front-end tools, like Autoprefixer, Stylelint and babel-preset-env
Jan 4 07:12:55 vm405 rocketchat[37994]: /data/Rocket.Chat/programs/server/npm/node_modules/mongodb/lib/utils.js:698
Jan 4 07:12:55 vm405 rocketchat[37994]: throw error;
Jan 4 07:12:55 vm405 rocketchat[37994]: ^
Jan 4 07:12:55 vm405 rocketchat[37994]: MongoError: Error waiting for snapshot not less than { ts: Timestamp(1672816293, 14), t: -1 }, current relevant optime is { ts: Timesta
mp(0, 0), t: -1 }. :: caused by :: operation exceeded time limit
Jan 4 07:12:55 vm405 rocketchat[37994]: at MessageStream.messageHandler (/data/Rocket.Chat/programs/server/npm/node_modules/mongodb/lib/cmap/connection.js:299:20)
Jan 4 07:12:55 vm405 rocketchat[37994]: at MessageStream.emit (events.js:400:28)
Jan 4 07:12:55 vm405 rocketchat[37994]: at MessageStream.emit (domain.js:475:12)
Jan 4 07:12:55 vm405 rocketchat[37994]: at processIncomingData (/data/Rocket.Chat/programs/server/npm/node_modules/mongodb/lib/cmap/message_stream.js:144:12)
Jan 4 07:12:55 vm405 rocketchat[37994]: at MessageStream.write (/data/Rocket.Chat/programs/server/npm/node_modules/mongodb/lib/cmap/message_stream.js:42:5)
Jan 4 07:12:55 vm405 rocketchat[37994]: at writeOrBuffer (internal/streams/writable.js:358:12)
Jan 4 07:12:55 vm405 rocketchat[37994]: at MessageStream.Writable.write (internal/streams/writable.js:303:10)
Jan 4 07:12:55 vm405 rocketchat[37994]: at Socket.ondata (internal/streams/readable.js:731:22)
Jan 4 07:12:55 vm405 rocketchat[37994]: at Socket.emit (events.js:400:28)
Jan 4 07:12:55 vm405 rocketchat[37994]: at Socket.emit (domain.js:475:12)
Jan 4 07:12:55 vm405 rocketchat[37994]: at addChunk (internal/streams/readable.js:293:12)
Jan 4 07:12:55 vm405 rocketchat[37994]: at readableAddChunk (internal/streams/readable.js:267:9)
Jan 4 07:12:55 vm405 rocketchat[37994]: at Socket.Readable.push (internal/streams/readable.js:206:10)
Jan 4 07:12:55 vm405 rocketchat[37994]: at TCP.onStreamRead (internal/stream_base_commons.js:188:23)
Jan 4 07:12:55 vm405 rocketchat[37994]: at TCP.callbackTrampoline (internal/async_hooks.js:130:17)
Jan 4 07:12:55 vm405 rocketchat[37994]: Emitted ‘error’ event on ChangeStream instance at:
Jan 4 07:12:55 vm405 rocketchat[37994]: at processError (/data/Rocket.Chat/programs/server/npm/node_modules/mongodb/lib/change_stream.js:571:38)
Jan 4 07:12:55 vm405 rocketchat[37994]: at ChangeStreamCursor. (/data/Rocket.Chat/programs/server/npm/node_modules/mongodb/lib/change_stream.js:435:5)
Jan 4 07:12:55 vm405 rocketchat[37994]: at ChangeStreamCursor.emit (events.js:400:28)
Jan 4 07:12:55 vm405 rocketchat[37994]: at ChangeStreamCursor.emit (domain.js:475:12)
Jan 4 07:12:55 vm405 rocketchat[37994]: at /data/Rocket.Chat/programs/server/npm/node_modules/mongodb/lib/core/cursor.js:353:16
Jan 4 07:12:55 vm405 rocketchat[37994]: at /data/Rocket.Chat/programs/server/npm/node_modules/mongodb/lib/core/cursor.js:746:9
Jan 4 07:12:55 vm405 rocketchat[37994]: at /data/Rocket.Chat/programs/server/npm/node_modules/mongodb/lib/change_stream.js:329:9
Jan 4 07:12:55 vm405 rocketchat[37994]: at done (/data/Rocket.Chat/programs/server/npm/node_modules/mongodb/lib/core/cursor.js:468:7)
Jan 4 07:12:55 vm405 rocketchat[37994]: at /data/Rocket.Chat/programs/server/npm/node_modules/mongodb/lib/core/cursor.js:543:11
Jan 4 07:12:55 vm405 rocketchat[37994]: at /data/Rocket.Chat/programs/server/npm/node_modules/mongodb/lib/utils.js:695:9
Jan 4 07:12:55 vm405 rocketchat[37994]: at executeCallback (/data/Rocket.Chat/programs/server/npm/node_modules/mongodb/lib/operations/execute_operation.js:65:7)
Jan 4 07:12:55 vm405 rocketchat[37994]: at callbackWithRetry (/data/Rocket.Chat/programs/server/npm/node_modules/mongodb/lib/operations/execute_operation.js:116:14)
Jan 4 07:12:55 vm405 rocketchat[37994]: at /data/Rocket.Chat/programs/server/npm/node_modules/mongodb/lib/operations/command_v2.js:103:9
Jan 4 07:12:55 vm405 rocketchat[37994]: at /data/Rocket.Chat/programs/server/npm/node_modules/mongodb/lib/cmap/connection_pool.js:350:13
Jan 4 07:12:55 vm405 rocketchat[37994]: at handleOperationResult (/data/Rocket.Chat/programs/server/npm/node_modules/mongodb/lib/core/sdam/server.js:567:5)
Jan 4 07:12:55 vm405 rocketchat[37994]: at MessageStream.messageHandler (/data/Rocket.Chat/programs/server/npm/node_modules/mongodb/lib/cmap/connection.js:299:11)
Jan 4 07:12:55 vm405 rocketchat[37994]: at MessageStream.emit (events.js:400:28)
Jan 4 07:12:55 vm405 rocketchat[37994]: [… lines matching original stack trace …]
Jan 4 07:12:55 vm405 rocketchat[37994]: at MessageStream.Writable.write (internal/streams/writable.js:303:10) {
Jan 4 07:12:55 vm405 rocketchat[37994]: operationTime: Timestamp { bsontype: ‘Timestamp’, low: 0, high: 0 },
Jan 4 07:12:55 vm405 rocketchat[37994]: ok: 0,
Jan 4 07:12:55 vm405 rocketchat[37994]: code: 50,
Jan 4 07:12:55 vm405 rocketchat[37994]: codeName: ‘MaxTimeMSExpired’,
Jan 4 07:12:55 vm405 rocketchat[37994]: ‘$clusterTime’: {
Jan 4 07:12:55 vm405 rocketchat[37994]: clusterTime: Timestamp { bsontype: ‘Timestamp’, low: 160, high_: 1672816313 },
Jan 4 07:12:55 vm405 rocketchat[37994]: signature: {
Jan 4 07:12:55 vm405 rocketchat[37994]: hash: Binary {
Jan 4 07:12:55 vm405 rocketchat[37994]: bsontype: ‘Binary’,
Jan 4 07:12:55 vm405 rocketchat[37994]: sub_type: 0,
Jan 4 07:12:55 vm405 rocketchat[37994]: position: 20,
Jan 4 07:12:55 vm405 rocketchat[37994]: buffer: Buffer(20) [Uint8Array] [
Jan 4 07:12:55 vm405 rocketchat[37994]: 50, 95, 138, 93, 24, 218,
Jan 4 07:12:55 vm405 rocketchat[37994]: 76, 33, 158, 12, 101, 27,
Jan 4 07:12:55 vm405 rocketchat[37994]: 195, 71, 200, 164, 103, 208,
Jan 4 07:12:55 vm405 rocketchat[37994]: 104, 225
Jan 4 07:12:55 vm405 rocketchat[37994]: ]
Jan 4 07:12:55 vm405 rocketchat[37994]: },
Jan 4 07:12:55 vm405 rocketchat[37994]: keyId: Long { bsontype: ‘Long’, low: 5, high: 1661396781 }
Jan 4 07:12:55 vm405 rocketchat[37994]: }
Jan 4 07:12:55 vm405 rocketchat[37994]: }
Jan 4 07:12:55 vm405 rocketchat[37994]: }
Jan 4 07:12:55 vm405 systemd[1]: rocketchat.service: Main process exited, code=exited, status=1/FAILURE
Jan 4 07:12:55 vm405 systemd[1]: rocketchat.service: Failed with result ‘exit-code’.