Failed to start rocketchat-server (snap) on Ubuntu 18.04 - Start request repeated too quickly.

[tuxmartin]

I have clean install of Ubuntu 18.04.1 and only core snap package installed.

After install of snap rocket-server, everything is ok. But after I restart snap.rocketchat-server.rocketchat-server.service or reboot server, rocket-chat do not start.

Multiple restart of service do not help.

root@rc:/# lsb_release -a
No LSB modules are available.
Distributor ID:	Ubuntu
Description:	Ubuntu 18.04.1 LTS
Release:	18.04
Codename:	bionic
root@rc:/# ls -lh /var/snap/
total 4.0K
drwxr-xr-x 4 root root 4.0K Oct  4 01:31 core
root@rc:/# ls -lh /snap/
total 12K
drwxr-xr-x 2 root root 4.0K Oct  8 22:14 bin
drwxr-xr-x 3 root root 4.0K Oct  4 01:31 core
-r--r--r-- 1 root root  548 Oct  4 01:31 README
root@rc:/# snap list
Name  Version    Rev   Tracking  Publisher   Notes
core  16-2.35.2  5548  stable    canonical✓  core
root@rc:/# 
root@rc:/# snap install rocketchat-server
rocketchat-server 0.69.2 from Rocket.Chat (rocketchat✓) installed
root@rc:/# 
root@rc:/# systemctl is-active snap.rocketchat-server.rocketchat-server.service 
active
root@rc:/# systemctl restart snap.rocketchat-server.rocketchat-server.service
root@rc:/# 
root@rc:/# systemctl is-active snap.rocketchat-server.rocketchat-server.service 
failed
root@rc:/#
root@rc:/# systemctl status snap.rocketchat-server.rocketchat-server.service
● 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: failed (Result: exit-code) since Mon 2018-10-08 22:17:47 CEST; 3s ago
  Process: 1942 ExecStart=/usr/bin/snap run rocketchat-server (code=exited, status=1/FAILURE)
 Main PID: 1942 (code=exited, status=1/FAILURE)

Oct 08 22:17:47 rc.vancl.eu systemd[1]: snap.rocketchat-server.rocketchat-server.service: Failed with result 'exit-code'.
Oct 08 22:17:47 rc.vancl.eu systemd[1]: snap.rocketchat-server.rocketchat-server.service: Service hold-off time over, scheduling restart.
Oct 08 22:17:47 rc.vancl.eu systemd[1]: snap.rocketchat-server.rocketchat-server.service: Scheduled restart job, restart counter is at 5.
Oct 08 22:17:47 rc.vancl.eu systemd[1]: Stopped Service for snap application rocketchat-server.rocketchat-server.
Oct 08 22:17:47 rc.vancl.eu systemd[1]: snap.rocketchat-server.rocketchat-server.service: Start request repeated too quickly.
Oct 08 22:17:47 rc.vancl.eu systemd[1]: snap.rocketchat-server.rocketchat-server.service: Failed with result 'exit-code'.
Oct 08 22:17:47 rc.vancl.eu systemd[1]: Failed to start Service for snap application rocketchat-server.rocketchat-server.
root@rc:/# 
root@rc:/# snap list
Name               Version    Rev   Tracking  Publisher    Notes
core               16-2.35.2  5548  stable    canonical✓   core
rocketchat-server  0.69.2     1324  stable    rocketchat✓  -
root@rc:/# 

• Ubuntu 18.04.1 64b.
• Rocket Chat server snap version 0.69.2

[reetp]

Think you need to try and debug rocket starting to see what is going on.

Something like this may help get more information (always worth a search on the interwebs first when you get an issue)

https://askubuntu.com/questions/783979/how-do-i-debug-snaps
https://askubuntu.com/questions/873495/how-do-i-use-snappy-debug-to-debug-a-snap

There may be other links that will help you get a log of rocket starting

[tuxmartin]

I tried snappy-debug, but it's not working:

root@rc:/# snap list
Name               Version           Rev   Tracking  Publisher    Notes
core               16-2.35.2         5548  stable    canonical✓   core
rocketchat-server  0.69.2            1324  stable    rocketchat✓  -
snappy-debug       0.31.7-snapd2.34  243   stable    canonical✓   -
root@rc:/# 
root@rc:/# snap interfaces rocketchat-server
Slot           Plug
:network       rocketchat-server
:network-bind  rocketchat-server
root@rc:/# 
root@rc:/# snap interfaces snappy-debug
Slot          Plug
:log-observe  snappy-debug
root@rc:/# 
root@rc:/# snap connect snappy-debug:log-observe rocketchat-server:network
error: snap "rocketchat-server" has no slot named "network"
root@rc:/# 
root@rc:/# snap connect snappy-debug:log-observe rocketchat-server:network-bind
error: snap "rocketchat-server" has no slot named "network-bind"
root@rc:/# 

[reetp]

Hmmm (I've never used snaps so just doing some basic searching which you could try too......)

https://askubuntu.com/questions/784489/how-do-system-services-work-in-snaps
See the comment at the bottom about trying to run it as a normal application

My guess is there is something wrong with rocket being able to connect, either to the outside world or mongo or somesuch.

If we read here we can see the interface names
https://docs.ubuntu.com/core/en/reference/interfaces/

Ahhhh..... and just foudn this

https://rocket.chat/docs/installation/manual-installation/ubuntu/snaps/#faq

See the last section.

[tuxmartin]

Hmmm (I've never used snaps so just doing some basic searching which you could try too......)

I never used snap too.

Rocket chat is my first snap use. But it is recommended install method on rocket.chat web, so I tried it.

[reetp]

Have you checked Mongo is running as per the FAQs?
sudo service snap.rocketchat-server.rocketchat-mongo status

Have you looked at the logs via this?
sudo journalctl -f -u snap.rocketchat-server.rocketchat-server
sudo journalctl -f -u snap.rocketchat-server.rocketchat-mongo

(note this is a bug tracker, not really a support forum, so you need to do a bit of heavy lifting yourself here...... if you have not used snaps before it might help to read more about them etc)

[tuxmartin]

I reinstalled Ubuntu on my VPS - nothing change, still the same error.

Mongo is not running. If I start it systemctl start snap.rocketchat-server.rocketchat-mongo.service, it fails.

I have clean install of ubuntu 18.04.1 server. So there are no conflicts with other apps.

If I would have old installation of debian(7,8)/ubuntu(14.04/16.04) or not standard configuration, I will understand problem. But on clean ubuntu server installation?

There are logs (I cannot find more useful logs).:

root@rc:/# systemctl status snap.rocketchat-server.rocketchat-*
● 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: failed (Result: exit-code) since Tue 2018-10-09 13:08:28 CEST; 54s ago
  Process: 1489 ExecStart=/usr/bin/snap run rocketchat-server.rocketchat-mongo (code=exited, status=1/FAILURE)
 Main PID: 1489 (code=exited, status=1/FAILURE)

Oct 09 13:08:27 rc.vancl.eu systemd[1]: snap.rocketchat-server.rocketchat-mongo.service: Failed with result 'exit-code'.
Oct 09 13:08:28 rc.vancl.eu systemd[1]: snap.rocketchat-server.rocketchat-mongo.service: Service hold-off time over, scheduling restart.
Oct 09 13:08:28 rc.vancl.eu systemd[1]: snap.rocketchat-server.rocketchat-mongo.service: Scheduled restart job, restart counter is at 5.
Oct 09 13:08:28 rc.vancl.eu systemd[1]: Stopped Service for snap application rocketchat-server.rocketchat-mongo.
Oct 09 13:08:28 rc.vancl.eu systemd[1]: snap.rocketchat-server.rocketchat-mongo.service: Start request repeated too quickly.
Oct 09 13:08:28 rc.vancl.eu systemd[1]: snap.rocketchat-server.rocketchat-mongo.service: Failed with result 'exit-code'.
Oct 09 13:08:28 rc.vancl.eu systemd[1]: Failed to start Service for snap application rocketchat-server.rocketchat-mongo.

● 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 Tue 2018-10-09 13:08:27 CEST; 55s ago
  Process: 1457 ExecStart=/usr/bin/snap run rocketchat-server.rocketchat-caddy (code=exited, status=1/FAILURE)
 Main PID: 1457 (code=exited, status=1/FAILURE)

Oct 09 13:08:27 rc.vancl.eu systemd[1]: snap.rocketchat-server.rocketchat-caddy.service: Failed with result 'exit-code'.
Oct 09 13:08:27 rc.vancl.eu systemd[1]: snap.rocketchat-server.rocketchat-caddy.service: Service hold-off time over, scheduling restart.
Oct 09 13:08:27 rc.vancl.eu systemd[1]: snap.rocketchat-server.rocketchat-caddy.service: Scheduled restart job, restart counter is at 5.
Oct 09 13:08:27 rc.vancl.eu systemd[1]: Stopped Service for snap application rocketchat-server.rocketchat-caddy.
Oct 09 13:08:27 rc.vancl.eu systemd[1]: snap.rocketchat-server.rocketchat-caddy.service: Start request repeated too quickly.
Oct 09 13:08:27 rc.vancl.eu systemd[1]: snap.rocketchat-server.rocketchat-caddy.service: Failed with result 'exit-code'.
Oct 09 13:08:27 rc.vancl.eu systemd[1]: Failed to start Service for snap application rocketchat-server.rocketchat-caddy.

● 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: failed (Result: exit-code) since Tue 2018-10-09 13:08:28 CEST; 54s ago
  Process: 1488 ExecStart=/usr/bin/snap run rocketchat-server (code=exited, status=1/FAILURE)
 Main PID: 1488 (code=exited, status=1/FAILURE)

Oct 09 13:08:27 rc.vancl.eu systemd[1]: snap.rocketchat-server.rocketchat-server.service: Failed with result 'exit-code'.
Oct 09 13:08:28 rc.vancl.eu systemd[1]: snap.rocketchat-server.rocketchat-server.service: Service hold-off time over, scheduling restart.
Oct 09 13:08:28 rc.vancl.eu systemd[1]: snap.rocketchat-server.rocketchat-server.service: Scheduled restart job, restart counter is at 5.
Oct 09 13:08:28 rc.vancl.eu systemd[1]: Stopped Service for snap application rocketchat-server.rocketchat-server.
Oct 09 13:08:28 rc.vancl.eu systemd[1]: snap.rocketchat-server.rocketchat-server.service: Start request repeated too quickly.
Oct 09 13:08:28 rc.vancl.eu systemd[1]: snap.rocketchat-server.rocketchat-server.service: Failed with result 'exit-code'.
Oct 09 13:08:28 rc.vancl.eu systemd[1]: Failed to start Service for snap application rocketchat-server.rocketchat-server.
root@rc:/# 
root@rc:/# journalctl -f -u snap.rocketchat-server.rocketchat-server
-- Logs begin at Mon 2018-09-03 16:57:20 CEST. --
Oct 09 13:08:27 rc.vancl.eu rocketchat-server.rocketchat-server[1488]: cannot change profile for the next exec call: No such file or directory
Oct 09 13:08:27 rc.vancl.eu rocketchat-server.rocketchat-server[1488]: snap-update-ns failed with code 1
Oct 09 13:08:27 rc.vancl.eu systemd[1]: snap.rocketchat-server.rocketchat-server.service: Main process exited, code=exited, status=1/FAILURE
Oct 09 13:08:27 rc.vancl.eu systemd[1]: snap.rocketchat-server.rocketchat-server.service: Failed with result 'exit-code'.
Oct 09 13:08:28 rc.vancl.eu systemd[1]: snap.rocketchat-server.rocketchat-server.service: Service hold-off time over, scheduling restart.
Oct 09 13:08:28 rc.vancl.eu systemd[1]: snap.rocketchat-server.rocketchat-server.service: Scheduled restart job, restart counter is at 5.
Oct 09 13:08:28 rc.vancl.eu systemd[1]: Stopped Service for snap application rocketchat-server.rocketchat-server.
Oct 09 13:08:28 rc.vancl.eu systemd[1]: snap.rocketchat-server.rocketchat-server.service: Start request repeated too quickly.
Oct 09 13:08:28 rc.vancl.eu systemd[1]: snap.rocketchat-server.rocketchat-server.service: Failed with result 'exit-code'.
Oct 09 13:08:28 rc.vancl.eu systemd[1]: Failed to start Service for snap application rocketchat-server.rocketchat-server.
^C
root@rc:/# 
root@rc:/# journalctl -f -u snap.rocketchat-server.rocketchat-mongo
-- Logs begin at Mon 2018-09-03 16:57:20 CEST. --
Oct 09 13:08:27 rc.vancl.eu rocketchat-server.rocketchat-mongo[1489]: cannot change profile for the next exec call: No such file or directory
Oct 09 13:08:27 rc.vancl.eu rocketchat-server.rocketchat-mongo[1489]: snap-update-ns failed with code 1
Oct 09 13:08:27 rc.vancl.eu systemd[1]: snap.rocketchat-server.rocketchat-mongo.service: Main process exited, code=exited, status=1/FAILURE
Oct 09 13:08:27 rc.vancl.eu systemd[1]: snap.rocketchat-server.rocketchat-mongo.service: Failed with result 'exit-code'.
Oct 09 13:08:28 rc.vancl.eu systemd[1]: snap.rocketchat-server.rocketchat-mongo.service: Service hold-off time over, scheduling restart.
Oct 09 13:08:28 rc.vancl.eu systemd[1]: snap.rocketchat-server.rocketchat-mongo.service: Scheduled restart job, restart counter is at 5.
Oct 09 13:08:28 rc.vancl.eu systemd[1]: Stopped Service for snap application rocketchat-server.rocketchat-mongo.
Oct 09 13:08:28 rc.vancl.eu systemd[1]: snap.rocketchat-server.rocketchat-mongo.service: Start request repeated too quickly.
Oct 09 13:08:28 rc.vancl.eu systemd[1]: snap.rocketchat-server.rocketchat-mongo.service: Failed with result 'exit-code'.
Oct 09 13:08:28 rc.vancl.eu systemd[1]: Failed to start Service for snap application rocketchat-server.rocketchat-mongo.
^C
root@rc:/# 

[reetp]

Can you please go back and fill in some of the details from the bug template (you should ALWAYS do this whenever you report an issue as it saves a lot of time and questions)

https://rocket.chat/docs/contributing/reporting-issues/
https://github.com/RocketChat/Rocket.Chat/issues/new?template=bug_report.md

Particularly make a note of your hardware/processor as I believe there is a potential race condition on ARM though I am not sure that is relevant here.

I'm pretty sure something went awry on your install and I think we probably need to get @geekgonecrazy to take a look as he seems to be the snap guru :-)

[tuxmartin]

Description:

I have clean install of Ubuntu 18.04.1 and only core snap package installed.

After install of snap rocket-server, everything is ok. But after I restart snap.rocketchat-server.rocketchat-server.service or reboot server, rocket-chat do not start.

Multiple restart of service do not help.

I reinstalled Ubuntu on my VPS - nothing change, still the same error.

Mongo is not running. If I start it systemctl start snap.rocketchat-server.rocketchat-mongo.service, it fails.

Steps to reproduce:

1. Create VPN on https://www.forpsicloud.cz/ with template "Ubuntu 18.04.1 server"
2. Login as root and run "snap install rocketchat-server"
3. Restart rocket.chat server: "systemctl restart snap.rocketchat-server.rocketchat-server.service"

Expected behavior:

Restart snap.rocketchat-server.rocketchat-server.service or reboot server do not break rocketchat-server :-)

Actual behavior:

After restart is not possible to start rocket.chat server again.

Server Setup Information:

• Version of Rocket.Chat Server: latest stable snap - 0.69.2
• Operating System: Ubuntu 18.04.1 LTS, 4.15.0-36-generic
• Deployment Method: snap
• Number of Running Instances: 1
• DB Replicaset Oplog: I used snap package.
• NodeJS Version: I used snap package.
• MongoDB Version: I used snap package.

Additional context

Upgrade apt packages do not help.

I have second VPS (1GB RAM, 20GB SSD) with Debian 9 and rocket.chat server works without any problem.

VPS:

• Provider: forpsicloud.cz
• RAM: 1GB
• Disk: 20GB SSD

[geekgonecrazy]

what do the logs show when you restart it that way?

I'd recommend using: sudo snap disable rocketchat-server this stops everything. Then sudo snap enable rocketchat-server which will bring everything back up and in operation unless there is a real issue in the logs.

If so for sure check logs: https://rocket.chat/docs/installation/manual-installation/ubuntu/snaps/#how-can-i-view-the-logs

[reetp]

@geekgonecrazy
Note his mongo seems dead too.... seems to be affecting both services, not just rocket.

[geekgonecrazy]

Yes if I had to guess I would say for some reason mongo isn't wanting to come up. So its logs will likely tell the true tale

[BryanQuigley]

Sometime vendors customize Ubuntu in ways that can make it less stable.. That Cloud provider isn't listed here: https://partners.ubuntu.com/find-a-partner

multipass launch -n rocket daily:18.04
multipass shell rocket
sudo apt update
sudo apt upgrade
sudo snap install rocketchat-server
Up fine, set password on site :3000
restart service snap.rocketchat-server.rocketchat-server.service
up after about 15 seconds
sudo reboot
up again

(multipass is a command to get Ubuntu easily). I'd watch out for trying to restart the service before it's fully ready. Other than that, I'd suspect some sort of customization on the cloud...

[tuxmartin]

I installed Rocket.Chat snap 0.69.2 on Debian 9.5 (the same cloud - forpsicloud.cz) and it works great.

I'm sorry, but I don't have time to trying Rocket.Chat on Ubuntu.

So for me problem was "solved".

[geekgonecrazy]

i'll go ahead and close this out.

@BryanQuigley yes I think it must be this. If they compile their own kernel snaps seem to never work exactly as expected on Ubuntu. Seen it caused by everything from missing squashfs to tweaked apparmor.

[Tupsi]

I have the same issue here and think it is a simple timing issue. It only happens after a complete reboot of the server. If I come back to it and just do a simple
systemctl start snap.rocketchat-server.rocketchat-server.service
on the command line later on, everything starts up as it should. (Service tries to start while mongodb is still starting, which does not work)

So the solution here would be to tell the startup scripts to do the whole thing a bit slower, still have to figure out how this is possible with systemd, so if anyone has an idea, I am all ears.

to clarify:
my logs clearly state that the mongodb is only ready for connections roughly 10s AFTER the server service has already given up trying.

`Sep 10 08:56:29 xxx rocketchat-server.rocketchat-mongo[2421]: 2019-09-10T08:56:29.796+0000 I REPL [ReplicationExecutor] Exited primary catch-up mode.

Sep 10 08:56:31 xxx rocketchat-server.rocketchat-mongo[2421]: 2019-09-10T08:56:31.725+0000 I REPL [rsSync] transition to primary complete; database writes are now permitted
`

`Sep 10 08:56:23 xxx systemd[1]: snap.rocketchat-server.rocketchat-server.service: Failed with result 'exit-code'.

Sep 10 08:56:23 xxx systemd[1]: Failed to start Service for snap application rocketchat-server.rocketchat-server.
`

[gusarg81]

Hi, I am facing this same issue in Ubuntu 18.04 (installed just fine in another server with 20.04).

I don't know if related, but in my Ubuntu 18.04 server I already have a snap of Wekan which uses mongodb as well.