Roadmap Reveal 🗺 What's next for Rocket.Chat, Sep 22

RC stopped working after reboot

Description

Rebooted server that is hosting RC, mongo and caddy are both running but server will not start.

Server Setup Information

  • Version of Rocket.Chat Server: 3.16.4
  • Operating System: Ubuntu Server 20
  • Deployment Method: snap
  • Number of Running Instances: 1
  • DB Replicaset Oplog:
  • NodeJS Version:
  • MongoDB Version: 3.6.14
  • Proxy: caddy
  • Firewalls involved: None

Any additional Information

Hi.

Can you give us a bit more information please?

Some logs would help.

Your snap has probably just been updated to 3.17.x but that in itself should not break it.

Anything unusual about the install? Do you use sub directories?

Please let us know soonest so we can try and get you running.

Sorry it was late when I posted and meant to come back and fill in with logs. I removed out my domain with mydomain.com so you can ignore that part. Everything was working smoothly till the reboot. These logs are not really telling me anything.

chris@rocketchat:~$ snap info rocketchat-server
name:      rocketchat-server
summary:   Group chat server for 100s,  installed in seconds.
publisher: Rocket.Chat (rocketchat✓)
store-url: https://snapcraft.io/rocketchat-server
contact:   https://open.rocket.chat/channel/ubuntu-snap
license:   unset
description: |
  Slack-like online chat server for your office, group or family.   Up and running in seconds.
  Supports file sharing, video conference, geolocation, and much more.   Web and mobile client.  
  MIT licensed Open Source project.   List of features at  https://rocket.chat/ ,  MIT licensed
  source code at https://github.com/RocketChat/Rocket.Chat , 24 x 7 community support and community
  server at https://open.rocket.chat/
commands:
  - rocketchat-server.backupdb
  - rocketchat-server.initcaddy
  - rocketchat-server.mongo
  - rocketchat-server.restoredb
services:
  rocketchat-server.rocketchat-caddy: simple, enabled, active
  rocketchat-server.rocketchat-mongo: simple, enabled, active
  rocketchat-server:                  simple, enabled, inactive
snap-id:      wdBUbiEuMNHmAHLBCXQXOcXaOCvbWS1e
tracking:     3.x/stable
refresh-date: today at 14:44 EDT
channels:
  3.x/stable:       3.17.0      2021-08-16 (1482) 289MB -
  3.x/candidate:    3.17.0-rc.5 2021-07-30 (1481) 288MB -
  3.x/beta:         ↑                                   
  3.x/edge:         3.17.0      2021-07-31 (1482) 289MB -
  latest/stable:    2.4.14      2020-12-23 (1453) 267MB -
  latest/candidate: 2.4.14      2021-07-30 (1453) 267MB -
  latest/beta:      2.1.1       2019-10-21 (1414) 251MB -
  latest/edge:      2.4.11      2021-05-11 (1427) 267MB -
  2.x/stable:       2.4.14      2020-12-23 (1453) 267MB -
  2.x/candidate:    2.4.14      2020-12-23 (1453) 267MB -
  2.x/beta:         2.4.14      2020-12-23 (1453) 267MB -
  2.x/edge:         ↑                                   
installed:          3.16.4                 (1480) 282MB -

CAddy

chris@rocketchat:~$ systemctl status snap.rocketchat-server.rocketchat-caddy
● 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: active (running) since Tue 2021-08-17 14:49:42 EDT; 12min ago
   Main PID: 621 (caddy)
      Tasks: 7 (limit: 4489)
     Memory: 32.8M
     CGroup: /system.slice/snap.rocketchat-server.rocketchat-caddy.service
             └─621 caddy -conf=/var/snap/rocketchat-server/1480/Caddyfile

Aug 17 14:49:42 rocketchat systemd[1]: Started Service for snap application rocketchat-server.rocketchat-caddy.
Aug 17 14:49:51 rocketchat rocketchat-server.rocketchat-caddy[621]: Activating privacy features... done.
Aug 17 14:49:51 rocketchat rocketchat-server.rocketchat-caddy[621]: Serving HTTPS on port 443
Aug 17 14:49:51 rocketchat rocketchat-server.rocketchat-caddy[621]: https://chat.mydomain.com
Aug 17 14:49:51 rocketchat rocketchat-server.rocketchat-caddy[621]: Serving HTTP on port 80
Aug 17 14:49:51 rocketchat rocketchat-server.rocketchat-caddy[621]: http://chat.mydomain.com
Aug 17 14:49:51 rocketchat rocketchat-server.rocketchat-caddy[621]: WARNING: File descriptor limit 1024 is too low for production servers. At least 8192 is recommended. Fix with `ulimit -n 8192`.

Mongo

chris@rocketchat:~$ systemctl status snap.rocketchat-server.rocketchat-mongo
● 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 Tue 2021-08-17 14:49:42 EDT; 13min ago
   Main PID: 622 (sh)
      Tasks: 70 (limit: 4489)
     Memory: 209.4M
     CGroup: /system.slice/snap.rocketchat-server.rocketchat-mongo.service
             ├─622 /bin/sh /snap/rocketchat-server/1480/bin/startmongo
             └─777 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

Aug 17 14:49:58 rocketchat rocketchat-server.rocketchat-mongo[777]: 2021-08-17T14:49:58.582-0400 I REPL     [replexec-0] Starting replication reporter thread
Aug 17 14:49:58 rocketchat rocketchat-server.rocketchat-mongo[777]: 2021-08-17T14:49:58.584-0400 I REPL     [rsSync] transition to SECONDARY from RECOVERING
Aug 17 14:49:58 rocketchat rocketchat-server.rocketchat-mongo[777]: 2021-08-17T14:49:58.585-0400 I REPL     [rsSync] conducting a dry run election to see if we could be elected. current term: 65
Aug 17 14:49:58 rocketchat rocketchat-server.rocketchat-mongo[777]: 2021-08-17T14:49:58.585-0400 I REPL     [replexec-0] dry election run succeeded, running for election in term 66
Aug 17 14:49:58 rocketchat rocketchat-server.rocketchat-mongo[777]: 2021-08-17T14:49:58.615-0400 I REPL     [replexec-2] election succeeded, assuming primary role in term 66
Aug 17 14:49:58 rocketchat rocketchat-server.rocketchat-mongo[777]: 2021-08-17T14:49:58.615-0400 I REPL     [replexec-2] transition to PRIMARY from SECONDARY
Aug 17 14:49:58 rocketchat rocketchat-server.rocketchat-mongo[777]: 2021-08-17T14:49:58.616-0400 I REPL     [replexec-2] Resetting sync source to empty, which was :27017
Aug 17 14:49:58 rocketchat rocketchat-server.rocketchat-mongo[777]: 2021-08-17T14:49:58.616-0400 I REPL     [replexec-2] Entering primary catch-up mode.
Aug 17 14:49:58 rocketchat rocketchat-server.rocketchat-mongo[777]: 2021-08-17T14:49:58.616-0400 I REPL     [replexec-2] Exited primary catch-up mode.
Aug 17 14:50:00 rocketchat rocketchat-server.rocketchat-mongo[777]: 2021-08-17T14:50:00.597-0400 I REPL     [rsSync] transition to primary complete; database writes are now permitted
chris@rocketchat:~$ sudo snap logs -f rocketchat-server.rocketchat-mongo
2021-08-17T18:49:58Z rocketchat-server.rocketchat-mongo[777]: 2021-08-17T14:49:58.582-0400 I REPL     [replexec-0] Starting replication reporter thread
2021-08-17T18:49:58Z rocketchat-server.rocketchat-mongo[777]: 2021-08-17T14:49:58.584-0400 I REPL     [rsSync] transition to SECONDARY from RECOVERING
2021-08-17T18:49:58Z rocketchat-server.rocketchat-mongo[777]: 2021-08-17T14:49:58.585-0400 I REPL     [rsSync] conducting a dry run election to see if we could be elected. current term: 65
2021-08-17T18:49:58Z rocketchat-server.rocketchat-mongo[777]: 2021-08-17T14:49:58.585-0400 I REPL     [replexec-0] dry election run succeeded, running for election in term 66
2021-08-17T18:49:58Z rocketchat-server.rocketchat-mongo[777]: 2021-08-17T14:49:58.615-0400 I REPL     [replexec-2] election succeeded, assuming primary role in term 66
2021-08-17T18:49:58Z rocketchat-server.rocketchat-mongo[777]: 2021-08-17T14:49:58.615-0400 I REPL     [replexec-2] transition to PRIMARY from SECONDARY
2021-08-17T18:49:58Z rocketchat-server.rocketchat-mongo[777]: 2021-08-17T14:49:58.616-0400 I REPL     [replexec-2] Resetting sync source to empty, which was :27017
2021-08-17T18:49:58Z rocketchat-server.rocketchat-mongo[777]: 2021-08-17T14:49:58.616-0400 I REPL     [replexec-2] Entering primary catch-up mode.
2021-08-17T18:49:58Z rocketchat-server.rocketchat-mongo[777]: 2021-08-17T14:49:58.616-0400 I REPL     [replexec-2] Exited primary catch-up mode.
2021-08-17T18:50:00Z rocketchat-server.rocketchat-mongo[777]: 2021-08-17T14:50:00.597-0400 I REPL     [rsSync] transition to primary complete; database writes are now permitted

Server

chris@rocketchat:~$ systemctl status snap.rocketchat-server.rocketchat-server
● 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: inactive (dead) since Tue 2021-08-17 14:49:51 EDT; 13min ago
    Process: 625 ExecStart=/usr/bin/snap run rocketchat-server (code=exited, status=0/SUCCESS)
   Main PID: 625 (code=exited, status=0/SUCCESS)

Aug 17 14:49:42 rocketchat systemd[1]: Started Service for snap application rocketchat-server.rocketchat-server.
Aug 17 14:49:51 rocketchat systemd[1]: snap.rocketchat-server.rocketchat-server.service: Succeeded.
chris@rocketchat:~$ sudo snap logs -f rocketchat-server.rocketchat-server
2021-08-17T18:43:21Z systemd[1]: snap.rocketchat-server.rocketchat-server.service: Succeeded.
2021-08-17T18:44:31Z systemd[1]: Started Service for snap application rocketchat-server.rocketchat-server.
2021-08-17T18:44:32Z rocketchat-server.rocketchat-server[1656]: Mongo is not available, can't start. Waiting 10 seconds and trying again
2021-08-17T18:44:36Z systemd[1]: Stopping Service for snap application rocketchat-server.rocketchat-server...
2021-08-17T18:44:36Z systemd[1]: snap.rocketchat-server.rocketchat-server.service: Succeeded.
2021-08-17T18:44:36Z systemd[1]: Stopped Service for snap application rocketchat-server.rocketchat-server.
2021-08-17T18:44:51Z systemd[1]: Started Service for snap application rocketchat-server.rocketchat-server.
2021-08-17T18:44:52Z systemd[1]: snap.rocketchat-server.rocketchat-server.service: Succeeded.
2021-08-17T18:49:42Z systemd[1]: Started Service for snap application rocketchat-server.rocketchat-server.
2021-08-17T18:49:51Z systemd[1]: snap.rocketchat-server.rocketchat-server.service: Succeeded.

Hmmm - you should have been updated to 3.17.0 I think but you show 3.16.4

Also I can’t see where it is failing - this shows Rocket running

Here it is waiting til Mongo is up as expected:

2021-08-17T18:44:32Z rocketchat-server.rocketchat-server[1656]: Mongo is not available, can’t start. Waiting 10 seconds and trying again

And this shows it is running:

2021-08-17T18:49:51Z systemd[1]: snap.rocketchat-server.rocketchat-server.service: Succeeded.

There don’t appear to be any other errors?

Hi :wave:

The actual server is not running. The simplest way to fix this would be to run sudo snap restart rocketchat-server OR - since all the other parts are running, simply start/restart the rocketchat-server service like so - sudo snap start rocketchat-server.rocketchat-server.

Bother - thanks Debdut. Losing my touch :worried:

I missed this I think:

Active: inactive (dead) since Tue 2021-08-17 14:49:51 EDT; 13min ago

SystemdD… :frowning:

1 Like

You’re getting old :ghost: , leave, now, before it’s too late !

Oh dear. You are right.

:wave:

sudo snap restart rocketchat-server OR sudo snap start rocketchat-server.rocketchat-server

Tried both, still not running

The problem was rocketchat could not access /sys/blocks. Ended up finding the problem inside sys.log. Would have been nice if this error was reported when you do snap status or in the snap logs.

Can you show us the log snippet? Also how you fixed it exactly?

I have already cleared the logs. I figured since rocket chat wasnt really giving me any idea of what was happening I would check the system logs. Looking through the syslog I saw “Access Denied” when rocket chat was trying to access /sys/blocks. Changed the privileges and rocket chat started up. Might be worth the Dev team capturing errors like that so users can know exactly where the problem is.