Snap 2.1 Update Issues

If your server isn’t starting check your mongo logs:

journalctl -u snap.rocketchat-server.rocketchat-mongo

If you encounter an error like:

Nov 5 23:46:25 {} rocketchat-server.rocketchat-mongo[18930]: 2019-11-05T23:46:25.359+0000 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.

IMPORTANT: If you do not have the above in your logs. DO NOT FOLLOW BELOW
Instead just wait for it to come up. It does take a while. The database has to update some of the files.

If you have:

UPGRADE PROBLEM: The data files need to be fully upgraded to version 3.4 before attempting an upgrade to 3.6;

Then please try:

# Stop Mongo
sudo systemctl stop snap.rocketchat-server.rocketchat-mongo

# Revert version back
snap revert --revision=1416 rocketchat-server

# If that fails run:
snap refresh rocketchat-server --channel stable/fix-migration

# Give it a few to start up and then run:
rocketchat-server.mongo --eval "printjson(db.adminCommand ({getParameter: 1, featureCompatibilityVersion: 1}))"

Example of output:

MongoDB shell version v3.4.20           ---->  not important
connecting to: mongodb://127.0.0.1:27017
MongoDB server version: 3.4.20
{ "featureCompatibilityVersion" : "3.2", "ok" : 1 }   ------>  this is the important part!

# If it outputs 3.2 then run
rocketchat-server.mongo  --eval "printjson(db.adminCommand ({ setFeatureCompatibilityVersion: \"3.4\" }))"


# Check again and make sure its 3.4
rocketchat-server.mongo --eval "printjson(db.adminCommand ({getParameter: 1, featureCompatibilityVersion: 1}))"

# Finally then you should be able to refresh back to latest
snap refresh rocketchat-server --channel=stable

Update if you get connection refused check the mongo logs. It’s likely still starting mongo.

journalctl -u snap.rocketchat-server.rocketchat-mongo

If it says any of the above commands aren’t valid try:

export PATH=$PATH:/snap/bin

A few distros it apparently don’t have this automatically added to path


If it’s just not starting but no errors. Give it time to finish starting.

1 Like

Thanks a lot! It’s working)

1 Like

Our rocket chat server updated this night automatically to version 2.1.1 and now the rocket chat service doesn’t start any more:

Is mongo running? See some messages above SNAP NEWS - Rocket.Chat 2.1

In my case:
Mongo is apparently running:

root@web-ph-dmz-rocketchat:~# 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 2019-11-06 09:26:11 CET; 13min ago
 Main PID: 631 (sh)
    Tasks: 70 (limit: 4915)
   CGroup: /system.slice/snap.rocketchat-server.rocketchat-mongo.service
           ├─631 /bin/sh /snap/rocketchat-server/1414/bin/startmongo
           └─895 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

Nov 06 09:26:51 web-ph-dmz-rocketchat rocketchat-server.rocketchat-mongo[631]: 2019-11-06T09:26:51.059+0100 I REPL     [replexec-1] Exited primary catch-up mode.
Nov 06 09:26:53 web-ph-dmz-rocketchat rocketchat-server.rocketchat-mongo[631]: 2019-11-06T09:26:53.012+0100 I REPL     [rsSync] transition to primary complete; database writes are now permitted
Nov 06 09:29:53 web-ph-dmz-rocketchat rocketchat-server.rocketchat-mongo[631]: 2019-11-06T09:29:53.589+0100 I NETWORK  [listener] connection accepted from 127.0.0.1:53290 #1 (1 connection now open)
Nov 06 09:29:53 web-ph-dmz-rocketchat rocketchat-server.rocketchat-mongo[631]: 2019-11-06T09:29:53.589+0100 I NETWORK  [conn1] received client metadata from 127.0.0.1:53290 conn1: { application: { name: "MongoDB Shell" }, driver: { name: "MongoDB Internal Client",
Nov 06 09:29:53 web-ph-dmz-rocketchat rocketchat-server.rocketchat-mongo[631]: 2019-11-06T09:29:53.597+0100 I NETWORK  [conn1] end connection 127.0.0.1:53290 (0 connections now open)
Nov 06 09:31:51 web-ph-dmz-rocketchat rocketchat-server.rocketchat-mongo[631]: 2019-11-06T09:31:51.009+0100 I CONTROL  [LogicalSessionCacheReap] Sessions collection is not set up; waiting until next sessions reap interval: config.system.sessions does not exist
Nov 06 09:36:51 web-ph-dmz-rocketchat rocketchat-server.rocketchat-mongo[631]: 2019-11-06T09:36:51.009+0100 I CONTROL  [LogicalSessionCacheReap] Sessions collection is not set up; waiting until next sessions reap interval: config.system.sessions does not exist
Nov 06 09:39:05 web-ph-dmz-rocketchat rocketchat-server.rocketchat-mongo[631]: 2019-11-06T09:39:05.782+0100 I NETWORK  [listener] connection accepted from 127.0.0.1:57604 #2 (1 connection now open)
Nov 06 09:39:05 web-ph-dmz-rocketchat rocketchat-server.rocketchat-mongo[631]: 2019-11-06T09:39:05.782+0100 I NETWORK  [conn2] received client metadata from 127.0.0.1:57604 conn2: { application: { name: "MongoDB Shell" }, driver: { name: "MongoDB Internal Client",
Nov 06 09:39:05 web-ph-dmz-rocketchat rocketchat-server.rocketchat-mongo[631]: 2019-11-06T09:39:05.785+0100 I NETWORK  [conn2] end connection 127.0.0.1:57604 (0 connections now open)

Data files have been upgaded to 3.4:

root@web-ph-dmz-rocketchat:~# rocketchat-server.mongo --eval "printjson(db.adminCommand ({getParameter: 1, featureCompatibilityVersion: 1}))"
MongoDB shell version v3.6.14
connecting to: mongodb://127.0.0.1:27017/?gssapiServiceName=mongodb
Implicit session: session { "id" : UUID("2bef4b6f-546e-4595-a85c-6c1608608910") }
MongoDB server version: 3.6.14
{ "featureCompatibilityVersion" : { "version" : "3.4" }, "ok" : 1 }

Both snap.rocketchat-server.rocketchat-caddy.service and snap.rocketchat-server.rocketchat-server.service do not start.
First error message reads:

rocketchat-server.rocketchat-caddy[657]: 2019/11/06 09:26:14 loading Caddyfile via flag: open /var/snap/rocketchat-server/1414/Caddyfile: no such file or directory

Hi pasiasty, this looks like mongo is still updating, rocketchat will fail to start until mongo is fully updated, regarding Caddy I don’t think you were using Caddy before that is why you don’t have a configuration file, you can ignore that error if that is the case.

When mongo finishes updating you should see compatibility version updated to 3.6, update could be slow depending on db size and resources available

1 Like

Also mongo DB not starting:

Nov 06 09:52:36 kommserver systemd[1]: Failed to start Service for snap application rocketchat-server.rocketchat-mongo.
Nov 06 09:52:36 kommserver systemd[1]: snap.rocketchat-server.rocketchat-mongo.service: Failed with result 'exit-code'.
Nov 06 09:52:36 kommserver systemd[1]: snap.rocketchat-server.rocketchat-mongo.service: Start request repeated too quickly.
Nov 06 09:52:36 kommserver systemd[1]: Stopped Service for snap application rocketchat-server.rocketchat-mongo.
Nov 06 09:52:36 kommserver systemd[1]: snap.rocketchat-server.rocketchat-mongo.service: Scheduled restart job, restart counter is at 5.
Nov 06 09:52:36 kommserver systemd[1]: snap.rocketchat-server.rocketchat-mongo.service: Service hold-off time over, scheduling restart.
Nov 06 09:52:36 kommserver systemd[1]: snap.rocketchat-server.rocketchat-mongo.service: Failed with result 'exit-code'.
Nov 06 09:52:36 kommserver systemd[1]: snap.rocketchat-server.rocketchat-mongo.service: Main process exited, code=exited, status=100/n/a
Nov 06 09:52:36 kommserver rocketchat-server.rocketchat-mongo[2563]: 2019-11-06T09:52:36.101+0100 I CONTROL  [initandlisten] shutting down with code:100
Nov 06 09:52:36 kommserver rocketchat-server.rocketchat-mongo[2563]: 2019-11-06T09:52:36.101+0100 I CONTROL  [initandlisten] now exiting
Nov 06 09:52:36 kommserver rocketchat-server.rocketchat-mongo[2563]: 2019-11-06T09:52:36.101+0100 I NETWORK  [initandlisten] shutdown: going to flush diaglog...
Nov 06 09:52:36 kommserver rocketchat-server.rocketchat-mongo[2563]: 2019-11-06T09:52:36.101+0100 I NETWORK  [initandlisten] removing socket file: /tmp/mongodb-27017.sock
Nov 06 09:52:36 kommserver rocketchat-server.rocketchat-mongo[2563]: 2019-11-06T09:52:36.101+0100 I NETWORK  [initandlisten] shutdown: going to close listening sockets...
Nov 06 09:52:36 kommserver rocketchat-server.rocketchat-mongo[2563]: 2019-11-06T09:52:36.101+0100 I STORAGE  [initandlisten] exception in initAndListen: 28595 -31802: WT_ERROR: non-specific WiredTiger error, terminating
Nov 06 09:52:36 kommserver rocketchat-server.rocketchat-mongo[2563]: 2019-11-06T09:52:36.100+0100 I -        [initandlisten] Assertion: 28595:-31802: WT_ERROR: non-specific WiredTiger error src/mongo/db/storage/wiredtiger/wired
Nov 06 09:52:36 kommserver rocketchat-server.rocketchat-mongo[2563]: 2019-11-06T09:52:36.095+0100 E STORAGE  [initandlisten] WiredTiger error (-31802) [1573030356:95350][2606:0x7fdc449bed00], txn-recover: Recovery failed: WT_ER
Nov 06 09:52:36 kommserver rocketchat-server.rocketchat-mongo[2563]: 2019-11-06T09:52:36.095+0100 E STORAGE  [initandlisten] WiredTiger error (0) [1573030356:95319][2606:0x7fdc449bed00], txn-recover: You should confirm that you
Nov 06 09:52:36 kommserver rocketchat-server.rocketchat-mongo[2563]: 2019-11-06T09:52:36.095+0100 E STORAGE  [initandlisten] WiredTiger error (0) [1573030356:95296][2606:0x7fdc449bed00], txn-recover: This may be due to the log
Nov 06 09:52:36 kommserver rocketchat-server.rocketchat-mongo[2563]: 2019-11-06T09:52:36.095+0100 E STORAGE  [initandlisten] WiredTiger error (0) [1573030356:95268][2606:0x7fdc449bed00], txn-recover: WiredTiger is unable to rea
Nov 06 09:52:36 kommserver rocketchat-server.rocketchat-mongo[2563]: 2019-11-06T09:52:36.095+0100 E STORAGE  [initandlisten] WiredTiger error (-31802) [1573030356:95170][2606:0x7fdc449bed00], txn-recover: unsupported WiredTiger
Nov 06 09:52:36 kommserver rocketchat-server.rocketchat-mongo[2563]: 2019-11-06T09:52:36.044+0100 I STORAGE  [initandlisten] wiredtiger_open config: create,cache_size=1454M,session_max=20000,eviction=(threads_min=4,threads_max=
Nov 06 09:52:36 kommserver rocketchat-server.rocketchat-mongo[2563]: 2019-11-06T09:52:36.044+0100 I STORAGE  [initandlisten] **          See http://dochub.mongodb.org/core/prodnotes-filesystem
Nov 06 09:52:36 kommserver rocketchat-server.rocketchat-mongo[2563]: 2019-11-06T09:52:36.044+0100 I STORAGE  [initandlisten] ** WARNING: Using the XFS filesystem is strongly recommended with the WiredTiger storage engine
Nov 06 09:52:36 kommserver rocketchat-server.rocketchat-mongo[2563]: 2019-11-06T09:52:36.044+0100 I STORAGE  [initandlisten]
Nov 06 09:52:36 kommserver rocketchat-server.rocketchat-mongo[2563]: 2019-11-06T09:52:36.043+0100 I -        [initandlisten] Detected data files in /var/snap/rocketchat-server/common created by the 'wiredTiger' storage engine,
Nov 06 09:52:35 kommserver rocketchat-server.rocketchat-mongo[2563]: 2019-11-06T09:52:35.977+0100 I CONTROL  [initandlisten] options: { net: { bindIp: "127.0.0.1" }, processManagement: { pidFilePath: "/var/snap/rocketchat-serve
Nov 06 09:52:35 kommserver rocketchat-server.rocketchat-mongo[2563]: 2019-11-06T09:52:35.977+0100 I CONTROL  [initandlisten]     target_arch: x86_64
Nov 06 09:52:35 kommserver rocketchat-server.rocketchat-mongo[2563]: 2019-11-06T09:52:35.977+0100 I CONTROL  [initandlisten]     distarch: x86_64
Nov 06 09:52:35 kommserver rocketchat-server.rocketchat-mongo[2563]: 2019-11-06T09:52:35.976+0100 I CONTROL  [initandlisten] build environment:
Nov 06 09:52:35 kommserver rocketchat-server.rocketchat-mongo[2563]: 2019-11-06T09:52:35.974+0100 I CONTROL  [initandlisten] modules: none
Nov 06 09:52:35 kommserver rocketchat-server.rocketchat-mongo[2563]: 2019-11-06T09:52:35.974+0100 I CONTROL  [initandlisten] allocator: tcmalloc
Nov 06 09:52:35 kommserver rocketchat-server.rocketchat-mongo[2563]: 2019-11-06T09:52:35.970+0100 I CONTROL  [initandlisten] git version: 447847d93d6e0a21b018d5df45528e815c7c13d8
Nov 06 09:52:35 kommserver rocketchat-server.rocketchat-mongo[2563]: 2019-11-06T09:52:35.970+0100 I CONTROL  [initandlisten] db version v3.4.20
Nov 06 09:52:35 kommserver rocketchat-server.rocketchat-mongo[2563]: 2019-11-06T09:52:35.968+0100 I CONTROL  [initandlisten] MongoDB starting : pid=2606 port=27017 dbpath=/var/snap/rocketchat-server/common 64-bit host=kommserve
Nov 06 09:52:35 kommserver systemd[1]: Started Service for snap application rocketchat-server.rocketchat-mongo.
Nov 06 09:52:35 kommserver systemd[1]: Stopped Service for snap application rocketchat-server.rocketchat-mongo.
Nov 06 09:52:35 kommserver systemd[1]: snap.rocketchat-server.rocketchat-mongo.service: Scheduled restart job, restart counter is at 4.
Nov 06 09:52:35 kommserver systemd[1]: snap.rocketchat-server.rocketchat-mongo.service: Service hold-off time over, scheduling restart.
Nov 06 09:52:35 kommserver systemd[1]: snap.rocketchat-server.rocketchat-mongo.service: Failed with result 'exit-code'.
Nov 06 09:52:35 kommserver systemd[1]: snap.rocketchat-server.rocketchat-mongo.service: Main process exited, code=exited, status=100/n/a
Nov 06 09:52:35 kommserver rocketchat-server.rocketchat-mongo[2506]: 2019-11-06T09:52:35.606+0100 I CONTROL  [initandlisten] shutting down with code:100
Nov 06 09:52:35 kommserver rocketchat-server.rocketchat-mongo[2506]: 2019-11-06T09:52:35.606+0100 I CONTROL  [initandlisten] now exiting
Nov 06 09:52:35 kommserver rocketchat-server.rocketchat-mongo[2506]: 2019-11-06T09:52:35.606+0100 I NETWORK  [initandlisten] shutdown: going to flush diaglog...
Nov 06 09:52:35 kommserver rocketchat-server.rocketchat-mongo[2506]: 2019-11-06T09:52:35.606+0100 I NETWORK  [initandlisten] removing socket file: /tmp/mongodb-27017.sock
Nov 06 09:52:35 kommserver rocketchat-server.rocketchat-mongo[2506]: 2019-11-06T09:52:35.606+0100 I NETWORK  [initandlisten] shutdown: going to close listening sockets...
Nov 06 09:52:35 kommserver rocketchat-server.rocketchat-mongo[2506]: 2019-11-06T09:52:35.606+0100 I STORAGE  [initandlisten] exception in initAndListen: 28595 -31802: WT_ERROR: non-specific WiredTiger error, terminating
Nov 06 09:52:35 kommserver rocketchat-server.rocketchat-mongo[2506]: 2019-11-06T09:52:35.605+0100 I -        [initandlisten] Assertion: 28595:-31802: WT_ERROR: non-specific WiredTiger error src/mongo/db/storage/wiredtiger/wired
Nov 06 09:52:35 kommserver rocketchat-server.rocketchat-mongo[2506]: 2019-11-06T09:52:35.598+0100 E STORAGE  [initandlisten] WiredTiger error (-31802) [1573030355:598804][2549:0x7f95c7713d00], txn-recover: Recovery failed: WT_E
Nov 06 09:52:35 kommserver rocketchat-server.rocketchat-mongo[2506]: 2019-11-06T09:52:35.598+0100 E STORAGE  [initandlisten] WiredTiger error (0) [1573030355:598778][2549:0x7f95c7713d00], txn-recover: You should confirm that yo
Nov 06 09:52:35 kommserver rocketchat-server.rocketchat-mongo[2506]: 2019-11-06T09:52:35.598+0100 E STORAGE  [initandlisten] WiredTiger error (0) [1573030355:598757][2549:0x7f95c7713d00], txn-recover: This may be due to the log
Nov 06 09:52:35 kommserver rocketchat-server.rocketchat-mongo[2506]: 2019-11-06T09:52:35.598+0100 E STORAGE  [initandlisten] WiredTiger error (0) [1573030355:598734][2549:0x7f95c7713d00], txn-recover: WiredTiger is unable to re
Nov 06 09:52:35 kommserver rocketchat-server.rocketchat-mongo[2506]: 2019-11-06T09:52:35.598+0100 E STORAGE  [initandlisten] WiredTiger error (-31802) [1573030355:598646][2549:0x7f95c7713d00], txn-recover: unsupported WiredTige
Nov 06 09:52:35 kommserver rocketchat-server.rocketchat-mongo[2506]: 2019-11-06T09:52:35.535+0100 I STORAGE  [initandlisten] wiredtiger_open config: create,cache_size=1454M,session_max=20000,eviction=(threads_min=4,threads_max=
Nov 06 09:52:35 kommserver rocketchat-server.rocketchat-mongo[2506]: 2019-11-06T09:52:35.535+0100 I STORAGE  [initandlisten] **          See http://dochub.mongodb.org/core/prodnotes-filesystem
Nov 06 09:52:35 kommserver rocketchat-server.rocketchat-mongo[2506]: 2019-11-06T09:52:35.535+0100 I STORAGE  [initandlisten] ** WARNING: Using the XFS filesystem is strongly recommended with the WiredTiger storage engine

Thanks. How can I check if DB upgrade is actually running?

cb01, did you revert to previous snap? in your case it looks like the db was still updating, did you get failed to upgrade message mentioned in SNAP NEWS - Rocket.Chat 2.1 ?

I had done a revert to revision=1416, then I wanted to execute the commands above, but then I get mongo not running.
I posted the log of that.
Now I have done a refresh of snap, mongo ist running but same old problem. (IMPORTANT: UPGRADE PROBLEM: The data files need to be fully upgraded to version 3.4…)

what a terrible Wednesday :slight_smile:

jupiieeeee… big thank’s my rocketchat server is running now, problem is solved with again revert and entering the commands from [aaron.ogle]. Seems, that my server was really
busy with DBupdate…

1 Like

Hi,

Same issue.

Can’t seem to revert to 1416

root@chat-1:/var/snap# snap revert rocketchat-server
error: cannot revert "rocketchat-server": no revision to revert to
root@chat-1:/var/snap# snap revert rocketchat-server=1416
error: cannot revert "rocketchat-server=1416": no revision to revert to

Mongo has the issue mentionned before
IMPORTANT: UPGRADE PROBLEM: The data files need to be fully upgraded to version 3.4 before attempting an upgrade to 3.6;

What should I do to redownload rev 1416 ?

@avenetj : make sure you used command :

snap revert --revision=1416 rocketchat-server

Tried this one. But fails, not found.

root@chat-1:/var/snap# snap revert --revision=1416 rocketchat-server
error: cannot revert "rocketchat-server": cannot find revision 1416 for snap "rocketchat-server"

Did you refresh manually? do you have a folder in /snap/rocketchat-server named 1416?

Hi Lucia

No /snap/rocketchat-server only has 1414 and current pointing to 1414

Any way to install 1416 ?

@lucia.guevgeozian : just in case you have an idea : I’ve been able to revert to 1.3.2 (rev 1416) but stuck between mongodb 3.4 and 3.6.
With mongodb 3.6 (rev 1414) : I’m getting the error described here (“UPGRADE PROBLEM”) and after revert to 3.4 (rev 1416), I’m getting :
[initandlisten] WiredTiger error (-31802) [1573029936:363524][8276:0x7f304d2afd00], txn-recover: unsupported WiredTiger file version: this build only supports major/minor versions up to 1/0, and the file is version 2/0: WT_ERROR: non-specific WiredTiger error

I’m now trying to copy the whole db dir (/var/snap/rocketchat-server/common) to another machine and check if repair could make the journal works.

Any other idea ?
Julien

P.S. : sorry, cross-posted with github as this thread seems more active.

Thanks, up and running after manual starting snap.rocketchat-server.rocketchat-server.service.

1 Like

@PandemiK try this, refresh forward to mongo 3.6, rev 1414, stop mongo sudo systemctl stop snap.rocketchat-server.rocketchat-mongo then revert, check comp version, and the rest of the steps

@avenetj how did you refresh and what channel are you tracking? do you remember your previous installed snap revision?

root@chat-1:/snap/rocketchat-server# snap list
Name               Version  Rev   Tracking  Publisher    Notes
core               16-2.42  7917  stable    canonical✓   core
rocketchat-server  2.1.1    1414  stable    rocketchat✓  -

Not sure how it refreshed, found it running 1414 this morning. I remember seeing 1416 on this server at some point but nowhere to be found.