Mongoose: readyState incorrect for replica-sets

[mayrbenjamin92]

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

What is the current behavior?
We are using the following expression:

mongoose.connection.readyState === 1

to determine whether we are successfully connected to a MongoDB replica set. This expression is part of a "health-check" handler in one of our micro-services which runs on top of Kubernetes. As soon as one of the replica-set members gets stopped, mongoose successfully reconnects, but the "readyState" will never ever be 1 again - which breaks the expression from above.

It seems, that there is currently no nice way to retrieve the information whether the application is currently correctly connected to a replica-set - the value works fine for standalone MongoDB deployments (a ka non-replica-set).

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

• connect your application to a MongoDB replica-set
• regularly console-log the value of mongoose.connection.readyState
• switch of one of the replica-set members
• see that the value switches to 0 (disconnected), but never switches back to 1
• see that you can actually use mongoose and e.g. execute queries without issues.

What is the expected behavior?
The "readyState" flag should be correct, even if used with a replica-set. There should be a way to determine whether we are properly connected to the database.

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

• Node.JS: 12.13
• Mongoose: 5.7.1
• MongoDB: 3.4.3

[nhitchins]

+1

• Node JS 10.16.0
• Mongoose: 5.6.9
• MongoDB: 4.0.13

I noticed mongodb driver just updated to 3.3.4 which fixes a bunch of possibly related issues.
https://github.com/mongodb/node-mongodb-native/blob/HEAD/HISTORY.md

[tomgrossman]

@nhitchins it seems that 3.3.4 fix this issue, hopefully mongoose release a minor update soon. @vkarpov15

[mayrbenjamin92]

@nhitchins do you have a plan when a minor could be released?

[lahiruchandima]

@mayrbenjamin92 try setting useUnifiedTopology to false when creating the mongoose connection. It worked for me.

But, if you tried certain operations like startSession() while connection is broken, they hang indefinitely, and doesn't complete even when reconnection happens: #8319

[mayrbenjamin92]

@lahiruchandima we already use the "useUnifiedTopology" setting. The "readyState" still reports 0, but we can query our replica-set without issues!

[lahiruchandima]

@mayrbenjamin92 useUnifiedTopology should be set to false. There are lot of open bugs related to useUnifiedTopology. Check https://jira.mongodb.org/browse/NODE-2147?jql=text%20~%20%22useUnifiedTopology%22

[vkarpov15]

@mayrbenjamin92 I can confirm this is a bug in 5.7.1, but it looks fixed in 5.7.10. The below script continues to print '1' after losing connection to the replica set primary in 5.7.10:

'use strict';

const mongoose = require('mongoose');

mongoose.connect('mongodb://localhost:27017,localhost:27018,localhost:27019/test?replicaSet=rs', {
  useNewUrlParser: true,
  useUnifiedTopology: true
});

setInterval(() => console.log(new Date(), mongoose.connection.readyState), 2000);

Upgrade to 5.7.10 and this issue should be fixed :+1:

[tomgrossman]

@vkarpov15 I'm using 5.7.10 and this issue is real. The only thing that solves it, is upgrading to mongodb 3.3.4.

This is my rs.status() output:

{
    "set" : "rs_test",
    "date" : ISODate("2019-11-19T07:10:11.813Z"),
    "myState" : 1,
    "term" : NumberLong(1),
    "syncingTo" : "",
    "syncSourceHost" : "",
    "syncSourceId" : -1,
    "heartbeatIntervalMillis" : NumberLong(2000),
    "optimes" : {
        "lastCommittedOpTime" : {
            "ts" : Timestamp(1574147406, 1),
            "t" : NumberLong(1)
        },
        "readConcernMajorityOpTime" : {
            "ts" : Timestamp(1574147406, 1),
            "t" : NumberLong(1)
        },
        "appliedOpTime" : {
            "ts" : Timestamp(1574147406, 1),
            "t" : NumberLong(1)
        },
        "durableOpTime" : {
            "ts" : Timestamp(1574147406, 1),
            "t" : NumberLong(1)
        }
    },
    "lastStableCheckpointTimestamp" : Timestamp(1574147393, 2),
    "members" : [ 
        {
            "_id" : 0,
            "name" : "tom-laptop:27017",
            "health" : 1.0,
            "state" : 1,
            "stateStr" : "PRIMARY",
            "uptime" : 33,
            "optime" : {
                "ts" : Timestamp(1574147406, 1),
                "t" : NumberLong(1)
            },
            "optimeDate" : ISODate("2019-11-19T07:10:06.000Z"),
            "syncingTo" : "",
            "syncSourceHost" : "",
            "syncSourceId" : -1,
            "infoMessage" : "could not find member to sync from",
            "electionTime" : Timestamp(1574147391, 2),
            "electionDate" : ISODate("2019-11-19T07:09:51.000Z"),
            "configVersion" : 2,
            "self" : true,
            "lastHeartbeatMessage" : ""
        }, 
        {
            "_id" : 1,
            "name" : "tom-laptop:27016",
            "health" : 1.0,
            "state" : 2,
            "stateStr" : "SECONDARY",
            "uptime" : 5,
            "optime" : {
                "ts" : Timestamp(1574147406, 1),
                "t" : NumberLong(1)
            },
            "optimeDurable" : {
                "ts" : Timestamp(1574147406, 1),
                "t" : NumberLong(1)
            },
            "optimeDate" : ISODate("2019-11-19T07:10:06.000Z"),
            "optimeDurableDate" : ISODate("2019-11-19T07:10:06.000Z"),
            "lastHeartbeat" : ISODate("2019-11-19T07:10:10.444Z"),
            "lastHeartbeatRecv" : ISODate("2019-11-19T07:10:10.977Z"),
            "pingMs" : NumberLong(0),
            "lastHeartbeatMessage" : "",
            "syncingTo" : "tom-laptop:27017",
            "syncSourceHost" : "tom-laptop:27017",
            "syncSourceId" : 0,
            "infoMessage" : "",
            "configVersion" : 2
        }
    ],
    "ok" : 1.0,
    "operationTime" : Timestamp(1574147406, 1),
    "$clusterTime" : {
        "clusterTime" : Timestamp(1574147406, 1),
        "signature" : {
            "hash" : { "$binary" : "AAAAAAAAAAAAAAAAAAAAAAAAAAA=", "$type" : "00" },
            "keyId" : NumberLong(0)
        }
    }
}

This is my app.js:

const mongoose = require('mongoose');

const opts = {
    useNewUrlParser: true,
    useUnifiedTopology: true
};

mongoose.connect('mongodb://tom-laptop:27017,tom-laptop:27016/test?replicaSet=rs_test', opts);

mongoose.connection.on('open', () => {
    console.log('open');
});

mongoose.connection.on('close', () => {
    console.log('close');
});

mongoose.connection.on('disconnected', () => {
    console.log('disconnected');
});

mongoose.connection.on('connected', () => {
    console.log('connected');
});

mongoose.connection.on('connecting', () => {
    console.log('connecting');
});

mongoose.connection.on('reconnected', () => {
    console.log('reconnected');
});

mongoose.connection.on('error', (err) => {
    console.error('error', err);
});

mongoose.connection.on('fullsetup', () => {
    console.log('fullsetup');
});

mongoose.connection.on('all', () => {
    console.log('all');
});

mongoose.connection.on('reconnectFailed', (err) => {
    console.error('reconnectFailed', err);
});

setInterval(() => {
    console.log(mongoose.connection.readyState)
}, 2000);

using mongoose 5.7.10 of course.
running while doing rs.stepDown() in the primary member in the middle, this is the output:

open
1
1
1
disconnected
0
0
0

when upgrading manually to mongodb 3.3.4, the issue is resolved. There is a reconnection and the readyState is 1.

Please reopen this issue

[mayrbenjamin92]

@tomgrossman You can simply upgrade to mongoose >= 5.7.11 (or even 5.7.12) which was released yesterday. I can validate that 5.7.11 works as they have upgraded the mongodb driver to 3.3.4 in 5.7.11 :)