Mongoose: MongoError: command find|insert|update requires authentication

[will3942]

Do you want to request a feature or report a bug?
bug

What is the current behavior?
Under high load, lots of errors appear in the console like this: MongoError: command find requires authentication with error code 13. I believe it is when a connection gets closed/times out and then reconnects we start seeing errors like this. It only ever happens under very high load with >200 requests/second executing ~4 queries per request.

MongoError: command find requires authentication
  File "/worker/node_modules/mongodb-core/lib/cursor.js", line 247, col 25, in queryCallback
    return callback(new MongoError(result.documents[0]), null);
  File "/worker/node_modules/mongodb-core/lib/connection/pool.js", line 531, col 18, in null.<anonymous>
    return cb(err, result);
  File "internal/process/next_tick.js", line 176, col 11, in process._tickCallback

MongoDB server is v4.0 (seen also on v3.6) running as a Docker container. The logs show no unauthorised errors related to these queries, only these unrelated ones:

root@ubuntu-s-8vcpu-32gb-lon1-01:~# docker logs mongodb | grep authorized
2018-08-10T10:13:42.389+0000 I ACCESS   [conn188] Unauthorized: not authorized on admin to execute command { getLog: "startupWarnings", $db: "admin" }
2018-08-10T10:13:42.677+0000 I ACCESS   [conn188] Unauthorized: not authorized on admin to execute command { replSetGetStatus: 1.0, forShell: 1.0, $db: "admin" }
2018-08-10T10:13:43.623+0000 I ACCESS   [conn188] Unauthorized: not authorized on nanowire to execute command { find: "system.users", filter: {}, $db: "nanowire" }

If the current behavior is a bug, please provide the steps to reproduce.

Connection is initialised like this:

import mongoose from 'mongoose';

mongoose.Promise = global.Promise;

const connectToMongoDB = () => {
  const opts = {
    keepAlive: true,
    keepAliveInitialDelay: 300000,
    socketTimeoutMS: 30000,
    poolSize: 50,
    reconnectTries: Number.MAX_VALUE,
    reconnectInterval: 500,
    autoReconnect: true,
  };

  return mongoose.connect('mongodb://user:password@mongodb:27017/nanowire', opts);
};

export default connectToMongoDB;

After that mongoose is just used as normal in an express app, executing 3 finds, 1 insert and 2 updates on every request.

What is the expected behavior?

No authentication errors should occur as only one database is used with the same credentials, there is definitely no mixing of credentials to different databases. This also only occurs at high load.

Please mention your node.js, mongoose and MongoDB version.

Node 9.11.2
Mongoose 5.2.7
MongoDB 4.0.0

[vkarpov15]

We'll investigate this but you should also open up an issue on the MongoDB driver's JIRA page because this is the sort of thing the MongoDB driver is responsible for, Mongoose doesn't handle reconnection logic.

[vkarpov15]

Also, do you have any evidence of connections closing / timing out? How long do each of these operations usually take, and have you tried bumping poolSize?

[will3942]

Thanks for the quick response, will open an issue there now.

I have a bunch of stacktraces like these:

MongoNetworkError: connection 71 to 167.99.194.156:27017 timed out
  File "/worker/node_modules/mongodb-core/lib/connection/connection.js", line 258, col 7, in Socket.<anonymous>
    new MongoNetworkError(f('connection %s to %s:%s timed out', self.id, self.host, self.port)),
  File "events.js", line 313, col 30, in Object.onceWrapper
  File "events.js", line 106, col 13, in emitNone
  File "events.js", line 208, col 7, in Socket.emit
  File "net.js", line 410, col 8, in Socket._onTimeout
  File "timers.js", line 498, col 11, in ontimeout
  File "timers.js", line 323, col 5, in tryOnTimeout
  File "timers.js", line 290, col 5, in Timer.listOnTimeout

MongoNetworkError: connection 54 to 167.99.194.156:27017 closed
  File "/worker/node_modules/mongodb-core/lib/connection/connection.js", line 275, col 9, in Socket.<anonymous>
    new MongoNetworkError(f('connection %s to %s:%s closed', self.id, self.host, self.port)),
  File "events.js", line 315, col 30, in Object.onceWrapper
  File "events.js", line 116, col 13, in emitOne
  File "events.js", line 211, col 7, in Socket.emit
  File "net.js", line 557, col 12, in TCP._handle.close [as _onclose]

And you can sort of see the frequency here in my Sentry logs:

Operations are usually very quick, when using the MongoDB database profiler and monitoring over a few minutes period only 1 or 2 queries took > 5ms.

I've not bumped the poolSize up greater than 50 so far as I would like to get rid of the authentication errors before bumping this up.

[vkarpov15]

Did any of those queries that took > 5ms take much longer than > 5 ms? Also, have you tried profiling how long these queries take in your application? Intermittent spikes in network latency might explain this issue.

[vkarpov15]

Hmmm so looking more closely at this, the not authorized on nanowire to execute command { find: "system.users", filter: {}, $db: "nanowire" } error message in your logs looks suspicious. Does your application query the system.users collection directly? Or does your application call addUser() or removeUser() ? As far as I can see, those are the only two explanations for that error message, and manipulating database users in your application would explain why your app is seeing authentication errors.

[SankaD]

I'm also getting following error when connecting to MongoDb Atlas from Firebase functions. Only happens when the servers been idle for sometime. Then doesn't work till I deploy functions again.

{ MongoError: command update requires authentication
    at /user_code/node_modules/mongoose/node_modules/mongodb-core/lib/connection/pool.js:581:63
    at authenticateStragglers (/user_code/node_modules/mongoose/node_modules/mongodb-core/lib/connection/pool.js:504:16)
    at Connection.messageHandler (/user_code/node_modules/mongoose/node_modules/mongodb-core/lib/connection/pool.js:540:5)
    at emitMessageHandler (/user_code/node_modules/mongoose/node_modules/mongodb-core/lib/connection/connection.js:310:10)
    at TLSSocket.<anonymous> (/user_code/node_modules/mongoose/node_modules/mongodb-core/lib/connection/connection.js:453:17)
    at emitOne (events.js:96:13)
    at TLSSocket.emit (events.js:188:7)
    at readableAddChunk (_stream_readable.js:176:18)
    at TLSSocket.Readable.push (_stream_readable.js:134:10)
    at TLSWrap.onread (net.js:559:20)
  operationTime: Timestamp { _bsontype: 'Timestamp', low_: 1, high_: 1540468510 },
  ok: 0,
  errmsg: 'command update requires authentication',
  code: 13,
  codeName: 'Unauthorized',
  '$clusterTime': 
   { clusterTime: Timestamp { _bsontype: 'Timestamp', low_: 1, high_: 1540468510 },
     signature: { hash: [Object], keyId: [Object] } },
  name: 'MongoError' }

[vkarpov15]

@SankaD approximately how long is "sometime"?

[SankaD]

@vkarpov15 more than an hour as I found (couldn't measure since it was random). But I think I've found my issue.

It seems to be related to not closing the mongoose connection when the firebase function instance is trying to exit (just my guess). Added the following lines to firebase functions. issue now occurs only rarely.

process.on('SIGINT', () => {
   mongoose.connection.close(() => {
        logger.info('Mongoose disconnected on app termination');
    });
});

[vkarpov15]

Interesting. I have never tried mongoose with firebase functions, will check it out

[vkarpov15]

@SankaD do you have a guide somewhere on how to connect to Atlas using Firebase functions? I'm getting the below error when deploying a firebase function that looks like this:

const functions = require('firebase-functions');
const mongoose = require('mongoose');

mongoose.connect('mongodb://OMITTED'); // Atlas URI without +srv
mongoose.model('Test', new mongoose.Schema({ name: String }));

// // Create and Deploy Your First Cloud Functions
// // https://firebase.google.com/docs/functions/write-firebase-functions
//
exports.helloWorld = functions.https.onRequest((request, response) => {
  response.send("Hello from Firebase!");
});

exports.mongooseTest = functions.https.onRequest((req, res) => {
  try {
  mongoose.model('Test').findOne().then(() => res.send('Query succeeded')).catch(err => res.send('Query error: ' + err.message));
  } catch(err) {
    res.send('Sync error: ' + err.message);
  }
});

Seems weird that I can't get Mongoose to successfully connect from Firebase functions. Is there anything else I need to do?

[SankaD]

@vkarpov15 Have you whitelisted your IP on atlas?

Following is my connection code.

```javascript
mongoose.connect(functions.config().mongo_url, {
useNewUrlParser: true,
dbName: "testdb",
keepAlive: true,
socketTimeoutMS: 540000
});

[vkarpov15]

I'll double check. I'm pretty certain I just allow connections from all IPs on my test Atlas instance...

[vkarpov15]

@SankaD I found what the issue is: firebase functions doesn't allow outbound connections from functions unless you pay them $25/mo:

That's a little too expensive to try to repro this issue. Since you have a fix that works, I'm just going to close this for now and we can re-open if this issue pops up again.

[SankaD]

@vkarpov15 It's not exactly solved. It just comes once every 2,3 days. So not a big issue currently. Thanks.

[chhatrachhorm]

I also face the same issue.
Does anyone know the workaround?
Why would this issue be closed although there isn't any solution at all?

[vkarpov15]

@chhatrachhorm please provide some code samples or more information. This issue is closed because we haven't been able to repro it.

[sd031]

I am also facing this issue, for version 5.4.7, getting error:

error_data: {"operationTime":"6669675531664883727","ok":0,"errmsg":"command find requires authentication","code":13,"codeName":"Unauthorized","$clusterTime":{"clusterTime":"6669675531664883727","signature":{"hash":"jqjMmazFtCflNf4HZVikFGd4xbE=","keyId":"6634412437120483330"}},"name":"MongoError"}

Do anyone have any idea why this happening, my config is:
{
keepAlive: true,
socketTimeoutMS: 540000,
autoReconnect: true,
poolSize: 20,
reconnectInterval: 500,
reconnectTries: Number.MAX_VALUE,
}

I am using mongoDb atlas.