Suddenly, mongod is not starting

[skiiiks]

Description

I had a working Rocket Chat yesterday. This morning I saw a “502 Bad gateway” in the web page. After trying to figure out what happened, I stopped rocketchat-caddy and rocketchat-server snap services and try to start again.

Then I start first with
sudo systemctl start snap.rocketchat-server.rocketchat-mongo.service
but it doesn’t start…

Server Setup Information

• Version of Rocket.Chat Server: I don’t know but I did a caddy refresh about 1 month ago
• Operating System: Ubuntu
• Deployment Method: snap
• Number of Running Instances: 1
• DB Replicaset Oplog: ??
• NodeJS Version: ??
• MongoDB Version: ??
• Proxy: i don’t know, I think caddy
• Firewalls involved: no

Any additional Information

I see in the syslog every 2 seconds this block of log (it’s in a infinite loop):

Nov  6 11:45:04 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:04.733+0100 I STORAGE  [initandlisten] WiredTiger message [1573037104:733295][25401:0x7f6af442ba40], txn-recover: Main recovery loop: starting at 22662/768

Nov  6 11:45:04 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:04.870+0100 I STORAGE  [initandlisten] WiredTiger message [1573037104:870656][25401:0x7f6af442ba40], txn-recover: Recovering log 22662 through 22663

Nov  6 11:45:04 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:04.952+0100 I STORAGE  [initandlisten] WiredTiger message [1573037104:952790][25401:0x7f6af442ba40], txn-recover: Recovering log 22663 through 22663
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.022+0100 I STORAGE  [initandlisten] WiredTiger message [1573037105:22233][25401:0x7f6af442ba40], txn-recover: Set global recovery timestamp: 0
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.065+0100 I STORAGE  [initandlisten] Starting WiredTigerRecordStoreThread local.oplog.rs
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.066+0100 I STORAGE  [initandlisten] The size storer reports that the oplog contains 1851139 records totaling to 1027076987 bytes
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.067+0100 I STORAGE  [initandlisten] Sampling from the oplog between Aug 17 11:30:27:1 and Nov  6 02:42:54:1 to determine where to place markers for truncation
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.067+0100 I STORAGE  [initandlisten] Taking 603 samples and assuming that each section of oplog contains approximately 30672 records totaling to 17017903 bytes
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.128+0100 I STORAGE  [initandlisten] Placing a marker at optime Aug 19 13:51:56:2
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.129+0100 I STORAGE  [initandlisten] Placing a marker at optime Aug 21 07:37:40:1
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.129+0100 I STORAGE  [initandlisten] Placing a marker at optime Aug 22 21:11:58:1
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.129+0100 I STORAGE  [initandlisten] Placing a marker at optime Aug 25 09:55:00:5
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.129+0100 I STORAGE  [initandlisten] Placing a marker at optime Aug 27 10:50:21:3
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.130+0100 I STORAGE  [initandlisten] Placing a marker at optime Aug 28 08:11:37:47
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.130+0100 I STORAGE  [initandlisten] Placing a marker at optime Aug 28 14:37:50:5
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.130+0100 I STORAGE  [initandlisten] Placing a marker at optime Aug 30 06:09:03:1
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.130+0100 I STORAGE  [initandlisten] Placing a marker at optime Sep  1 04:10:04:1
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.131+0100 I STORAGE  [initandlisten] Placing a marker at optime Sep  3 03:05:27:1
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.131+0100 I STORAGE  [initandlisten] Placing a marker at optime Sep  4 12:21:39:6
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.131+0100 I STORAGE  [initandlisten] Placing a marker at optime Sep  5 10:51:16:14
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.131+0100 I STORAGE  [initandlisten] Placing a marker at optime Sep  7 02:00:28:391
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.131+0100 I STORAGE  [initandlisten] Placing a marker at optime Sep  8 11:42:24:1
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.132+0100 I STORAGE  [initandlisten] Placing a marker at optime Sep 10 08:46:48:10
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.132+0100 I STORAGE  [initandlisten] Placing a marker at optime Sep 11 15:03:00:2
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.132+0100 I STORAGE  [initandlisten] Placing a marker at optime Sep 12 18:29:55:1
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.132+0100 I STORAGE  [initandlisten] Placing a marker at optime Sep 14 13:25:05:2
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.133+0100 I STORAGE  [initandlisten] Placing a marker at optime Sep 16 12:33:11:9
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.133+0100 I STORAGE  [initandlisten] Placing a marker at optime Sep 17 13:14:16:2
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.133+0100 I STORAGE  [initandlisten] Placing a marker at optime Sep 17 17:35:55:11
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.133+0100 I STORAGE  [initandlisten] Placing a marker at optime Sep 18 01:22:15:1
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.133+0100 I STORAGE  [initandlisten] Placing a marker at optime Sep 19 07:59:53:1
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.134+0100 I STORAGE  [initandlisten] Placing a marker at optime Sep 20 12:38:59:13
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.134+0100 I STORAGE  [initandlisten] Placing a marker at optime Sep 21 11:33:59:17
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.134+0100 I STORAGE  [initandlisten] Placing a marker at optime Sep 23 09:33:24:1
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.134+0100 I STORAGE  [initandlisten] Placing a marker at optime Sep 24 14:12:15:18
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.134+0100 I STORAGE  [initandlisten] Placing a marker at optime Sep 25 13:55:19:14
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.134+0100 I STORAGE  [initandlisten] Placing a marker at optime Sep 26 14:10:37:4
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.135+0100 I STORAGE  [initandlisten] Placing a marker at optime Sep 27 21:11:23:1
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.135+0100 I STORAGE  [initandlisten] Placing a marker at optime Sep 29 10:40:29:1
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.135+0100 I STORAGE  [initandlisten] Placing a marker at optime Sep 30 18:29:37:2
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.135+0100 I STORAGE  [initandlisten] Placing a marker at optime Oct  2 00:06:42:2
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.135+0100 I STORAGE  [initandlisten] Placing a marker at optime Oct  2 19:14:45:11
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.135+0100 I STORAGE  [initandlisten] Placing a marker at optime Oct  3 22:18:03:4
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.135+0100 I STORAGE  [initandlisten] Placing a marker at optime Oct  5 06:51:29:4
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.135+0100 I STORAGE  [initandlisten] Placing a marker at optime Oct  7 00:25:28:1
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.135+0100 I STORAGE  [initandlisten] Placing a marker at optime Oct  8 06:58:04:6
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.135+0100 I STORAGE  [initandlisten] Placing a marker at optime Oct  9 11:14:09:14
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.135+0100 I STORAGE  [initandlisten] Placing a marker at optime Oct 10 13:44:12:20
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.135+0100 I STORAGE  [initandlisten] Placing a marker at optime Oct 11 21:03:16:3
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.135+0100 I STORAGE  [initandlisten] Placing a marker at optime Oct 13 19:10:01:2
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.135+0100 I STORAGE  [initandlisten] Placing a marker at optime Oct 14 22:26:24:1
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.135+0100 I STORAGE  [initandlisten] Placing a marker at optime Oct 16 07:00:36:4
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.135+0100 I STORAGE  [initandlisten] Placing a marker at optime Oct 17 07:02:51:1
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.135+0100 I STORAGE  [initandlisten] Placing a marker at optime Oct 18 12:41:43:2
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.135+0100 I STORAGE  [initandlisten] Placing a marker at optime Oct 20 05:14:35:1
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.135+0100 I STORAGE  [initandlisten] Placing a marker at optime Oct 21 15:46:22:5
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.135+0100 I STORAGE  [initandlisten] Placing a marker at optime Oct 22 16:41:39:2
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.135+0100 I STORAGE  [initandlisten] Placing a marker at optime Oct 23 20:48:36:3
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.135+0100 I STORAGE  [initandlisten] Placing a marker at optime Oct 24 20:00:35:5
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.135+0100 I STORAGE  [initandlisten] Placing a marker at optime Oct 25 20:52:13:2
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.135+0100 I STORAGE  [initandlisten] Placing a marker at optime Oct 27 17:52:54:1
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.135+0100 I STORAGE  [initandlisten] Placing a marker at optime Oct 28 20:56:02:5
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.135+0100 I STORAGE  [initandlisten] Placing a marker at optime Oct 29 19:10:48:1
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.135+0100 I STORAGE  [initandlisten] Placing a marker at optime Oct 31 02:00:00:274
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.135+0100 I STORAGE  [initandlisten] Placing a marker at optime Nov  1 16:04:43:2
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.135+0100 I STORAGE  [initandlisten] Placing a marker at optime Nov  3 13:45:24:2
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.135+0100 I STORAGE  [initandlisten] Placing a marker at optime Nov  4 12:35:41:4
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.135+0100 I STORAGE  [initandlisten] Placing a marker at optime Nov  5 16:40:30:9
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.203+0100 W STORAGE  [initandlisten] Detected configuration for non-active storage engine mmapv1 when current storage engine is wiredTiger
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.204+0100 I CONTROL  [initandlisten]
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.204+0100 I CONTROL  [initandlisten] ** WARNING: Access control is not enabled for the database.
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.205+0100 I CONTROL  [initandlisten] **          Read and write access to data and configuration is unrestricted.
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.205+0100 I CONTROL  [initandlisten] ** WARNING: You are running this process as the root user, which is not recommended.
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.205+0100 I CONTROL  [initandlisten]
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.303+0100 F CONTROL  [initandlisten] ** IMPORTANT: UPGRADE PROBLEM: The data files need to be fully upgraded to version 3.4 before attempting an upgrade to 3.6; see http://dochub.mongodb.org/core/3.6-upgrade-fcv for more details.
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.304+0100 I NETWORK  [initandlisten] shutdown: going to close listening sockets...
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.304+0100 I NETWORK  [initandlisten] removing socket file: /tmp/mongodb-27017.sock
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.305+0100 I REPL     [initandlisten] shutdown: removing all drop-pending collections...
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.305+0100 I REPL     [initandlisten] shutdown: removing checkpointTimestamp collection...
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.305+0100 I REPL     [initandlisten] shutting down replication subsystems
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.305+0100 W REPL     [initandlisten] ReplicationCoordinatorImpl::shutdown() called before startup() finished.  Shutting down without cleaning up the replication system
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.306+0100 I STORAGE  [WTOplogJournalThread] oplog journal thread loop shutting down
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.306+0100 I STORAGE  [initandlisten] WiredTigerKVEngine shutting down
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.675+0100 I STORAGE  [initandlisten] WiredTiger message [1573037105:675647][25401:0x7f6af442ba40], txn-recover: Main recovery loop: starting at 22663/4352
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.811+0100 I STORAGE  [initandlisten] WiredTiger message [1573037105:811833][25401:0x7f6af442ba40], txn-recover: Recovering log 22663 through 22664
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.888+0100 I STORAGE  [initandlisten] WiredTiger message [1573037105:888972][25401:0x7f6af442ba40], txn-recover: Recovering log 22664 through 22664
Nov  6 11:45:05 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:05.963+0100 I STORAGE  [initandlisten] WiredTiger message [1573037105:963729][25401:0x7f6af442ba40], txn-recover: Set global recovery timestamp: 0
Nov  6 11:45:06 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:06.091+0100 I STORAGE  [initandlisten] shutdown: removing fs lock...
Nov  6 11:45:06 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:06.091+0100 I CONTROL  [initandlisten] now exiting
Nov  6 11:45:06 vps660936 rocketchat-server.rocketchat-mongo[25367]: 2019-11-06T11:45:06.092+0100 I CONTROL  [initandlisten] shutting down with code:62
Nov  6 11:45:06 vps660936 systemd[1]: snap.rocketchat-server.rocketchat-mongo.service: Main process exited, code=exited, status=62/n/a
Nov  6 11:45:06 vps660936 systemd[1]: snap.rocketchat-server.rocketchat-mongo.service: Failed with result 'exit-code'.
Nov  6 11:45:06 vps660936 systemd[1]: snap.rocketchat-server.rocketchat-mongo.service: Service hold-off time over, scheduling restart.
Nov  6 11:45:06 vps660936 systemd[1]: snap.rocketchat-server.rocketchat-mongo.service: Scheduled restart job, restart counter is at 154.
Nov  6 11:45:06 vps660936 systemd[1]: Stopped Service for snap application rocketchat-server.rocketchat-mongo.
Nov  6 11:45:06 vps660936 systemd[1]: Started Service for snap application rocketchat-server.rocketchat-mongo.
Nov  6 11:45:06 vps660936 rocketchat-server.rocketchat-mongo[25448]: 2019-11-06T11:45:06.396+0100 I CONTROL  [initandlisten] MongoDB starting : pid=25482 port=27017 dbpath=/var/snap/rocketchat-server/common 64-bit host=vps660936
Nov  6 11:45:06 vps660936 rocketchat-server.rocketchat-mongo[25448]: 2019-11-06T11:45:06.401+0100 I CONTROL  [initandlisten] db version v3.6.14
Nov  6 11:45:06 vps660936 rocketchat-server.rocketchat-mongo[25448]: 2019-11-06T11:45:06.402+0100 I CONTROL  [initandlisten] git version: cbef87692475857c7ee6e764c8f5104b39c342a1
Nov  6 11:45:06 vps660936 rocketchat-server.rocketchat-mongo[25448]: 2019-11-06T11:45:06.402+0100 I CONTROL  [initandlisten] allocator: tcmalloc
Nov  6 11:45:06 vps660936 rocketchat-server.rocketchat-mongo[25448]: 2019-11-06T11:45:06.402+0100 I CONTROL  [initandlisten] modules: none
Nov  6 11:45:06 vps660936 rocketchat-server.rocketchat-mongo[25448]: 2019-11-06T11:45:06.403+0100 I CONTROL  [initandlisten] build environment:
Nov  6 11:45:06 vps660936 rocketchat-server.rocketchat-mongo[25448]: 2019-11-06T11:45:06.403+0100 I CONTROL  [initandlisten]     distarch: x86_64
Nov  6 11:45:06 vps660936 rocketchat-server.rocketchat-mongo[25448]: 2019-11-06T11:45:06.403+0100 I CONTROL  [initandlisten]     target_arch: x86_64
Nov  6 11:45:06 vps660936 rocketchat-server.rocketchat-mongo[25448]: 2019-11-06T11:45:06.403+0100 I CONTROL  [initandlisten] options: { net: { bindIp: "127.0.0.1" }, processManagement: { pidFilePath: "/var/snap/rocketchat-server/common/mongod.pid" }, replication: { replSet: "rs0" }, storage: { dbPath: "/var/snap/rocketchat-server/common", journal: { enabled: true }, mmapv1: { smallFiles: true } } }
Nov  6 11:45:06 vps660936 rocketchat-server.rocketchat-mongo[25448]: 2019-11-06T11:45:06.406+0100 I -        [initandlisten] Detected data files in /var/snap/rocketchat-server/common created by the 'wiredTiger' storage engine, so setting the active storage engine to 'wiredTiger'.
Nov  6 11:45:06 vps660936 rocketchat-server.rocketchat-mongo[25448]: 2019-11-06T11:45:06.406+0100 I STORAGE  [initandlisten]
Nov  6 11:45:06 vps660936 rocketchat-server.rocketchat-mongo[25448]: 2019-11-06T11:45:06.406+0100 I STORAGE  [initandlisten] ** WARNING: Using the XFS filesystem is strongly recommended with the WiredTiger storage engine
Nov  6 11:45:06 vps660936 rocketchat-server.rocketchat-mongo[25448]: 2019-11-06T11:45:06.407+0100 I STORAGE  [initandlisten] **          See http://dochub.mongodb.org/core/prodnotes-filesystem
Nov  6 11:45:06 vps660936 rocketchat-server.rocketchat-mongo[25448]: 2019-11-06T11:45:06.407+0100 I STORAGE  [initandlisten] wiredtiger_open config: create,cache_size=460M,session_max=20000,eviction=(threads_min=4,threads_max=4),config_base=false,statistics=(fast),compatibility=(release="3.0",require_max="3.0"),log=(enabled=true,archive=true,path=journal,compressor=snappy),file_manager=(close_idle_time=100000),statistics_log=(wait=0),verbose=(recovery_progress),

Also I see a lot of new files in the directory /var/snap/rocketchat-server/common

root:/var/snap/rocketchat-server/common# ls -al
total 1936272
drwxr-xr-x 5 root root     24576 Nov  6 12:40 .
drwxr-xr-x 5 root root      4096 Nov  6 02:43 ..

-rw-r--r-- 1 root root   3825664 Nov  6 12:40 collection-11--25811209489162180.wt
 ... a lot of more here (cut because length of message ;-)
-rw-r--r-- 1 root root 762068992 Nov  6 12:40 collection-4--1485077525528355707.wt

drwxr-xr-x 2 root root      4096 Nov  6 02:42 diagnostic.data

-rw-r--r-- 1 root root      4096 Nov  6 02:42 index-0--25811209489162180.wt
 ... a lot of more here (cut because length of message ;-)
-rw-r--r-- 1 root root     36864 Nov  6 02:42 index-0--7308221755362267958.wt

drwxr-xr-x 2 root root      4096 Nov  6 12:40 journal
-rw-r--r-- 1 root root     57344 Nov  6 12:40 _mdb_catalog.wt
-rw-r--r-- 1 root root         0 Nov  6 12:40 mongod.lock
-rw-r--r-- 1 root root         6 Nov  6 12:40 mongod.pid
drwxr-xr-x 3 root root      4096 Mar 12  2019 restore
-rw-r--r-- 1 root root 256425330 Mar 12  2019 rocketchat_backup_20190312.0935.tar.gz
-rw-r--r-- 1 root root     61440 Nov  6 12:40 sizeStorer.wt
-rw-r--r-- 1 root root        95 Mar 12  2019 storage.bson
-rw-r--r-- 1 root root        46 Mar 12  2019 WiredTiger
-rw------- 1 root root      4096 Nov  6 12:40 WiredTigerLAS.wt
-rw-r--r-- 1 root root        21 Mar 12  2019 WiredTiger.lock
-rw------- 1 root root       976 Nov  6 12:40 WiredTiger.turtle
-rw-r--r-- 1 root root    806912 Nov  6 12:40 WiredTiger.wt

Something happened lat night at 02:42 definetely

[dw-dlh]

I had the same problem, and fixed mine. Apparently the snap tried to ‘jump’ too many mongodb versions?
NOTE: this ‘repair’ might get broken by the devs when they fix this.
I’m running snaps, your mileage might vary.

I fixed mine

• I got a copy of mongodb 3.4 from https://fastdl.mongodb.org/linux/mongodb-linux-x86_64-3.4.23.tgz (the “linux legacy” release) and unpacked it into root’s home folder

• I cd’d into the unpacked directory/bin and ran

• ./mongod --repair --dbpath /var/snap/rocketchat-server/common/

• then

• ./mongod --dbpath /var/snap/rocketchat-server/common/

• then in a separate session I ran ./mongo

• issued the command
  db.adminCommand( { setFeatureCompatibilityVersion: “3.4” } )

• exited mongo

• exited mongod (with ctrl-c)

• cd’d to /snap/rocketchat-server/current/bin

• ran
  ./mongod --repair --dbpath /var/snap/rocketchat-server/common/

• waited for it to finish

• rebooted (probably unnecessary)

• logged in (as I was impatient) and did
  tail -f /var/log/daemon.log

[skiiiks]

I LOVE YOU !!!
I read about the “db.adminCommand( { setFeatureCompatibilityVersion: “3.4” } )” staff, but I didn’t figure out how to “apply” it if mongo was unable to run
Your solution is brilliant !! now it’s working !!!

just one thing … now I’m seeing in the syslog a lot of these lines, any idea ?

Nov  6 15:49:01 vps660936 kernel: [  127.301312] audit: type=1400 audit(1573051741.000:414): apparmor="DENIED" operation="open" profile="snap.rocketchat-server.rocketchat-mongo" name="/proc/1104/net/netstat" pid=1104 comm="ftdc" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Nov  6 15:49:01 vps660936 kernel: [  127.301888] audit: type=1400 audit(1573051741.000:415): apparmor="DENIED" operation="open" profile="snap.rocketchat-server.rocketchat-mongo" name="/proc/1104/net/snmp" pid=1104 comm="ftdc" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Nov  6 15:49:02 vps660936 kernel: [  128.301323] audit: type=1400 audit(1573051742.000:416): apparmor="DENIED" operation="open" profile="snap.rocketchat-server.rocketchat-mongo" name="/proc/1104/net/netstat" pid=1104 comm="ftdc" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Nov  6 15:49:02 vps660936 kernel: [  128.301669] audit: type=1400 audit(1573051742.000:417): apparmor="DENIED" operation="open" profile="snap.rocketchat-server.rocketchat-mongo" name="/proc/1104/net/snmp" pid=1104 comm="ftdc" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Nov  6 15:49:03 vps660936 kernel: [  129.302134] audit: type=1400 audit(1573051743.000:418): apparmor="DENIED" operation="open" profile="snap.rocketchat-server.rocketchat-mongo" name="/proc/1104/net/netstat" pid=1104 comm="ftdc" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Nov  6 15:49:03 vps660936 kernel: [  129.302510] audit: type=1400 audit(1573051743.000:419): apparmor="DENIED" operation="open" profile="snap.rocketchat-server.rocketchat-mongo" name="/proc/1104/net/snmp" pid=1104 comm="ftdc" requested_mask="r" denied_mask="r" fsuid=0 ouid=0

[dw-dlh]

I got those when mongod did the repair. I have to admit, I have limited knowledge on how all these interactions work. I haven’t gotten any of those since restarting rocketchat and it “doing the upgrade”

If you’re not getting any more of them, it might have been database upgrade related - but I’m not certain. If you’re still getting them now, then I have no good suggestions.

[skiiiks]

Seems this solves the problem:
https://www.gitmemory.com/issue/RocketChat/Rocket.Chat/14562/498321790

Have a nice day !!!

[dw-dlh]

I didn’t find it before my blind jabs in the dark, but here’s an official thread including (down later in the thread) official recommended fixes for this problem for anyone else that encounters them.

SNAP NEWS - Rocket.Chat 2.1

The next snap release will bring your current RocketChat server to version 2! It will also upgrade two important dependencies, node and mongo. We will be releasing it next Thursday Oct, 31st, and it will auto refresh as usual. We added a functionality to allow you to make a backup of your RocketChat server database on refresh, please check first that the space needed for the backup is available in your system, and then run this command below if you want to backup your database before mongo up…

[Tallaras]

Yes this helped, but I have other problem. RocketChat start, missing 502 error BUT i have messages and everything before 1 April. Can someone have idea how fix this?