Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Cannot upgrade snap 5.4.5 to 6.x #54

Open
tuxmartin opened this issue Apr 19, 2023 · 10 comments
Open

Cannot upgrade snap 5.4.5 to 6.x #54

tuxmartin opened this issue Apr 19, 2023 · 10 comments

Comments

@tuxmartin
Copy link

Description:

I tried to upgrade Rocket.Chat from 5.4.5 to 6.x using Snap on Debian 11, but it crashed.

Steps to reproduce:

  1. snap switch rocketchat-server --channel=6.x/stable
  2. snap refresh

Server Setup Information:

  • Version of Rocket.Chat Server: 5.4.5
  • Operating System: Debian 11
  • Deployment Method: snap
  • Number of Running Instances: 1
  • NodeJS Version: 14.19.3
  • MongoDB Version: 4.4.15

Relevant logs:

[email protected] / # snap list
Name               Version    Rev    Tracking       Publisher    Notes
core               16-2.58.3  14946  latest/stable  canonical✓   core
core18             20230320   2721   latest/stable  canonical✓   base
core20             20230308   1852   latest/stable  canonical✓   base
hello-world        6.4        29     latest/stable  canonical✓   -
rocketchat-server  5.4.5      1544   5.x/stable     rocketchat✓  -
[email protected] / # snap refresh 
All snaps up to date.
[email protected] / # snap switch rocketchat-server --channel=6.x/stable
"rocketchat-server" switched to the "6.x/stable" channel

[email protected] / # snap list
Name               Version    Rev    Tracking       Publisher    Notes
core               16-2.58.3  14946  latest/stable  canonical✓   core
core18             20230320   2721   latest/stable  canonical✓   base
core20             20230308   1852   latest/stable  canonical✓   base
hello-world        6.4        29     latest/stable  canonical✓   -
rocketchat-server  5.4.5      1544   6.x/stable     rocketchat✓  -
[email protected] / # 
[email protected] / # 
[email protected] / # snap refresh 
error: cannot perform the following tasks:
- Start snap "rocketchat-server" (1545) services (systemctl command [start snap.rocketchat-server.rocketchat-mongo.service] failed with exit status 1: Job for snap.rocketchat-server.rocketchat-mongo.service failed because the control process exited with error code.
See "systemctl status snap.rocketchat-server.rocketchat-mongo.service" and "journalctl -xe" for details.
)
[email protected] / # systemctl status snap.rocketchat-server.rocketchat-mongo.service
● 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 2023-04-19 02:04:33 CEST; 13s ago
   Main PID: 2445768 (mongod)
      Tasks: 75 (limit: 9502)
     Memory: 266.5M
        CPU: 3.018s
     CGroup: /system.slice/snap.rocketchat-server.rocketchat-mongo.service
[email protected] / # 
@douglascarlos-dev
Copy link

Estou com o mesmo problema

@kupe-dono
Copy link

Hello,

I have the same issue.

Host System : Ubuntu 22.04.2 LTS (GNU/Linux 5.15.0-70-generic x86_64)

@host > snap info rocketchat-server

name:      rocketchat-server
summary:   Rocket.Chat server
publisher: Rocket.Chat (rocketchat✓)
store-url: https://snapcraft.io/rocketchat-server
contact:   https://open.rocket.chat/channel/ubuntu-snap
license:   unset
description: |
  Have your own Slack like online chat, built with Meteor. https://rocket.chat/
commands:
  - rocketchat-server.backupdb
  - rocketchat-server.mongo
  - rocketchat-server.restoredb
services:
  rocketchat-server.rocketchat-caddy: simple, disabled, inactive
  rocketchat-server.rocketchat-mongo: forking, enabled, active
  rocketchat-server:                  simple, enabled, active
snap-id:      wdBUbiEuMNHmAHLBCXQXOcXaOCvbWS1e
tracking:     6.x/candidate
refresh-date: today at 10:32 CEST

Steps to reproduce :
sudo snap switch rocketchat-server --channel=6.x/candidate or stable (same results)
sudo snap refresh rocketchat-server

Relevant logs :

Apr 20 10:32:25 rocket.local systemd[1]: Reloading.
Apr 20 10:32:26 rocket.local systemd[1]: Mounting Mount unit for rocketchat-server, revision 1545...
Apr 20 10:32:26 rocket.local kernel: loop8: detected capacity change from 0 to 639088
Apr 20 10:32:26 rocket.local systemd[1]: Mounted Mount unit for rocketchat-server, revision 1545.
Apr 20 10:32:26 rocket.local systemd[1]: Started snap.rocketchat-server.hook.pre-refresh.7ad1be10-eed1-4a71-a160-a2acc243c66e.scope.
Apr 20 10:32:27 rocket.local kernel: audit: type=1400 audit(1681979547.041:87): apparmor="DENIED" operation="open" profile="snap.rocketchat-server.hook.pre-refresh" name="/proc/1703/mountinfo" pid=1703 comm="mongo" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Apr 20 10:32:27 rocket.local kernel: audit: type=1400 audit(1681979547.337:88): apparmor="DENIED" operation="open" profile="snap.rocketchat-server.hook.pre-refresh" name="/proc/1711/mountinfo" pid=1711 comm="mongo" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Apr 20 10:32:27 rocket.local kernel: audit: type=1400 audit(1681979547.417:89): apparmor="DENIED" operation="open" profile="snap.rocketchat-server.hook.pre-refresh" name="/proc/1719/mountinfo" pid=1719 comm="mongo" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Apr 20 10:32:27 rocket.local kernel: audit: type=1400 audit(1681979547.493:90): apparmor="DENIED" operation="open" profile="snap.rocketchat-server.hook.pre-refresh" name="/proc/1727/mountinfo" pid=1727 comm="mongo" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Apr 20 10:32:27 rocket.local kernel: audit: type=1400 audit(1681979547.709:91): apparmor="DENIED" operation="open" profile="snap.rocketchat-server.hook.pre-refresh" name="/proc/1739/mountinfo" pid=1739 comm="mongod" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Apr 20 10:32:27 rocket.local mongod[1120]: {"t":{"$date":"2023-04-20T10:32:27.720+02:00"},"s":"I",  "c":"REPL",     "id":40441,   "ctx":"SignalHandler","msg":"Stopping TopologyVersionObserver"}
Apr 20 10:32:27 rocket.local mongod[1120]: {"t":{"$date":"2023-04-20T10:32:27.726+02:00"},"s":"I",  "c":"REPL",     "id":40447,   "ctx":"TopologyVersionObserver","msg":"Stopped TopologyVersionObserver"}
Apr 20 10:32:28 rocket.local rocketchat-server.rocketchat-mongo[1769]: {"t":{"$date":"2023-04-20T10:32:28.372+02:00"},"s":"I",  "c":"CONTROL",  "id":23285,   "ctx":"main","msg":"Automatically disabling TLS 1.0, to force-enable TLS 1.0 specify --sslDisabledProtocols 'none'"}
Apr 20 10:32:28 rocket.local rocketchat-server.rocketchat-mongo[1769]: {"t":{"$date":"2023-04-20T10:32:28.374+02:00"},"s":"W",  "c":"ASIO",     "id":22601,   "ctx":"main","msg":"No TransportLayer configured during NetworkInterface startup"}
Apr 20 10:32:28 rocket.local rocketchat-server.rocketchat-mongo[1769]: {"t":{"$date":"2023-04-20T10:32:28.374+02:00"},"s":"I",  "c":"NETWORK",  "id":4648601, "ctx":"main","msg":"Implicit TCP FastOpen unavailable. If TCP FastOpen is required, set tcpFastOpenServer, tcpFastOpenClient, and tcpFastOpenQueueSize."}
Apr 20 10:32:28 rocket.local rocketchat-server.rocketchat-mongo[1769]: There doesn't seem to be a server running with dbpath: /var/snap/rocketchat-server/common
Apr 20 10:32:28 rocket.local rocketchat-server.rocketchat-mongo[1740]: [ERROR] mongo server shutdown failed
Apr 20 10:32:28 rocket.local systemd[1]: snap.rocketchat-server.rocketchat-mongo.service: Control process exited, code=exited, status=1/FAILURE
Apr 20 10:32:28 rocket.local systemd[1]: snap.rocketchat-server.rocketchat-mongo.service: Failed with result 'exit-code'.
Apr 20 10:32:28 rocket.local systemd[1]: snap.rocketchat-server.rocketchat-mongo.service: Consumed 8.439s CPU time.
Apr 20 10:32:28 rocket.local systemd[1]: snap.rocketchat-server.rocketchat-mongo.service: Scheduled restart job, restart counter is at 1.
Apr 20 10:32:28 rocket.local systemd[1]: Stopped Service for snap application rocketchat-server.rocketchat-mongo.
Apr 20 10:32:28 rocket.local systemd[1]: snap.rocketchat-server.rocketchat-mongo.service: Consumed 8.439s CPU time.
Apr 20 10:32:28 rocket.local systemd[1]: Starting Service for snap application rocketchat-server.rocketchat-mongo...
Apr 20 10:32:28 rocket.local rocketchat-server.rocketchat-mongo[1801]: about to fork child process, waiting until server is ready for connections.
Apr 20 10:32:28 rocket.local rocketchat-server.rocketchat-mongo[1803]: forked process: 1803
Apr 20 10:32:28 rocket.local mongod[1803]: {"t":{"$date":"2023-04-20T10:32:28.621+02:00"},"s":"W",  "c":"ASIO",     "id":22601,   "ctx":"main","msg":"No TransportLayer configured during NetworkInterface startup"}
Apr 20 10:32:28 rocket.local mongod[1803]: {"t":{"$date":"2023-04-20T10:32:28.621+02:00"},"s":"W",  "c":"ASIO",     "id":22601,   "ctx":"main","msg":"No TransportLayer configured during NetworkInterface startup"}
Apr 20 10:32:28 rocket.local systemd[1]: snap.rocketchat-server.hook.pre-refresh.7ad1be10-eed1-4a71-a160-a2acc243c66e.scope: Deactivated successfully.
Apr 20 10:32:28 rocket.local systemd[1]: snap.rocketchat-server.hook.pre-refresh.7ad1be10-eed1-4a71-a160-a2acc243c66e.scope: Consumed 1.524s CPU time.
Apr 20 10:32:28 rocket.local systemd[1]: snap.rocketchat-server.rocketchat-mongo.service: Deactivated successfully.
Apr 20 10:32:28 rocket.local systemd[1]: Stopped Service for snap application rocketchat-server.rocketchat-mongo.
Apr 20 10:32:28 rocket.local systemd[1]: Stopping Service for snap application rocketchat-server.rocketchat-server...
Apr 20 10:32:29 rocket.local rocketchat-server.rocketchat-server[1183]: /snap/rocketchat-server/1544/helpers/rocketchat.sh: line 23:  1252 Killed                  node $SNAP/main.js
Apr 20 10:32:29 rocket.local systemd[1]: snap.rocketchat-server.rocketchat-server.service: Deactivated successfully.
Apr 20 10:32:29 rocket.local systemd[1]: Stopped Service for snap application rocketchat-server.rocketchat-server.
Apr 20 10:32:29 rocket.local systemd[1]: snap.rocketchat-server.rocketchat-server.service: Consumed 34.543s CPU time.
Apr 20 10:32:29 rocket.local snapd[835]: services.go:1103: RemoveSnapServices - disabling snap.rocketchat-server.rocketchat-caddy.service
Apr 20 10:32:29 rocket.local snapd[835]: services.go:1103: RemoveSnapServices - disabling snap.rocketchat-server.rocketchat-mongo.service
Apr 20 10:32:29 rocket.local snapd[835]: services.go:1103: RemoveSnapServices - disabling snap.rocketchat-server.rocketchat-server.service
Apr 20 10:32:29 rocket.local systemd[1]: Reloading.
Apr 20 10:32:30 rocket.local kernel: audit: type=1400 audit(1681979550.745:92): apparmor="STATUS" operation="profile_replace" info="same as current profile, skipping" profile="unconfined" name="/snap/snapd/18933/usr/lib/snapd/snap-confine" pid=1890 comm="apparmor_parser"
Apr 20 10:32:30 rocket.local kernel: audit: type=1400 audit(1681979550.745:93): apparmor="STATUS" operation="profile_replace" info="same as current profile, skipping" profile="unconfined" name="/snap/snapd/18933/usr/lib/snapd/snap-confine//mount-namespace-capture-helper" pid=1890 comm="apparmor_parser"
Apr 20 10:32:31 rocket.local kernel: audit: type=1400 audit(1681979551.001:94): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="snap.rocketchat-server.hook.post-refresh" pid=1895 comm="apparmor_parser"
Apr 20 10:32:31 rocket.local kernel: audit: type=1400 audit(1681979551.005:95): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="snap.rocketchat-server.hook.install" pid=1894 comm="apparmor_parser"
Apr 20 10:32:31 rocket.local kernel: audit: type=1400 audit(1681979551.037:96): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="snap.rocketchat-server.hook.pre-refresh" pid=1896 comm="apparmor_parser"
Apr 20 10:32:31 rocket.local systemd[1]: Reloading.
Apr 20 10:32:32 rocket.local systemd[1]: Started snap.rocketchat-server.hook.post-refresh.18eba5bd-c9f5-4be7-b7ba-209105b2a246.scope.
Apr 20 10:32:32 rocket.local systemd[1]: snap.rocketchat-server.hook.post-refresh.18eba5bd-c9f5-4be7-b7ba-209105b2a246.scope: Deactivated successfully.
Apr 20 10:32:32 rocket.local systemd[1]: Reloading.
Apr 20 10:32:33 rocket.local systemd[1]: Starting Service for snap application rocketchat-server.rocketchat-mongo...
Apr 20 10:32:33 rocket.local kernel: show_signal: 8 callbacks suppressed
Apr 20 10:32:33 rocket.local kernel: traps: mongod[2024] trap invalid opcode ip:557876bd26da sp:7ffcfc3a8120 error:0 in mongod[557872b2f000+520e000]
Apr 20 10:32:33 rocket.local rocketchat-server.rocketchat-mongo[2000]: /snap/rocketchat-server/1545/helpers/mongo.sh: line 17:  2024 Illegal instruction     (core dumped) mongod --config=$SNAP_DATA/mongod.conf --fork --syslog
Apr 20 10:32:33 rocket.local rocketchat-server.rocketchat-mongo[2000]: [ERROR] mongo server start failed
Apr 20 10:32:33 rocket.local systemd[1]: snap.rocketchat-server.rocketchat-mongo.service: Control process exited, code=exited, status=1/FAILURE
Apr 20 10:32:33 rocket.local systemd[1]: snap.rocketchat-server.rocketchat-mongo.service: Failed with result 'exit-code'.
Apr 20 10:32:33 rocket.local systemd[1]: Failed to start Service for snap application rocketchat-server.rocketchat-mongo.
Apr 20 10:32:33 rocket.local systemd[1]: Cannot find unit for notify message of PID 1999, ignoring.
Apr 20 10:32:33 rocket.local systemd[1]: Stopped Service for snap application rocketchat-server.rocketchat-mongo.
Apr 20 10:32:33 rocket.local systemd[1]: Reloading.
Apr 20 10:32:34 rocket.local snapd[835]: taskrunner.go:289: [change 42 "Start snap \"rocketchat-server\" (1545) services" task] failed: systemctl command [start snap.rocketchat-server.rocketchat-mongo.service] failed with exit status 1: Job for snap.rocketchat-server.rocketchat-mongo.service failed because the control process exited with error code.
Apr 20 10:32:34 rocket.local snapd[835]: See "systemctl status snap.rocketchat-server.rocketchat-mongo.service" and "journalctl -xeu snap.rocketchat-server.rocketchat-mongo.service" for details.
Apr 20 10:32:34 rocket.local snapd[835]: services.go:1103: RemoveSnapServices - disabling snap.rocketchat-server.rocketchat-caddy.service
Apr 20 10:32:34 rocket.local snapd[835]: services.go:1103: RemoveSnapServices - disabling snap.rocketchat-server.rocketchat-mongo.service
Apr 20 10:32:34 rocket.local snapd[835]: services.go:1103: RemoveSnapServices - disabling snap.rocketchat-server.rocketchat-server.service
Apr 20 10:32:34 rocket.local systemd[1]: Reloading.
Apr 20 10:32:35 rocket.local kernel: audit: type=1400 audit(1681979555.182:105): apparmor="STATUS" operation="profile_replace" info="same as current profile, skipping" profile="unconfined" name="/snap/snapd/18933/usr/lib/snapd/snap-confine" pid=2115 comm="apparmor_parser"
Apr 20 10:32:35 rocket.local kernel: audit: type=1400 audit(1681979555.182:106): apparmor="STATUS" operation="profile_replace" info="same as current profile, skipping" profile="unconfined" name="/snap/snapd/18933/usr/lib/snapd/snap-confine//mount-namespace-capture-helper" pid=2115 comm="apparmor_parser"
Apr 20 10:32:35 rocket.local kernel: audit: type=1400 audit(1681979555.442:107): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="snap.rocketchat-server.hook.post-refresh" pid=2120 comm="apparmor_parser"
Apr 20 10:32:35 rocket.local kernel: audit: type=1400 audit(1681979555.442:108): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="snap.rocketchat-server.hook.pre-refresh" pid=2121 comm="apparmor_parser"
Apr 20 10:32:35 rocket.local kernel: audit: type=1400 audit(1681979555.446:109): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="snap.rocketchat-server.hook.install" pid=2119 comm="apparmor_parser"
Apr 20 10:32:35 rocket.local kernel: audit: type=1400 audit(1681979555.474:110): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="snap.rocketchat-server.mongo" pid=2122 comm="apparmor_parser"
Apr 20 10:32:35 rocket.local kernel: audit: type=1400 audit(1681979555.474:111): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="snap.rocketchat-server.hook.configure" pid=2118 comm="apparmor_parser"
Apr 20 10:32:35 rocket.local kernel: audit: type=1400 audit(1681979555.474:112): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="snap.rocketchat-server.backupdb" pid=2117 comm="apparmor_parser"
Apr 20 10:32:35 rocket.local kernel: audit: type=1400 audit(1681979555.726:113): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="snap.rocketchat-server.restoredb" pid=2123 comm="apparmor_parser"
Apr 20 10:32:35 rocket.local systemd[1]: Reloading.
Apr 20 10:32:36 rocket.local systemd[1]: Reloading.
Apr 20 10:32:36 rocket.local systemd[1]: Starting Service for snap application rocketchat-server.rocketchat-mongo...
Apr 20 10:32:36 rocket.local rocketchat-server.rocketchat-mongo[2223]: about to fork child process, waiting until server is ready for connections.
Apr 20 10:32:36 rocket.local rocketchat-server.rocketchat-mongo[2225]: forked process: 2225
Apr 20 10:32:37 rocket.local mongod[2225]: {"t":{"$date":"2023-04-20T10:32:37.001+02:00"},"s":"W",  "c":"ASIO",     "id":22601,   "ctx":"main","msg":"No TransportLayer configured during NetworkInterface startup"}
Apr 20 10:32:37 rocket.local mongod[2225]: {"t":{"$date":"2023-04-20T10:32:37.001+02:00"},"s":"W",  "c":"ASIO",     "id":22601,   "ctx":"main","msg":"No TransportLayer configured during NetworkInterface startup"}
Apr 20 10:32:38 rocket.local mongod[2225]: {"t":{"$date":"2023-04-20T10:32:38.153+02:00"},"s":"W",  "c":"CONTROL",  "id":22120,   "ctx":"initandlisten","msg":"Access control is not enabled for the database. Read and write access to data and configuration is unrestricted","tags":["startupWarnings"]}
Apr 20 10:32:38 rocket.local mongod[2225]: {"t":{"$date":"2023-04-20T10:32:38.153+02:00"},"s":"W",  "c":"CONTROL",  "id":22138,   "ctx":"initandlisten","msg":"You are running this process as the root user, which is not recommended","tags":["startupWarnings"]}
Apr 20 10:32:38 rocket.local mongod[2225]: {"t":{"$date":"2023-04-20T10:32:38.153+02:00"},"s":"W",  "c":"CONTROL",  "id":22184,   "ctx":"initandlisten","msg":"Soft rlimits too low","attr":{"currentValue":1024,"recommendedMinimum":64000},"tags":["startupWarnings"]}
Apr 20 10:32:38 rocket.local mongod[2225]: {"t":{"$date":"2023-04-20T10:32:38.227+02:00"},"s":"W",  "c":"FTDC",     "id":23915,   "ctx":"initandlisten","msg":"Error getting directory iterator '{sysBlockPathStr}': {ec_message}","attr":{"sysBlockPathStr":"/sys/block","ec_message":"Permission denied"}}
Apr 20 10:32:38 rocket.local mongod[2225]: {"t":{"$date":"2023-04-20T10:32:38.240+02:00"},"s":"I",  "c":"REPL",     "id":40440,   "ctx":"initandlisten","msg":"Starting the TopologyVersionObserver"}
Apr 20 10:32:38 rocket.local mongod[2225]: {"t":{"$date":"2023-04-20T10:32:38.241+02:00"},"s":"I",  "c":"REPL",     "id":40445,   "ctx":"TopologyVersionObserver","msg":"Started TopologyVersionObserver"}
Apr 20 10:32:38 rocket.local rocketchat-server.rocketchat-mongo[2223]: child process started successfully, parent exiting
Apr 20 10:32:38 rocket.local systemd[1]: Started Service for snap application rocketchat-server.rocketchat-mongo.
Apr 20 10:32:38 rocket.local systemd[1]: Started Service for snap application rocketchat-server.rocketchat-server.
Apr 20 10:32:38 rocket.local systemd[1]: snap-rocketchat\x2dserver-1545.mount: Deactivated successfully.
Apr 20 10:32:38 rocket.local rocketchat-server.rocketchat-server[2294]: node $SNAP/main.js
Apr 20 10:32:38 rocket.local systemd[1]: Reloading.
Apr 20 10:32:39 rocket.local kernel: kauditd_printk_skb: 6 callbacks suppressed
Apr 20 10:32:39 rocket.local kernel: audit: type=1400 audit(1681979559.002:120): apparmor="DENIED" operation="open" profile="snap.rocketchat-server.rocketchat-mongo" name="/proc/2225/net/netstat" pid=2225 comm="ftdc" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Apr 20 10:32:39 rocket.local kernel: audit: type=1400 audit(1681979559.002:121): apparmor="DENIED" operation="open" profile="snap.rocketchat-server.rocketchat-mongo" name="/proc/2225/net/snmp" pid=2225 comm="ftdc" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Apr 20 10:32:39 rocket.local kernel: audit: type=1400 audit(1681979559.002:122): apparmor="DENIED" operation="open" profile="snap.rocketchat-server.rocketchat-mongo" name="/proc/2225/mountinfo" pid=2225 comm="ftdc" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Apr 20 10:32:39 rocket.local kernel: audit: type=1400 audit(1681979559.002:123): apparmor="DENIED" operation="open" profile="snap.rocketchat-server.rocketchat-mongo" name="/proc/vmstat" pid=2225 comm="ftdc" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Apr 20 10:32:39 rocket.local systemd[1]: Starting Ubuntu Advantage Timer for running repeated jobs...
Apr 20 10:32:39 rocket.local snapd[835]: handlers.go:673: Reported install problem for "rocketchat-server" as already-reported
Apr 20 10:32:39 rocket.local systemd[1]: ua-timer.service: Deactivated successfully.
Apr 20 10:32:39 rocket.local systemd[1]: Finished Ubuntu Advantage Timer for running repeated jobs.
Apr 20 10:32:40 rocket.local kernel: audit: type=1400 audit(1681979559.998:124): apparmor="DENIED" operation="open" profile="snap.rocketchat-server.rocketchat-mongo" name="/proc/2225/net/netstat" pid=2225 comm="ftdc" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Apr 20 10:32:40 rocket.local kernel: audit: type=1400 audit(1681979559.998:125): apparmor="DENIED" operation="open" profile="snap.rocketchat-server.rocketchat-mongo" name="/proc/2225/net/snmp" pid=2225 comm="ftdc" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Apr 20 10:32:40 rocket.local kernel: audit: type=1400 audit(1681979559.998:126): apparmor="DENIED" operation="open" profile="snap.rocketchat-server.rocketchat-mongo" name="/proc/2225/mountinfo" pid=2225 comm="ftdc" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Apr 20 10:32:40 rocket.local kernel: audit: type=1400 audit(1681979559.998:127): apparmor="DENIED" operation="open" profile="snap.rocketchat-server.rocketchat-mongo" name="/proc/vmstat" pid=2225 comm="ftdc" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Apr 20 10:32:41 rocket.local kernel: audit: type=1400 audit(1681979560.998:128): apparmor="DENIED" operation="open" profile="snap.rocketchat-server.rocketchat-mongo" name="/proc/2225/net/netstat" pid=2225 comm="ftdc" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Apr 20 10:32:41 rocket.local kernel: audit: type=1400 audit(1681979560.998:129): apparmor="DENIED" operation="open" profile="snap.rocketchat-server.rocketchat-mongo" name="/proc/2225/net/snmp" pid=2225 comm="ftdc" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Apr 20 10:32:44 rocket.local kernel: kauditd_printk_skb: 14 callbacks suppressed
Apr 20 10:32:44 rocket.local kernel: audit: type=1400 audit(1681979564.146:144): apparmor="ALLOWED" operation="open" profile="/usr/sbin/sssd" name="/proc/812/cmdline" pid=913 comm="sssd_nss" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Apr 20 10:32:45 rocket.local kernel: audit: type=1400 audit(1681979564.998:145): apparmor="DENIED" operation="open" profile="snap.rocketchat-server.rocketchat-mongo" name="/proc/2225/net/netstat" pid=2225 comm="ftdc" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Apr 20 10:32:45 rocket.local kernel: audit: type=1400 audit(1681979564.998:146): apparmor="DENIED" operation="open" profile="snap.rocketchat-server.rocketchat-mongo" name="/proc/2225/net/snmp" pid=2225 comm="ftdc" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Apr 20 10:32:45 rocket.local kernel: audit: type=1400 audit(1681979564.998:147): apparmor="DENIED" operation="open" profile="snap.rocketchat-server.rocketchat-mongo" name="/proc/2225/mountinfo" pid=2225 comm="ftdc" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Apr 20 10:32:45 rocket.local kernel: audit: type=1400 audit(1681979564.998:148): apparmor="DENIED" operation="open" profile="snap.rocketchat-server.rocketchat-mongo" name="/proc/vmstat" pid=2225 comm="ftdc" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Apr 20 10:32:46 rocket.local kernel: audit: type=1400 audit(1681979565.998:149): apparmor="DENIED" operation="open" profile="snap.rocketchat-server.rocketchat-mongo" name="/proc/2225/net/netstat" pid=2225 comm="ftdc" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Apr 20 10:32:46 rocket.local kernel: audit: type=1400 audit(1681979565.998:150): apparmor="DENIED" operation="open" profile="snap.rocketchat-server.rocketchat-mongo" name="/proc/2225/net/snmp" pid=2225 comm="ftdc" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Apr 20 10:32:46 rocket.local kernel: audit: type=1400 audit(1681979565.998:151): apparmor="DENIED" operation="open" profile="snap.rocketchat-server.rocketchat-mongo" name="/proc/2225/mountinfo" pid=2225 comm="ftdc" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Apr 20 10:32:46 rocket.local kernel: audit: type=1400 audit(1681979565.998:152): apparmor="DENIED" operation="open" profile="snap.rocketchat-server.rocketchat-mongo" name="/proc/vmstat" pid=2225 comm="ftdc" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Apr 20 10:32:46 rocket.local rocketchat-server.rocketchat-server[2358]: strict mode: use allowUnionTypes to allow union type keyword at "#/properties/value" (strictTypes)
Apr 20 10:32:47 rocket.local kernel: audit: type=1400 audit(1681979566.998:153): apparmor="DENIED" operation="open" profile="snap.rocketchat-server.rocketchat-mongo" name="/proc/2225/net/netstat" pid=2225 comm="ftdc" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Apr 20 10:32:47 rocket.local rocketchat-server.rocketchat-server[2358]: LocalStore: store created at
Apr 20 10:32:47 rocket.local rocketchat-server.rocketchat-server[2358]: LocalStore: store created at
Apr 20 10:32:47 rocket.local rocketchat-server.rocketchat-server[2358]: LocalStore: store created at
Apr 20 10:32:50 rocket.local kernel: kauditd_printk_skb: 11 callbacks suppressed
Apr 20 10:32:50 rocket.local kernel: audit: type=1400 audit(1681979569.999:165): apparmor="DENIED" operation="open" profile="snap.rocketchat-server.rocketchat-mongo" name="/proc/2225/net/netstat" pid=2225 comm="ftdc" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Apr 20 10:32:50 rocket.local kernel: audit: type=1400 audit(1681979569.999:166): apparmor="DENIED" operation="open" profile="snap.rocketchat-server.rocketchat-mongo" name="/proc/2225/net/snmp" pid=2225 comm="ftdc" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Apr 20 10:32:50 rocket.local kernel: audit: type=1400 audit(1681979569.999:167): apparmor="DENIED" operation="open" profile="snap.rocketchat-server.rocketchat-mongo" name="/proc/2225/mountinfo" pid=2225 comm="ftdc" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Apr 20 10:32:50 rocket.local kernel: audit: type=1400 audit(1681979569.999:168): apparmor="DENIED" operation="open" profile="snap.rocketchat-server.rocketchat-mongo" name="/proc/vmstat" pid=2225 comm="ftdc" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Apr 20 10:32:51 rocket.local kernel: audit: type=1400 audit(1681979570.999:169): apparmor="DENIED" operation="open" profile="snap.rocketchat-server.rocketchat-mongo" name="/proc/2225/net/netstat" pid=2225 comm="ftdc" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Apr 20 10:32:51 rocket.local kernel: audit: type=1400 audit(1681979570.999:170): apparmor="DENIED" operation="open" profile="snap.rocketchat-server.rocketchat-mongo" name="/proc/2225/net/snmp" pid=2225 comm="ftdc" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Apr 20 10:32:51 rocket.local kernel: audit: type=1400 audit(1681979570.999:171): apparmor="DENIED" operation="open" profile="snap.rocketchat-server.rocketchat-mongo" name="/proc/2225/mountinfo" pid=2225 comm="ftdc" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Apr 20 10:32:51 rocket.local kernel: audit: type=1400 audit(1681979570.999:172): apparmor="DENIED" operation="open" profile="snap.rocketchat-server.rocketchat-mongo" name="/proc/vmstat" pid=2225 comm="ftdc" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Apr 20 10:32:51 rocket.local rocketchat-server.rocketchat-server[2358]: MessageType.render is deprecated. Use MessageType.message instead. livechat_webrtc_video_call
Apr 20 10:32:51 rocket.local rocketchat-server.rocketchat-server[2358]: {"level":40,"time":"2023-04-20T08:32:51.820Z","pid":2358,"hostname":"rocket","name":"VoIPService","msg":"Voip is not enabled. Cant start the service"}
Apr 20 10:32:52 rocket.local kernel: audit: type=1400 audit(1681979572.015:173): apparmor="DENIED" operation="open" profile="snap.rocketchat-server.rocketchat-mongo" name="/proc/2225/net/netstat" pid=2225 comm="ftdc" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Apr 20 10:32:52 rocket.local kernel: audit: type=1400 audit(1681979572.015:174): apparmor="DENIED" operation="open" profile="snap.rocketchat-server.rocketchat-mongo" name="/proc/2225/net/snmp" pid=2225 comm="ftdc" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Apr 20 10:32:55 rocket.local rocketchat-server.rocketchat-server[2358]: Browserslist: caniuse-lite is outdated. Please run:
Apr 20 10:32:55 rocket.local rocketchat-server.rocketchat-server[2358]:   npx update-browserslist-db@latest
Apr 20 10:32:55 rocket.local rocketchat-server.rocketchat-server[2358]:   Why you should do it regularly: https://github.com/browserslist/update-db#readme
Apr 20 10:32:55 rocket.local rocketchat-server.rocketchat-server[2358]: {"level":40,"time":"2023-04-20T08:32:55.410Z","pid":2358,"hostname":"rocket","name":"VoIPService","msg":"VoIP service already stopped"}
Apr 20 10:32:55 rocket.local rocketchat-server.rocketchat-server[2358]: {"level":51,"time":"2023-04-20T08:32:55.804Z","pid":2358,"hostname":"rocket","name":"Migrations","msg":"Not migrating, already at version 281"}
Apr 20 10:32:55 rocket.local rocketchat-server.rocketchat-server[2358]: {"level":51,"time":"2023-04-20T08:32:55.853Z","pid":2358,"hostname":"rocket","name":"DatabaseWatcher","msg":"Using change streams"}
Apr 20 10:32:56 rocket.local kernel: kauditd_printk_skb: 14 callbacks suppressed
Apr 20 10:32:56 rocket.local kernel: audit: type=1400 audit(1681979575.999:189): apparmor="DENIED" operation="open" profile="snap.rocketchat-server.rocketchat-mongo" name="/proc/2225/net/netstat" pid=2225 comm="ftdc" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Apr 20 10:32:56 rocket.local kernel: audit: type=1400 audit(1681979575.999:190): apparmor="DENIED" operation="open" profile="snap.rocketchat-server.rocketchat-mongo" name="/proc/2225/net/snmp" pid=2225 comm="ftdc" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Apr 20 10:32:56 rocket.local kernel: audit: type=1400 audit(1681979575.999:191): apparmor="DENIED" operation="open" profile="snap.rocketchat-server.rocketchat-mongo" name="/proc/2225/mountinfo" pid=2225 comm="ftdc" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Apr 20 10:32:56 rocket.local kernel: audit: type=1400 audit(1681979575.999:192): apparmor="DENIED" operation="open" profile="snap.rocketchat-server.rocketchat-mongo" name="/proc/vmstat" pid=2225 comm="ftdc" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Apr 20 10:32:56 rocket.local rocketchat-server.rocketchat-server[2358]: Loaded the Apps Framework and loaded a total of 1 Apps!
Apr 20 10:32:56 rocket.local rocketchat-server.rocketchat-server[2358]: +--------------------------------------------------------+
Apr 20 10:32:56 rocket.local rocketchat-server.rocketchat-server[2358]: |                     SERVER RUNNING                     |
Apr 20 10:32:56 rocket.local rocketchat-server.rocketchat-server[2358]: +--------------------------------------------------------+
Apr 20 10:32:56 rocket.local rocketchat-server.rocketchat-server[2358]: |                                                        |
Apr 20 10:32:56 rocket.local rocketchat-server.rocketchat-server[2358]: |  Rocket.Chat Version: 5.4.5                            |
Apr 20 10:32:56 rocket.local rocketchat-server.rocketchat-server[2358]: |       NodeJS Version: 14.19.3 - x64                    |
Apr 20 10:32:56 rocket.local rocketchat-server.rocketchat-server[2358]: |      MongoDB Version: 4.4.15                           |
Apr 20 10:32:56 rocket.local rocketchat-server.rocketchat-server[2358]: |       MongoDB Engine: wiredTiger                       |
Apr 20 10:32:56 rocket.local rocketchat-server.rocketchat-server[2358]: |             Platform: linux                            |
Apr 20 10:32:56 rocket.local rocketchat-server.rocketchat-server[2358]: |         Process Port: 3000                             |
Apr 20 10:32:56 rocket.local rocketchat-server.rocketchat-server[2358]: |             Site URL: https://rocket.local  |
Apr 20 10:32:56 rocket.local rocketchat-server.rocketchat-server[2358]: |     ReplicaSet OpLog: Enabled                          |
Apr 20 10:32:56 rocket.local rocketchat-server.rocketchat-server[2358]: |          Commit Hash: 45d3ca8961                       |
Apr 20 10:32:56 rocket.local rocketchat-server.rocketchat-server[2358]: |        Commit Branch: HEAD                             |
Apr 20 10:32:56 rocket.local rocketchat-server.rocketchat-server[2358]: |                                                        |
Apr 20 10:32:56 rocket.local rocketchat-server.rocketchat-server[2358]: +--------------------------------------------------------+

@debdutdeb
Copy link
Member

this seems like the old apparmour issue

@debdutdeb debdutdeb transferred this issue from RocketChat/Rocket.Chat Apr 20, 2023
@homberger
Copy link

homberger commented Apr 21, 2023

Copied from the logs above:

kernel: traps: mongod[2024] trap invalid opcode ip:557876bd26da sp:7ffcfc3a8120 error:0 in mongod[557872b2f000+520e000]
rocketchat-server.rocketchat-mongo[2000]: /snap/rocketchat-server/1545/helpers/mongo.sh: line 17:  2024 Illegal instruction     (core dumped) mongod --config=$SNAP_DATA/mongod.conf --fork --syslog
rocketchat-server.rocketchat-mongo[2000]: [ERROR] mongo server start failed

@kupe-dono
Please check if your cpu is supporting avx or avx2 instructions. (not tested this: If it is running on a virtual machine using QEMU, you need QEMU 7.2 or newer to have support of avx/avx2 instructions. If QEMU is an older version, you could try to use the cpu of the host system)

Copied from MongoDB Platform Support Notes:

MongoDB 5.0 requires use of the AVX instruction set.
It requires the following minimum x86_64 microarchitectures:

For Intel x86_64, MongoDB requires one of:
- a Sandy Bridge or later Core processor, or
- a Tiger Lake or later Celeron or Pentium processor.

For AMD x86_64, MongoDB requires:
- a Bulldozer or later processor.

The available snap version of Rocket.Chat is not checking if the cpu is supporting avx/avx2, but there is a commit on branch develop that will fix this problem, I guess:

https://github.com/RocketChat/rocketchat-server-snap/blob/c66f1d08becef6878adc8009c89db22f4b2b3264/snap/hooks/install#L80-L84

@tuxmartin
Copy link
Author

@homberger Hello, thanks for the information about MongoDB.

My Rocket.Chat is in the virtual machine on Proxmox (qemu) with a very old CPU Intel Xeon W3530 (launch date Q1'10) without AVX support. So I have to stay with Rocket.Chat 5.x :-(
Because if I try to add avx feature, it crashes on error:

kvm: warning: host doesn't support requested feature: CPUID.01H:ECX.avx [bit 28]
kvm: Host doesn't support requested features
TASK ERROR: start failed: QEMU exited with code 1

For people with newer CPU, just add a file with this content:

# cat /etc/pve/virtual-guest/cpu-models.conf
cpu-model: avx
  flags +avx
  phys-bits host
  hidden 0
  hv-vendor-id proxmox
  reported-model kvm64

And set CPU to "avx" on your virtual machine, and it should work.

@kupe-dono
Copy link

Thanks a lot @homberger, my proxmox is in 7.3 version but the proc vm's type was configured on default(kvm64).
I set it to "host" and it works :)

@homberger
Copy link

homberger commented Apr 21, 2023

@tuxmartin

My Rocket.Chat is in the virtual machine on Proxmox (qemu) with a very old CPU Intel Xeon W3530 (launch date Q1'10) without AVX support. So I have to stay with Rocket.Chat 5.x :-(

I did not test this yet, but I am going to use this approach if it will be necessary for any installation:
You could try to override the mongodb version the snap is using. Use MongoDB 4.4 instead of 5.0 with Rocket.Chat 6.
Docs (easier than I thought):
https://snapcraft.io/docs/overrides#heading--overriding-the-pull-step

This will be overridden by you:
https://github.com/RocketChat/rocketchat-server-snap/blob/6.0.0/snap/snapcraft.yaml#L73-L83

@tuxmartin
Copy link
Author

@homberger it looks good. How can I use it?

@k-ahn
Copy link

k-ahn commented Dec 27, 2023

@tuxmartin I have the same question. @homberger Help!

@k-ahn
Copy link

k-ahn commented Mar 26, 2024

@homberger Please share the details!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

6 participants