Rocket.chat not starting after SNAP version refresh 5.4.5 -> 6.0.0

Description

Hello @dudanogueira @debdut.chakraborty - @Community Support
This is a followup to my RC post on the snap channel (…)

after the upgrade process (snap refresh) the rocket.chat server service cannot start and loop into this error :

error: 'An error occurred when creating an index for collection "users: An equivalent index already exists with the same name but different options. Requested index: { v: 2, unique: true, key: { xxxxxxxxxxxxxx: 1 }, name: "xxxxxxxxxxxxx_1", sparse: true }, existing index: { v: 1, unique: true, key: { xxxxxxxxxxxxxxxxx: 1 }, name: "xxxxxxxxxxxxxxxx_1", ns: "parties.users", sparse: 1 }',

it seems to be related to the all users indexes … (first it is showing username_1 but then after I drop the index it will show
basically if I drop the full users table - I can start my instance but without any user data

Did someone ran into this issue when upgrading snap 5.4.5 → 6.0.0 ?

Server Setup Information

  • Version of Rocket.Chat Server: 5.4.5
  • Operating System: Ubuntu 20.04
  • Deployment Method: snap
  • Number of Running Instances: 1
  • DB Replicaset Oplog: Enabled
  • NodeJS Version: v14.19.3
  • MongoDB Version: 4.4.15 / wiredTiger (oplog Enabled)
  • Proxy: nginx
  • Firewalls involved: no

Please Help

Hi Mehdi.Yayaoui, Major release version has been a problem with snap in the past, but personally I have not seen any other problem reported on this upgrade for 6.0.0.

I was checking into some other documents and maybe you’ll find this useful: Introducing SNAP Tracks!
Also, in general this is the snaps documentation we have: Snaps - Rocket.Chat Docs

Hello @gabriel.casals thank you for replying back.

I actually got it fixed somehow - as always I had to tickle my mongodb instance which I think is not aging well :slight_smile:

I had to drop all the indexes in the users collection

after that the service was up again

but I still have some wired messages in the log keywords : marketplace / autotranslate …
is this a known issue with 6.0.0 ? or should I try a debug ?

{"level":50,"time":"2023-04-25T08:15:32.786Z","pid":2493,"hostname":"STE-02001.ADS.LOCAL","name":"Rocket.Chat Apps","msg":"Error getting the app requests stats from marketplace 'request to https://marketplace.rocket.chat/v1/app-request/stats failed, reason: write EPROTO 139722926172032:error:1408F10B:SSL routines:ssl3_get_record:wrong version number:../deps/openssl/openssl/ssl/record/ssl3_record.c:332:<br>'"} 

{"level":50,"time":"2023-04-25T08:12:53.124Z","pid":2493,"hostname":"STE-02001.ADS.LOCAL","name":"System","msg":"Exception while invoking method autoTranslate.getSupportedLanguages","err":{"type":"errorClass","message":"Auto-Translate is disabled [error-autotranslate-disabled]","stack":"Error: Auto-Translate is disabled [error-autotranslate-disabled]<br>    at MethodInvocation.autoTranslate.getSupportedLanguages (app/autotranslate/server/methods/getSupportedLanguages.ts:11:10)<br>    at MethodInvocation.methodsMap.<computed> (app/lib/server/lib/debug.js:74:34)<br>    at maybeAuditArgumentChecks (packages/ddp-server/livedata_server.js:1902:12)<br>    at packages/ddp-server/livedata_server.js:1820:15<br>    at Meteor.EnvironmentVariable.EVp.withValue (packages/meteor.js:1329:12)<br>    at packages/ddp-server/livedata_server.js:1818:36<br>    at new Promise (<anonymous>)<br>    at Server.applyAsync (packages/ddp-server/livedata_server.js:1817:12)<br>    at Server.apply (packages/ddp-server/livedata_server.js:1756:26)<br>    at Server.call (packages/ddp-server/livedata_server.js:1738:17)<br>    at Object.post (app/api/server/v1/misc.ts:554:27)<br>    at app/api/server/api.js:463:96<br>    at Meteor.EnvironmentVariable.EVp.withValue (packages/meteor.js:1329:12)<br>    at Object._internalRouteActionHandler [as action] (app/api/server/api.js:463:39)<br>    at Route._callEndpoint (packages/rocketchat_restivus/lib/route.coffee:150:32)<br>    at packages/rocketchat_restivus/lib/route.coffee:59:33<br>    at packages/simple_json-routes.js:100:9<br> => awaited here:<br>    at Promise.await (/snap/rocketchat-server/1545/programs/server/npm/node_modules/meteor/promise/node_modules/meteor-promise/promise_server.js:60:12)<br>    at Server.apply (packages/ddp-server/livedata_server.js:1769:22)<br>    at Server.call (packages/ddp-server/livedata_server.js:1738:17)<br>    at Object.post (app/api/server/v1/misc.ts:554:27)<br>    at app/api/server/api.js:463:96<br>    at Meteor.EnvironmentVariable.EVp.withValue (packages/meteor.js:1329:12)<br>    at Object._internalRouteActionHandler [as action] (app/api/server/api.js:463:39)<br>    at Route._callEndpoint (packages/rocketchat_restivus/lib/route.coffee:150:32)<br>    at packages/rocketchat_restivus/lib/route.coffee:59:33<br>    at packages/simple_json-routes.js:100:9","isClientSafe":true,"error":"error-autotranslate-disabled","reason":"Auto-Translate is disabled","errorType":"Meteor.Error"},"msg":"Auto-Translate is disabled [error-autotranslate-disabled]"}

Auto-Translate one is a know issue, for 6.x; Marketplace one have not seen it before.
When possible, try to upgrade to 6.1.5 version; fixes some know bugs with apps (apps migrations and install had issues with 6.0.0 and 6.1.0)

@debdut.chakraborty any tipcs for this one?

I‘m having the same issue after my snap upgrade from 5.x/stable to 6.x/stable. I tried to delete a bunch of indexes in mongoDB, but it didn’t lead to a functioning system.

@tmoehle try to drop all the users indexes at once using

db.users.dropIndexes()

I tried that. After that a few more indexes had to be dropped (as they were reported in the log). But in the end my rocketchat instance didn’t come up again.

@tmoehle I would not venture into suggesting more mongodb maneuvers - I’m not very qualified for that :slight_smile:
As far as I’m concerned, RC-server service could not fireup and I was getting index errors in the logs…
One thing was clear though ; all the reported indexes were in the users collection, so I used the compass app (you could use the shell into the os shell prompt also) to login into the db shell and droped all user index at once (I could then see in the users indexes tab fresh new indexes - this is why I used compass btw … ).
I would recommend backing up the db or snapshotting the vm and trying to drop other indexes…

Hi,
I have encountered the same problem but no solution.
Have you found how to solve it?

I have now tried to backup my rocketchat instance according to the RocketChat Docs, then uninstall it, reinstall version 6 and then restore the backup. Now I’m getting a new error:

Apr 30 10:04:07 chat rocketchat-server.rocketchat-server[1794]: +----------------------------------------------------------------------+
Apr 30 10:04:07 chat rocketchat-server.rocketchat-server[1794]: |                         ERROR! SERVER STOPPED                        |
Apr 30 10:04:07 chat rocketchat-server.rocketchat-server[1794]: +----------------------------------------------------------------------+
Apr 30 10:04:07 chat rocketchat-server.rocketchat-server[1794]: |                                                                      |
Apr 30 10:04:07 chat rocketchat-server.rocketchat-server[1794]: |  Your database migration failed:                                     |
Apr 30 10:04:07 chat rocketchat-server.rocketchat-server[1794]: |  index not found with name [snippeted_1]                             |
Apr 30 10:04:07 chat rocketchat-server.rocketchat-server[1794]: |                                                                      |
Apr 30 10:04:07 chat rocketchat-server.rocketchat-server[1794]: |  Please make sure you are running the latest version and try again.  |
Apr 30 10:04:07 chat rocketchat-server.rocketchat-server[1794]: |  If the problem persists, please contact support.                    |
Apr 30 10:04:07 chat rocketchat-server.rocketchat-server[1794]: |                                                                      |
Apr 30 10:04:07 chat rocketchat-server.rocketchat-server[1794]: |  This Rocket.Chat version: 6.1.5                                     |
Apr 30 10:04:07 chat rocketchat-server.rocketchat-server[1794]: |  Database locked at version: 286                                     |
Apr 30 10:04:07 chat rocketchat-server.rocketchat-server[1794]: |  Database target version: 292                                        |
Apr 30 10:04:07 chat rocketchat-server.rocketchat-server[1794]: |                                                                      |
Apr 30 10:04:07 chat rocketchat-server.rocketchat-server[1794]: |  Commit: 44da8e3e4665301f36c5c7abab368d57c3a8e056                    |
Apr 30 10:04:07 chat rocketchat-server.rocketchat-server[1794]: |  Date: Mon Apr 24 17:06:38 2023 -0300                                |
Apr 30 10:04:07 chat rocketchat-server.rocketchat-server[1794]: |  Branch: HEAD                                                        |
Apr 30 10:04:07 chat rocketchat-server.rocketchat-server[1794]: |  Tag: 6.1.5                                                          |
Apr 30 10:04:07 chat rocketchat-server.rocketchat-server[1794]: |                                                                      |
Apr 30 10:04:07 chat rocketchat-server.rocketchat-server[1794]: +----------------------------------------------------------------------+
Apr 30 10:04:07 chat rocketchat-server.rocketchat-server[1794]: {"level":50,"time":"2023-04-30T08:04:07.855Z","pid":1794,"hostname":"chat","name":"Migrations","err":{"type":"MongoServerError","message":"index not found with name [snippeted_1]","stack":"MongoServerError: index not found with name [snippeted_1]\n    at Connection.onMessage (/snap/rocketchat-server/1547/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb/lib/cmap/connection.js:230:30)\n    at MessageStream.<anonymous> (/snap/rocketchat-server/1547/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb/lib/cmap/connection.js:61:60)\n    at MessageStream.emit (events.js:400:28)\n    at MessageStream.emit (domain.js:475:12)\n    at processIncomingData (/snap/rocketchat-server/1547/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb/lib/cmap/message_stream.js:125:16)\n    at MessageStream._write (/snap/rocketchat-server/1547/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb/lib/cmap/message_stream.js:33:9)\n    at writeOrBuffer (internal/streams/writable.js:358:12)\n    at MessageStream.Writable.write (internal/streams/writable.js:303:10)\n    at Socket.ondata (internal/streams/readable.js:731:22)\n    at Socket.emit (events.js:400:28)\n    at Socket.emit (domain.js:475:12)\n    at addChunk (internal/streams/readable.js:293:12)\n    at readableAddChunk (internal/streams/readable.js:267:9)\n    at Socket.Readable.push (internal/streams/readable.js:206:10)\n    at TCP.onStreamRead (internal/stream_base_commons.js:188:23)\n    at TCP.callbackTrampoline (internal/async_hooks.js:130:17)\n => awaited here:\n    at Function.Promise.await (/snap/rocketchat-server/1547/programs/server/npm/node_modules/meteor/promise/node_modules/meteor-promise/promise_server.js:56:12)\n    at server/startup/migrations/v287.ts:58:3\n    at /snap/rocketchat-server/1547/programs/server/npm/node_modules/meteor/promise/node_modules/meteor-promise/fiber_pool.js:43:40\n => awaited here:\n    at Function.Promise.await (/snap/rocketchat-server/1547/programs/server/npm/node_modules/meteor/promise/node_modules/meteor-promise/promise_server.js:56:12)\n    at migrate (server/lib/migrations.ts:158:10)\n    at migrateDatabase (server/lib/migrations.ts:262:5)\n    at migrateDatabase (server/lib/migrations.ts:198:11)\n    at migrateDatabase (server/lib/migrations.ts:198:11)\n    at migrateDatabase (server/lib/migrations.ts:198:11)\n    at migrateDatabase (server/lib/migrations.ts:198:11)\n    at migrateDatabase (server/lib/migrations.ts:198:11)\n    at migrateDatabase (server/lib/migrations.ts:198:11)\n    at migrateDatabase (server/lib/migrations.ts:198:11)\n    at migrateDatabase (server/lib/migrations.ts:198:11)\n    at module (server/startup/migrations/xrun.js:8:1)\n    at fileEvaluate (packages/modules-runtime.js:336:7)\n    at Module.require (packages/modules-runtime.js:238:14)\n    at Module.moduleLink [as link] (/snap/rocketchat-server/1547/programs/server/npm/node_modules/meteor/modules/node_modules/@meteorjs/reify/lib/runtime/index.js:52:22)\n    at module (/snap/rocketchat-server/1547/programs/server/app/app.js:1420021:8)\n    at fileEvaluate (packages/modules-runtime.js:336:7)\n    at Module.require (packages/modules-runtime.js:238:14)\n    at Module.moduleLink [as link] (/snap/rocketchat-server/1547/programs/server/npm/node_modules/meteor/modules/node_modules/@meteorjs/reify/lib/runtime/index.js:52:22)\n    at module (/snap/rocketchat-server/1547/programs/server/app/app.js:1426059:8)\n    at fileEvaluate (packages/modules-runtime.js:336:7)\n    at Module.require (packages/modules-runtime.js:238:14)","ok":0,"code":27,"codeName":"IndexNotFound","$clusterTime":{"clusterTime":{"$timestamp":"7227750697205235713"},"signature":{"hash":"AAAAAAAAAAAAAAAAAAAAAAAAAAA=","keyId":0}},"operationTime":{"$timestamp":"7227750697205235713"}},"msg":"index not found with name [snippeted_1]"}

to my best knowledge - it is not recommended to restore a DB backup on a different +version (the best way to do that is install the exact version of your backed DB then proceed with the restore)
Can you get back to the latest working version of your snap 5.4.5 ?
(by rolling back a snapshot / using snap revert …)
if you can, I would suggest from that point : backup/snapshot the server - and refresh again to 6.1.5.

I would also mention that, for me (and from previous similar issues), I would sometimes remove manually the DB lock so I can get a successful migration.
in the migration collection
locked → false
version → target version
again this is for reference - I’m not recommending this…

Same problem here after Migrating from 4 to 5 (no problems) and then after reboot 5 to 6 (index error as described).

I’m not so fond of tweaking my MongoDB, and would like to see an “official” fix - for this seems to affect quite a few instances?

1 Like

Same problem here, going from v5 to v6 on snap does not work properly at all.

@debdut.chakraborty could you help us fix this? The whole point of a snap install, which has long been the officially recommended form of installation, is that it’s easy and straightforward. Could you please offer a solution to upgrade safely and easily from v5 to v6 on snap installs?

2 Likes

The whole point of a snap install, which has long been the officially recommended form of installation

seems that’s not the case anymore…
@debdut.chakraborty, I know this is not the topic of this thread, and maybe an absurd abuse of “@” :slight_smile:
but can you please advise on a safe and relieble way to migrate existing snap to other deployements plateform Docker or rocketchatctl.
I’m not saying snap is dead but it would be great if we would scale up easily with instances / users and have a release roadmap closer to the official branch.

Anyway 6.xx is a great release - keep up the good work !

1 Like

@debdut.chakraborty @dudanogueira Are you guys seriously just ignoring snap users, after years of RocketChat recommending snap installs?

Every few days I get a chat notifcation from rocketcat to update my installation, and yet the most recommended way of installation is completely broken and multiple threads about it are being completely ignored for weeks.

Can you guys at least comment here and update everyone on the state of affairs here? Did you guys just suddenly and abruptly abandon snap installation upgrade paths?

2 Likes

Launch MongoDB shell:
sudo rocketchat-server.mongo
Switch DB:
use parties
Drop indexes:
db.users.dropIndexes()
Exit MongoDB shell:
exit
Restart Rocketchat
sudo snap restart rocketchat-server
Wait for a couple of seconds until rocket finished restart

Yep
But we already figured that out - you can check on top of the thread
Rocket.Chat team should fix these issues - and snap should be given top priority as a deployment vector
Thnks anyway

2 Likes

Hello. And what if it didn’t help? Does not start after upgrading from 5.4.10 to 6.4.5 (snap)