5.8.3 introduces connection issue. works in 5.8.2

[amit777]

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

What is the current behavior? My node app connects to a mongodb sharded cluster using mongos successfully

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

I'm providing this report asap and still trying to figure out a reproduction. All I know is that as soon as I upgrade to 5.8.3, my node app fails to connect to the mongo cluster with this error:

connecting to activity.db=

mongodb://localhost:27018/test_db 

dbOptions={"db":{"native_parser":true},"mongos":{"poolSize":5,"socketOptions":{"socketTimeoutMS":1000000,"connectTimeoutMS":1000,"keepAlive":120}}}

MongoNetworkError: failed to connect to server [localhost:27018] on first connect [MongoNetworkError: connection timed out
    at connectionFailureError (/opt/app/node_modules/mongodb/lib/core/connection/connect.js:377:14)
    at Socket.<anonymous> (/opt/app/node_modules/mongodb/lib/core/connection/connect.js:276:16)
    at Object.onceWrapper (events.js:299:28)
    at Socket.emit (events.js:210:5)
    at Socket.EventEmitter.emit (domain.js:476:20)
    at Socket._onTimeout (net.js:468:8)
    at listOnTimeout (internal/timers.js:531:17)
    at processTimers (internal/timers.js:475:7) {
  name: 'MongoNetworkError',
  [Symbol(mongoErrorContextSymbol)]: {}
}]
    at Pool.<anonymous> (/opt/app/node_modules/mongodb/lib/core/topologies/server.js:433:11)
    at Pool.emit (events.js:210:5)
    at Pool.EventEmitter.emit (domain.js:476:20)
    at /opt/app/node_modules/mongodb/lib/core/connection/pool.js:577:14
    at /opt/app/node_modules/mongodb/lib/core/connection/pool.js:1007:11
    at /opt/app/node_modules/mongodb/lib/core/connection/connect.js:31:7
    at callback (/opt/app/node_modules/mongodb/lib/core/connection/connect.js:247:5)
    at Socket.<anonymous> (/opt/app/node_modules/mongodb/lib/core/connection/connect.js:276:7)
    at Object.onceWrapper (events.js:299:28)
    at Socket.emit (events.js:210:5)
    at Socket.EventEmitter.emit (domain.js:476:20)
    at Socket._onTimeout (net.js:468:8)
    at listOnTimeout (internal/timers.js:531:17)
    at processTimers (internal/timers.js:475:7) {
  name: 'MongoNetworkError',
  [Symbol(mongoErrorContextSymbol)]: {}
}

What is the expected behavior? The app should connect to the sharded cluster

What are the versions of Node.js, Mongoose and MongoDB you are using? Note that "latest" is not a version.

Node 12.13.0 Mongoose 5.8.3 (has the issue). 5.8.2 (does not have issue) MongoDB: 3.4.23

[amit777]

Here is my code for connecting:

var mongoose = require('mongoose');
mongoose.Promise = global.Promise;
var Schema = mongoose.Schema;
var config = require('config');
var chalk = require('chalk');

var conn;
var connect = function () {
  const dburl = config.get('activity.db');
  const dbOptions = config.get('activity.dbOptions');
  console.log(chalk.green(`activity.js: connecting to activity.db=${dburl} activity.dbOptions=` + JSON.stringify(dbOptions)));
  conn = mongoose.createConnection(dburl, dbOptions);
  console.log(chalk.green(`activity.js: don calling createConnection(dburl, dbOptions)`));
};
connect();
conn.on('error', console.log);
conn.on('disconnected', connect);
conn.on('timeout', function (e) {
  console.log('####Error: ACTIVITYPUMP TIMEOUT EVENT CAUGHT' + e);
});

One note is that I haven't moved some config options to the top level so i'm getting deprecation warnings.

[amit777]

Note: it looks like mongodb dep was upgraded from 3.3.4 to 3.4.1. Maybe this issue was introduced in there? I don't see any other obvious change from mongoose 5.8.2 to 5.8.3 that could be the culprit.

[amit777]

create mongodb JIRA issue here for reference: https://jira.mongodb.org/browse/NODE-2399

[amit777]

after some more research, it looks like this may be due to a connect timeout since we have it set to 1000ms. If I remove this, it seems like everything works even in 5.8.3. Will test some more. So basically something seems to have been introduced into the latest mongodb driver that causes my connection time to exceed our current 1000ms threshold consistently. When I'm at 5.8.2, the connection does not timeout.

[markstos]

I can reproduce this issue and think this issue should be re-opened until it's better understood.

Our test suite passes with Mongoose 5.8.2 but fails with 5.8.3. We get the same error:

MongoNetworkError: failed to connect to server [localhost:27018] on first connect

I've tried playing with the connection options and am not able to resolve it so far. I've started using eachAsync() and would like to upgrade further to get access to a bug fix for it, but this issue is blocking the upgrade.

I'm looking at it more today.

[markstos]

I determined that our case the issue is triggered when useUnifiedTopology is set to false and resolved when useUnifiedTopology is set to true. Since we were planning on updating this setting anyway, this is an acceptable resolution for us.

[markstos]

This problem is potentially a major issue for people are using 5.8.X < 5.8.3 and believe they can safely upgrade to a later version in the 5.8.X series. This issue brings an app completely crashing down.

[vkarpov15]

@markstos I'm glad you fixed the issue. I haven't been able to repro this issue, so I'll keep it closed - anyone who is experiencing a similar issue should open up a new issue.