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
|
// tests getlog as well as slow querying logging
//
// @tags: [
// # This test attempts to perform a find command and see that it ran using the getLog command.
// # The former operation may be routed to a secondary in the replica set, whereas the latter must
// # be routed to the primary.
// assumes_read_preference_unchanged,
// does_not_support_stepdowns,
// ]
load("jstests/libs/logv2_helpers.js");
(function() {
'use strict';
// We turn off gossiping the mongo shell's clusterTime because it causes the slow command log
// messages to get truncated since they'll exceed 512 characters. The truncated log messages
// will fail to match the find and update patterns defined later on in this test.
TestData.skipGossipingClusterTime = true;
const glcol = db.getLogTest2;
glcol.drop();
function contains(arr, func) {
let i = arr.length;
while (i--) {
if (func(arr[i])) {
return true;
}
}
return false;
}
function stringContains(haystack, needle) {
if (isJsonLog(db.getMongo())) {
if (needle.indexOf(":"))
needle = '"' + needle.replace(':', "\":");
needle = needle.replace(/ /g, "");
}
return haystack.indexOf(needle) != -1;
}
// test doesn't work when talking to mongos
if (db.hello().msg === "isdbgrid") {
return;
}
// 1. Run a slow query
glcol.save({"SENTINEL": 1});
glcol.findOne({
"SENTINEL": 1,
"$where": function() {
sleep(1000);
return true;
}
});
const query = assert.commandWorked(db.adminCommand({getLog: "global"}));
assert(query.log, "no log field");
assert.gt(query.log.length, 0, "no log lines");
// Ensure that slow query is logged in detail.
assert(contains(query.log, function(v) {
print(v);
return stringContains(v, " find ") && stringContains(v, "filter:") &&
stringContains(v, "keysExamined:") && stringContains(v, "docsExamined:") &&
v.indexOf("SENTINEL") != -1;
}));
// 2. Run a slow update
glcol.update({
"SENTINEL": 1,
"$where": function() {
sleep(1000);
return true;
}
},
{"x": "x"});
const update = assert.commandWorked(db.adminCommand({getLog: "global"}));
assert(update.log, "no log field");
assert.gt(update.log.length, 0, "no log lines");
// Ensure that slow update is logged in deail.
assert(contains(update.log, function(v) {
return stringContains(v, " update ") != -1 && stringContains(v, "command") &&
stringContains(v, "keysExamined:") && stringContains(v, "docsExamined:") &&
v.indexOf("SENTINEL") != -1;
}));
})();
|
