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
|
/**
* Tests to ensure that COLUMN_SCAN plan and scanned columns appear in slow query log lines when
* the columstore index is the winning plan.
* @tags: [
* featureFlagColumnstoreIndexes,
* ]
*/
(function() {
"use strict";
load("jstests/libs/columnstore_util.js"); // For setUpServerForColumnStoreIndexTest.
const conn = MongoRunner.runMongod({});
assert.neq(null, conn, "mongod was unable to start up");
const db = conn.getDB(jsTestName());
assert.commandWorked(db.dropDatabase());
if (!setUpServerForColumnStoreIndexTest(db)) {
MongoRunner.stopMongod(conn);
return;
}
const coll = db.collection;
// Set logLevel to 1 so that all queries will be logged.
assert.commandWorked(db.setLogLevel(1));
// Set profiling level to profile all queries.
// Additionally, set slow threshold to -1 to ensure that all operations are logged as SLOW.
assert.commandWorked(db.setProfilingLevel(2, {slowms: -1}));
assert.commandWorked(coll.createIndex({"$**": "columnstore"}));
const docs = [
{_id: 0, x: 1, y: [{a: 2}, {a: 3}, {a: 4}]},
{_id: 1, x: 1},
{_id: 2, x: 2, y: [{b: 5}, {b: 6}, {b: 7}]},
{_id: 3, x: 1, y: [{b: 5}, {b: [1, 2, {c: 5}]}, {c: 7}]},
{_id: 4, x: 5, y: [{b: {c: 1}}]}
];
assert.commandWorked(coll.insertMany(docs));
const queryComment = 'findColumnScan';
coll.find({x: {$gt: 1}}, {_id: 1, x: 1}).comment(queryComment).toArray();
const relevantLog = JSON.parse(checkLog.getLogMessage(db, /\"planSummary\":\"COLUMN_SCAN/));
assert(relevantLog !== null);
assert.eq(relevantLog.id, 51803, 'Slow query log (id: 51803) not found.');
assert.eq(relevantLog.attr.command.comment,
'findColumnScan',
`Relevant query with comment '${queryComment}' not found.`);
// We expect a log line with a planSummary format like "COLUMN_SCAN
// {match:['x'],output:['_id','x']}". We assert only on the pieces (and frequency) here to avoid
// depending on the exact order.
const planSummary = relevantLog.attr.planSummary;
assert(planSummary.match(/COLUMN_SCAN/),
`'COLUMN_SCAN' plan not found. Instead, got: ${planSummary}`);
assert(planSummary.match(/'match'/), `'match' not found. Instead, got: ${planSummary}`);
assert(planSummary.match(/'output'/), `'output' not found. Instead, got: ${planSummary}`);
assert.eq(planSummary.match(/'x'/g).length,
2,
`'x' should appear twice in planSummary. Instead, got: ${planSummary}`);
assert.eq(planSummary.match(/'_id'/g).length,
1,
`'_id' should appear once in planSummary. Instead, got: ${planSummary}`);
MongoRunner.stopMongod(conn);
}());
|