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
111
112
113
114
115
116
117
118
119
120
121
|
// Checks that the global histogram counter for transactions are updated as we expect.
// @tags: [requires_replication, uses_transactions]
(function() {
"use strict";
// Set up the replica set.
const rst = new ReplSetTest({nodes: 1});
rst.startSet();
rst.initiate();
const primary = rst.getPrimary();
// Set up the test database.
const dbName = "test";
const collName = "global_transaction_latency_histogram";
const testDB = primary.getDB(dbName);
testDB.runCommand({drop: collName, writeConcern: {w: "majority"}});
assert.commandWorked(testDB.runCommand({create: collName, writeConcern: {w: "majority"}}));
// Start the session.
const sessionOptions = {
causalConsistency: false
};
const session = testDB.getMongo().startSession(sessionOptions);
const sessionDb = session.getDatabase(dbName);
const sessionColl = sessionDb[collName];
function getHistogramStats() {
return testDB.serverStatus({opLatencies: {histograms: 1}}).opLatencies;
}
// Checks that the actual value is within a minimum on the bound of the expected value. All
// arguments must be in the same units.
function assertLowerBound(expected, actual, bound) {
assert.gte(actual, expected - bound);
}
// This function checks the diff between the last histogram and the current histogram, not the
// absolute values.
function checkHistogramDiff(lastHistogram, thisHistogram, fields) {
for (let key in fields) {
if (fields.hasOwnProperty(key)) {
assert.eq(thisHistogram[key].ops - lastHistogram[key].ops, fields[key]);
}
}
return thisHistogram;
}
// This function checks the diff between the last histogram's accumulated transactions latency
// and this histogram's accumulated transactions latency is within a reasonable bound of what
// we expect.
function checkHistogramLatencyDiff(lastHistogram, thisHistogram, sleepTime) {
let latencyDiff = thisHistogram.transactions.latency - lastHistogram.transactions.latency;
// Check the bound in microseconds, which is the unit the latency is in. We do not check
// upper bound because of unknown extra server latency.
assertLowerBound(sleepTime * 1000, latencyDiff, 50000);
return thisHistogram;
}
let lastHistogram = getHistogramStats();
// Verify the base stats are correct.
lastHistogram = checkHistogramDiff(lastHistogram,
getHistogramStats(),
{"reads": 0, "writes": 0, "commands": 1, "transactions": 0});
// Test histogram increments on a successful transaction. "commitTransaction" and "serverStatus"
// commands are counted towards the "commands" counter.
session.startTransaction();
assert.commandWorked(sessionColl.insert({_id: "insert-1"}));
assert.commandWorked(session.commitTransaction_forTesting());
lastHistogram = checkHistogramDiff(lastHistogram,
getHistogramStats(),
{"reads": 0, "writes": 1, "commands": 2, "transactions": 1});
// Test histogram increments on aborted transaction due to error (duplicate insert).
session.startTransaction();
assert.commandFailedWithCode(sessionColl.insert({_id: "insert-1"}), ErrorCodes.DuplicateKey);
lastHistogram = checkHistogramDiff(lastHistogram,
getHistogramStats(),
{"reads": 0, "writes": 1, "commands": 1, "transactions": 1});
// Ensure that the transaction was aborted on failure.
assert.commandFailedWithCode(session.commitTransaction_forTesting(), ErrorCodes.NoSuchTransaction);
lastHistogram = checkHistogramDiff(lastHistogram,
getHistogramStats(),
{"reads": 0, "writes": 0, "commands": 2, "transactions": 0});
// Test histogram increments on an aborted transaction. "abortTransaction" command is counted
// towards the "commands" counter.
session.startTransaction();
assert.commandWorked(sessionColl.insert({_id: "insert-2"}));
assert.commandWorked(session.abortTransaction_forTesting());
lastHistogram = checkHistogramDiff(lastHistogram,
getHistogramStats(),
{"reads": 0, "writes": 1, "commands": 2, "transactions": 1});
// Test histogram increments on a multi-statement committed transaction.
session.startTransaction();
assert.commandWorked(sessionColl.insert({_id: "insert-3"}));
assert.commandWorked(sessionColl.insert({_id: "insert-4"}));
assert.eq(sessionColl.find({_id: "insert-1"}).itcount(), 1);
assert.commandWorked(session.commitTransaction_forTesting());
lastHistogram = checkHistogramDiff(lastHistogram,
getHistogramStats(),
{"reads": 1, "writes": 2, "commands": 2, "transactions": 1});
// Test that the cumulative transaction latency counter is updated appropriately after a
// sequence of back-to-back 200 ms transactions.
const sleepTime = 200;
for (let i = 0; i < 3; i++) {
session.startTransaction();
assert.eq(sessionColl.find({_id: "insert-1"}).itcount(), 1);
sleep(sleepTime);
assert.commandWorked(session.commitTransaction_forTesting());
lastHistogram = checkHistogramLatencyDiff(lastHistogram, getHistogramStats(), sleepTime);
}
session.endSession();
rst.stopSet();
}());
|
