Connection timeout in Mongoose, Mongo server sees a connection that stays for 6ms only #9094

Gp2mv3 · 2020-06-04T16:13:12Z

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

What is the current behavior?
I receive connection timeout when connecting to my mongo container (freshly started, pinging and running) in my tests (using Gitlab-runner in docker).

Here is the complete stacktrace:

{ MongooseServerSelectionError: connection timed out
    at NativeConnection.Connection.openUri (/opt/app/node_modules/mongoose/lib/connection.js:823:32)
    at Mongoose.connect (/opt/app/node_modules/mongoose/lib/index.js:333:15)
    at connectToMongo (/opt/app/src/models/index.js:1:4306)
    at Object.<anonymous> (/opt/app/src/models/index.js:1:4698)
    at Module._compile (internal/modules/cjs/loader.js:778:30)
    at Module.replacementCompile (/opt/app/node_modules/nyc/node_modules/append-transform/index.js:58:13)
    at Module._compile (/opt/app/node_modules/pirates/lib/index.js:99:24)
    at Module._extensions..js (internal/modules/cjs/loader.js:789:10)
    at /opt/app/node_modules/nyc/node_modules/append-transform/index.js:62:4
    at newLoader (/opt/app/node_modules/pirates/lib/index.js:104:7)
    at Object.<anonymous> (/opt/app/node_modules/nyc/node_modules/append-transform/index.js:62:4)
    at Module.load (internal/modules/cjs/loader.js:653:32)
    at tryModuleLoad (internal/modules/cjs/loader.js:593:12)
    at Function.Module._load (internal/modules/cjs/loader.js:585:3)
    at Module.require (internal/modules/cjs/loader.js:692:17)
    at require (internal/modules/cjs/helpers.js:25:18)
    at Object.<anonymous> (/opt/app/src/app.js:1:38668)
    at Module._compile (internal/modules/cjs/loader.js:778:30)
    at Module.replacementCompile (/opt/app/node_modules/nyc/node_modules/append-transform/index.js:58:13)
    at Module._compile (/opt/app/node_modules/pirates/lib/index.js:99:24)
    at Module._extensions..js (internal/modules/cjs/loader.js:789:10)
    at /opt/app/node_modules/nyc/node_modules/append-transform/index.js:62:4
    at newLoader (/opt/app/node_modules/pirates/lib/index.js:104:7)
    at Object.<anonymous> (/opt/app/node_modules/nyc/node_modules/append-transform/index.js:62:4)
    at Module.load (internal/modules/cjs/loader.js:653:32)
    at tryModuleLoad (internal/modules/cjs/loader.js:593:12)
    at Function.Module._load (internal/modules/cjs/loader.js:585:3)
    at Module.require (internal/modules/cjs/loader.js:692:17)
    at require (internal/modules/cjs/helpers.js:25:18)
    at Object.<anonymous> (/opt/app/test/api/ads.js:4:1)
    at Module._compile (internal/modules/cjs/loader.js:778:30)
    at Module.replacementCompile (/opt/app/node_modules/nyc/node_modules/append-transform/index.js:58:13)
    at Module._compile (/opt/app/node_modules/pirates/lib/index.js:99:24)
    at Module._extensions..js (internal/modules/cjs/loader.js:789:10)
    at /opt/app/node_modules/nyc/node_modules/append-transform/index.js:62:4
    at newLoader (/opt/app/node_modules/pirates/lib/index.js:104:7)
    at Object.<anonymous> (/opt/app/node_modules/nyc/node_modules/append-transform/index.js:62:4)
    at Module.load (internal/modules/cjs/loader.js:653:32)
    at tryModuleLoad (internal/modules/cjs/loader.js:593:12)
    at Function.Module._load (internal/modules/cjs/loader.js:585:3)
    at Module.require (internal/modules/cjs/loader.js:692:17)
    at require (internal/modules/cjs/helpers.js:25:18)
    at /opt/app/node_modules/mocha/lib/mocha.js:334:36
    at Array.forEach (<anonymous>)
    at Mocha.loadFiles (/opt/app/node_modules/mocha/lib/mocha.js:331:14)
    at Mocha.run (/opt/app/node_modules/mocha/lib/mocha.js:809:10)
    at Object.exports.singleRun (/opt/app/node_modules/mocha/lib/cli/run-helpers.js:108:16)
    at exports.runMocha (/opt/app/node_modules/mocha/lib/cli/run-helpers.js:142:13)
    at Object.exports.handler.argv [as handler] (/opt/app/node_modules/mocha/lib/cli/run.js:292:3)
    at Object.runCommand (/opt/app/node_modules/yargs/lib/command.js:242:26)
    at Object.parseArgs [as _parseArgs] (/opt/app/node_modules/yargs/yargs.js:1104:24)
    at Object.parse (/opt/app/node_modules/yargs/yargs.js:566:25)
    at Object.exports.main (/opt/app/node_modules/mocha/lib/cli/cli.js:68:6)
    at Object.<anonymous> (/opt/app/node_modules/mocha/bin/mocha:164:29)
    at Module._compile (internal/modules/cjs/loader.js:778:30)
    at Module.replacementCompile (/opt/app/node_modules/nyc/node_modules/append-transform/index.js:58:13)
    at Module._extensions..js (internal/modules/cjs/loader.js:789:10)
    at Object.<anonymous> (/opt/app/node_modules/nyc/node_modules/append-transform/index.js:62:4)
    at Module.load (internal/modules/cjs/loader.js:653:32)
    at tryModuleLoad (internal/modules/cjs/loader.js:593:12)
    at Function.Module._load (internal/modules/cjs/loader.js:585:3)
    at Function.Module.runMain (internal/modules/cjs/loader.js:831:12)
    at runMain (/root/.node-spawn-wrap-23-7d7347fbfa62/node:68:10)
    at Function.<anonymous> (/root/.node-spawn-wrap-23-7d7347fbfa62/node:171:5)
    at Object.<anonymous> (/opt/app/node_modules/nyc/bin/wrap.js:23:4)
    at Module._compile (internal/modules/cjs/loader.js:778:30)
    at Object.Module._extensions..js (internal/modules/cjs/loader.js:789:10)
    at Module.load (internal/modules/cjs/loader.js:653:32)
    at tryModuleLoad (internal/modules/cjs/loader.js:593:12)
    at Function.Module._load (internal/modules/cjs/loader.js:585:3)
    at Function.Module.runMain (internal/modules/cjs/loader.js:831:12)
    at /root/.node-spawn-wrap-23-7d7347fbfa62/node:178:8
    at Object.<anonymous> (/root/.node-spawn-wrap-23-7d7347fbfa62/node:181:3)
    at Module._compile (internal/modules/cjs/loader.js:778:30)
    at Object.Module._extensions..js (internal/modules/cjs/loader.js:789:10)
    at Module.load (internal/modules/cjs/loader.js:653:32)
    at tryModuleLoad (internal/modules/cjs/loader.js:593:12)
    at Function.Module._load (internal/modules/cjs/loader.js:585:3)
    at Function.Module.runMain (internal/modules/cjs/loader.js:831:12)
    at startup (internal/bootstrap/node.js:283:19)
    at bootstrapNodeJSCore (internal/bootstrap/node.js:623:3)
  message: 'connection timed out',
  reason:
   TopologyDescription {
     type: 'Single',
     setName: null,
     maxSetVersion: null,
     maxElectionId: null,
     servers: Map { 'mongo:27017' => [ServerDescription] },
     stale: false,
     compatible: true,
     compatibilityError: null,
     logicalSessionTimeoutMinutes: null,
     heartbeatFrequencyMS: 10000,
     localThresholdMS: 15,
     commonWireVersion: null } }

The connection config is as follow:

async function connectToMongo() {
  try {
    await mongoose.connect(url, {
      useFindAndModify: false,
      useCreateIndex: true,
      promiseLibrary: global.Promise,
      useNewUrlParser: true,
      useUnifiedTopology: true,
      poolSize: 10,
      family: 4,
    });
  } catch (err) {
    if (err) {
      console.error(err);
      process.exit(1);
      throw err;
    }
  }
}
connectToMongo();

And in the mongo logs, I see those lines related to the connection/disconnection (which is definately not a timeout when looking at the timestamp):

2020-06-04T15:54:31.200+0000 I NETWORK [listener] connection accepted from 172.17.0.5:38864 #1 (1 connection now open)
2020-06-04T15:54:31.206+0000 I NETWORK [conn1] end connection 172.17.0.5:38864 (0 connections now open)

What is the expected behavior?
A correct connection?
Before running my node code, there is a ping to the mongo container (which works fine with the right IP), the two containers are linked correctly and running correctly. I tested on two different runners (Ubuntu & OS X) and the issue is the same.
This problem is complicated to reproduce as it only happens in the gitlab runner and not always: 3/4 of the time.

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

Mongo 4.2, mongoose 5.9.17 and Node 12.

The text was updated successfully, but these errors were encountered:

Gp2mv3 · 2020-06-04T16:14:11Z

What can be the cause of this issue?
I don't think it's related to the environment (in docker containers) as the docker networking part is working well.

rubinovk · 2020-06-16T07:18:53Z

Hi, I'm having a similar error since updating to 5.9.16.

Unhandled rejection MongooseServerSelectionError: connection timed out
    at new MongooseServerSelectionError (D:\App\server\node_modules\mongoose\lib\error\serverSelection.js:24:11)
    at NativeConnection.Connection.openUri (D:\App\server\node_modules\mongoose\lib\connection.js:823:32)
    at Mongoose.createConnection (D:\App\server\node_modules\mongoose\lib\index.js:279:17)
    at Object.openMongoConnection (D:\App\server\connections.js:65:23)
    at Object.openBIG (D:\App\server\connections.js:88:21)
    at Object.<anonymous> (D:\App\server\server.js:63:59)
    at Module._compile (internal/modules/cjs/loader.js:1156:30)
    at Object.Module._extensions..js (internal/modules/cjs/loader.js:1176:10)
    at Module.load (internal/modules/cjs/loader.js:1000:32)
    at Function.Module._load (internal/modules/cjs/loader.js:899:14)
    at Module.require (internal/modules/cjs/loader.js:1042:19)
    at require (internal/modules/cjs/helpers.js:77:18)
    at Object.<anonymous> (C:\Program Files\iisnode\interceptor.js:210:1)
    at Module._compile (internal/modules/cjs/loader.js:1156:30)
    at Object.Module._extensions..js (internal/modules/cjs/loader.js:1176:10)
    at Module.load (internal/modules/cjs/loader.js:1000:32)
    at Function.Module._load (internal/modules/cjs/loader.js:899:14)
    at Function.executeUserEntryPoint [as runMain] (internal/modules/run_main.js:74:12)
    at internal/main/run_main_module.js:18:47

What is the workaround or fix?
Thanks

vkarpov15 · 2020-06-18T17:20:35Z

Without looking at how your docker container is set up, no way for me to know. This error bubbles up from Node sockets' 'timeout' event, so it may be that the MongoDB server isn't allowed to write to the socket?

I'd try connecting to your docker container using the mongo shell: if you can connect with the mongo shell, that means it might be a Mongoose bug. If you can't connect with the mongo shell, that means it is likely a networking issue.

vkarpov15 added this to the 5.9.19 milestone Jun 11, 2020

vkarpov15 added the needs repro script Maybe a bug, but no repro script. The issue reporter should create a script that demos the issue label Jun 11, 2020

vkarpov15 modified the milestones: 5.9.19, 5.9.20 Jun 11, 2020

vkarpov15 removed this from the 5.9.20 milestone Jun 18, 2020

vkarpov15 added help This issue can likely be resolved in GitHub issues. No bug fixes, features, or docs necessary and removed needs repro script Maybe a bug, but no repro script. The issue reporter should create a script that demos the issue labels Jun 18, 2020

vkarpov15 closed this as completed Jul 10, 2020

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Connection timeout in Mongoose, Mongo server sees a connection that stays for 6ms only #9094

Connection timeout in Mongoose, Mongo server sees a connection that stays for 6ms only #9094

Gp2mv3 commented Jun 4, 2020

Gp2mv3 commented Jun 4, 2020

rubinovk commented Jun 16, 2020

vkarpov15 commented Jun 18, 2020

Connection timeout in Mongoose, Mongo server sees a connection that stays for 6ms only #9094

Connection timeout in Mongoose, Mongo server sees a connection that stays for 6ms only #9094

Comments

Gp2mv3 commented Jun 4, 2020

Gp2mv3 commented Jun 4, 2020

rubinovk commented Jun 16, 2020

vkarpov15 commented Jun 18, 2020