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
|
/**
* Tests that the query planning time is captured in the profiler.
*/
(function() {
"use strict";
load('jstests/libs/analyze_plan.js');
load("jstests/libs/profiler.js"); // For getLatestProfilerEntry.
const conn = MongoRunner.runMongod();
const testDB = conn.getDB('test');
var coll = testDB[jsTestName()];
var coll = testDB[jsTestName()];
var collTwo = testDB[jsTestName() + 'Two'];
coll.drop();
for (var i = 0; i < 100; i++) {
coll.insert({foo: 0});
coll.insert({foo: 1});
collTwo.insert({foo: Math.random(0, 1), bar: Math.random(0, 1)});
}
assert.commandWorked(testDB.setProfilingLevel(2));
var commandProfilerFilter = {op: "command", ns: "test.profile_query_planning_time_metric"};
var findProfilerFilter = {op: "query", ns: "test.profile_query_planning_time_metric"};
function verifyProfilerLog(profilerFilter) {
let profileObj = getLatestProfilerEntry(testDB, profilerFilter);
assert.gt(profileObj.planningTimeMicros, 0);
}
// agg query
coll.aggregate([{
$setWindowFields: {
sortBy: {_id: 1},
output: {foo: {$linearFill: "$foo"}},
}
}]);
verifyProfilerLog(commandProfilerFilter);
// agg query with some stages pushed to find layer.
coll.aggregate([{$match: {foo: 0}}, {$group: {_id: null, count: {$sum: 1}}}]);
verifyProfilerLog(commandProfilerFilter);
// agg query with all stages pushed to find layer.
coll.aggregate([{$sort: {foo: 1}}]);
verifyProfilerLog(commandProfilerFilter);
// multiple batches require multiple plan executors. We want to confirm we are only storing the
// metrics for the outer executor associated with planning the query, and not a subsequent executor
// that is constructed when a new operation context gets created during getMore() calls.
coll.aggregate([{$unionWith: {coll: collTwo.getName()}}], {cursor: {batchSize: 2}});
verifyProfilerLog(commandProfilerFilter);
// $lookup has inner executor/cursor, we want to confirm we are only reporting metrics from the
// outer executor associated with planning the query.
coll.aggregate({
$lookup: {from: collTwo.getName(), localField: "foo", foreignField: "bar", as: "merged_docs"}
});
verifyProfilerLog(commandProfilerFilter);
// Count and find have different entry points (eg different run() methods) from agg and we want to
// confirm we are starting the timer as planning begins in each of these workflows/paths.
coll.count({foo: 0});
verifyProfilerLog(commandProfilerFilter);
coll.findOne({});
verifyProfilerLog(findProfilerFilter);
MongoRunner.stopMongod(conn);
}());
|
