Rocket.chat: "UnhandledPromiseRejectionWarning: MongoError: ns not found" during startup

Created on 7 Aug 2018 · 15Comments · Source: RocketChat/Rocket.Chat

Description:

(node:9956) UnhandledPromiseRejectionWarning: MongoError: ns not found
    at Function.MongoError.create (/opt/rocket.chat-0.68.3/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb-core/lib/error.js:31:11)
    at /opt/rocket.chat-0.68.3/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb-core/lib/connection/pool.js:497:72
    at authenticateStragglers (/opt/rocket.chat-0.68.3/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb-core/lib/connection/pool.js:443:16)
    at Connection.messageHandler (/opt/rocket.chat-0.68.3/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb-core/lib/connection/pool.js:477:5)
    at Socket.<anonymous> (/opt/rocket.chat-0.68.3/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb-core/lib/connection/connection.js:333:22)
    at emitOne (events.js:116:13)
    at Socket.emit (events.js:211:7)
    at addChunk (_stream_readable.js:263:12)
    at readableAddChunk (_stream_readable.js:250:11)
    at Socket.Readable.push (_stream_readable.js:208:10)
    at TCP.onread (net.js:597:20)

(node:9956) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). (rejection id: 1)
(node:9956) [DEP0018] DeprecationWarning: Unhandled promise rejections are deprecated. In the future, promise rejections that are not handled will terminate the Node.js process with a non-zero exit code.

Steps to reproduce:

This occurs when I run multiple instances of Rocket.Chat (via supervisor).

Server Setup Information:

Version of Rocket.Chat Server: 0.68.3
Operating System: Debian Jessie
Deployment Method: tar (bundle)
Number of Running Instances: 3
DB Replicaset Oplog: yes
NodeJS Version: 8.11.3
MongoDB Version: 3.2.20

Additional context

Not sure if this breaks anything. Just noticed this error in logs. Application seems to be working fine though.

Source

futrix

Most helpful comment

Just faced with this error on our kubernetes cluster with multiple replicas.
Note that this error occurred only when run multiple instances concurrently.
So I think it's from migration execution when multiple instance start in the same time.

For the error messagens not found is from this line:
https://github.com/mongodb/mongo/blob/acd196d77043d007b07b48b6e2c4fb13cfa5b938/src/mongo/db/catalog/drop_collection.cpp#L70-L72

which means occurs this error when performing actions on collections that don't exist.

So, maybe it's because we drop collection in migration files, and only the first instance drop properly, and the rest throw this error.

Then I found this lines:

https://github.com/RocketChat/Rocket.Chat/blob/7bd82ef94361af1d0344404af7e3847aab1328f7/server/startup/migrations/v099.js#L201-L205

The drop action in the promise without catch, that's why it throw UnhandledPromiseRejectionWarning

Try the workaround:

try {
    avatarsFiles.rawCollection().drop();
    avatarsChunks.rawCollection().drop();
} catch (error) {
    console.warn('avatars.files and avatars.chunks collection may not exists!');
}

Xuhao on 7 Jan 2019

👍2

All 15 comments

The error is still present in current RC - 0.69.0-rc.0. How can I investigate this further?

futrix on 23 Aug 2018

Same here. I'm starting 4 instances via docker-compose and sometimes only one instance throws this error.

Rocket.Chat Version: 0.70.4
NodeJS Version: 8.11.3 - x64

beranPro on 16 Oct 2018

same here with

Server Setup Information:

Version of Rocket.Chat Server: 0.71.1
Operating System: Debian Stretch
Deployment Method: tar (bundle)
Number of Running Instances: 3
DB Replicaset Oplog: yes
NodeJS Version: 8.12.0
MongoDB Version: 3.2.11

tars21 on 21 Nov 2018

What does your connection string look like? Are you specifying anything beyond just replicaSet in the connection string? How different is your oplog connection string?

geekgonecrazy on 1 Dec 2018

we are using the examples from the documentation in our environment:

Environment=NODE_ENV=production
Environment=MONGO_URL=mongodb://localhost:27017/rocketchat?replicaSet=001-rs
Environment=MONGO_OPLOG_URL=mongodb://localhost:27017/local?replicaSet=001-rs

tars21 on 3 Dec 2018

If you goto your mongo mode and run rs.status() are you greeted with a list of hosts? Or an error? Sounds kinda like replicaSet isn’t initialized.

Another way to test is drop the oplog environment variable and see if error persists

geekgonecrazy on 3 Dec 2018

I've taken a look in our logs. This error message just appeared once two weeks ago and our Rocket.Chat process restarts every night.

The output of rs.status() seems to be fine:

{
    "set" : "001-rs",
    "date" : ISODate("2018-12-04T07:30:39.354Z"),
    "myState" : 1,
    "term" : NumberLong(100),
    "heartbeatIntervalMillis" : NumberLong(2000),
    "members" : [
        {
            "_id" : 0,
            "name" : "chat:27017",
            "health" : 1,
            "state" : 1,
            "stateStr" : "PRIMARY",
            "uptime" : 23730,
            "optime" : {
                "ts" : Timestamp(1543908639, 8),
                "t" : NumberLong(100)
            },
            "optimeDate" : ISODate("2018-12-04T07:30:39Z"),
            "electionTime" : Timestamp(1543884910, 1),
            "electionDate" : ISODate("2018-12-04T00:55:10Z"),
            "configVersion" : 1,
            "self" : true
        }
    ],
    "ok" : 1
}

tars21 on 4 Dec 2018

@sampaiodiego @rodrigok any idea what is causing this? I suspected it was reading from a secondary with delayed data or something. But connection string and replicaset all looks fine

geekgonecrazy on 7 Dec 2018

Hm... Maybe this behavior because the instances are run concurrently? Each instance worked with database.

nlapshin on 7 Dec 2018

I was curios and fired some containers up to see for myself:

rocket.chat 0.71.1 (three docker instances)
one mongodb (another docker) with enabled replSet rs0:

(node:1) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). (rejection id: 1) (node:1) [DEP0018] DeprecationWarning: Unhandled promise rejections are deprecated. In the future, promise rejections that are not handled will terminate the Node.js process with a non-zero exit code.
This message came right after
UnhandledPromiseRejectionWarning: MongoError: ns not found
Didn't take a look what happened there.

maxdwit on 10 Dec 2018