Loading...

Type: Bug
Resolution: Gone away
Priority: Major - P3
Fix Version/s: None
Affects Version/s: 3.5.6
Component/s: None
Labels:
- external-user

Confidence Status:
None

Aha! Reference:
None
Tracking Level:
None
Risk Status:
None
Exec Notes:
None
Goal Link:
None
Goal Name(s):
None

If useUnifiedTopology is set while connected to a replicaset, the behavior of the driver to reject operations when connection between app <-> DB is lost is not always consistent.

After the fix mentioned in ~~NODE-2364~~, the operations are not stuck anymore and properly rejected by the driver. However, this rejection doesn't respect the settings of serverSelectionTimeoutMS, socketTimeoutMS and connectTimeoutMS. In our case, I have made a test from my laptop connecting to a replica set on Mongo Atlas with the aforementioned parameters all set to 2000ms with the expectation that across connection losses (simulated by turning of Wifi periodically for 30s every 1 minute), the queries connecting should be rejected after ~2000ms. However, with a sampling test of ~50 queries, there were always 2-3 cases where the rejected queries were rejected after much longer than ~2000ms as the test result shown below (the 28th query was rejected after 32073ms):

2 => { status: 'released', elapsed: 263 },
 3 => { status: 'released', elapsed: 263 },
 4 => { status: 'released', elapsed: 263 },
 5 => { status: 'released', elapsed: 264 },
 6 => { status: 'released', elapsed: 272 },
 7 => { status: 'released', elapsed: 236 },
 8 => { status: 'released', elapsed: 246 },
 9 => { status: 'released', elapsed: 305 },
 10 => { status: 'released', elapsed: 242 },
 11 => { status: 'released', elapsed: 237 },
 12 => { status: 'released', elapsed: 251 },
 13 => { status: 'released', elapsed: 236 },
 14 => { status: 'released', elapsed: 229 },
 15 => { status: 'released', elapsed: 239 },
 16 => { status: 'released', elapsed: 238 },
 17 => { status: 'released', elapsed: 222 },
 18 => { status: 'released', elapsed: 248 },
 19 => { status: 'released', elapsed: 254 },
 20 => { status: 'released', elapsed: 233 },
 21 => { status: 'released', elapsed: 246 },
 22 => { status: 'released', elapsed: 240 },
 23 => { status: 'released', elapsed: 229 },
 24 => { status: 'released', elapsed: 269 },
 25 => { status: 'released', elapsed: 251 },
 26 => { status: 'released', elapsed: 260 },
 27 => { status: 'released', elapsed: 243 },
 28 => { status: 'error', elapsed: 32073 },
 29 => { status: 'error', elapsed: 2003 },
 30 => { status: 'error', elapsed: 2024 },
 31 => { status: 'error', elapsed: 2005 },
 32 => { status: 'released', elapsed: 245 },
 33 => { status: 'released', elapsed: 243 },
 34 => { status: 'released', elapsed: 252 },
 35 => { status: 'released', elapsed: 509 },
 36 => { status: 'error', elapsed: 3037 },
 37 => { status: 'error', elapsed: 2003 },
 38 => { status: 'error', elapsed: 2007 },
 39 => { status: 'error', elapsed: 2006 },
 40 => { status: 'error', elapsed: 2002 },
 41 => { status: 'error', elapsed: 2006 },
 42 => { status: 'error', elapsed: 2004 },
 43 => { status: 'error', elapsed: 2009 },
 44 => { status: 'error', elapsed: 2005 },
 45 => { status: 'error', elapsed: 2007 },
 46 => { status: 'error', elapsed: 2011 }

The test code:

const dbServiceProvider = 'test';
const connString = 'mongodb://srv1:27017,srv2:27017,srv3:27017/test?ssl=true&replicaSet=Cluster0-shard-0&authSource=admin&retryWrites=true&w=majority';
const options = {
    useNewUrlParser: true,
    useUnifiedTopology: true,
    minSize: 1,
    poolSize: 2,
    ssl: true,
    serverSelectionTimeoutMS: 2000,
    socketTimeoutMS: 2000,
    connectTimeoutMS: 2000
};
function patchEmitter(emitter) {
    var oldEmit = emitter.emit;
    emitter.emit = function () {
        var emitArgs = arguments;
        console.log(emitArgs[0]);
        oldEmit.apply(emitter, arguments);
    }
}
async function wait(ms) {
    return new Promise((resolve) => {
        setTimeout(resolve, ms);
    });
}
async function connect() {
    const client = await MongoClient.connect(connString, options);
    patchEmitter(client);
    return client.db(dbServiceProvider);
}
var count = 1;
var connected = false;
var dbClient;
var connectionStatus = new Map();
var connectionClosed = false;
async function test() {
    if (!connected) {
        console.log("connecting ====>");
        dbClient = await connect();
        connected = true;
    }
    while (true) {
        await wait(2000);
        var idx = ++count;
        var time = new Date().getTime();
        try {
            console.error("Connection status: ====>", connectionStatus);
            connectionStatus.set(idx, { status: "not_released", since: time });
            console.log('data loading', idx);
            const result = await dbClient.collection("tasks").find({}).limit(1).toArray();
            console.log('data loaded', idx);
            connectionStatus.set(idx, { status: "released", elapsed: new Date().getTime() - time });
        } catch (e) {
            console.error(e, 'error');
            console.error("elapsed time", new Date().getTime() - time);
            connectionStatus.set(idx, { status: "error", elapsed: new Date().getTime() - time });
        }
    }
}

async function closeConnection() {
    console.error("turn-off wifi =====> ")
    execSync("sudo networksetup -setnetworkserviceenabled Wi-Fi off")
    connectionClosed = true
    setTimeout(openConnection, 30000);
}

async function openConnection() {
    console.error("enable wifi =====> ")
    execSync("sudo networksetup -setnetworkserviceenabled Wi-Fi on")
    setTimeout(() => {
        connectionClosed = false
    }, 5000)
}

test();
setInterval(closeConnection, 60000);

Details

Description

Attachments

Activity

People

Dates