diff options
Diffstat (limited to 'jstests/noPassthrough/connection_establishment_metrics.js')
-rw-r--r-- | jstests/noPassthrough/connection_establishment_metrics.js | 132 |
1 files changed, 86 insertions, 46 deletions
diff --git a/jstests/noPassthrough/connection_establishment_metrics.js b/jstests/noPassthrough/connection_establishment_metrics.js index 1a57dc2a25b..3ef97392b60 100644 --- a/jstests/noPassthrough/connection_establishment_metrics.js +++ b/jstests/noPassthrough/connection_establishment_metrics.js @@ -39,7 +39,8 @@ function validateSlowConnectionLogEntry(entry) { } assert.eq(total, entry.attr.totalTimeMillis); } -function validateLogAndExtractEntry() { + +function validateLogAndExtractEntry(st) { const mongosLog = assert.commandWorked(st.s.adminCommand({getLog: "global"})); let queryLogEntry = null; for (const line of findMatchingLogLines(mongosLog.log, {id: 6496400})) { @@ -52,59 +53,98 @@ function validateLogAndExtractEntry() { return queryLogEntry; } +function validateLogAndExtractCountAndEntry(st) { + const mongosLog = assert.commandWorked(st.s.adminCommand({getLog: "global"})); + let queryLogEntry = null; + let matchingLines = findMatchingLogLines(mongosLog.log, {id: 6496400}); + for (const line of matchingLines) { + let entry = JSON.parse(line); + validateSlowConnectionLogEntry(entry); + if (entry.attr.totalTimeMillis >= kConnectionEstablishmentDelayMillis) { + queryLogEntry = entry; + } + } + return {count: matchingLines.length, entry: queryLogEntry}; +} + const kConnectionEstablishmentDelayMillis = 250; const kDBName = 'TestDB'; const kCollectionName = 'sharded_coll'; const kKeyName = 'foo'; -let st = new ShardingTest({shards: 1}); - -jsTestLog("Setting up the test collection."); - -assert.commandWorked(st.s.adminCommand({enableSharding: kDBName})); -assert.commandWorked( - st.s.adminCommand({shardcollection: `${kDBName}.${kCollectionName}`, key: {[kKeyName]: 1}})); - -let db = st.getDB(kDBName); -assert.commandWorked(db[kCollectionName].insertOne({primaryOnly: true, [kKeyName]: 42})); - -jsTestLog("Activating the delay in connection establishment."); -let connDelayFailPoint = configureFailPoint( - st.s, 'asioTransportLayerDelayConnection', {millis: kConnectionEstablishmentDelayMillis}); -assert.commandWorked(st.s.adminCommand( - {setParameter: 1, slowConnectionThresholdMillis: kConnectionEstablishmentDelayMillis})); -assert.commandWorked( - st.s.adminCommand({dropConnections: 1, hostAndPort: [st.rs0.getPrimary().host]})); - -jsTestLog("Running the query."); - -function runTestQuery(db) { - return startParallelShell( - funWithArgs((host, dbName, collName, keyName) => { - let conn = new Mongo(host); - assert.eq(1, - conn.getDB(dbName) - .getCollection(collName) - .find({primaryOnly: true, [keyName]: 42}) - .itcount()); - }, db.getMongo().host, db.getName(), kCollectionName, kKeyName), null, true); -} -let queryShell = runTestQuery(db); +let runTest = (connectionHealthLoggingOn) => { + let st = new ShardingTest({shards: 1}); + + if (!connectionHealthLoggingOn) { + assert.commandWorked(st.s.adminCommand( + {setParameter: 1, enableDetailedConnectionHealthMetricLogLines: false})); + } + + const initialLogEntryCount = validateLogAndExtractCountAndEntry(st).count; + + jsTestLog("Setting up the test collection."); + + assert.commandWorked(st.s.adminCommand({enableSharding: kDBName})); + assert.commandWorked(st.s.adminCommand( + {shardcollection: `${kDBName}.${kCollectionName}`, key: {[kKeyName]: 1}})); + + let db = st.getDB(kDBName); + assert.commandWorked(db[kCollectionName].insertOne({primaryOnly: true, [kKeyName]: 42})); + + jsTestLog("Activating the delay in connection establishment."); + let connDelayFailPoint = configureFailPoint( + st.s, 'asioTransportLayerDelayConnection', {millis: kConnectionEstablishmentDelayMillis}); + assert.commandWorked(st.s.adminCommand( + {setParameter: 1, slowConnectionThresholdMillis: kConnectionEstablishmentDelayMillis})); + assert.commandWorked( + st.s.adminCommand({dropConnections: 1, hostAndPort: [st.rs0.getPrimary().host]})); + + jsTestLog("Running the query."); + + function runTestQuery(db) { + return startParallelShell( + funWithArgs((host, dbName, collName, keyName) => { + let conn = new Mongo(host); + assert.eq(1, + conn.getDB(dbName) + .getCollection(collName) + .find({primaryOnly: true, [keyName]: 42}) + .itcount()); + }, db.getMongo().host, db.getName(), kCollectionName, kKeyName), null, true); + } + let queryShell = runTestQuery(db); + + if (connectionHealthLoggingOn) { + jsTestLog("Checking the mongos log."); + + assert.soon(() => validateLogAndExtractCountAndEntry(st).entry != null, + "Slow connection establishment log entry not found."); -jsTestLog("Checking the mongos log."); + queryShell(); + connDelayFailPoint.off(); -assert.soon(() => validateLogAndExtractEntry() != null, - "Slow connection establishment log entry not found."); + jsTestLog("Checking the output of serverStatus."); + let queryLogEntry = validateLogAndExtractCountAndEntry(st).entry; + let status = assert.commandWorked(st.s.adminCommand({serverStatus: 1})); + printjson(status); + assert.gte(status.metrics.network.totalEgressConnectionEstablishmentTimeMillis, + queryLogEntry.attr.totalTimeMillis); + } else { + assert.eq(validateLogAndExtractCountAndEntry(st).count, initialLogEntryCount); -queryShell(); -connDelayFailPoint.off(); + queryShell(); + connDelayFailPoint.off(); + + jsTestLog("Checking the output of serverStatus."); + let status = assert.commandWorked(st.s.adminCommand({serverStatus: 1})); + printjson(status); + assert.gte(status.metrics.network.totalEgressConnectionEstablishmentTimeMillis, 0); + } -jsTestLog("Checking the output of serverStatus."); -let queryLogEntry = validateLogAndExtractEntry(); -let status = assert.commandWorked(st.s.adminCommand({serverStatus: 1})); -printjson(status); -assert.gte(status.metrics.network.totalEgressConnectionEstablishmentTimeMillis, - queryLogEntry.attr.totalTimeMillis); + st.stop(); +}; -st.stop(); +// Parameter is connectionHealthLoggingOn == true/false +runTest(true); +runTest(false); })(); |