1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
|
/**
* Tests for the connection establishment metrics.
*
* @tags: [requires_fcv_61, featureFlagConnHealthMetrics]
*/
(function() {
"use strict";
load("jstests/libs/fail_point_util.js");
load("jstests/libs/log.js");
load("jstests/libs/parallel_shell_helpers.js");
function hasNonNegativeAttr(entry, attrName) {
return entry.attr.hasOwnProperty(attrName) && entry.attr[attrName] >= 0;
}
function hasNullAttr(entry, attrName) {
return entry.attr.hasOwnProperty(attrName) && entry.attr[attrName] == null;
}
function hasOptionalMillisAttr(entry, attrName) {
return hasNullAttr(entry, attrName) || hasNonNegativeAttr(entry, attrName + 'Millis');
}
function validateSlowConnectionLogEntry(entry) {
assert(entry.hasOwnProperty('attr'));
assert(entry.attr.hasOwnProperty('hostAndPort'));
assert(hasNonNegativeAttr(entry, 'dnsResolutionTimeMillis'));
assert(hasNonNegativeAttr(entry, 'tcpConnectionTimeMillis'));
assert(hasOptionalMillisAttr(entry, 'tlsHandshakeTime'));
assert(hasNonNegativeAttr(entry, 'authTimeMillis'));
assert(hasOptionalMillisAttr(entry, 'hookTime'));
assert(hasNonNegativeAttr(entry, 'totalTimeMillis'));
let total = entry.attr.dnsResolutionTimeMillis + entry.attr.tcpConnectionTimeMillis +
entry.attr.authTimeMillis;
if (entry.attr.tlsHandshakeTimeMillis >= 0) {
total += entry.attr.tlsHandshakeTimeMillis;
}
if (entry.attr.hookTimeMillis >= 0) {
total += entry.attr.hookTimeMillis;
}
assert.eq(total, entry.attr.totalTimeMillis);
}
function validateLogAndExtractEntry() {
const mongosLog = assert.commandWorked(st.s.adminCommand({getLog: "global"}));
let queryLogEntry = null;
for (const line of findMatchingLogLines(mongosLog.log, {id: 6496400})) {
let entry = JSON.parse(line);
validateSlowConnectionLogEntry(entry);
if (entry.attr.totalTimeMillis >= kConnectionEstablishmentDelayMillis) {
queryLogEntry = entry;
}
}
return 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, 'transportLayerASIOdelayConnection', {millis: kConnectionEstablishmentDelayMillis});
assert.commandWorked(st.s.adminCommand(
{setParameter: 1, slowConnectionThresholdMillis: kConnectionEstablishmentDelayMillis}));
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);
jsTestLog("Checking the mongos log.");
assert.soon(() => validateLogAndExtractEntry() != null,
"Slow connection establishment log entry not found.",
5000,
250);
queryShell();
connDelayFailPoint.off();
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();
})();
|
