RocketChat suddenly unavailable (MongoDB connection refused)

Description

Our RocketChat server stopped working yesterday evening (as far as I can tell after an auto-update). It only presents a “Service Unavailable” error via the web interface.

I tried reverting it and also reinstalled and restored the last backup but could not revive it yet.

The overall message from the Web server is

Service Unavailable

The server is temporarily unable to service your request due to maintenance downtime or capacity problems. Please try again later.

Apache/2.4.25 (Debian) Server at chat.km3net.de Port 443

And the caddy service is not coming up:

root@pi1145:~# snap services
Service                              Startup  Current   Notes
rocketchat-server.rocketchat-caddy   enabled  inactive  -
rocketchat-server.rocketchat-mongo   enabled  active    -
rocketchat-server.rocketchat-server  enabled  active    -

Snap status reports it’s running rocketchat-server 3.2.2:

root@pi1145:~# snap list
Name               Version    Rev   Tracking       Publisher    Notes
core               16-2.44.3  9066  latest/stable  canonical*   core
rocketchat-server  3.2.2      1433  3.x/stable     rocketchat*  -

Caddy:

root@pi1145:~# service snap.rocketchat-server.rocketchat-caddy status
* snap.rocketchat-server.rocketchat-caddy.service - Service for snap application rocketchat-server.rocketchat-caddy
   Loaded: loaded (/etc/systemd/system/snap.rocketchat-server.rocketchat-caddy.service; enabled; vendor preset: enabled)
   Active: failed (Result: exit-code) since Wed 2020-05-13 01:54:16 CEST; 20h ago
  Process: 4037 ExecStart=/usr/bin/snap run rocketchat-server.rocketchat-caddy (code=exited, status=1/FAILURE)
 Main PID: 4037 (code=exited, status=1/FAILURE)

Warning: Journal has been rotated since unit was started. Log output is incomplete or unavailable.

Server

root@pi1145:~# service snap.rocketchat-server.rocketchat-server status
* snap.rocketchat-server.rocketchat-server.service - Service for snap application rocketchat-server.rocketchat-server
   Loaded: loaded (/etc/systemd/system/snap.rocketchat-server.rocketchat-server.service; enabled; vendor preset: enabled)
   Active: active (running) since Wed 2020-05-13 22:30:47 CEST; 2s ago
 Main PID: 20632 (startRocketChat)
    Tasks: 8 (limit: 4915)
   CGroup: /system.slice/snap.rocketchat-server.rocketchat-server.service
           |-20632 /bin/bash /snap/rocketchat-server/1433/bin/startRocketChat
           `-20693 node /snap/rocketchat-server/1433/main.js

May 13 22:30:47 pi1145 rocketchat-server.rocketchat-server[20632]: MongoDB shell version v3.6.14
May 13 22:30:47 pi1145 rocketchat-server.rocketchat-server[20632]: connecting to: mongodb://127.0.0.1:27017/?gssapiServiceName=mongodb
May 13 22:30:47 pi1145 rocketchat-server.rocketchat-server[20632]: 2020-05-13T22:30:47.559+0200 W NETWORK  [thread1] Failed to connect to 127.0.0.1:27017, in(checking socket for error after poll), reason: Connection refused
May 13 22:30:47 pi1145 rocketchat-server.rocketchat-server[20632]: 2020-05-13T22:30:47.560+0200 E QUERY    [thread1] Error: couldn't connect to server 127.0.0.1:27017, connection attempt failed :
May 13 22:30:47 pi1145 rocketchat-server.rocketchat-server[20632]: connect@src/mongo/shell/mongo.js:263:13
May 13 22:30:47 pi1145 rocketchat-server.rocketchat-server[20632]: @(connect):1:6
May 13 22:30:47 pi1145 rocketchat-server.rocketchat-server[20632]: exception: connect failed
May 13 22:30:47 pi1145 rocketchat-server.rocketchat-server[20632]: Checking if mongo featureCompatibilityVersion is correct, changing if not
May 13 22:30:47 pi1145 rocketchat-server.rocketchat-server[20632]: exception: connect failed
May 13 22:30:47 pi1145 rocketchat-server.rocketchat-server[20632]: exception: connect failed

MongoDB

* snap.rocketchat-server.rocketchat-mongo.service - Service for snap application rocketchat-server.rocketchat-mongo
   Loaded: loaded (/etc/systemd/system/snap.rocketchat-server.rocketchat-mongo.service; enabled; vendor preset: enabled)
   Active: active (running) since Wed 2020-05-13 22:31:06 CEST; 835ms ago
 Main PID: 21109 (sh)
    Tasks: 4 (limit: 4915)
   CGroup: /system.slice/snap.rocketchat-server.rocketchat-mongo.service
           |-21109 /bin/sh /snap/rocketchat-server/1433/bin/startmongo
           `-21138 mongod --bind_ip 127.0.0.1 --pidfilepath /var/snap/rocketchat-server/common/mongod.pid --smallfiles --journal --dbpath=/var/snap/rocketchat-server/common --replSet rs0

May 13 22:31:06 pi1145 rocketchat-server.rocketchat-mongo[21109]: 2020-05-13T22:31:06.201+0200 I CONTROL  [initandlisten] modules: none
May 13 22:31:06 pi1145 rocketchat-server.rocketchat-mongo[21109]: 2020-05-13T22:31:06.202+0200 I CONTROL  [initandlisten] build environment:
May 13 22:31:06 pi1145 rocketchat-server.rocketchat-mongo[21109]: 2020-05-13T22:31:06.202+0200 I CONTROL  [initandlisten]     distarch: x86_64
May 13 22:31:06 pi1145 rocketchat-server.rocketchat-mongo[21109]: 2020-05-13T22:31:06.202+0200 I CONTROL  [initandlisten]     target_arch: x86_64
May 13 22:31:06 pi1145 rocketchat-server.rocketchat-mongo[21109]: 2020-05-13T22:31:06.202+0200 I CONTROL  [initandlisten] options: { net: { bindIp: "127.0.0.1" }, processManagement: { pidFilePath: "/var/snap/rocketchat-server/common/mongod.pid" }, replicat
May 13 22:31:06 pi1145 rocketchat-server.rocketchat-mongo[21109]: 2020-05-13T22:31:06.202+0200 I -        [initandlisten] Detected data files in /var/snap/rocketchat-server/common created by the 'wiredTiger' storage engine, so setting the active storage en
May 13 22:31:06 pi1145 rocketchat-server.rocketchat-mongo[21109]: 2020-05-13T22:31:06.202+0200 I STORAGE  [initandlisten]
May 13 22:31:06 pi1145 rocketchat-server.rocketchat-mongo[21109]: 2020-05-13T22:31:06.203+0200 I STORAGE  [initandlisten] ** WARNING: Using the XFS filesystem is strongly recommended with the WiredTiger storage engine
May 13 22:31:06 pi1145 rocketchat-server.rocketchat-mongo[21109]: 2020-05-13T22:31:06.203+0200 I STORAGE  [initandlisten] **          See http://dochub.mongodb.org/core/prodnotes-filesystem
May 13 22:31:06 pi1145 rocketchat-server.rocketchat-mongo[21109]: 2020-05-13T22:31:06.204+0200 I STORAGE  [initandlisten] wiredtiger_open config: create,cache_size=2402M,session_max=20000,eviction=(threads_min=4,threads_max=4),config_base=false,statistics=

Server Setup Information

  • Version of Rocket.Chat Server: 3.2.2
  • Operating System: Linux pi1145 4.9.0-11-amd64 #1 SMP Debian 4.9.189-3+deb9u2 (2019-11-11) x86_64 GNU/Linux
  • Deployment Method: snap
  • Number of Running Instances: 1
  • DB Replicaset Oplog:
  • NodeJS Version:
  • MongoDB Version: db version v3.6.14
  • Proxy: apache
  • Firewalls involved:

Any additional Information

Here is the snap changes rocketchat-server output:

root@pi1145:~# snap changes --abs-time rocketchat-server
ID   Status  Spawn                      Ready                      Summary
50   Done    2020-05-12T23:44:23+02:00  2020-05-12T23:44:59+02:00  Refresh "rocketchat-server" snap from "2.x/stable" channel
51   Done    2020-05-13T01:23:21+02:00  2020-05-13T01:23:30+02:00  Revert "rocketchat-server" snap
52   Done    2020-05-13T01:29:53+02:00  2020-05-13T01:29:53+02:00  Change configuration of "rocketchat-server" snap
54   Done    2020-05-13T01:42:22+02:00  2020-05-13T01:46:18+02:00  Remove "rocketchat-server" snap
55   Done    2020-05-13T01:46:41+02:00  2020-05-13T01:46:56+02:00  Install "rocketchat-server" snap
1 Like

I got it working with a combination of restoring /var/snap/rocketchat-server/common from the regular system backups, restoring a previous snapshot (snap restore ...) from snap itself and installing a version from channel 2.x (snap install rocketchat-server --channel=2.x).

What is the process to restore a snapshot from rocket chat? I ran snap restore 1 and it displays a message that rocketchat-server is restored but if I run snap list, it only shows the core.