Suprisingly, it worked well. I’m pretty sure I already made this procedure but for reference, it worked for me (perhaps the use of systemd instead of snap stop, dunno).
Many thanks for your help, @lucia.guevgeozian
1 Like
Is it planned to make rev 1416 available to download ? It does not appear in snap refresh --list
@avenetj if you had 1416 before, can you stop mongo with sudo systemctl stop snap.rocketchat-server.rocketchat-mongo and after that run snap refresh rocketchat-server --channel stable/fix-migration
It works fine now, thanks !
1 Like
Make sure to run the rest of the steps and get back to the regular stable channel
After I ran
rocketchat-server.mongo --eval "printjson(db.adminCommand ({getParameter: 1, featureCompatibilityVersion: 1}))"
Output was 3.4
Then I ran
snap refresh rocketchat-server --channel=stable
But now mango won’t start.
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 Wed 2019-11-06 12:13:22 UTC; 1min 13s ago
Process: 3844 ExecStart=/usr/bin/snap run rocketchat-server.rocketchat-mongo (code=exited, status=100)
Main PID: 3844 (code=exited, status=100)Nov 06 12:13:22 chat-1 systemd[1]: snap.rocketchat-server.rocketchat-mongo.service: Main process exited, code=exited, status=100/n/a
Nov 06 12:13:22 chat-1 systemd[1]: snap.rocketchat-server.rocketchat-mongo.service: Failed with result ‘exit-code’.
Nov 06 12:13:22 chat-1 systemd[1]: snap.rocketchat-server.rocketchat-mongo.service: Service hold-off time over, scheduling restart.
Nov 06 12:13:22 chat-1 systemd[1]: snap.rocketchat-server.rocketchat-mongo.service: Scheduled restart job, restart counter is at 5.
Nov 06 12:13:22 chat-1 systemd[1]: Stopped Service for snap application rocketchat-server.rocketchat-mongo.
Nov 06 12:13:22 chat-1 systemd[1]: snap.rocketchat-server.rocketchat-mongo.service: Start request repeated too quickly.
Nov 06 12:13:22 chat-1 systemd[1]: snap.rocketchat-server.rocketchat-mongo.service: Failed with result ‘exit-code’.
Nov 06 12:13:22 chat-1 systemd[1]: Failed to start Service for snap application rocketchat-server.rocketchat-mongo.
Can you check mongo logs?
> Nov 06 12:27:00 chat-1 systemd[1]: Started Service for snap application rocketchat-server.rocketchat-mongo.
> Nov 06 12:27:00 chat-1 rocketchat-server.rocketchat-mongo[7540]: 2019-11-06T12:27:00.593+0000 I CONTROL [initandlisten] MongoDB starting : pid=7579 port=27017 dbpath=/var/snap/rocketchat-server/common 64-bit host=chat-1
> Nov 06 12:27:00 chat-1 rocketchat-server.rocketchat-mongo[7540]: 2019-11-06T12:27:00.596+0000 I CONTROL [initandlisten] db version v3.4.20
> Nov 06 12:27:00 chat-1 rocketchat-server.rocketchat-mongo[7540]: 2019-11-06T12:27:00.596+0000 I CONTROL [initandlisten] git version: 447847d93d6e0a21b018d5df45528e815c7c13d8
> Nov 06 12:27:00 chat-1 rocketchat-server.rocketchat-mongo[7540]: 2019-11-06T12:27:00.596+0000 I CONTROL [initandlisten] allocator: tcmalloc
> Nov 06 12:27:00 chat-1 rocketchat-server.rocketchat-mongo[7540]: 2019-11-06T12:27:00.596+0000 I CONTROL [initandlisten] modules: none
> Nov 06 12:27:00 chat-1 rocketchat-server.rocketchat-mongo[7540]: 2019-11-06T12:27:00.596+0000 I CONTROL [initandlisten] build environment:
> Nov 06 12:27:00 chat-1 rocketchat-server.rocketchat-mongo[7540]: 2019-11-06T12:27:00.596+0000 I CONTROL [initandlisten] distarch: x86_64
> Nov 06 12:27:00 chat-1 rocketchat-server.rocketchat-mongo[7540]: 2019-11-06T12:27:00.596+0000 I CONTROL [initandlisten] target_arch: x86_64
> Nov 06 12:27:00 chat-1 rocketchat-server.rocketchat-mongo[7540]: 2019-11-06T12:27:00.596+0000 I CONTROL [initandlisten] options: { net: { bindIp: "127.0.0.1" }, processManagement: { pidFilePath: "/var/snap/rocketchat-server/common/mongod.pid" }, replication: { replSet: "rs0" }, storage: { dbPath: "/var/snap/rocketchat-server/common", journal: { enabled: true }, mmapv1: { smallFiles: true } } }
> Nov 06 12:27:00 chat-1 rocketchat-server.rocketchat-mongo[7540]: 2019-11-06T12:27:00.631+0000 I - [initandlisten] Detected data files in /var/snap/rocketchat-server/common created by the 'wiredTiger' storage engine, so setting the active storage engine to 'wiredTiger'.
> Nov 06 12:27:00 chat-1 rocketchat-server.rocketchat-mongo[7540]: 2019-11-06T12:27:00.631+0000 I STORAGE [initandlisten]
> Nov 06 12:27:00 chat-1 rocketchat-server.rocketchat-mongo[7540]: 2019-11-06T12:27:00.631+0000 I STORAGE [initandlisten] ** WARNING: Using the XFS filesystem is strongly recommended with the WiredTiger storage engine
> Nov 06 12:27:00 chat-1 rocketchat-server.rocketchat-mongo[7540]: 2019-11-06T12:27:00.631+0000 I STORAGE [initandlisten] ** See http://dochub.mongodb.org/core/prodnotes-filesystem
> Nov 06 12:27:00 chat-1 rocketchat-server.rocketchat-mongo[7540]: 2019-11-06T12:27:00.631+0000 I STORAGE [initandlisten] wiredtiger_open config: create,cache_size=3476M,session_max=20000,eviction=(threads_min=4,threads_max=4),config_base=false,statistics=(fast),log=(enabled=true,archive=true,path=journal,compressor=snappy),file_manager=(close_idle_time=100000),checkpoint=(wait=60,log_size=2GB),statistics_log=(wait=0),verbose=(recovery_progress),
> Nov 06 12:27:00 chat-1 rocketchat-server.rocketchat-mongo[7540]: 2019-11-06T12:27:00.666+0000 E STORAGE [initandlisten] WiredTiger error (-31802) [1573043220:666576][7579:0x7f0f34cb4d00], 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
> Nov 06 12:27:00 chat-1 rocketchat-server.rocketchat-mongo[7540]: 2019-11-06T12:27:00.666+0000 E STORAGE [initandlisten] WiredTiger error (0) [1573043220:666654][7579:0x7f0f34cb4d00], txn-recover: WiredTiger is unable to read the recovery log.
> Nov 06 12:27:00 chat-1 rocketchat-server.rocketchat-mongo[7540]: 2019-11-06T12:27:00.666+0000 E STORAGE [initandlisten] WiredTiger error (0) [1573043220:666674][7579:0x7f0f34cb4d00], txn-recover: This may be due to the log files being encrypted, being from an older version or due to corruption on disk
> Nov 06 12:27:00 chat-1 rocketchat-server.rocketchat-mongo[7540]: 2019-11-06T12:27:00.666+0000 E STORAGE [initandlisten] WiredTiger error (0) [1573043220:666692][7579:0x7f0f34cb4d00], txn-recover: You should confirm that you have opened the database with the correct options including all encryption and compression options
> Nov 06 12:27:00 chat-1 rocketchat-server.rocketchat-mongo[7540]: 2019-11-06T12:27:00.666+0000 E STORAGE [initandlisten] WiredTiger error (-31802) [1573043220:666946][7579:0x7f0f34cb4d00], txn-recover: Recovery failed: WT_ERROR: non-specific WiredTiger error
> Nov 06 12:27:00 chat-1 rocketchat-server.rocketchat-mongo[7540]: 2019-11-06T12:27:00.671+0000 I - [initandlisten] Assertion: 28595:-31802: WT_ERROR: non-specific WiredTiger error src/mongo/db/storage/wiredtiger/wiredtiger_kv_engine.cpp 277
> Nov 06 12:27:00 chat-1 rocketchat-server.rocketchat-mongo[7540]: 2019-11-06T12:27:00.671+0000 I STORAGE [initandlisten] exception in initAndListen: 28595 -31802: WT_ERROR: non-specific WiredTiger error, terminating
> Nov 06 12:27:00 chat-1 rocketchat-server.rocketchat-mongo[7540]: 2019-11-06T12:27:00.671+0000 I NETWORK [initandlisten] shutdown: going to close listening sockets...
> Nov 06 12:27:00 chat-1 rocketchat-server.rocketchat-mongo[7540]: 2019-11-06T12:27:00.671+0000 I NETWORK [initandlisten] removing socket file: /tmp/mongodb-27017.sock
> Nov 06 12:27:00 chat-1 rocketchat-server.rocketchat-mongo[7540]: 2019-11-06T12:27:00.671+0000 I NETWORK [initandlisten] shutdown: going to flush diaglog...
> Nov 06 12:27:00 chat-1 rocketchat-server.rocketchat-mongo[7540]: 2019-11-06T12:27:00.671+0000 I CONTROL [initandlisten] now exiting
> Nov 06 12:27:00 chat-1 rocketchat-server.rocketchat-mongo[7540]: 2019-11-06T12:27:00.671+0000 I CONTROL [initandlisten] shutting down with code:100
> Nov 06 12:27:00 chat-1 systemd[1]: snap.rocketchat-server.rocketchat-mongo.service: Main process exited, code=exited, status=100/n/a
> Nov 06 12:27:00 chat-1 systemd[1]: snap.rocketchat-server.rocketchat-mongo.service: Failed with result 'exit-code'.
> Nov 06 12:27:00 chat-1 systemd[1]: snap.rocketchat-server.rocketchat-mongo.service: Service hold-off time over, scheduling restart.
> Nov 06 12:27:00 chat-1 systemd[1]: snap.rocketchat-server.rocketchat-mongo.service: Scheduled restart job, restart counter is at 5.
> Nov 06 12:27:00 chat-1 systemd[1]: Stopped Service for snap application rocketchat-server.rocketchat-mongo.
> Nov 06 12:27:00 chat-1 systemd[1]: snap.rocketchat-server.rocketchat-mongo.service: Start request repeated too quickly.
> Nov 06 12:27:00 chat-1 systemd[1]: snap.rocketchat-server.rocketchat-mongo.service: Failed with result 'exit-code'.
> Nov 06 12:27:00 chat-1 systemd[1]: Failed to start Service for snap application rocketchat-server.rocketchat-mongo.This is strange seems like the upgrade failed, I would go back to the last revision mongo was running, and check rocketchat is up and running too, to see db files are not corrupt, could it be a hardware, disk issue?
I can try that, how do I revert to previous mongo ?
that should work again I suppose
Hi Lucia, I’ve facing the same issue with mongo v3.6.14, I follow step suggested by [aaron.ogle] but the problem persist.
I go back to the last mongo revision (now v3.4.20) but without success…
Here the mongo logs:
Nov 06 14:40:40 piuapplication systemd[1]: Started Service for snap application rocketchat-server.rocketchat-mongo.
Nov 06 14:40:40 piuapplication rocketchat-server.rocketchat-mongo[24899]: 2019-11-06T14:40:40.682+0100 I CONTROL [initandlisten] MongoDB starting : pid=24941 port=27017 dbpath=/var/snap/rocketchat-server/common 64-bit host=piuapplicatio
Nov 06 14:40:40 piuapplication rocketchat-server.rocketchat-mongo[24899]: 2019-11-06T14:40:40.682+0100 I CONTROL [initandlisten] db version v3.4.20
Nov 06 14:40:40 piuapplication rocketchat-server.rocketchat-mongo[24899]: 2019-11-06T14:40:40.683+0100 I CONTROL [initandlisten] git version: 447847d93d6e0a21b018d5df45528e815c7c13d8
Nov 06 14:40:40 piuapplication rocketchat-server.rocketchat-mongo[24899]: 2019-11-06T14:40:40.683+0100 I CONTROL [initandlisten] allocator: tcmalloc
Nov 06 14:40:40 piuapplication rocketchat-server.rocketchat-mongo[24899]: 2019-11-06T14:40:40.683+0100 I CONTROL [initandlisten] modules: none
Nov 06 14:40:40 piuapplication rocketchat-server.rocketchat-mongo[24899]: 2019-11-06T14:40:40.683+0100 I CONTROL [initandlisten] build environment:
Nov 06 14:40:40 piuapplication rocketchat-server.rocketchat-mongo[24899]: 2019-11-06T14:40:40.683+0100 I CONTROL [initandlisten] distarch: x86_64
Nov 06 14:40:40 piuapplication rocketchat-server.rocketchat-mongo[24899]: 2019-11-06T14:40:40.683+0100 I CONTROL [initandlisten] target_arch: x86_64
Nov 06 14:40:40 piuapplication rocketchat-server.rocketchat-mongo[24899]: 2019-11-06T14:40:40.683+0100 I CONTROL [initandlisten] options: { net: { bindIp: "127.0.0.1" }, processManagement: { pidFilePath: "/var/snap/rocketchat-server/com
Nov 06 14:40:40 piuapplication rocketchat-server.rocketchat-mongo[24899]: 2019-11-06T14:40:40.710+0100 I - [initandlisten] Detected data files in /var/snap/rocketchat-server/common created by the 'wiredTiger' storage engine, so se
Nov 06 14:40:40 piuapplication rocketchat-server.rocketchat-mongo[24899]: 2019-11-06T14:40:40.710+0100 I STORAGE [initandlisten]
Nov 06 14:40:40 piuapplication rocketchat-server.rocketchat-mongo[24899]: 2019-11-06T14:40:40.710+0100 I STORAGE [initandlisten] ** WARNING: Using the XFS filesystem is strongly recommended with the WiredTiger storage engine
Nov 06 14:40:40 piuapplication rocketchat-server.rocketchat-mongo[24899]: 2019-11-06T14:40:40.710+0100 I STORAGE [initandlisten] ** See http://dochub.mongodb.org/core/prodnotes-filesystem
Nov 06 14:40:40 piuapplication rocketchat-server.rocketchat-mongo[24899]: 2019-11-06T14:40:40.711+0100 I STORAGE [initandlisten] wiredtiger_open config: create,cache_size=3476M,session_max=20000,eviction=(threads_min=4,threads_max=4),co
Nov 06 14:40:40 piuapplication rocketchat-server.rocketchat-mongo[24899]: 2019-11-06T14:40:40.794+0100 E STORAGE [initandlisten] WiredTiger error (-31802) [1573047640:794434][24941:0x7fb31d29ed00], txn-recover: unsupported WiredTiger fi
Nov 06 14:40:40 piuapplication rocketchat-server.rocketchat-mongo[24899]: 2019-11-06T14:40:40.794+0100 E STORAGE [initandlisten] WiredTiger error (-31802) [1573047640:794505][24941:0x7fb31d29ed00], txn-recover: Recovery failed: WT_ERROR
Nov 06 14:40:40 piuapplication rocketchat-server.rocketchat-mongo[24899]: 2019-11-06T14:40:40.796+0100 I - [initandlisten] Assertion: 28595:-31802: WT_ERROR: non-specific WiredTiger error src/mongo/db/storage/wiredtiger/wiredtiger
Nov 06 14:40:40 piuapplication rocketchat-server.rocketchat-mongo[24899]: 2019-11-06T14:40:40.796+0100 I STORAGE [initandlisten] exception in initAndListen: 28595 -31802: WT_ERROR: non-specific WiredTiger error, terminating
Nov 06 14:40:40 piuapplication rocketchat-server.rocketchat-mongo[24899]: 2019-11-06T14:40:40.796+0100 I NETWORK [initandlisten] shutdown: going to close listening sockets...
Nov 06 14:40:40 piuapplication rocketchat-server.rocketchat-mongo[24899]: 2019-11-06T14:40:40.796+0100 I NETWORK [initandlisten] removing socket file: /tmp/mongodb-27017.sock
Nov 06 14:40:40 piuapplication rocketchat-server.rocketchat-mongo[24899]: 2019-11-06T14:40:40.796+0100 I NETWORK [initandlisten] shutdown: going to flush diaglog...
Nov 06 14:40:40 piuapplication rocketchat-server.rocketchat-mongo[24899]: 2019-11-06T14:40:40.796+0100 I CONTROL [initandlisten] now exiting
Nov 06 14:40:40 piuapplication rocketchat-server.rocketchat-mongo[24899]: 2019-11-06T14:40:40.796+0100 I CONTROL [initandlisten] shutting down with code:100
Nov 06 14:40:40 piuapplication systemd[1]: snap.rocketchat-server.rocketchat-mongo.service: Main process exited, code=exited, status=100/n/a
Nov 06 14:40:40 piuapplication systemd[1]: snap.rocketchat-server.rocketchat-mongo.service: Failed with result 'exit-code'.
Nov 06 14:40:40 piuapplication systemd[1]: snap.rocketchat-server.rocketchat-mongo.service: Service hold-off time over, scheduling restart.
Nov 06 14:40:40 piuapplication systemd[1]: snap.rocketchat-server.rocketchat-mongo.service: Scheduled restart job, restart counter is at 3.
Nov 06 14:40:40 piuapplication systemd[1]: Stopped Service for snap application rocketchat-server.rocketchat-mongo.
Thanks in advance
Did you see the upgrade error message in Aaron’s post in the logs? Do you know which revision where you running before? going back to fix-migration revision didn’t work? what was the error?
These are the version:
Name Version Rev Tracking Publisher Notes
core 16-2.41 7713 stable canonical✓ core,disabled
core 16-2.42 7917 stable canonical✓ core
rocketchat-server 1.3.2 1416 stable rocketchat✓ disabled
rocketchat-server 2.1.1 1414 stable rocketchat✓ -
I have the same problem both with 2.1.1 and 1.3.2 after the revert
@abaldac can you provide a bit more details on how the upgrade steps went, and what were the errors in the different steps and what command did you execute, so we can see why the fix-migration refresh didn’t work in your case
I follow the Aaron’s steps:
Stop Mongo
sudo systemctl stop snap.rocketchat-server.rocketchat-mongo <! SUCCESS >
Revert version back
snap revert --revision=1416 rocketchat-server <! SUCCESS >
If that fails run:
snap refresh rocketchat-server --channel stable/fix-migration <! NOT NECESSARY >
Give it a few to start up and then run:
rocketchat-server.mongo --eval “printjson(db.adminCommand ({getParameter: 1, featureCompatibilityVersion: 1}))” <! SUCCESS >
If it outputs 3.2 then run
rocketchat-server.mongo --eval “printjson(db.adminCommand ({ setFeatureCompatibilityVersion: “3.4” }))” <! NOT NECESSARY, the varsion was 3.4 >
Check again and make sure its 3.4
rocketchat-server.mongo --eval “printjson(db.adminCommand ({getParameter: 1, featureCompatibilityVersion: 1}))” <! NOT NECESSARY >
Finally then you should be able to refresh back to latest
snap refresh rocketchat-server --channel=stable <! SUCCESS >
After this step che mongo service is running but the logs say:
Nov 06 15:59:52 piuapplication systemd[1]: Started Service for snap application rocketchat-server.rocketchat-mongo.
Nov 06 15:59:52 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:52.471+0100 I CONTROL [initandlisten] MongoDB starting : pid=1461 port=27017 dbpath=/var/snap/rocketchat-server/common 64-bit host=piuapplication
Nov 06 15:59:52 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:52.471+0100 I CONTROL [initandlisten] db version v3.6.14
Nov 06 15:59:52 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:52.471+0100 I CONTROL [initandlisten] git version: cbef87692475857c7ee6e764c8f5104b39c342a1
Nov 06 15:59:52 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:52.471+0100 I CONTROL [initandlisten] allocator: tcmalloc
Nov 06 15:59:52 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:52.471+0100 I CONTROL [initandlisten] modules: none
Nov 06 15:59:52 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:52.471+0100 I CONTROL [initandlisten] build environment:
Nov 06 15:59:52 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:52.471+0100 I CONTROL [initandlisten] distarch: x86_64
Nov 06 15:59:52 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:52.471+0100 I CONTROL [initandlisten] target_arch: x86_64
Nov 06 15:59:52 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:52.471+0100 I CONTROL [initandlisten] options: { net: { bindIp: "127.0.0.1" }, processManagement: { pidFilePath: "/var/snap/rocketchat-server/comm
Nov 06 15:59:52 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:52.471+0100 I - [initandlisten] Detected data files in /var/snap/rocketchat-server/common created by the 'wiredTiger' storage engine, so set
Nov 06 15:59:52 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:52.471+0100 I STORAGE [initandlisten]
Nov 06 15:59:52 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:52.471+0100 I STORAGE [initandlisten] ** WARNING: Using the XFS filesystem is strongly recommended with the WiredTiger storage engine
Nov 06 15:59:52 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:52.471+0100 I STORAGE [initandlisten] ** See http://dochub.mongodb.org/core/prodnotes-filesystem
Nov 06 15:59:52 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:52.471+0100 I STORAGE [initandlisten] wiredtiger_open config: create,cache_size=3476M,session_max=20000,eviction=(threads_min=4,threads_max=4),con
Nov 06 15:59:53 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:53.433+0100 I STORAGE [initandlisten] WiredTiger message [1573052393:433418][1461:0x7f673b08da40], txn-recover: Main recovery loop: starting at 50
Nov 06 15:59:53 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:53.576+0100 I STORAGE [initandlisten] WiredTiger message [1573052393:576099][1461:0x7f673b08da40], txn-recover: Recovering log 50354 through 50355
Nov 06 15:59:53 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:53.658+0100 I STORAGE [initandlisten] WiredTiger message [1573052393:658454][1461:0x7f673b08da40], txn-recover: Recovering log 50355 through 50355
Nov 06 15:59:53 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:53.729+0100 I STORAGE [initandlisten] WiredTiger message [1573052393:729868][1461:0x7f673b08da40], txn-recover: Set global recovery timestamp: 0
Nov 06 15:59:53 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:53.771+0100 I STORAGE [initandlisten] Starting WiredTigerRecordStoreThread local.oplog.rs
Nov 06 15:59:53 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:53.771+0100 I STORAGE [initandlisten] The size storer reports that the oplog contains 3405841 records totaling to 1517177709 bytes
Nov 06 15:59:53 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:53.771+0100 I STORAGE [initandlisten] Sampling from the oplog between Mar 28 11:18:11:1 and Nov 6 12:36:07:1 to determine where to place markers
Nov 06 15:59:53 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:53.771+0100 I STORAGE [initandlisten] Taking 443 samples and assuming that each section of oplog contains approximately 76856 records totaling to
Nov 06 15:59:53 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:53.818+0100 I STORAGE [initandlisten] Placing a marker at optime Apr 7 12:10:37:1
Nov 06 15:59:53 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:53.818+0100 I STORAGE [initandlisten] Placing a marker at optime Apr 17 21:25:30:1
Nov 06 15:59:53 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:53.818+0100 I STORAGE [initandlisten] Placing a marker at optime Apr 29 11:32:36:1
Nov 06 15:59:53 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:53.818+0100 I STORAGE [initandlisten] Placing a marker at optime May 11 08:48:35:1
Nov 06 15:59:53 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:53.818+0100 I STORAGE [initandlisten] Placing a marker at optime May 21 16:50:44:1
Nov 06 15:59:53 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:53.818+0100 I STORAGE [initandlisten] Placing a marker at optime May 27 22:29:33:1
Nov 06 15:59:53 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:53.818+0100 I STORAGE [initandlisten] Placing a marker at optime Jun 3 13:00:26:1
Nov 06 15:59:53 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:53.818+0100 I STORAGE [initandlisten] Placing a marker at optime Jun 9 18:22:36:1
Nov 06 15:59:53 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:53.818+0100 I STORAGE [initandlisten] Placing a marker at optime Jun 14 17:39:25:1
Nov 06 15:59:53 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:53.818+0100 I STORAGE [initandlisten] Placing a marker at optime Jun 20 14:12:00:20
Nov 06 15:59:53 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:53.818+0100 I STORAGE [initandlisten] Placing a marker at optime Jun 24 17:05:43:1
Nov 06 15:59:53 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:53.818+0100 I STORAGE [initandlisten] Placing a marker at optime Jun 28 10:43:01:10
Nov 06 15:59:53 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:53.818+0100 I STORAGE [initandlisten] Placing a marker at optime Jul 2 17:32:41:22
Nov 06 15:59:53 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:53.818+0100 I STORAGE [initandlisten] Placing a marker at optime Jul 5 23:59:59:2
Nov 06 15:59:53 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:53.818+0100 I STORAGE [initandlisten] Placing a marker at optime Jul 11 10:52:17:9
Nov 06 15:59:53 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:53.818+0100 I STORAGE [initandlisten] Placing a marker at optime Jul 16 02:00:00:5
Nov 06 15:59:53 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:53.818+0100 I STORAGE [initandlisten] Placing a marker at optime Jul 16 13:42:24:2
Nov 06 15:59:53 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:53.818+0100 I STORAGE [initandlisten] Placing a marker at optime Jul 19 14:15:29:8
Nov 06 15:59:53 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:53.818+0100 I STORAGE [initandlisten] Placing a marker at optime Jul 23 13:58:22:1
Nov 06 15:59:53 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:53.818+0100 I STORAGE [initandlisten] Placing a marker at optime Jul 28 11:02:30:1
Nov 06 15:59:53 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:53.818+0100 I STORAGE [initandlisten] Placing a marker at optime Jul 31 19:50:16:2
Nov 06 15:59:53 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:53.818+0100 I STORAGE [initandlisten] Placing a marker at optime Aug 5 11:32:34:8
Nov 06 15:59:53 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:53.818+0100 I STORAGE [initandlisten] Placing a marker at optime Aug 7 14:52:28:11
Nov 06 15:59:53 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:53.818+0100 I STORAGE [initandlisten] Placing a marker at optime Aug 10 07:20:53:1
Nov 06 15:59:53 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:53.818+0100 I STORAGE [initandlisten] Placing a marker at optime Aug 15 10:03:12:1
Nov 06 15:59:53 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:53.818+0100 I STORAGE [initandlisten] Placing a marker at optime Aug 18 02:03:59:1
Nov 06 15:59:53 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:53.818+0100 I STORAGE [initandlisten] Placing a marker at optime Aug 26 11:49:28:1
Nov 06 15:59:53 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:53.818+0100 I STORAGE [initandlisten] Placing a marker at optime Aug 29 17:23:45:7
Nov 06 15:59:53 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:53.818+0100 I STORAGE [initandlisten] Placing a marker at optime Sep 3 09:11:52:5
Nov 06 15:59:53 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:53.818+0100 I STORAGE [initandlisten] Placing a marker at optime Sep 6 03:00:30:2
Nov 06 15:59:53 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:53.818+0100 I STORAGE [initandlisten] Placing a marker at optime Sep 10 17:49:36:1
Nov 06 15:59:53 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:53.818+0100 I STORAGE [initandlisten] Placing a marker at optime Sep 16 09:49:38:4
Nov 06 15:59:53 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:53.818+0100 I STORAGE [initandlisten] Placing a marker at optime Sep 18 16:11:49:29
Nov 06 15:59:53 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:53.818+0100 I STORAGE [initandlisten] Placing a marker at optime Sep 20 14:36:45:1
Nov 06 15:59:53 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:53.818+0100 I STORAGE [initandlisten] Placing a marker at optime Sep 25 10:10:53:7
Nov 06 15:59:53 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:53.818+0100 I STORAGE [initandlisten] Placing a marker at optime Sep 30 10:05:39:3
Nov 06 15:59:53 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:53.818+0100 I STORAGE [initandlisten] Placing a marker at optime Oct 3 16:31:09:2
Nov 06 15:59:53 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:53.818+0100 I STORAGE [initandlisten] Placing a marker at optime Oct 8 03:28:46:1
Nov 06 15:59:53 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:53.818+0100 I STORAGE [initandlisten] Placing a marker at optime Oct 11 14:37:17:1
Nov 06 15:59:53 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:53.818+0100 I STORAGE [initandlisten] Placing a marker at optime Oct 16 14:42:47:4
Nov 06 15:59:53 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:53.818+0100 I STORAGE [initandlisten] Placing a marker at optime Oct 21 10:13:15:1
Nov 06 15:59:53 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:53.818+0100 I STORAGE [initandlisten] Placing a marker at optime Oct 25 03:33:01:2
Nov 06 15:59:53 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:53.818+0100 I STORAGE [initandlisten] Placing a marker at optime Oct 29 16:07:59:1
Nov 06 15:59:53 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:53.818+0100 I STORAGE [initandlisten] Placing a marker at optime Nov 4 14:37:02:2
Nov 06 15:59:53 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:53.873+0100 W STORAGE [initandlisten] Detected configuration for non-active storage engine mmapv1 when current storage engine is wiredTiger
Nov 06 15:59:53 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:53.873+0100 I CONTROL [initandlisten]
Nov 06 15:59:53 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:53.873+0100 I CONTROL [initandlisten] ** WARNING: Access control is not enabled for the database.
Nov 06 15:59:53 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:53.873+0100 I CONTROL [initandlisten] ** Read and write access to data and configuration is unrestricted.
Nov 06 15:59:53 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:53.873+0100 I CONTROL [initandlisten] ** WARNING: You are running this process as the root user, which is not recommended.
Nov 06 15:59:53 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:53.873+0100 I CONTROL [initandlisten]
Nov 06 15:59:53 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:53.950+0100 F CONTROL [initandlisten] ** IMPORTANT: UPGRADE PROBLEM: The data files need to be fully upgraded to version 3.4 before attempting an
Nov 06 15:59:53 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:53.951+0100 I NETWORK [initandlisten] shutdown: going to close listening sockets...
Nov 06 15:59:53 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:53.951+0100 I NETWORK [initandlisten] removing socket file: /tmp/mongodb-27017.sock
Nov 06 15:59:53 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:53.951+0100 I REPL [initandlisten] shutdown: removing all drop-pending collections...
Nov 06 15:59:53 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:53.951+0100 I REPL [initandlisten] shutdown: removing checkpointTimestamp collection...
Nov 06 15:59:53 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:53.951+0100 I REPL [initandlisten] shutting down replication subsystems
Nov 06 15:59:53 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:53.951+0100 W REPL [initandlisten] ReplicationCoordinatorImpl::shutdown() called before startup() finished. Shutting down without cleaning up
Nov 06 15:59:53 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:53.951+0100 I STORAGE [WTOplogJournalThread] oplog journal thread loop shutting down
Nov 06 15:59:53 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:53.951+0100 I STORAGE [initandlisten] WiredTigerKVEngine shutting down
Nov 06 15:59:54 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:54.290+0100 I STORAGE [initandlisten] WiredTiger message [1573052394:290067][1461:0x7f673b08da40], txn-recover: Main recovery loop: starting at 50
Nov 06 15:59:54 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:54.432+0100 I STORAGE [initandlisten] WiredTiger message [1573052394:432613][1461:0x7f673b08da40], txn-recover: Recovering log 50355 through 50356
Nov 06 15:59:54 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:54.514+0100 I STORAGE [initandlisten] WiredTiger message [1573052394:514383][1461:0x7f673b08da40], txn-recover: Recovering log 50356 through 50356
Nov 06 15:59:54 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:54.587+0100 I STORAGE [initandlisten] WiredTiger message [1573052394:587052][1461:0x7f673b08da40], txn-recover: Set global recovery timestamp: 0
Nov 06 15:59:54 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:54.698+0100 I STORAGE [initandlisten] shutdown: removing fs lock...
Nov 06 15:59:54 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:54.698+0100 I CONTROL [initandlisten] now exiting
Nov 06 15:59:54 piuapplication rocketchat-server.rocketchat-mongo[1421]: 2019-11-06T15:59:54.698+0100 I CONTROL [initandlisten] shutting down with code:62
Nov 06 15:59:54 piuapplication systemd[1]: snap.rocketchat-server.rocketchat-mongo.service: Main process exited, code=exited, status=62/n/a
Nov 06 15:59:54 piuapplication systemd[1]: snap.rocketchat-server.rocketchat-mongo.service: Failed with result 'exit-code'.
Nov 06 15:59:54 piuapplication systemd[1]: snap.rocketchat-server.rocketchat-mongo.service: Service hold-off time over, scheduling restart.
Nov 06 15:59:54 piuapplication systemd[1]: snap.rocketchat-server.rocketchat-mongo.service: Scheduled restart job, restart counter is at 1179.
Nov 06 15:59:54 piuapplication systemd[1]: Stopped Service for snap application rocketchat-server.rocketchat-mongo.
As you can see in third last line “Scheduled restart job, restart counter is at 1179.” mongo try to restart
cyclically.
Thanks
The log you’ve posted indicates you still have the 3.4 upgrade incomplete. One of the above steps might have been missed somehow - maybe didn’t wait long enough for the db to do the upgrade?
If you want to hit it with a sledgehammer, you can try my method. If your chat server is production, I recommend you take a snapshot or backup before trying it though.
to be clear - this is not an official fix from the Rocket.Chat team!
Yes, looks like you could have executed the steps to fast, can you go back to mongo 3.4, test rocketchat is running, and then refresh to stable
Thanks @dw-dlh and @lucia.guevgeozian, before trying the Daniel’s method, I can run again the “clean procedure”, my question is:
how do i check when the db (3.6) update is finished?
UPDATE: I go back to mongo 3.4 this is the log:
Nov 06 16:56:21 piuapplication systemd[1]: Started Service for snap application rocketchat-server.rocketchat-mongo.
Nov 06 16:56:24 piuapplication rocketchat-server.rocketchat-mongo[534]: 2019-11-06T16:56:24.722+0100 I CONTROL [initandlisten] MongoDB starting : pid=634 port=27017 dbpath=/var/snap/rocketchat-server/common 64-bit host=piuapplication
Nov 06 16:56:24 piuapplication rocketchat-server.rocketchat-mongo[534]: 2019-11-06T16:56:24.722+0100 I CONTROL [initandlisten] db version v3.4.20
Nov 06 16:56:24 piuapplication rocketchat-server.rocketchat-mongo[534]: 2019-11-06T16:56:24.722+0100 I CONTROL [initandlisten] git version: 447847d93d6e0a21b018d5df45528e815c7c13d8
Nov 06 16:56:24 piuapplication rocketchat-server.rocketchat-mongo[534]: 2019-11-06T16:56:24.722+0100 I CONTROL [initandlisten] allocator: tcmalloc
Nov 06 16:56:24 piuapplication rocketchat-server.rocketchat-mongo[534]: 2019-11-06T16:56:24.722+0100 I CONTROL [initandlisten] modules: none
Nov 06 16:56:24 piuapplication rocketchat-server.rocketchat-mongo[534]: 2019-11-06T16:56:24.722+0100 I CONTROL [initandlisten] build environment:
Nov 06 16:56:24 piuapplication rocketchat-server.rocketchat-mongo[534]: 2019-11-06T16:56:24.722+0100 I CONTROL [initandlisten] distarch: x86_64
Nov 06 16:56:24 piuapplication rocketchat-server.rocketchat-mongo[534]: 2019-11-06T16:56:24.722+0100 I CONTROL [initandlisten] target_arch: x86_64
Nov 06 16:56:24 piuapplication rocketchat-server.rocketchat-mongo[534]: 2019-11-06T16:56:24.722+0100 I CONTROL [initandlisten] options: { net: { bindIp: "127.0.0.1" }, processManagement: { pidFilePath: "/var/snap/rocketchat-server/commo
Nov 06 16:56:24 piuapplication rocketchat-server.rocketchat-mongo[534]: 2019-11-06T16:56:24.751+0100 I - [initandlisten] Detected data files in /var/snap/rocketchat-server/common created by the 'wiredTiger' storage engine, so sett
Nov 06 16:56:24 piuapplication rocketchat-server.rocketchat-mongo[534]: 2019-11-06T16:56:24.751+0100 I STORAGE [initandlisten]
Nov 06 16:56:24 piuapplication rocketchat-server.rocketchat-mongo[534]: 2019-11-06T16:56:24.751+0100 I STORAGE [initandlisten] ** WARNING: Using the XFS filesystem is strongly recommended with the WiredTiger storage engine
Nov 06 16:56:24 piuapplication rocketchat-server.rocketchat-mongo[534]: 2019-11-06T16:56:24.751+0100 I STORAGE [initandlisten] ** See http://dochub.mongodb.org/core/prodnotes-filesystem
Nov 06 16:56:24 piuapplication rocketchat-server.rocketchat-mongo[534]: 2019-11-06T16:56:24.751+0100 I STORAGE [initandlisten] wiredtiger_open config: create,cache_size=3476M,session_max=20000,eviction=(threads_min=4,threads_max=4),conf
Nov 06 16:56:24 piuapplication rocketchat-server.rocketchat-mongo[534]: 2019-11-06T16:56:24.894+0100 E STORAGE [initandlisten] WiredTiger error (-31802) [1573055784:894304][634:0x7f7bd530fd00], txn-recover: unsupported WiredTiger file v
Nov 06 16:56:24 piuapplication rocketchat-server.rocketchat-mongo[534]: 2019-11-06T16:56:24.894+0100 E STORAGE [initandlisten] WiredTiger error (-31802) [1573055784:894370][634:0x7f7bd530fd00], txn-recover: Recovery failed: WT_ERROR: no
Nov 06 16:56:24 piuapplication rocketchat-server.rocketchat-mongo[534]: 2019-11-06T16:56:24.896+0100 I - [initandlisten] Assertion: 28595:-31802: WT_ERROR: non-specific WiredTiger error src/mongo/db/storage/wiredtiger/wiredtiger_k
Nov 06 16:56:25 piuapplication rocketchat-server.rocketchat-mongo[534]: 2019-11-06T16:56:25.012+0100 I STORAGE [initandlisten] exception in initAndListen: 28595 -31802: WT_ERROR: non-specific WiredTiger error, terminating
Nov 06 16:56:25 piuapplication rocketchat-server.rocketchat-mongo[534]: 2019-11-06T16:56:25.012+0100 I NETWORK [initandlisten] shutdown: going to close listening sockets...
Nov 06 16:56:25 piuapplication rocketchat-server.rocketchat-mongo[534]: 2019-11-06T16:56:25.012+0100 I NETWORK [initandlisten] removing socket file: /tmp/mongodb-27017.sock
Nov 06 16:56:25 piuapplication rocketchat-server.rocketchat-mongo[534]: 2019-11-06T16:56:25.012+0100 I NETWORK [initandlisten] shutdown: going to flush diaglog...
Nov 06 16:56:25 piuapplication rocketchat-server.rocketchat-mongo[534]: 2019-11-06T16:56:25.012+0100 I CONTROL [initandlisten] now exiting
Nov 06 16:56:25 piuapplication rocketchat-server.rocketchat-mongo[534]: 2019-11-06T16:56:25.012+0100 I CONTROL [initandlisten] shutting down with code:100
Nov 06 16:56:25 piuapplication systemd[1]: snap.rocketchat-server.rocketchat-mongo.service: Main process exited, code=exited, status=100/n/a
Nov 06 16:56:25 piuapplication systemd[1]: snap.rocketchat-server.rocketchat-mongo.service: Failed with result 'exit-code'.
Nov 06 16:56:25 piuapplication systemd[1]: snap.rocketchat-server.rocketchat-mongo.service: Service hold-off time over, scheduling restart.
Nov 06 16:56:25 piuapplication systemd[1]: snap.rocketchat-server.rocketchat-mongo.service: Scheduled restart job, restart counter is at 1.
Nov 06 16:56:25 piuapplication systemd[1]: Stopped Service for snap application rocketchat-server.rocketchat-mongo.
also in this case mongo try to restart cyclically.
Reverting to previous revision didnt help, mango is not starting.
2 Likes