diff options
Diffstat (limited to 'jstests/noPassthrough/queryStats')
36 files changed, 3682 insertions, 0 deletions
diff --git a/jstests/noPassthrough/queryStats/agg_cmd_one_way_tokenization.js b/jstests/noPassthrough/queryStats/agg_cmd_one_way_tokenization.js new file mode 100644 index 00000000000..27e4b317faa --- /dev/null +++ b/jstests/noPassthrough/queryStats/agg_cmd_one_way_tokenization.js @@ -0,0 +1,187 @@ +/** + * Test that $queryStats properly tokenizes aggregation commands, on mongod and mongos. + * @tags: [requires_fcv_60] + */ +load("jstests/libs/query_stats_utils.js"); +(function() { +"use strict"; + +const kHashedDbName = "iDlS7h5jf5HHxWPJpeHRbA+jLTNNZaqxVVkplrEkfko="; +const kHashedCollName = "w6Ax20mVkbJu4wQWAMjL8Sl+DfXAr2Zqdc3kJRB7Oo0="; +const kHashedFieldA = "GDiF6ZEXkeo4kbKyKEAAViZ+2RHIVxBQV9S6b6Lu7gU="; +const kHashedFieldB = "m1xtUkfSpZNxXjNZYKwo86vGD37Zxmd2gtt+TXDO558="; + +function verifyConsistentFields(key) { + assert.eq({"db": `${kHashedDbName}`, "coll": `${kHashedCollName}`}, key.queryShape.cmdNs); + assert.eq("aggregate", key.queryShape.command); + assert.eq(kShellApplicationName, key.client.application.name); +} + +function runTest(conn) { + const db = conn.getDB("testDB"); + const admin = conn.getDB("admin"); + + db.test.drop(); + db.otherColl.drop(); + assert.commandWorked(db.test.insert({a: "foobar", b: 15})); + assert.commandWorked(db.test.insert({a: "foobar", b: 20})); + assert.commandWorked(db.otherColl.insert({a: "foobar", price: 2.50})); + + // First checks proper tokenization on a basic pipeline. + { + db.test + .aggregate([ + {$sort: {a: -1}}, + {$match: {a: {$regex: "foo(.*)"}, b: {$gt: 10}}}, + {$skip: 5}, + ]) + .toArray(); + + const stats = getQueryStatsAggCmd(admin, {transformIdentifiers: true}); + + assert.eq(1, + stats.length, + {allStats: getQueryStats(admin), metrics: db.serverStatus().metrics.queryStats}); + const key = stats[0].key; + verifyConsistentFields(key); + // Make sure there is no otherNss field when there are no secondary namespaces. + assert(!key.hasOwnProperty('otherNss'), key); + // Ensure the query stats key pipeline holds the raw input without optimization (e.g., the + // $sort stays before the $match, as in the raw query). + assert.eq( + [ + {"$sort": {[kHashedFieldA]: -1}}, + { + "$match": { + "$and": [ + {[kHashedFieldA]: {"$regex": "?string"}}, + {[kHashedFieldB]: {"$gt": "?number"}} + ] + } + }, + {"$skip": "?number"} + ], + key.queryShape.pipeline, + key.queryShape.pipeline); + } + + // Checks proper tokenization on another basic pipeline that is a subset of the original + // pipeline to make sure there are separate query stats entries per separate query shape. + { + db.test.aggregate([{$match: {a: {$regex: "foo(.*)"}, b: {$gt: 0}}}]).toArray(); + const stats = getQueryStatsAggCmd(admin, {transformIdentifiers: true}); + + assert.eq(2, stats.length); + const key = stats[0].key; + verifyConsistentFields(key); + // Make sure there is no otherNss field when there are no secondary namespaces. + assert(!key.hasOwnProperty('otherNss'), key); + assert.eq([{ + "$match": { + "$and": [ + {[kHashedFieldA]: {"$regex": "?string"}}, + {[kHashedFieldB]: {"$gt": "?number"}} + ] + } + }], + key.queryShape.pipeline, + key.queryShape.pipeline); + } + // Checks proper tokenization on a pipeline that involves a let variable and a $lookup stage + // that has its own subpipeline and references another namespace. + { + const kHashedOtherCollName = "8Rfz9QKu4P3BbyJ3Zpf5kxlUGx7gMvVk2PXZlJVfikE="; + const kHashedAsOutputName = "OsoJyz+7myXF2CkbE5dKd9DJ1gDAUw5uyt12k1ENQpY="; + const kHashedFieldOrderName = "KcpgS5iaiD5/3BKdQRG5rodz+aEE9FkcTPTYZ+G7cpA="; + const kHashedFieldPrice = "LiAftyHzrbrVhwtTPaiHd8Lu9gUILkWgcP682amX7lI="; + const kHashedFieldMaxPrice = "lFzklZZ6KbbYMBTi8KtTTp1GZCcPaUKUmOe3iko+IF8="; + const kHashedFieldTime = "+TNONlWFBKVmiDN2ujCAexPQ1bat38CEzAQgkn2bvIg="; + + db.test.aggregate([{ + $lookup: { + from: "otherColl", + let: { order_name: "$a", price: "$price"}, + pipeline: [{ + $match: { + $expr: { + $and: [ + { $eq: ["$a", "$$order_name"] }, + { $lte: ["$$price", "$$max_price"] } + ] + } + } + }], + as: "my_output" + }}, + { + $match: {$expr: {$lte: ["$$CURRENT.time", "$$NOW"]}} + }], {let: {max_price: 3.00}}).toArray(); + const stats = getQueryStatsAggCmd(admin, {transformIdentifiers: true}); + + assert.eq(3, stats.length); + // This one will sort last because of the 'let' parameters. + const key = stats[2].key; + verifyConsistentFields(key); + assert.eq( + [ + { + "$lookup": { + "from": `${kHashedOtherCollName}`, + "as": `${kHashedAsOutputName}`, + "let": { + [kHashedFieldOrderName]: asFieldPath(kHashedFieldA), + [kHashedFieldPrice]: asFieldPath(kHashedFieldPrice) + }, + "pipeline": [{ + "$match": { + "$expr": { + "$and": [ + { + "$eq": [ + asFieldPath(kHashedFieldA), + asVarRef(kHashedFieldOrderName) + ], + }, + { + "$lte": [ + asVarRef(kHashedFieldPrice), + asVarRef(kHashedFieldMaxPrice) + ] + } + ] + } + } + }] + } + }, + {"$match": {"$expr": {"$lte": [asFieldPath(kHashedFieldTime), asVarRef("NOW")]}}} + ], + key.queryShape.pipeline, + key.queryShape.pipeline); + assert.eq({[kHashedFieldMaxPrice]: "?number"}, key.queryShape.let); + assert.eq([{"db": `${kHashedDbName}`, "coll": `${kHashedOtherCollName}`}], key.otherNss); + } +} + +const conn = MongoRunner.runMongod({ + setParameter: { + internalQueryStatsRateLimit: -1, + } +}); +runTest(conn); +MongoRunner.stopMongod(conn); + +const st = new ShardingTest({ + mongos: 1, + shards: 1, + config: 1, + rs: {nodes: 1}, + mongosOptions: { + setParameter: { + internalQueryStatsRateLimit: -1, + } + }, +}); +runTest(st.s); +st.stop(); +}()); diff --git a/jstests/noPassthrough/queryStats/application_name_find.js b/jstests/noPassthrough/queryStats/application_name_find.js new file mode 100644 index 00000000000..c0dc2bcf848 --- /dev/null +++ b/jstests/noPassthrough/queryStats/application_name_find.js @@ -0,0 +1,37 @@ +/** + * Test that applicationName and namespace appear in queryStats for the find command. + * @tags: [requires_fcv_60] + */ +load("jstests/libs/query_stats_utils.js"); +(function() { +"use strict"; + +const kApplicationName = "MongoDB Shell"; + +// Turn on the collecting of queryStats metrics. +let options = { + setParameter: {internalQueryStatsRateLimit: -1}, +}; + +const conn = MongoRunner.runMongod(options); +conn.setLogLevel(3, "query"); +const testDB = conn.getDB('test'); +var coll = testDB[jsTestName()]; +coll.drop(); + +coll.insert({v: 1}); +coll.insert({v: 2}); +coll.insert({v: 3}); + +coll.find({v: 1}).toArray(); + +let queryStats = getQueryStats(conn); +assert.eq(1, queryStats.length, queryStats); +assert.eq(kApplicationName, queryStats[0].key.client.application.name, queryStats); + +queryStats = getQueryStatsFindCmd(conn, {transformIdentifiers: true}); +assert.eq(1, queryStats.length, queryStats); +assert.eq(kApplicationName, queryStats[0].key.client.application.name, queryStats); + +MongoRunner.stopMongod(conn); +}()); diff --git a/jstests/noPassthrough/queryStats/clear_query_stats_store.js b/jstests/noPassthrough/queryStats/clear_query_stats_store.js new file mode 100644 index 00000000000..1aafd2b9b87 --- /dev/null +++ b/jstests/noPassthrough/queryStats/clear_query_stats_store.js @@ -0,0 +1,46 @@ +/** + * Test that the queryStats store can be cleared when the cache size is reset to 0. + * @tags: [requires_fcv_60] + */ +load("jstests/libs/query_stats_utils.js"); // For verifyMetrics and getQueryStats. + +(function() { +"use strict"; + +// Turn on the collecting of queryStats metrics. +let options = { + setParameter: {internalQueryStatsRateLimit: -1, internalQueryStatsCacheSize: "10MB"}, +}; + +const conn = MongoRunner.runMongod(options); +const testDB = conn.getDB('test'); +var coll = testDB[jsTestName()]; +coll.drop(); + +let query = {}; +for (var j = 0; j < 10; ++j) { + query["foo.field.xyz." + j] = 1; + query["bar.field.xyz." + j] = 2; + query["baz.field.xyz." + j] = 3; + coll.aggregate([{$match: query}]).itcount(); +} + +// Confirm number of entries in the store and that none have been evicted. +let res = getQueryStats(conn); +assert.eq(res.length, 10, res); +assert.eq(testDB.serverStatus().metrics.queryStats.numEvicted, 0); +assert.gt(testDB.serverStatus().metrics.queryStats.queryStatsStoreSizeEstimateBytes, 0); + +// Command to clear the cache. +assert.commandWorked(testDB.adminCommand({setParameter: 1, internalQueryStatsCacheSize: "0MB"})); + +// 10 regular queries plus the $queryStats query, means 11 entries evicted when the cache is +// cleared. +assert.eq(testDB.serverStatus().metrics.queryStats.numEvicted, 11); +assert.eq(testDB.serverStatus().metrics.queryStats.queryStatsStoreSizeEstimateBytes, 0); + +// Calling $queryStats should fail when the query stats store size is 0 bytes. +assert.throwsWithCode(() => testDB.getSiblingDB("admin").aggregate([{$queryStats: {}}]), + ErrorCodes.QueryFeatureNotAllowed); +MongoRunner.stopMongod(conn); +}()); diff --git a/jstests/noPassthrough/queryStats/documentSourceQueryStats_redaction_parameters.js b/jstests/noPassthrough/queryStats/documentSourceQueryStats_redaction_parameters.js new file mode 100644 index 00000000000..40db2885967 --- /dev/null +++ b/jstests/noPassthrough/queryStats/documentSourceQueryStats_redaction_parameters.js @@ -0,0 +1,126 @@ +/** + * Test the $queryStats hmac properties. + * @tags: [requires_fcv_60] + */ + +load("jstests/aggregation/extras/utils.js"); // For assertAdminDBErrCodeAndErrMsgContains. +load("jstests/libs/query_stats_utils.js"); // For getQueryStatsFindCmd + +(function() { +"use strict"; + +// Assert the expected queryStats key with no hmac. +function assertQueryStatsKeyWithoutHmac(queryStatsKey) { + assert.eq(queryStatsKey.filter, {"foo": {"$lte": "?number"}}); + assert.eq(queryStatsKey.sort, {"bar": -1}); + assert.eq(queryStatsKey.limit, "?number"); +} + +function runTest(conn) { + const testDB = conn.getDB('test'); + const coll = testDB[jsTestName()]; + coll.drop(); + + coll.insert({foo: 1}); + coll.find({foo: {$lte: 2}}).sort({bar: -1}).limit(2).toArray(); + // Default is no hmac. + assertQueryStatsKeyWithoutHmac(getQueryStatsFindCmd(conn)[0].key.queryShape); + + // Turning on hmac should apply hmac to all field names on all entries, even previously cached + // ones. + const queryStatsKey = getQueryStatsFindCmd(conn, {transformIdentifiers: true})[0]["key"]; + assert.eq(queryStatsKey.queryShape.filter, + {"fNWkKfogMv6MJ77LpBcuPrO7Nq+R+7TqtD+Lgu3Umc4=": {"$lte": "?number"}}); + assert.eq(queryStatsKey.queryShape.sort, {"CDDQIXZmDehLKmQcRxtdOQjMqoNqfI2nGt2r4CgJ52o=": -1}); + assert.eq(queryStatsKey.queryShape.limit, "?number"); + + // Turning hmac back off should preserve field names on all entries, even previously cached + // ones. + const queryStats = getQueryStatsFindCmd(conn)[0]["key"]; + assertQueryStatsKeyWithoutHmac(queryStats.queryShape); + + // Explicitly set transformIdentifiers to false. + assertQueryStatsKeyWithoutHmac( + getQueryStatsFindCmd(conn, {transformIdentifiers: false})[0]["key"].queryShape); + + // Wrong parameter name throws error. + let pipeline = [{$queryStats: {redactFields: true}}]; + assertAdminDBErrCodeAndErrMsgContains( + coll, pipeline, 40415, "BSON field '$queryStats.redactFields' is an unknown field."); + + // Wrong parameter name throws error. + pipeline = [{$queryStats: {algorithm: "hmac-sha-256"}}]; + assertAdminDBErrCodeAndErrMsgContains( + coll, pipeline, 40415, "BSON field '$queryStats.algorithm' is an unknown field."); + + // Wrong parameter type throws error. + pipeline = [{$queryStats: {transformIdentifiers: {algorithm: 1}}}]; + assertAdminDBErrCodeAndErrMsgContains( + coll, + pipeline, + ErrorCodes.TypeMismatch, + "BSON field '$queryStats.transformIdentifiers.algorithm' is the wrong type 'double', expected type 'string'"); + + pipeline = [{$queryStats: {transformIdentifiers: {algorithm: "hmac-sha-256", hmacKey: 1}}}]; + assertAdminDBErrCodeAndErrMsgContains( + coll, + pipeline, + ErrorCodes.TypeMismatch, + "BSON field '$queryStats.transformIdentifiers.hmacKey' is the wrong type 'double', expected type 'binData'"); + + // Unsupported algorithm throws error. + pipeline = [{$queryStats: {transformIdentifiers: {algorithm: "hmac-sha-1"}}}]; + assertAdminDBErrCodeAndErrMsgContains( + coll, + pipeline, + ErrorCodes.BadValue, + "Enumeration value 'hmac-sha-1' for field '$queryStats.transformIdentifiers.algorithm' is not a valid value."); + + // TransformIdentifiers with missing algorithm throws error. + pipeline = [{$queryStats: {transformIdentifiers: {}}}]; + assertAdminDBErrCodeAndErrMsgContains( + coll, + pipeline, + 40414, + "BSON field '$queryStats.transformIdentifiers.algorithm' is missing but a required field"); + + // TransformIdentifiers with algorithm but missing hmacKey throws error. + pipeline = [{$queryStats: {transformIdentifiers: {algorithm: "hmac-sha-256"}}}]; + assertAdminDBErrCodeAndErrMsgContains( + coll, + pipeline, + ErrorCodes.FailedToParse, + "The 'hmacKey' parameter of the $queryStats stage must be specified when applying the hmac-sha-256 algorithm"); + + // Parameter object with unrecognized key throws error. + pipeline = + [{$queryStats: {transformIdentifiers: {algorithm: "hmac-sha-256", hmacStrategy: "on"}}}]; + assertAdminDBErrCodeAndErrMsgContains( + coll, + pipeline, + 40415, + "BSON field '$queryStats.transformIdentifiers.hmacStrategy' is an unknown field."); +} + +const conn = MongoRunner.runMongod({ + setParameter: { + internalQueryStatsRateLimit: -1, + } +}); +runTest(conn); +MongoRunner.stopMongod(conn); + +const st = new ShardingTest({ + mongos: 1, + shards: 1, + config: 1, + rs: {nodes: 1}, + mongosOptions: { + setParameter: { + internalQueryStatsRateLimit: -1, + } + }, +}); +runTest(st.s); +st.stop(); +}()); diff --git a/jstests/noPassthrough/queryStats/feature_flag_off_sampling_rate_on.js b/jstests/noPassthrough/queryStats/feature_flag_off_sampling_rate_on.js new file mode 100644 index 00000000000..77388690062 --- /dev/null +++ b/jstests/noPassthrough/queryStats/feature_flag_off_sampling_rate_on.js @@ -0,0 +1,44 @@ +/** + * Test that calls to read from query stats store fail when feature flag is turned off and sampling + * rate > 0. + */ +load('jstests/libs/analyze_plan.js'); +load("jstests/libs/feature_flag_util.js"); + +(function() { +"use strict"; + +// Set sampling rate to -1. +let options = { + setParameter: {internalQueryStatsRateLimit: -1, featureFlagQueryStats: false}, +}; +const conn = MongoRunner.runMongod(options); +const testdb = conn.getDB('test'); + +var coll = testdb[jsTestName()]; +coll.drop(); + +// Bulk insert documents to reduces roundtrips and make timeout on a slow machine less likely. +const bulk = coll.initializeUnorderedBulkOp(); +for (let i = 1; i <= 20; i++) { + bulk.insert({foo: 0, bar: Math.floor(Math.random() * 3)}); +} +assert.commandWorked(bulk.execute()); + +// Pipeline to read queryStats store should fail without feature flag turned on even though sampling +// rate is > 0. +assert.commandFailedWithCode( + testdb.adminCommand({aggregate: 1, pipeline: [{$queryStats: {}}], cursor: {}}), + ErrorCodes.QueryFeatureNotAllowed); + +// Pipeline, with a filter, to read queryStats store fails without feature flag turned on even +// though sampling rate is > 0. +assert.commandFailedWithCode(testdb.adminCommand({ + aggregate: 1, + pipeline: [{$queryStats: {}}, {$match: {"key.queryShape.find": {$eq: "###"}}}], + cursor: {} +}), + ErrorCodes.QueryFeatureNotAllowed); + +MongoRunner.stopMongod(conn); +}()); diff --git a/jstests/noPassthrough/queryStats/find_cmd_one_way_tokenization.js b/jstests/noPassthrough/queryStats/find_cmd_one_way_tokenization.js new file mode 100644 index 00000000000..55a8f322f90 --- /dev/null +++ b/jstests/noPassthrough/queryStats/find_cmd_one_way_tokenization.js @@ -0,0 +1,66 @@ +/** + * Test that $queryStats properly tokenizes find commands, on mongod and mongos. + * @tags: [requires_fcv_60] + */ +load("jstests/libs/query_stats_utils.js"); +(function() { +"use strict"; + +const kHashedFieldName = "lU7Z0mLRPRUL+RfAD5jhYPRRpXBsZBxS/20EzDwfOG4="; + +function runTest(conn) { + const db = conn.getDB("test"); + const admin = conn.getDB("admin"); + + db.test.drop(); + db.test.insert({v: 1}); + + db.test.find({v: 1}).toArray(); + + let queryStats = getQueryStatsFindCmd(admin, {transformIdentifiers: true}); + + assert.eq(1, queryStats.length); + assert.eq("find", queryStats[0].key.queryShape.command); + assert.eq({[kHashedFieldName]: {$eq: "?number"}}, queryStats[0].key.queryShape.filter); + + db.test.insert({v: 2}); + + const cursor = db.test.find({v: {$gt: 0, $lt: 3}}).batchSize(1); + queryStats = getQueryStatsFindCmd(admin, {transformIdentifiers: true}); + // Cursor isn't exhausted, so there shouldn't be another entry yet. + assert.eq(1, queryStats.length); + + assert.commandWorked( + db.runCommand({getMore: cursor.getId(), collection: db.test.getName(), batchSize: 2})); + + queryStats = getQueryStatsFindCmd(admin, {transformIdentifiers: true}); + assert.eq(2, queryStats.length); + assert.eq("find", queryStats[1].key.queryShape.command); + assert.eq({ + "$and": [{[kHashedFieldName]: {"$gt": "?number"}}, {[kHashedFieldName]: {"$lt": "?number"}}] + }, + queryStats[1].key.queryShape.filter); +} + +let conn = MongoRunner.runMongod({ + setParameter: { + internalQueryStatsRateLimit: -1, + } +}); +runTest(conn); +MongoRunner.stopMongod(conn); + +let st = new ShardingTest({ + mongos: 1, + shards: 1, + config: 1, + rs: {nodes: 1}, + mongosOptions: { + setParameter: { + internalQueryStatsRateLimit: -1, + } + }, +}); +runTest(st.s); +st.stop(); +}()); diff --git a/jstests/noPassthrough/queryStats/geometry_without_coordinates.js b/jstests/noPassthrough/queryStats/geometry_without_coordinates.js new file mode 100644 index 00000000000..72a5015bfab --- /dev/null +++ b/jstests/noPassthrough/queryStats/geometry_without_coordinates.js @@ -0,0 +1,22 @@ +// This test was designed to reproduce SERVER-77430. There was a mistaken assertion in a parser that +// we are interested in proving will not fail here. +// @tags: [requires_fcv_60] +(function() { +"use strict"; + +const st = new ShardingTest({ + mongos: 1, + shards: 1, + config: 1, + rs: {nodes: 1}, + mongosOptions: { + setParameter: { + internalQueryStatsRateLimit: -1, + } + }, +}); +const coll = st.s.getDB("test").geometry_without_coordinates; +// This is a query that once mistakenly threw an error. +assert.doesNotThrow(() => coll.find({geo: {$geoIntersects: {$geometry: {x: 40, y: 5}}}}).itcount()); +st.stop(); +}()); diff --git a/jstests/noPassthrough/queryStats/query_stats_agg_cmd_collect_on_mongos.js b/jstests/noPassthrough/queryStats/query_stats_agg_cmd_collect_on_mongos.js new file mode 100644 index 00000000000..30cdcce8a18 --- /dev/null +++ b/jstests/noPassthrough/queryStats/query_stats_agg_cmd_collect_on_mongos.js @@ -0,0 +1,143 @@ +/** + * Test that mongos is collecting query stats metrics for agg queries. + * @tags: [requires_fcv_60] + */ + +load('jstests/libs/query_stats_utils.js'); + +(function() { +"use strict"; + +const st = new ShardingTest({ + mongos: 1, + shards: 1, + config: 1, + rs: {nodes: 1}, + mongosOptions: { + setParameter: { + internalQueryStatsRateLimit: -1, + } + }, +}); +const mongos = st.s; +const db = mongos.getDB("test"); + +// Assert that, for agg queries, no query stats results are written until a cursor has reached +// exhaustion; ensure accurate results once they're written. +{ + const coll = db.coll; + coll.insert({v: 1}); + coll.insert({v: 4}); + const queryStatsKey = { + queryShape: { + cmdNs: {db: "test", coll: "coll"}, + command: "aggregate", + pipeline: [ + {$match: {$and: [{v: {$gt: "?number"}}, {v: {$lt: "?number"}}]}}, + {$project: {_id: true, hello: true}} + ] + + }, + cursor: {batchSize: "?number"}, + applicationName: "MongoDB Shell", + }; + + const cursor = coll.aggregate( + [ + {$match: {v: {$gt: 0, $lt: 5}}}, + {$project: {hello: true}}, + ], + {cursor: {batchSize: 1}}); // returns 1 doc + + // Since the cursor hasn't been exhausted yet, ensure no query stats results have been written + // yet. + let queryStats = getQueryStats(db); + assert.eq(0, queryStats.length, queryStats); + + // Run a getMore to exhaust the cursor, then ensure query stats results have been written + // accurately. batchSize must be 2 so the cursor recognizes exhaustion. + assert.commandWorked(db.runCommand({ + getMore: cursor.getId(), + collection: coll.getName(), + batchSize: 2 + })); // returns 1 doc, exhausts the cursor + queryStats = getQueryStatsAggCmd(db); + assert.eq(1, queryStats.length, queryStats); + assertExpectedResults(queryStats[0], + queryStatsKey, + /* expectedExecCount */ 1, + /* expectedDocsReturnedSum */ 2, + /* expectedDocsReturnedMax */ 2, + /* expectedDocsReturnedMin */ 2, + /* expectedDocsReturnedSumOfSq */ NumberDecimal("4"), + /* getMores */ true); + + // Run more queries (to exhaustion) with the same query shape, and ensure query stats results + // are accurate. + coll.aggregate([ + {$match: {v: {$gt: 0, $lt: 5}}}, + {$project: {hello: true}}, + ]); // returns 2 docs + coll.aggregate([ + {$match: {v: {$gt: 2, $lt: 3}}}, + {$project: {hello: true}}, + ]); // returns 0 docs + coll.aggregate([ + {$match: {v: {$gt: 0, $lt: 2}}}, + {$project: {hello: true}}, + ]); // returns 1 doc + queryStats = getQueryStatsAggCmd(db); + assert.eq(1, queryStats.length, queryStats); + assertExpectedResults(queryStats[0], + queryStatsKey, + /* expectedExecCount */ 4, + /* expectedDocsReturnedSum */ 5, + /* expectedDocsReturnedMax */ 2, + /* expectedDocsReturnedMin */ 0, + /* expectedDocsReturnedSumOfSq */ NumberDecimal("9"), + /* getMores */ true); +} + +// Assert on batchSize-limited agg queries that killCursors will write metrics with partial results +// to the query stats store. +{ + const coll = db.coll2; + coll.insert({v: 1}); + coll.insert({v: 4}); + + const queryStatsKey = { + queryShape: { + cmdNs: {db: "test", coll: "coll2"}, + command: "aggregate", + pipeline: [{$match: {$and: [{v: {$gt: "?number"}}, {v: {$lt: "?number"}}]}}] + }, + cursor: {batchSize: "?number"}, + applicationName: "MongoDB Shell", + }; + + const cursor1 = coll.aggregate( + [ + {$match: {v: {$gt: 0, $lt: 5}}}, + ], + {cursor: {batchSize: 1}}); // returns 1 doc + const cursor2 = coll.aggregate( + [ + {$match: {v: {$gt: 0, $lt: 2}}}, + ], + {cursor: {batchSize: 1}}); // returns 1 doc + + assert.commandWorked( + db.runCommand({killCursors: coll.getName(), cursors: [cursor1.getId(), cursor2.getId()]})); + const queryStats = getLatestQueryStatsEntry(db, {collName: coll.getName()}); + assertExpectedResults(queryStats, + queryStatsKey, + /* expectedExecCount */ 2, + /* expectedDocsReturnedSum */ 2, + /* expectedDocsReturnedMax */ 1, + /* expectedDocsReturnedMin */ 1, + /* expectedDocsReturnedSumOfSq */ NumberDecimal("2"), + /* getMores */ false); +} + +st.stop(); +}()); diff --git a/jstests/noPassthrough/queryStats/query_stats_agg_key.js b/jstests/noPassthrough/queryStats/query_stats_agg_key.js new file mode 100644 index 00000000000..0eec5525733 --- /dev/null +++ b/jstests/noPassthrough/queryStats/query_stats_agg_key.js @@ -0,0 +1,64 @@ +/** + * This test confirms that query stats store key fields for an aggregate command are properly nested + * and none are missing. + * @tags: [requires_fcv_60] + */ +load("jstests/libs/query_stats_utils.js"); // For runCommandAndValidateQueryStats and + // withQueryStatsEnabled +(function() { +"use strict"; + +const collName = jsTestName(); +const aggregateCommandObj = { + aggregate: collName, + pipeline: [{"$out": "collOut"}], + allowDiskUse: false, + cursor: {batchSize: 2}, + maxTimeMS: 50 * 1000, + bypassDocumentValidation: false, + readConcern: {level: "local"}, + writeConcern: {w: 1}, + collation: {locale: "en_US", strength: 2}, + hint: {"v": 1}, + comment: "", + let : {}, + apiDeprecationErrors: false, + apiVersion: "1", + apiStrict: false, +}; + +const queryShapeAggregateFields = + ["cmdNs", "command", "pipeline", "allowDiskUse", "collation", "let"]; + +// The outer fields not nested inside queryShape. +const queryStatsAggregateKeyFields = [ + "queryShape", + "cursor", + "maxTimeMS", + "bypassDocumentValidation", + "comment", + "otherNss", + "apiDeprecationErrors", + "apiVersion", + "apiStrict", + "collectionType", + "client", + "hint", + "readConcern", + "writeConcern", + "cursor.batchSize", +]; + +withQueryStatsEnabled(collName, (coll) => { + // Have to create an index for hint not to fail. + assert.commandWorked(coll.createIndex({v: 1})); + + runCommandAndValidateQueryStats({ + coll: coll, + commandName: "aggregate", + commandObj: aggregateCommandObj, + shapeFields: queryShapeAggregateFields, + keyFields: queryStatsAggregateKeyFields + }); +}); +}());
\ No newline at end of file diff --git a/jstests/noPassthrough/queryStats/query_stats_agg_key_change_stream.js b/jstests/noPassthrough/queryStats/query_stats_agg_key_change_stream.js new file mode 100644 index 00000000000..63f917c6c07 --- /dev/null +++ b/jstests/noPassthrough/queryStats/query_stats_agg_key_change_stream.js @@ -0,0 +1,182 @@ +/** + * This test confirms that query stats store key fields for an aggregate command are properly nested + * and none are missing. It also validates the exact pipeline in the query shape. + * @tags: [ + * uses_change_streams, + * requires_fcv_60 + * ] + */ + +load("jstests/libs/query_stats_utils.js"); // For runCommandAndValidateQueryStats. +load("jstests/libs/collection_drop_recreate.js"); // For assertDropAndRecreateCollection. +const dbName = jsTestName(); +const collName = "coll"; + +const queryShapeAggregateFields = + ["cmdNs", "command", "pipeline", "allowDiskUse", "collation", "let"]; + +// The outer fields not nested inside queryShape. +const queryStatsAggregateKeyFields = [ + "queryShape", + "cursor", + "maxTimeMS", + "bypassDocumentValidation", + "comment", + "apiDeprecationErrors", + "apiVersion", + "apiStrict", + "collectionType", + "client", + "hint", + "readConcern", + "cursor.batchSize", +]; + +const testCases = [ + // Default fields. + { + pipeline: [{"$changeStream": {}}], + expectedShapifiedPipeline: [{ + "$changeStream": { + startAtOperationTime: "?timestamp", + fullDocument: "default", + fullDocumentBeforeChange: "off" + } + }] + }, + // Non default field values. + { + pipeline: [{ + "$changeStream": { + fullDocument: "updateLookup", + fullDocumentBeforeChange: "required", + showExpandedEvents: true, + } + }], + expectedShapifiedPipeline: [{ + "$changeStream": { + startAtOperationTime: "?timestamp", + fullDocument: "updateLookup", + fullDocumentBeforeChange: "required", + showExpandedEvents: true, + } + }], + }, + // $changeStream followed by a $match. $changeStream internally creates another $match stage + // which shouldn't appear in the query shape, but a $match in the user specified pipeline should + // appear in the query shape. + { + pipeline: [{$changeStream: {}}, {$match: {a: "field"}}], + expectedShapifiedPipeline: [ + { + "$changeStream": { + startAtOperationTime: "?timestamp", + fullDocument: "default", + fullDocumentBeforeChange: "off" + } + }, + {$match: {a: {$eq: "?string"}}} + ] + } +]; + +function assertPipelineField(conn, expectedPipeline) { + const entry = getLatestQueryStatsEntry(conn, {collName: collName}); + const statsPipeline = getValueAtPath(entry, "key.queryShape.pipeline"); + assert.eq(statsPipeline, expectedPipeline); +} + +function validateResumeTokenQueryShape(conn, coll) { + // Start a change stream. + const changeStream = coll.watch([]); + + // Going to create an invalid event by checking a change stream on a dropped collection. + assert.commandWorked(coll.insert({_id: 1})); + assert(coll.drop()); + assert.soon(() => changeStream.hasNext()); + changeStream.next(); + const invalidateResumeToken = changeStream.getResumeToken(); + + // Resume the change stream using 'startAfter' field. + coll.watch([], {startAfter: invalidateResumeToken}); + assert.commandWorked(coll.insert({_id: 2})); + + const expectedShapifiedPipeline = [{ + "$changeStream": { + startAfter: {_data: "?string"}, + fullDocument: "default", + fullDocumentBeforeChange: "off" + } + }]; + assertPipelineField(conn, expectedShapifiedPipeline); +} + +function validateChangeStreamAggKey(conn) { + const db = conn.getDB("test"); + assertDropAndRecreateCollection(db, collName); + + // Change streams with 'startAfter' or 'resumeAfter' are only executed after a certain event and + // require re-parsing a resume token. To validate the query shape of these pipelines, we have to + // execute the events to register the pipeline. + validateResumeTokenQueryShape(conn, db[collName]); + + // Validate the key for the rest of the pipelines. + testCases.forEach(input => { + const pipeline = input.pipeline; + const aggCmdObj = { + aggregate: collName, + pipeline: pipeline, + allowDiskUse: false, + cursor: {batchSize: 2}, + maxTimeMS: 50 * 1000, + bypassDocumentValidation: false, + readConcern: {level: "majority"}, + collation: {locale: "en_US", strength: 2}, + hint: {"v": 1}, + comment: "", + let : {}, + apiDeprecationErrors: false, + apiVersion: "1", + apiStrict: false, + }; + + runCommandAndValidateQueryStats({ + coll: db[collName], + commandName: "aggregate", + commandObj: aggCmdObj, + shapeFields: queryShapeAggregateFields, + keyFields: queryStatsAggregateKeyFields + }); + assertPipelineField(conn, input.expectedShapifiedPipeline); + }); +} + +{ + // Test on a sharded cluster. + const st = new ShardingTest({ + mongos: 1, + shards: 2, + config: 1, + rs: {nodes: 1, setParameter: {writePeriodicNoops: true, periodicNoopIntervalSecs: 1}}, + mongosOptions: { + setParameter: { + internalQueryStatsRateLimit: -1, + } + }, + }); + validateChangeStreamAggKey(st.s); + st.stop(); +} + +{ + // Test the non-sharded case. + const rst = new ReplSetTest({nodes: 2}); + rst.startSet({setParameter: {internalQueryStatsRateLimit: -1}}); + rst.initiate(); + rst.getPrimary().getDB("admin").setLogLevel(3, "queryStats"); + + // Only aggregations run on replica sets have the '$readPreference' field in the key. + queryStatsAggregateKeyFields.push("$readPreference"); + validateChangeStreamAggKey(rst.getPrimary()); + rst.stopSet(); +} diff --git a/jstests/noPassthrough/queryStats/query_stats_agg_key_change_stream_passthrough_shard.js b/jstests/noPassthrough/queryStats/query_stats_agg_key_change_stream_passthrough_shard.js new file mode 100644 index 00000000000..3a8123021d2 --- /dev/null +++ b/jstests/noPassthrough/queryStats/query_stats_agg_key_change_stream_passthrough_shard.js @@ -0,0 +1,94 @@ +/** + * This test confirms that query stats store key fields for an aggregate command are properly nested + * and none are missing when running a change stream query with $_passthroughToShard. + * @tags: [ + * requires_sharding, + * uses_change_streams, + * requires_fcv_60 + * ] + */ + +load("jstests/libs/query_stats_utils.js"); +const dbName = jsTestName(); +const collName = "coll"; + +// $_passthroughToShard is only possible on a sharded cluster. +const st = new ShardingTest({ + shards: 2, + mongos: 1, + config: 1, + rs: {nodes: 1}, + other: { + mongosOptions: { + setParameter: { + internalQueryStatsRateLimit: -1, + } + } + } +}); + +const sdb = st.s0.getDB(dbName); +assert.commandWorked(sdb.dropDatabase()); + +sdb.setProfilingLevel(0, -1); +st.shard0.getDB(dbName).setProfilingLevel(0, -1); + +// Shard the relevant collections. +assert.commandWorked(st.s.adminCommand({enableSharding: dbName, primaryShard: st.shard0.name})); +// Shard the collection on {_id: 1}, split at {_id: 0} and move the empty upper chunk to +// shard1. +st.shardColl(collName, {_id: 1}, {_id: 0}, {_id: 0}, dbName); + +const shardId = st.shard0.shardName; +let coll = sdb[collName]; + +const aggregateCommandObj = { + aggregate: coll.getName(), + pipeline: [{"$changeStream": {}}], + allowDiskUse: false, + cursor: {batchSize: 2}, + maxTimeMS: 50 * 1000, + bypassDocumentValidation: false, + readConcern: {level: "majority"}, + collation: {locale: "en_US", strength: 2}, + hint: {"v": 1}, + comment: "", + let : {}, + apiDeprecationErrors: false, + apiVersion: "1", + apiStrict: false, + $_passthroughToShard: {shard: shardId} +}; + +const queryShapeAggregateFields = + ["cmdNs", "command", "pipeline", "allowDiskUse", "collation", "let"]; + +// The outer fields not nested inside queryShape. +const queryStatsAggregateKeyFields = [ + "queryShape", + "cursor", + "maxTimeMS", + "bypassDocumentValidation", + "comment", + "apiDeprecationErrors", + "apiVersion", + "apiStrict", + "collectionType", + "client", + "hint", + "readConcern", + "cursor.batchSize", + "$_passthroughToShard", + "$_passthroughToShard.shard" +]; +assert.commandWorked(coll.createIndex({v: 1})); + +runCommandAndValidateQueryStats({ + coll: coll, + commandName: "aggregate", + commandObj: aggregateCommandObj, + shapeFields: queryShapeAggregateFields, + keyFields: queryStatsAggregateKeyFields +}); + +st.stop();
\ No newline at end of file diff --git a/jstests/noPassthrough/queryStats/query_stats_agg_key_explain.js b/jstests/noPassthrough/queryStats/query_stats_agg_key_explain.js new file mode 100644 index 00000000000..4d1b68c7b6d --- /dev/null +++ b/jstests/noPassthrough/queryStats/query_stats_agg_key_explain.js @@ -0,0 +1,84 @@ +/** + * This test confirms that query stats store key fields for an aggregate command are properly nested + * and none are missing when running an explain query. + * @tags: [requires_fcv_60] + */ +load("jstests/libs/query_stats_utils.js"); + +const collName = jsTestName(); + +const aggregateCommandObj = { + aggregate: collName, + pipeline: [{"$out": "collOut"}], + allowDiskUse: false, + cursor: {batchSize: 2}, + maxTimeMS: 50 * 1000, + bypassDocumentValidation: false, + readConcern: {level: "local"}, + // This flag sets the explain verbosity to 'queryPlanner'. + explain: true, + collation: {locale: "en_US", strength: 2}, + hint: {"v": 1}, + comment: "", + let : {}, + apiDeprecationErrors: false, + apiVersion: "1", + apiStrict: false, +}; + +const queryShapeAggregateFields = + ["cmdNs", "command", "pipeline", "allowDiskUse", "collation", "let"]; + +// The outer fields not nested inside queryShape. +const queryStatsAggregateKeyFields = [ + "queryShape", + "cursor", + "maxTimeMS", + "bypassDocumentValidation", + "comment", + "otherNss", + "apiDeprecationErrors", + "apiVersion", + "apiStrict", + "collectionType", + "client", + "hint", + "readConcern", + "explain", + "cursor.batchSize", +]; + +// Copy the command object to test {explain: false}. +const aggregateCommandObjExplainFalse = Object.assign({}, aggregateCommandObj); +aggregateCommandObjExplainFalse.explain = false; + +// Setting the explain flag to 'false' has the same behavior as having no explain flag at all, +// making it not appear on the key. +const queryStatsAggregateKeyFieldsExplainFalse = + queryStatsAggregateKeyFields.filter(e => e !== "explain"); + +withQueryStatsEnabled(collName, (coll) => { + // Create an index for hint not to fail. + assert.commandWorked(coll.createIndex({v: 1})); + + // Run an aggregate with {explain: true} and make sure that the 'explain' + // field shows up in the query stats store key. + runCommandAndValidateQueryStats({ + coll: coll, + commandName: "aggregate", + commandObj: aggregateCommandObj, + shapeFields: queryShapeAggregateFields, + keyFields: queryStatsAggregateKeyFields + }); + + // Run an aggregate with {explain: false} and make sure that the 'explain' + // field doesn't shows up in the query stats store key. + runCommandAndValidateQueryStats({ + coll: coll, + commandName: "aggregate", + commandObj: aggregateCommandObjExplainFalse, + // The shape remains the same since 'explain' is at the key level. + shapeFields: queryShapeAggregateFields, + keyFields: queryStatsAggregateKeyFieldsExplainFalse + }); +}); diff --git a/jstests/noPassthrough/queryStats/query_stats_change_stream.js b/jstests/noPassthrough/queryStats/query_stats_change_stream.js new file mode 100644 index 00000000000..a610ff5f0bc --- /dev/null +++ b/jstests/noPassthrough/queryStats/query_stats_change_stream.js @@ -0,0 +1,227 @@ +// Tests the collection of query stats for a change stream query. +// @tags: [ +// uses_change_streams, +// requires_replication, +// requires_sharding, +// requires_fcv_60 +// ] + +load("jstests/libs/query_stats_utils.js"); // For getLatestQueryStatsEntry. +load("jstests/libs/fixture_helpers.js"); // For FixtureHelpers. +load("jstests/libs/collection_drop_recreate.js"); // For assertDropAndRecreateCollection. + +function testCollectionChangeStream(conn) { + const db = conn.getDB("test"); + assertDropAndRecreateCollection(db, "coll"); + + // Check change stream explain is recorded. + assert.commandWorked( + db.coll.explain({"verbosity": "queryPlanner"}).aggregate([{"$changeStream": {}}])); + let queryStatsEntry = getLatestQueryStatsEntry(db); + checkChangeStreamEntry({ + queryStatsEntry: queryStatsEntry, + db: db, + collectionName: "coll", + numExecs: 1, + numDocsReturned: 0 + }); + assert(queryStatsEntry.key.hasOwnProperty("explain")); + + // Check creation of change stream cursor is recorded. + let cursor = db.coll.watch([], {batchSize: 1}); + + let numExecs = 1; + let numDocsReturned = 0; + + checkChangeStreamEntry({ + queryStatsEntry: getLatestQueryStatsEntry(db), + db: db, + collectionName: "coll", + numExecs: numExecs, + numDocsReturned: numDocsReturned + }); + + // Insert document into a collection and make sure retrieving the information updates the query + // stats entry. + assert.commandWorked(db.coll.insert({_id: 0, a: 1})); + numExecs += getNumberOfGetMoresUntilNextDocForChangeStream(cursor); + numDocsReturned++; + + checkChangeStreamEntry({ + queryStatsEntry: getLatestQueryStatsEntry(db), + db: db, + collectionName: "coll", + numExecs: numExecs, + numDocsReturned: numDocsReturned + }); + + // Close cursor and check that it updates query stats entry. + cursor.close(); + numExecs++; + queryStatsEntry = getLatestQueryStatsEntry(db); + checkChangeStreamEntry({ + queryStatsEntry: queryStatsEntry, + db: db, + collectionName: "coll", + numExecs: numExecs, + numDocsReturned: numDocsReturned + }); + // Closing the cursor should result in 0 ms for the operation. + assert.eq(queryStatsEntry.metrics.lastExecutionMicros, 0); +} + +function testDatabaseChangeStream(conn) { + const db = conn.getDB("test"); + assertDropAndRecreateCollection(db, "coll1"); + assertDropAndRecreateCollection(db, "coll2"); + + // Check creation of change stream cursor is recorded. + let wholeDBCursor = db.watch([]); + let numExecs = 1; + let numDocsReturned = 0; + + checkChangeStreamEntry({ + queryStatsEntry: getLatestQueryStatsEntry(db), + db: db, + collectionName: "$cmd.aggregate", + numExecs: numExecs, + numDocsReturned: numDocsReturned + }); + + // Insert document into a collection and make sure retrieving the information updates the query + // stats entry. + assert.commandWorked(db.coll1.insert({_id: 1, a: 2})); + numExecs += getNumberOfGetMoresUntilNextDocForChangeStream(wholeDBCursor); + numDocsReturned++; + + checkChangeStreamEntry({ + queryStatsEntry: getLatestQueryStatsEntry(db), + db: db, + collectionName: "$cmd.aggregate", + numExecs: numExecs, + numDocsReturned: numDocsReturned + }); + + // Insert document into a different collection and make sure retrieving the information updates + // the query stats entry. + assert.commandWorked(db.coll2.insert({_id: 1, a: 2})); + numExecs += getNumberOfGetMoresUntilNextDocForChangeStream(wholeDBCursor); + numDocsReturned++; + checkChangeStreamEntry({ + queryStatsEntry: getLatestQueryStatsEntry(db), + db: db, + collectionName: "$cmd.aggregate", + numExecs: numExecs, + numDocsReturned: numDocsReturned + }); + + // Close cursor and check that it increases numExecs. + wholeDBCursor.close(); + numExecs++; + let queryStatsEntry = getLatestQueryStatsEntry(db); + checkChangeStreamEntry({ + queryStatsEntry: queryStatsEntry, + db: db, + collectionName: "$cmd.aggregate", + numExecs: numExecs, + numDocsReturned: numDocsReturned + }); + + // Closing the cursor should result in 0 ms for the operation. + assert.eq(queryStatsEntry.metrics.lastExecutionMicros, 0); +} + +function testWholeClusterChangeStream(conn) { + const dbA = conn.getDB("testA"); + const dbB = conn.getDB("testB"); + assertDropAndRecreateCollection(dbA, "collA"); + assertDropAndRecreateCollection(dbB, "collB"); + + // Creating the change stream cursor should create a query stats entry. + let wholeClusterCursor = dbA.getMongo().watch([]); + let numExecs = 1; + let numDocsReturned = 0; + + checkChangeStreamEntry({ + queryStatsEntry: getLatestQueryStatsEntry(dbA), + db: dbA, + collectionName: "$cmd.aggregate", + numExecs: numExecs, + numDocsReturned: numDocsReturned + }); + + // Insert document into a database and make sure retrieving the information updates the query + // stats entry. + assert.commandWorked(dbA.collA.insert({_id: 1, a: 2})); + numExecs += getNumberOfGetMoresUntilNextDocForChangeStream(wholeClusterCursor); + numDocsReturned++; + + checkChangeStreamEntry({ + queryStatsEntry: getLatestQueryStatsEntry(dbA), + db: dbA, + collectionName: "$cmd.aggregate", + numExecs: numExecs, + numDocsReturned: numDocsReturned + }); + + // Insert document into different database and make sure retrieving the information updates the + // query stats entry. + assert.commandWorked(dbB.collB.insert({_id: 1, a: 2})); + numExecs += getNumberOfGetMoresUntilNextDocForChangeStream(wholeClusterCursor); + numDocsReturned++; + + checkChangeStreamEntry({ + queryStatsEntry: getLatestQueryStatsEntry(dbA), + db: dbA, + collectionName: "$cmd.aggregate", + numExecs: numExecs, + numDocsReturned: numDocsReturned + }); + + // Close cursor and check that it increases numExecs. + wholeClusterCursor.close(); + numExecs++; + let queryStatsEntry = getLatestQueryStatsEntry(dbA); + checkChangeStreamEntry({ + queryStatsEntry: queryStatsEntry, + db: dbA, + collectionName: "$cmd.aggregate", + numExecs: numExecs, + numDocsReturned: numDocsReturned + }); + // Closing the cursor should result in 0 ms for the operation. + assert.eq(queryStatsEntry.metrics.lastExecutionMicros, 0); +} + +function runTest(conn) { + testCollectionChangeStream(conn); + testDatabaseChangeStream(conn); + testWholeClusterChangeStream(conn); +} + +{ + // Test the non-sharded case. + const rst = new ReplSetTest({nodes: 2}); + rst.startSet({setParameter: {internalQueryStatsRateLimit: -1}}); + rst.initiate(); + rst.getPrimary().getDB("admin").setLogLevel(3, "queryStats"); + runTest(rst.getPrimary()); + rst.stopSet(); +} + +{ + // Test on a sharded cluster. + const st = new ShardingTest({ + mongos: 1, + shards: 2, + config: 1, + rs: {nodes: 1, setParameter: {writePeriodicNoops: true, periodicNoopIntervalSecs: 1}}, + mongosOptions: { + setParameter: { + internalQueryStatsRateLimit: -1, + } + }, + }); + runTest(st.s); + st.stop(); +} diff --git a/jstests/noPassthrough/queryStats/query_stats_change_stream_evict.js b/jstests/noPassthrough/queryStats/query_stats_change_stream_evict.js new file mode 100644 index 00000000000..c9782f4388e --- /dev/null +++ b/jstests/noPassthrough/queryStats/query_stats_change_stream_evict.js @@ -0,0 +1,71 @@ +// Tests the collection of query stats for a change stream query if the entry is evicted while the +// cursor is still active. +// @tags: [ +// uses_change_streams, +// requires_replication, +// requires_sharding, +// requires_fcv_60 +// ] +load("jstests/libs/query_stats_utils.js"); // For getLatestQueryStatsEntry, getQueryStats, + // resetQueryStatsStore. +load("jstests/libs/fixture_helpers.js"); // For FixtureHelpers. +load("jstests/libs/collection_drop_recreate.js"); // For assertDropAndRecreateCollection. + +function runTest(conn) { + const db = conn.getDB("test"); + assertDropAndRecreateCollection(db, "coll"); + + // Check creation of change stream cursor is recorded. + let cursor = db.coll.watch([]); + + // Check that change stream entry was recorded. + let queryStatsEntry = getLatestQueryStatsEntry(db); + checkChangeStreamEntry({ + queryStatsEntry: queryStatsEntry, + db: db, + collectionName: "coll", + numExecs: 1, + numDocsReturned: 0 + }); + + // Reset the store to evict the change streams metric. + resetQueryStatsStore(db, "1MB"); + + // Insert document into a collection which should update the cursor. + assert.commandWorked(db.coll.insert({_id: 0, a: 1})); + assert.soon(() => cursor.hasNext()); + + // There should be nothing stored in the query stats store. + let queryStats = getQueryStats(db); + assert.eq(queryStats, []); + + // Close cursor. + cursor.close(); +} + +{ + // Test the non-sharded case. + const rst = new ReplSetTest({nodes: 2}); + rst.startSet({setParameter: {internalQueryStatsRateLimit: -1}}); + rst.initiate(); + rst.getPrimary().getDB("admin").setLogLevel(3, "queryStats"); + runTest(rst.getPrimary()); + rst.stopSet(); +} + +{ + // Test on a sharded cluster. + const st = new ShardingTest({ + mongos: 1, + shards: 2, + config: 1, + rs: {nodes: 1, setParameter: {writePeriodicNoops: true, periodicNoopIntervalSecs: 1}}, + mongosOptions: { + setParameter: { + internalQueryStatsRateLimit: -1, + } + }, + }); + runTest(st.s); + st.stop(); +}
\ No newline at end of file diff --git a/jstests/noPassthrough/queryStats/query_stats_change_stream_per_shard_cursor.js b/jstests/noPassthrough/queryStats/query_stats_change_stream_per_shard_cursor.js new file mode 100644 index 00000000000..d2147f73eeb --- /dev/null +++ b/jstests/noPassthrough/queryStats/query_stats_change_stream_per_shard_cursor.js @@ -0,0 +1,222 @@ +/** + * Tests the collection of query stats for a change stream query created using $_passthroughToShard. + * @tags: [ + * requires_sharding, + * uses_change_streams, + * requires_fcv_60 + * ] + */ +load("jstests/libs/query_stats_utils.js"); + +const dbName = jsTestName(); + +function testCollectionChangeStream(sdb, shardId) { + // Check that change stream explain command is recorded. + let aggregateCmd = { + aggregate: "coll", + cursor: {}, + pipeline: [{$changeStream: {}}], + $_passthroughToShard: {shard: shardId}, + }; + + assert.commandWorked(sdb.runCommand({explain: aggregateCmd, verbosity: "executionStats"})); + + let queryStatsEntry = getLatestQueryStatsEntry(sdb); + checkChangeStreamEntry({ + queryStatsEntry: queryStatsEntry, + db: sdb, + collectionName: "coll", + numExecs: 1, + numDocsReturned: 0 + }); + + assert(queryStatsEntry.key.hasOwnProperty("explain")); + jsTestLog("passthroughToShard"); + jsTestLog(queryStatsEntry); + assert(queryStatsEntry.key.hasOwnProperty("$_passthroughToShard")); + assert(queryStatsEntry.key.$_passthroughToShard.hasOwnProperty("shard")); + + // Check creation of change stream cursor with $_passthroughToShard is recorded. + let resp = sdb.runCommand(aggregateCmd); + assert.commandWorked(resp); + + let cursor = new DBCommandCursor(sdb, resp); + + let numExecs = 1; + let numDocsReturned = 0; + + queryStatsEntry = getLatestQueryStatsEntry(sdb); + checkChangeStreamEntry({ + queryStatsEntry: queryStatsEntry, + db: sdb, + collectionName: "coll", + numExecs: numExecs, + numDocsReturned: numDocsReturned + }); + assert(queryStatsEntry.key.hasOwnProperty("$_passthroughToShard")); + assert(queryStatsEntry.key.$_passthroughToShard.hasOwnProperty("shard")); + + // Insert document into collection on the shard the change stream was created on (negative id + // value), and make sure retrieving the information updates the query stats entry. + assert.commandWorked(sdb.coll.insertOne({location: 1, _id: -3})); + numExecs += getNumberOfGetMoresUntilNextDocForChangeStream(cursor); + numDocsReturned++; + + queryStatsEntry = getLatestQueryStatsEntry(sdb); + checkChangeStreamEntry({ + queryStatsEntry: queryStatsEntry, + db: sdb, + collectionName: "coll", + numExecs: numExecs, + numDocsReturned: numDocsReturned + }); + assert(queryStatsEntry.key.hasOwnProperty("$_passthroughToShard")); + assert(queryStatsEntry.key.$_passthroughToShard.hasOwnProperty("shard")); + + // Close cursor and check that it updates query stats entry. + cursor.close(); + numExecs++; + queryStatsEntry = getLatestQueryStatsEntry(sdb); + checkChangeStreamEntry({ + queryStatsEntry: queryStatsEntry, + db: sdb, + collectionName: "coll", + numExecs: numExecs, + numDocsReturned: numDocsReturned + }); + assert(queryStatsEntry.key.hasOwnProperty("$_passthroughToShard")); + assert(queryStatsEntry.key.$_passthroughToShard.hasOwnProperty("shard")); + + // Closing the cursor should result in 0 ms for the operation. + assert.eq(queryStatsEntry.metrics.lastExecutionMicros, 0); +} + +function testDatabaseChangeStream(sdb, shardId) { + // Check creation of change stream cursor with $_passthroughToShard for whole database is + // recorded. + let aggregateCmd = { + aggregate: 1, + cursor: {}, + pipeline: [{$changeStream: {}}], + $_passthroughToShard: {shard: shardId} + }; + + let resp = sdb.runCommand(aggregateCmd); + assert.commandWorked(resp); + + let cursor = new DBCommandCursor(sdb, resp); + + // Check creation of change stream cursor is recorded. + let numExecs = 1; + let numDocsReturned = 0; + + let queryStatsEntry = getLatestQueryStatsEntry(sdb); + checkChangeStreamEntry({ + queryStatsEntry: queryStatsEntry, + db: sdb, + collectionName: "$cmd.aggregate", + numExecs: numExecs, + numDocsReturned: numDocsReturned + }); + + assert(queryStatsEntry.key.hasOwnProperty("$_passthroughToShard")); + assert(queryStatsEntry.key.$_passthroughToShard.hasOwnProperty("shard")); + + // Insert document into collection on the shard the change stream is watching (negative id + // value), and make sure retrieving the information updates the query stats entry. + assert.commandWorked(sdb.coll.insertOne({location: 3, _id: -5})); + numExecs += getNumberOfGetMoresUntilNextDocForChangeStream(cursor); + numDocsReturned++; + + queryStatsEntry = getLatestQueryStatsEntry(sdb); + checkChangeStreamEntry({ + queryStatsEntry: queryStatsEntry, + db: sdb, + collectionName: "$cmd.aggregate", + numExecs: numExecs, + numDocsReturned: numDocsReturned + }); + + assert(queryStatsEntry.key.hasOwnProperty("$_passthroughToShard")); + assert(queryStatsEntry.key.$_passthroughToShard.hasOwnProperty("shard")); + + // Insert document into different collection on the shard the change stream is watching + // (negative id value), and make sure retrieving the information updates the query stats entry. + assert.commandWorked(sdb.coll2.insertOne({location: 4, _id: -10})); + numExecs += getNumberOfGetMoresUntilNextDocForChangeStream(cursor); + numDocsReturned++; + + queryStatsEntry = getLatestQueryStatsEntry(sdb); + checkChangeStreamEntry({ + queryStatsEntry: queryStatsEntry, + db: sdb, + collectionName: "$cmd.aggregate", + numExecs: numExecs, + numDocsReturned: numDocsReturned + }); + assert(queryStatsEntry.key.hasOwnProperty("$_passthroughToShard")); + assert(queryStatsEntry.key.$_passthroughToShard.hasOwnProperty("shard")); + + // Close cursor and check that it increases numExecs. + cursor.close(); + numExecs++; + + queryStatsEntry = getLatestQueryStatsEntry(sdb); + checkChangeStreamEntry({ + queryStatsEntry: queryStatsEntry, + db: sdb, + collectionName: "$cmd.aggregate", + numExecs: numExecs, + numDocsReturned: numDocsReturned + }); + assert(queryStatsEntry.key.hasOwnProperty("$_passthroughToShard")); + assert(queryStatsEntry.key.$_passthroughToShard.hasOwnProperty("shard")); + + // Closing the cursor should result in 0 ms for the operation. + assert.eq(queryStatsEntry.metrics.lastExecutionMicros, 0); +} + +function runTest(sdb, shardId) { + testCollectionChangeStream(sdb, shardId); + testDatabaseChangeStream(sdb, shardId); +} + +function setupShardedCluster() { + const st = new ShardingTest({ + shards: 2, + mongos: 1, + config: 1, + rs: {nodes: 1, setParameter: {writePeriodicNoops: false}}, + other: { + mongosOptions: { + setParameter: { + internalQueryStatsRateLimit: -1, + } + } + } + }); + + const sdb = st.s0.getDB(dbName); + assert.commandWorked(sdb.dropDatabase()); + + sdb.setProfilingLevel(0, -1); + st.shard0.getDB(dbName).setProfilingLevel(0, -1); + + // Shard the relevant collections. + assert.commandWorked(st.s.adminCommand({enableSharding: dbName, primaryShard: st.shard0.name})); + // Shard the collection on {_id: 1}, split at {_id: 0} and move the empty upper chunk to + // shard1. + st.shardColl("coll", {_id: 1}, {_id: 0}, {_id: 0}, dbName); + st.shardColl("coll2", {_id: 1}, {_id: 0}, {_id: 0}, dbName); + + // Returns shardID of shard containing the negative _id values. + const shardId = st.shard0.shardName; + return [sdb, st, shardId]; +} + +{ + let [sdb, st, shardId] = setupShardedCluster(); + st.shard0.getDB("admin").setLogLevel(3, "queryStats"); + runTest(sdb, shardId); + st.stop(); +} diff --git a/jstests/noPassthrough/queryStats/query_stats_collectionType.js b/jstests/noPassthrough/queryStats/query_stats_collectionType.js new file mode 100644 index 00000000000..77428f9dc29 --- /dev/null +++ b/jstests/noPassthrough/queryStats/query_stats_collectionType.js @@ -0,0 +1,208 @@ +/** + * Test that collectionType is returned properly in $queryStats. Checks for collection types + * "collection", "view", "timeseries", "nonExistent", and "virtual". Type "changeStream" is covered + * in query_stats_changeStreams.js. + * @tags: [requires_fcv_60] + */ +load("jstests/libs/query_stats_utils.js"); +(function() { +"use strict"; + +function runTest(conn) { + const testDB = conn.getDB('test'); + + // We create one collection for each corresponding type reported by query stats. + assert.commandWorked(testDB.createCollection(jsTestName() + "_collection")); + assert.commandWorked(testDB.createView( + jsTestName() + "_view", jsTestName() + "_collection", [{$match: {v: {$gt: 42}}}])); + assert.commandWorked( + testDB.createCollection(jsTestName() + "_timeseries", {timeseries: {timeField: "time"}})); + // We create an additional view over the existing view to test full view resolution. We use + // the $setWindowFields stage since it desugars into multiple stages, to make sure the query + // shape produced is restricted to the user-provided query. + assert.commandWorked(testDB.createView(jsTestName() + "_viewOverView", jsTestName() + "_view", [ + { + $setWindowFields: { + partitionBy: "$x", + sortBy: {v: 1}, + output: {sum: {$sum: "$y", window: {documents: ["unbounded", "current"]}}} + } + }, + {$project: {_id: 0, v: 1, x: 1, y: "$output.sum"}} + ])); + + // Next we run queries over each of the collection types to generate query stats. + + // Base _collection has a few simple documents. + var coll = testDB[jsTestName() + "_collection"]; + coll.insert({v: 1}); + coll.insert({v: 2}); + coll.insert({v: 3}); + coll.find({v: 3}).toArray(); + coll.aggregate([]).toArray(); + + // View _view is over _collection. + coll = testDB[jsTestName() + "_view"]; + coll.find({v: 5}).toArray(); + coll.aggregate([{$match: {v: {$lt: 99}}}]).toArray(); + + // View _viewOverView is over _view. + coll = testDB[jsTestName() + "_viewOverView"]; + // Run an empty find to make sure filter in query stats key is recorded as empty. + coll.find({}).toArray(); + // We test with $densify since it desugars into multiple stages, again to ensure the query + // shape calculated is restricted to the user-provided query. (In this case, the desugared + // $densify is acceptable, as long as the view pipeline is ignored). + coll.aggregate([{$densify: {field: "y", range: {step: 10, bounds: "full"}}}]).toArray(); + + // Timeseries collection _timeseries. + coll = testDB[jsTestName() + "_timeseries"]; + coll.insert({v: 1, time: ISODate("2021-05-18T00:00:00.000Z")}); + coll.insert({v: 2, time: ISODate("2021-05-18T01:00:00.000Z")}); + coll.insert({v: 3, time: ISODate("2021-05-18T02:00:00.000Z")}); + coll.find({v: 6}).toArray(); + // Run an empty aggregate to ensure pipeline in query stats key is recorded as empty. + coll.aggregate().toArray(); + + // QueryStats should still be collected for queries run on nonexistent collections. + assert.commandWorked(testDB.runCommand({find: jsTestName() + "_nonExistent", filter: {v: 6}})); + assert.commandWorked( + testDB.runCommand({aggregate: jsTestName() + "_nonExistent", pipeline: [], cursor: {}})); + + // Verify that we have two query stats entries for the collection type. This assumes we have + // executed one find and one agg query for the given collection type. + function verifyQueryStatsForCollectionType( + collectionType, collectionName = jsTestName() + "_" + collectionType) { + const queryStats = getQueryStats(conn, { + extraMatch: + {"key.collectionType": collectionType, "key.queryShape.cmdNs.coll": collectionName} + }); + // We should see one entry for find() and one for aggregate() + // for each collection type. The queries account for the fact + // that find() queries over views are rewritten to + // aggregate(). Ie, the query shapes are different because the + // queries are different. + assert.eq(2, queryStats.length, "Expected result for collection type " + collectionType); + } + + verifyQueryStatsForCollectionType("collection"); + verifyQueryStatsForCollectionType("view"); + verifyQueryStatsForCollectionType("view", jsTestName() + "_viewOverView"); + verifyQueryStatsForCollectionType("timeseries"); + verifyQueryStatsForCollectionType("nonExistent"); + + // Run commands that should be tracked as "virtual" collection type. + assert.commandWorked( + testDB.adminCommand({aggregate: 1, pipeline: [{$currentOp: {}}], cursor: {}})); + assert.commandWorked(testDB.adminCommand( + {aggregate: 1, pipeline: [{$documents: [{a: 1}, {a: 4}]}], cursor: {}})); + assert.commandWorked( + testDB.adminCommand({aggregate: 1, pipeline: [{$listLocalSessions: {}}], cursor: {}})); + + // Verify the queries on "virtual" collection types were tracked appropriately. This includes + // the 3 queries directly run above, in addition to 1 entry for the $queryStats aggregations + // run for the test. + let queryStats = getQueryStats(conn, {extraMatch: {"key.collectionType": "virtual"}}); + assert.eq(4, queryStats.length); + + // Verify that, for views, we capture the original query before it's rewritten. The view would + // include a $match stage with $gt predicate on 'v'. The viewOnView would include the same + // $match stage, the $setWindowFields stage, and the $project stage. The timeseries would + // include the bucket unpacking stages. + const findOnViewShape = getQueryStats(conn, { + extraMatch: { + "key.collectionType": "view", + "key.queryShape.command": "find", + "key.queryShape.cmdNs.coll": jsTestName() + "_view" + } + })[0] + .key.queryShape; + assert.eq(findOnViewShape.filter, {"v": {"$eq": "?number"}}); + + const aggOnViewShape = getQueryStats(conn, { + extraMatch: { + "key.collectionType": "view", + "key.queryShape.command": "aggregate", + "key.queryShape.cmdNs.coll": jsTestName() + "_view" + } + })[0] + .key.queryShape; + assert.eq(aggOnViewShape.pipeline, [{"$match": {"v": {"$lt": "?number"}}}]); + + const findOnViewOverViewShape = + getQueryStats(conn, { + extraMatch: { + "key.collectionType": "view", + "key.queryShape.command": "find", + "key.queryShape.cmdNs.coll": jsTestName() + "_viewOverView" + } + })[0] + .key.queryShape; + assert.eq(findOnViewOverViewShape.filter, {}); + + const aggOnViewOverViewShape = + getQueryStats(conn, { + extraMatch: { + "key.collectionType": "view", + "key.queryShape.command": "aggregate", + "key.queryShape.cmdNs.coll": jsTestName() + "_viewOverView" + } + })[0] + .key.queryShape; + assert.eq(aggOnViewOverViewShape.pipeline, [ + {"$sort": {"y": 1}}, + { + "$_internalDensify": { + "field": "y", + "partitionByFields": [], + "range": {"step": "?number", "bounds": "full"} + } + } + ]); + + const findOnTimeseriesShape = getQueryStats(conn, { + extraMatch: { + "key.collectionType": "timeseries", + "key.queryShape.command": "find", + "key.queryShape.cmdNs.coll": jsTestName() + "_timeseries" + } + })[0] + .key.queryShape; + assert.eq(findOnTimeseriesShape.filter, {"v": {"$eq": "?number"}}); + + const aggOnTimeseriesShape = getQueryStats(conn, { + extraMatch: { + "key.collectionType": "timeseries", + "key.queryShape.command": "aggregate", + "key.queryShape.cmdNs.coll": jsTestName() + "_timeseries" + } + })[0] + .key.queryShape; + assert.eq(aggOnTimeseriesShape.pipeline, []); +} + +const conn = MongoRunner.runMongod({ + setParameter: { + internalQueryStatsRateLimit: -1, + } +}); +runTest(conn); +MongoRunner.stopMongod(conn); + +// TODO Implement this in SERVER-76263. +if (false) { + const st = new ShardingTest({ + mongos: 1, + shards: 1, + config: 1, + rs: {nodes: 1}, + mongosOptions: { + setParameter: { + internalQueryStatsSamplingRate: -1, + } + }, + }); + runTest(st.s); + st.stop(); +} +}()); diff --git a/jstests/noPassthrough/queryStats/query_stats_disable_after_initial_request.js b/jstests/noPassthrough/queryStats/query_stats_disable_after_initial_request.js new file mode 100644 index 00000000000..e088c045eef --- /dev/null +++ b/jstests/noPassthrough/queryStats/query_stats_disable_after_initial_request.js @@ -0,0 +1,98 @@ +/** + * Tests that QueryStats metrics aren't collected if the feature is enabled initially but is + * disabled before the lifetime of the request is complete. + * @tags: [requires_fcv_60] + */ +load("jstests/libs/query_stats_utils.js"); // For getQueryStatsFindCmd. +(function() { +"use strict"; + +// Test that no QueryStats entry is written when (1) dispatching an initial find query, (2) +// disabling QueryStats, then (3) completing the command. Below, we run variations of this test +// with combinations of different strategies to disable QueryStats and to end the command. +function testStatsAreNotCollectedWhenDisabledBeforeCommandCompletion( + {conn, coll, disableQueryStatsFn, endCommandFn, enableQueryStatsFn}) { + // Issue a find commannd with a batchSize of 1 so that the query is not exhausted. + const cursor = coll.find({foo: 1}).batchSize(1); + // Must run .next() to make sure the initial request is executed now. + cursor.next(); + + // Disable QueryStats, then end the command,which triggers the path to writeQueryStats. + disableQueryStatsFn(); + endCommandFn(cursor); + + // Must re-enable QueryStats in order to check via $queryStats that nothing was recorded. + enableQueryStatsFn(); + const res = getQueryStatsFindCmd(conn, {collName: coll.getName()}); + assert.eq(res.length, 0, res); +} + +// Turn on the collecting of QueryStats metrics. +let options = {setParameter: {internalQueryStatsRateLimit: -1}}; + +const conn = MongoRunner.runMongod(options); +const testDB = conn.getDB('test'); +var coll = testDB[jsTestName()]; +coll.drop(); + +const bulk = coll.initializeUnorderedBulkOp(); +const numDocs = 100; +for (let i = 0; i < numDocs / 2; ++i) { + bulk.insert({foo: 0, bar: Math.floor(Math.random() * 3)}); + bulk.insert({foo: 1, bar: Math.floor(Math.random() * -2)}); +} +assert.commandWorked(bulk.execute()); + +function setQueryStatsCacheSize(size) { + assert.commandWorked(testDB.adminCommand({setParameter: 1, internalQueryStatsCacheSize: size})); +} + +function setFCV(newFCV) { + assert.commandWorked(testDB.adminCommand({setFeatureCompatibilityVersion: newFCV})); +} + +// Tests the scenario of disabling QueryStats by setting internalQueryStatsCacheSize to +// 0 and ending the command by running it to completion. +testStatsAreNotCollectedWhenDisabledBeforeCommandCompletion({ + conn: testDB, + coll, + disableQueryStatsFn: () => setQueryStatsCacheSize("0MB"), + endCommandFn: (cursor) => cursor.itcount(), + enableQueryStatsFn: () => setQueryStatsCacheSize("10MB") +}); + +// Tests the scenario of disabling QueryStats by setting internalQueryStatsCacheSize to +// 0 and ending the command by killing the cursor. +testStatsAreNotCollectedWhenDisabledBeforeCommandCompletion({ + conn: testDB, + coll, + disableQueryStatsFn: () => setQueryStatsCacheSize("0MB"), + endCommandFn: (cursor) => assert.commandWorked( + testDB.runCommand({killCursors: coll.getName(), cursors: [cursor.getId()]})), + enableQueryStatsFn: () => setQueryStatsCacheSize("10MB") +}); + +jsTestLog(lastLTSFCV); +// Tests the scenario of disabling query stats by downgrading the FCV and ending the command by +// running it to completion. +testStatsAreNotCollectedWhenDisabledBeforeCommandCompletion({ + conn: testDB, + coll, + disableQueryStatsFn: () => setFCV(lastLTSFCV), + endCommandFn: (cursor) => cursor.itcount(), + enableQueryStatsFn: () => setFCV(binVersionToFCV("latest")) +}); + +// Tests the scenario of disabling query stats by downgrading the FCV and ending the command by +// killing the cursor. +testStatsAreNotCollectedWhenDisabledBeforeCommandCompletion({ + conn: testDB, + coll, + disableQueryStatsFn: () => setFCV(lastLTSFCV), + endCommandFn: (cursor) => assert.commandWorked( + testDB.runCommand({killCursors: coll.getName(), cursors: [cursor.getId()]})), + enableQueryStatsFn: () => setFCV(binVersionToFCV("latest")) +}); + +MongoRunner.stopMongod(conn); +}()); diff --git a/jstests/noPassthrough/queryStats/query_stats_explain_cmd_agg.js b/jstests/noPassthrough/queryStats/query_stats_explain_cmd_agg.js new file mode 100644 index 00000000000..2a12b85f274 --- /dev/null +++ b/jstests/noPassthrough/queryStats/query_stats_explain_cmd_agg.js @@ -0,0 +1,37 @@ +/** + * This test confirms that the correct verbosity levels are stored in the query stats key for + * explain commands on an agg query. + * @tags: [requires_fcv_60] + */ +load("jstests/libs/query_stats_utils.js"); + +const testColl = jsTestName(); + +const testPipeline = [{"$match": {"bar": {"$gte": 1}}}, {"$count": "bars"}]; + +function assertVerbosityField(coll, pipeline, verbosity) { + assert.commandWorked(coll.explain(verbosity).aggregate(pipeline)); + const entry = getLatestQueryStatsEntry(coll.getDB().getMongo(), {collName: coll.getName()}); + assert.eq(getValueAtPath(entry, "key.explain"), verbosity, tojson(entry)); + assert.eq(getValueAtPath(entry, "metrics.execCount"), 1, tojson(entry)); + // TODO SERVER-89439: Uncomment this block and perhaps add more assertions. + // if (!FixtureHelpers.isSharded(coll)) { + // TODO SERVER-89053: Remove conditional statement to assert in sharded tests. + // assert.gt(getValueAtPath(entry, "metrics.lastExecutionMicros"), 1, tojson(entry)); + // } +} + +withQueryStatsEnabled(testColl, (coll) => { + // Insert documents to ensure we raise 'execCount'. + const bulk = coll.initializeUnorderedBulkOp(); + const numDocs = 100; + for (let i = 0; i < numDocs / 2; ++i) { + bulk.insert({foo: 0, bar: Math.floor(Math.random() * 3)}); + bulk.insert({foo: 1, bar: Math.floor(Math.random() * -2)}); + } + assert.commandWorked(bulk.execute()); + + assertVerbosityField(coll, testPipeline, 'queryPlanner'); + assertVerbosityField(coll, testPipeline, 'allPlansExecution'); + assertVerbosityField(coll, testPipeline, 'executionStats'); +}); diff --git a/jstests/noPassthrough/queryStats/query_stats_expressions.js b/jstests/noPassthrough/queryStats/query_stats_expressions.js new file mode 100644 index 00000000000..133582cb715 --- /dev/null +++ b/jstests/noPassthrough/queryStats/query_stats_expressions.js @@ -0,0 +1,76 @@ +/** + * Test that queryStats works properly for a find command that uses agg expressions and produces the + * proper query shape without issues during re-parsing. + * @tags: [requires_fcv_60] + */ +load("jstests/libs/query_stats_utils.js"); // For getQueryStats and resetQueryStatsStore. + +(function() { +"use strict"; + +// Turn on the collecting of queryStats metrics. +let options = { + setParameter: {internalQueryStatsRateLimit: -1}, +}; + +const conn = MongoRunner.runMongod(options); +const testDB = conn.getDB('test'); +var coll = testDB[jsTestName()]; +coll.drop(); + +const bulk = coll.initializeUnorderedBulkOp(); +const numDocs = 100; +for (let i = 0; i < numDocs / 2; ++i) { + bulk.insert({foo: i, bar: i, applyDiscount: true, word: "asdf"}); + bulk.insert({foo: i, bar: i, applyDiscount: false, word: "ghjk"}); +} +assert.commandWorked(bulk.execute()); +coll.createIndex({foo: 1}); + +// Tests that $meta is re-parsed correctly by ensuring the metaDataKeyword is not serialized as +// string literal. +{ + resetQueryStatsStore(conn, "1MB"); + coll.find({$expr: {idxKey: {$meta: "indexKey"}}}).itcount(); + let queryStats = getQueryStats(testDB); + assert.eq({"$expr": {"idxKey": {"$meta": "indexKey"}}}, queryStats[0].key.queryShape.filter); +} + +// Tests that $regexMatch is re-parsed correctly. The parser does not check that regex is a valid +// regex pattern, so regular serialization is okay. +{ + resetQueryStatsStore(conn, "1MB"); + coll.find({$expr: {result: {$regexMatch: {input: "$word", regex: "^a"}}}}).itcount(); + let queryStats = getQueryStats(testDB); + assert.eq({"$expr": {"result": {"$regexMatch": {"input": "$word", "regex": "?string"}}}}, + queryStats[0].key.queryShape.filter); +} + +// Tests that $let is re-parsed correctly, by ensuring the variables are not serialized as string +// literals. +{ + resetQueryStatsStore(conn, "1MB"); + coll.find({$expr: {$let: { + vars: { + total: { $add: [ '$foo', '$bar' ] }, + discounted: { $cond: { if: '$applyDiscount', then: 0.9, else: 1 } } + }, + in: { $multiply: [ "$$total", "$$discounted" ] } + }}}).itcount(); + let queryStats = getQueryStats(testDB); + assert.eq({ + "$expr": { + "$let": { + "vars": { + "total": {"$add": ["$foo", "$bar"]}, + "discounted": {"$cond": ["$applyDiscount", "?number", "?number"]} + }, + "in": {"$multiply": ["$$total", "$$discounted"]} + } + } + }, + queryStats[0].key.queryShape.filter); +} + +MongoRunner.stopMongod(conn); +}()); diff --git a/jstests/noPassthrough/queryStats/query_stats_feature_flag.js b/jstests/noPassthrough/queryStats/query_stats_feature_flag.js new file mode 100644 index 00000000000..5580c5ec29d --- /dev/null +++ b/jstests/noPassthrough/queryStats/query_stats_feature_flag.js @@ -0,0 +1,31 @@ +/** + * Test that calls to read from query stats store fail when feature flag is turned off. + */ +load('jstests/libs/analyze_plan.js'); +load("jstests/libs/feature_flag_util.js"); + +(function() { +"use strict"; + +// This test specifically tests error handling when the feature flag is not on. +// TODO SERVER-65800 this test can be removed when the feature flag is removed. +const conn = MongoRunner.runMongod({ + setParameter: {featureFlagQueryStats: false}, +}); +const testDB = conn.getDB('test'); + +// Pipeline to read queryStats store should fail without feature flag turned on. +assert.commandFailedWithCode( + testDB.adminCommand({aggregate: 1, pipeline: [{$queryStats: {}}], cursor: {}}), + ErrorCodes.QueryFeatureNotAllowed); + +// Pipeline, with a filter, to read queryStats store fails without feature flag turned on. +assert.commandFailedWithCode(testDB.adminCommand({ + aggregate: 1, + pipeline: [{$queryStats: {}}, {$match: {"key.queryShape.find": {$eq: "###"}}}], + cursor: {} +}), + ErrorCodes.QueryFeatureNotAllowed); + +MongoRunner.stopMongod(conn); +}()); diff --git a/jstests/noPassthrough/queryStats/query_stats_find_cmd_collect_on_mongos.js b/jstests/noPassthrough/queryStats/query_stats_find_cmd_collect_on_mongos.js new file mode 100644 index 00000000000..a1f3bc5d59e --- /dev/null +++ b/jstests/noPassthrough/queryStats/query_stats_find_cmd_collect_on_mongos.js @@ -0,0 +1,126 @@ +/** + * Test that mongos is collecting query stats metrics for find queries. + * @tags: [requires_fcv_60] + */ + +load('jstests/libs/query_stats_utils.js'); + +(function() { +"use strict"; + +const st = new ShardingTest({ + mongos: 1, + shards: 1, + config: 1, + rs: {nodes: 1}, + mongosOptions: { + setParameter: { + internalQueryStatsRateLimit: -1, + } + }, +}); +const mongos = st.s; +const db = mongos.getDB("test"); +const coll = db.coll; +coll.insert({v: 1}); +coll.insert({v: 4}); + +// Assert that, for find queries, no query stats results are written until a cursor has reached +// exhaustion; ensure accurate results once they're written. +{ + const queryStatsKey = { + queryShape: { + cmdNs: {db: "test", coll: "coll"}, + command: "find", + filter: {$and: [{v: {$gt: "?number"}}, {v: {$lt: "?number"}}]}, + }, + readConcern: {level: "local", provenance: "implicitDefault"}, + batchSize: "?number", + client: {application: {name: "MongoDB Shell"}} + }; + + const cursor = coll.find({v: {$gt: 0, $lt: 5}}).batchSize(1); // returns 1 doc + + // Since the cursor hasn't been exhausted yet, ensure no query stats results have been written + // yet. + let queryStats = getQueryStats(db); + assert.eq(0, queryStats.length, queryStats); + + // Run a getMore to exhaust the cursor, then ensure query stats results have been written + // accurately. batchSize must be 2 so the cursor recognizes exhaustion. + assert.commandWorked(db.runCommand({ + getMore: cursor.getId(), + collection: coll.getName(), + batchSize: 2 + })); // returns 1 doc, exhausts the cursor + queryStats = getQueryStatsFindCmd(db); + assert.eq(1, queryStats.length, queryStats); + assertExpectedResults(queryStats[0], + queryStatsKey, + /* expectedExecCount */ 1, + /* expectedDocsReturnedSum */ 2, + /* expectedDocsReturnedMax */ 2, + /* expectedDocsReturnedMin */ 2, + /* expectedDocsReturnedSumOfSq */ NumberDecimal("4"), + /* getMores */ true); + + // Run more queries (to exhaustion) with the same query shape, and ensure query stats results + // are accurate. + coll.find({v: {$gt: 2, $lt: 3}}).batchSize(10).toArray(); // returns 0 docs + coll.find({v: {$gt: 0, $lt: 1}}).batchSize(10).toArray(); // returns 0 docs + coll.find({v: {$gt: 0, $lt: 2}}).batchSize(10).toArray(); // return 1 doc + queryStats = getQueryStatsFindCmd(db); + assert.eq(1, queryStats.length, queryStats); + assertExpectedResults(queryStats[0], + queryStatsKey, + /* expectedExecCount */ 4, + /* expectedDocsReturnedSum */ 3, + /* expectedDocsReturnedMax */ 2, + /* expectedDocsReturnedMin */ 0, + /* expectedDocsReturnedSumOfSq */ NumberDecimal("5"), + /* getMores */ true); +} + +// Assert on batchSize-limited find queries that killCursors will write metrics with partial results +// to the query stats store. +{ + const coll2 = db.coll2; + coll2.insert({v: 1}); + coll2.insert({v: 4}); + const queryStatsKey = { + queryShape: { + cmdNs: {db: "test", coll: "coll2"}, + command: "find", + filter: {$and: [{v: {$gt: "?number"}}, {v: {$lt: "?number"}}]}, + }, + readConcern: {level: "local", provenance: "implicitDefault"}, + batchSize: "?number", + client: {application: {name: "MongoDB Shell"}} + }; + + const cursor1 = coll2.find({v: {$gt: 0, $lt: 5}}).batchSize(1); // returns 1 doc + const cursor2 = coll2.find({v: {$gt: 0, $lt: 2}}).batchSize(1); // returns 1 doc + + assert.commandWorked( + db.runCommand({killCursors: coll2.getName(), cursors: [cursor1.getId(), cursor2.getId()]})); + const queryStats = getLatestQueryStatsEntry(db); + assertExpectedResults(queryStats, + queryStatsKey, + /* expectedExecCount */ 2, + /* expectedDocsReturnedSum */ 2, + /* expectedDocsReturnedMax */ 1, + /* expectedDocsReturnedMin */ 1, + /* expectedDocsReturnedSumOfSq */ NumberDecimal("2"), + /* getMores */ false); +} + +// SERVER-83964 Test that query stats are collected if the database doesn't exist. +{ + const nonExistentDB = db.getSiblingDB("newDB"); + assert.eq(null, nonExistentDB.anything.findOne()); + const entry = getLatestQueryStatsEntry(db, {collName: "anything"}); + assert.neq(null, entry); +} + +st.stop(); +}()); diff --git a/jstests/noPassthrough/queryStats/query_stats_find_key.js b/jstests/noPassthrough/queryStats/query_stats_find_key.js new file mode 100644 index 00000000000..2c1d65f5bb5 --- /dev/null +++ b/jstests/noPassthrough/queryStats/query_stats_find_key.js @@ -0,0 +1,113 @@ +/** + * This test confirms that query stats store key fields for a find command are properly nested and + * none are missing. + * @tags: [requires_fcv_60] + */ +load("jstests/libs/query_stats_utils.js"); // For runCommandAndValidateQueryStats and + // withQueryStatsEnabled and getLatestQueryStatsEntry +(function() { +"use strict"; + +const collName = jsTestName(); + +const findCommandObj = { + find: collName, + filter: {v: {$eq: 2}}, + oplogReplay: true, + comment: "this is a test!!", + min: {"v": 0}, + max: {"v": 4}, + hint: {"v": 1}, + sort: {a: -1}, + returnKey: false, + noCursorTimeout: true, + showRecordId: false, + tailable: false, + awaitData: false, + allowPartialResults: true, + skip: 1, + limit: 2, + maxTimeMS: 50 * 1000, + collation: {locale: "en_US", strength: 2}, + allowDiskUse: true, + readConcern: {level: "local"}, + batchSize: 2, + singleBatch: true, + let : {}, + projection: {_id: 0}, + apiDeprecationErrors: false, + apiVersion: "1", + apiStrict: false, +}; + +const queryShapeFindFields = [ + "cmdNs", + "command", + "filter", + "sort", + "projection", + "skip", + "limit", + "singleBatch", + "max", + "min", + "returnKey", + "showRecordId", + "tailable", + "oplogReplay", + "awaitData", + "collation", + "allowDiskUse", + "let" +]; + +// The outer fields not nested inside queryShape. +const findKeyFields = [ + "queryShape", + "batchSize", + "comment", + "maxTimeMS", + "noCursorTimeout", + "readConcern", + "allowPartialResults", + "apiDeprecationErrors", + "apiVersion", + "apiStrict", + "collectionType", + "client", + "hint" +]; + +/** + * Regression test for SERVER-85532: $hint syntax will not be validated if the collection does not + * exist. Make sure that query stats can still handle an invalid hint. See SERVER-85500. + * + * @param testDB + */ +function validateInvalidHint(testDB) { + const collName = "invalid_hint_coll"; + var coll = testDB[collName]; + coll.drop(); + // $hint is supposed to be a string or object, but this works: + assert.commandWorked(testDB.runCommand({ + find: collName, + hint: {$hint: -1.0}, + })); + const entry = getLatestQueryStatsEntry(testDB.getMongo(), {collName: collName}); + assert.eq(entry.key.hint, {$hint: "?number"}); +} + +withQueryStatsEnabled(collName, (coll) => { + // Have to create an index for hint not to fail. + assert.commandWorked(coll.createIndex({v: 1})); + + runCommandAndValidateQueryStats({ + coll: coll, + commandName: "find", + commandObj: findCommandObj, + shapeFields: queryShapeFindFields, + keyFields: findKeyFields, + }); + validateInvalidHint(coll); +}); +}()); diff --git a/jstests/noPassthrough/queryStats/query_stats_key_hash.js b/jstests/noPassthrough/queryStats/query_stats_key_hash.js new file mode 100644 index 00000000000..0eaacf9fecf --- /dev/null +++ b/jstests/noPassthrough/queryStats/query_stats_key_hash.js @@ -0,0 +1,98 @@ +/** + * This test confirms that the hash generated alongside query stats entries is unique and stable + * across restarts. + * @tags: [requires_fcv_60] + */ +(function() { +'use strict'; + +load("jstests/libs/query_stats_utils.js"); // For getQueryStatsFindCmd and getQueryStatsKeyHashes. + +const replTest = new ReplSetTest({name: 'queryStatsKeyHashTest', nodes: 2}); + +// Turn on the collecting of query stats metrics. +replTest.startSet({setParameter: {internalQueryStatsRateLimit: -1}}); +replTest.initiate(); + +const conn = replTest.getPrimary(); +const collName = jsTestName(); +const coll = conn.getDB("test")[collName]; +coll.drop(); +coll.insert({x: 5}); + +let totalShapes = 0; + +// Simple query, different field names. +coll.find({x: 5}).toArray(); +++totalShapes; +coll.find({y: 5}).toArray(); +++totalShapes; + +// Simple $regex query, sort, and limit. +coll.find({x: {$regex: ".*"}}).sort({y: -1}).limit(10).toArray(); +++totalShapes; +coll.find({x: {$regex: "."}}).sort({y: -1}).limit(10).toArray(); +// Don't increment 'totalShapes' - different $regex value still means the same shape. +coll.find({x: {$regex: "."}}).sort({y: -1}).limit(10).toArray(); + +// Simple query with projection and limit. +coll.find({x: {$regex: ".*"}}, {_id: 0, x: "$$ROOT", y: {$bsonSize: ["$$ROOT"]}}) + .limit(5) + .toArray(); +++totalShapes; +coll.find({x: {$regex: ".*"}}, {_id: 0, x: "$$ROOT", y: {$bsonSize: ["$$ROOT"]}}) + .limit(10) + .toArray(); +// Don't increment 'totalShapes' - different limit value still means the same shape. +coll.find({x: {$regex: ".*"}}, {_id: false, x: "$$ROOT", y: {$bsonSize: ["$$ROOT"]}}) + .limit(5) + .toArray(); +// Don't increment 'totalShapes' - 'false' projection is the same as '0'. +coll.find({x: {$regex: ".*"}}, {_id: 0, x: "$$ROOT", y: {$bsonSize: ["$$CURRENT"]}}) + .limit(5) + .toArray(); +++totalShapes; // different $bsonSize argument +coll.find({x: {$regex: ".*"}}, {x: "$$ROOT", y: {$bsonSize: ["$$ROOT"]}, _id: true}) + .limit(5) + .toArray(); +++totalShapes; // explicit '_id' inclusion projection +coll.find({x: {$regex: ".*"}}, {x: "$$ROOT", y: {$bsonSize: ["$$ROOT"]}}).limit(5).toArray(); +// Don't increment 'totalShapes' - '_id' inclusion projection is implicit. + +// Different command options. +const filter = { + x: 5 +}; +const maxTimeMS = 123; +const batchSize = 10; +const readPref = "primary"; +coll.find(filter).maxTimeMS(maxTimeMS).batchSize(batchSize).readPref(readPref).toArray(); +++totalShapes; +// Vary values for the options specified - shape should not change for 'maxTimeMS' and +// 'batchSize', but should for 'readPreference'. +coll.find(filter).maxTimeMS(456).batchSize(batchSize).readPref(readPref).toArray(); +coll.find(filter).maxTimeMS(maxTimeMS).batchSize(20).readPref(readPref).toArray(); +coll.find(filter).maxTimeMS(maxTimeMS).batchSize(batchSize).readPref("nearest").toArray(); +++totalShapes; + +const untransformedEntries = getQueryStatsFindCmd(conn, {collName, transformIdentifiers: false}); +const untransformedKeyHashes = getQueryStatsKeyHashes(untransformedEntries); + +// Ensure that we got as many unique key hashes as we expect give the queries that we ran. +assert.eq(untransformedKeyHashes.length, totalShapes, tojson(untransformedEntries)); + +// We need to filter on the HMAC-ed collection name when we set {transformIdentifiers: true}. +const transformedCollName = "h52faC1z+jJCQp/Hq008ffChPpnk/nhAgo70uX1FFFI="; +const transformedEntries = + getQueryStatsFindCmd(conn, {collName: transformedCollName, transformIdentifiers: true}); +const transformedKeyHashes = getQueryStatsKeyHashes(transformedEntries); + +// We expect the hash to be derived from the untransformed shape, so the transformed $queryStats +// call should produce the same hash values as the untransformed one. +assert.sameMembers(untransformedKeyHashes, + transformedKeyHashes, + `untransformedEntries = ${tojson(untransformedEntries)}, transformedEntries = ${ + tojson(transformedEntries)}`); + +replTest.stopSet(); +})(); diff --git a/jstests/noPassthrough/queryStats/query_stats_logging.js b/jstests/noPassthrough/queryStats/query_stats_logging.js new file mode 100644 index 00000000000..c09f2948aa0 --- /dev/null +++ b/jstests/noPassthrough/queryStats/query_stats_logging.js @@ -0,0 +1,99 @@ +/** + * Test logging of $queryStats. + * @tags: [requires_fcv_60] + */ + +(function() { +"use strict"; +let options = { + setParameter: {internalQueryStatsRateLimit: -1}, +}; + +function countMatching(arr, func) { + let count = 0; + let i = arr.length; + while (i--) { + if (func(arr[i])) { + count += 1; + } + } + return count; +} + +function runQueryStatsAndVerifyLogs({pipeline, transformed, logLevel}) { + const conn = MongoRunner.runMongod(options); + const db = conn.getDB('test'); + var coll = db[jsTestName()]; + coll.drop(); + + // Set the logLevel. + assert.commandWorked(db.setLogLevel(logLevel, "queryStats")); + + // Insert a document and run two find command with different shapes so that we have two entries + // in the queryStats store. + assert.commandWorked(coll.insert({foo: 1, bar: "hello"})); + assert.eq(coll.find({foo: 1}).itcount(), 1); + assert.eq(coll.find({bar: "hello"}).itcount(), 1); + + // Run $queryStats with the specified pipeline. + let result = conn.adminCommand({aggregate: 1, pipeline: [pipeline], cursor: {}}); + assert.commandWorked(result); + + if (logLevel >= 1) { + // Checking that we log the invocation of $queryStats. + let spec = transformed + ? {"transformIdentifiers": {"algorithm": "hmac-sha-256", "hmacKey": "###"}} + : {}; + assert(checkLog.checkContainsWithCountJson( + conn, 7808300, {"commandSpec": spec}, 1, null, true), + "failed to find log with id " + 7808300); + } + + // We only log the output of $queryStats when invoked with transformation, and log level at + // least 3. + if (logLevel >= 3 && transformed) { + // Checking that we are logging both entries in the query stats store. + assert(checkLog.checkContainsWithCountJson(conn, 7808301, {}, 2, null, true), + "failed to find log with id " + 7808301); + + // Checking that the output is what we expect. + const query = assert.commandWorked(db.adminCommand({getLog: "global"})); + assert(query.hasOwnProperty("log"), "no log field"); + assert.eq(countMatching(query.log, function(v) { + const has = (s) => v.indexOf(s) !== -1; + return has("thisOutput") && has("key:") && has("queryShape") && + (has("?number") || has("?string")); + }), 2); + + // Checking that we log when we are done outputting the results of $queryStats. + assert(checkLog.checkContainsWithCountJson(conn, 7808302, {}, 1, null, true), + "failed to find log with id " + 7808302); + } + + // At a log level of 0 we should not be seeing any of these logs. + if (logLevel == 0) { + assert(checkLog.checkContainsWithCountJson(conn, 7808300, {}, 0, null, true)); + assert(checkLog.checkContainsWithCountJson(conn, 7808301, {}, 0, null, true)); + assert(checkLog.checkContainsWithCountJson(conn, 7808302, {}, 0, null, true)); + } + + MongoRunner.stopMongod(conn); +} + +// Testing logging with transformation. +const hmacKey = "MjM0NTY3ODkxMDExMTIxMzE0MTUxNjE3MTgxOTIwMjE="; +let pipeline = { + $queryStats: {transformIdentifiers: {algorithm: "hmac-sha-256", hmacKey: BinData(8, hmacKey)}} +}; +runQueryStatsAndVerifyLogs({pipeline: pipeline, transformed: true, logLevel: 3}); +runQueryStatsAndVerifyLogs({pipeline: pipeline, transformed: true, logLevel: 1}); +runQueryStatsAndVerifyLogs({pipeline: pipeline, transformed: true, logLevel: 0}); + +// Testing logging without transformation. +pipeline = { + $queryStats: {} +}; +runQueryStatsAndVerifyLogs({pipeline: pipeline, transformed: false, logLevel: 3}); +runQueryStatsAndVerifyLogs({pipeline: pipeline, transformed: false, logLevel: 1}); +runQueryStatsAndVerifyLogs({pipeline: pipeline, transformed: false, logLevel: 0}); +}()); diff --git a/jstests/noPassthrough/queryStats/query_stats_metrics_across_getMore_calls.js b/jstests/noPassthrough/queryStats/query_stats_metrics_across_getMore_calls.js new file mode 100644 index 00000000000..1bfb1c36ae5 --- /dev/null +++ b/jstests/noPassthrough/queryStats/query_stats_metrics_across_getMore_calls.js @@ -0,0 +1,173 @@ +/** + * Test that the queryStats metrics are aggregated properly by distinct query shape over getMore + * calls, for agg commands. + * @tags: [requires_fcv_60] + */ +load("jstests/libs/query_stats_utils.js"); // For verifyMetrics and getQueryStatsAggCmd. + +(function() { +"use strict"; + +// Turn on the collecting of queryStats metrics. +let options = { + setParameter: {internalQueryStatsRateLimit: -1}, +}; + +const conn = MongoRunner.runMongod(options); +const testDB = conn.getDB('test'); +var coll = testDB[jsTestName()]; +coll.drop(); + +// Bulk insert documents to reduces roundtrips and make timeout on a slow machine less likely. +const bulk = coll.initializeUnorderedBulkOp(); +const numDocs = 100; +for (let i = 0; i < numDocs / 2; ++i) { + bulk.insert({foo: 0, bar: Math.floor(Math.random() * 3)}); + bulk.insert({foo: 1, bar: Math.floor(Math.random() * -2)}); +} +assert.commandWorked(bulk.execute()); +// Assert that two queries with identical structures are represented by the same key. +{ + // Note: toArray() is necessary for the batchSize-limited query to run to cursor exhaustion + // (when it writes to the queryStats store). + coll.aggregate([{$match: {foo: 1}}], {cursor: {batchSize: 2}}).toArray(); + coll.aggregate([{$match: {foo: 0}}], {cursor: {batchSize: 2}}).toArray(); + + // This command will return all queryStats store entires. + const queryStatsResults = getQueryStatsAggCmd(testDB); + // Assert there is only one entry. + assert.eq(queryStatsResults.length, 1, queryStatsResults); + const queryStatsEntry = queryStatsResults[0]; + assert.eq(queryStatsEntry.key.queryShape.cmdNs.db, "test"); + assert.eq(queryStatsEntry.key.queryShape.cmdNs.coll, jsTestName()); + assert.eq(queryStatsEntry.key.client.application.name, "MongoDB Shell"); + + // Assert we update execution count for identically shaped queries. + assert.eq(queryStatsEntry.metrics.execCount, 2); + + // Assert queryStats values are accurate for the two above queries. + assert.eq(queryStatsEntry.metrics.docsReturned.sum, numDocs); + assert.eq(queryStatsEntry.metrics.docsReturned.min, numDocs / 2); + assert.eq(queryStatsEntry.metrics.docsReturned.max, numDocs / 2); + + verifyMetrics(queryStatsResults); +} + +const fooEqBatchSize = 5; +const fooNeBatchSize = 3; +// Assert on batchSize-limited queries that killCursors will write metrics with partial results to +// the queryStats store. +{ + let cursor1 = coll.find({foo: {$eq: 0}}).batchSize(fooEqBatchSize); + let cursor2 = coll.find({foo: {$ne: 0}}).batchSize(fooNeBatchSize); + // Issue one getMore for the first query, so 2 * fooEqBatchSize documents are returned total. + assert.commandWorked(testDB.runCommand( + {getMore: cursor1.getId(), collection: coll.getName(), batchSize: fooEqBatchSize})); + + // Kill both cursors so the queryStats metrics are stored. + assert.commandWorked(testDB.runCommand( + {killCursors: coll.getName(), cursors: [cursor1.getId(), cursor2.getId()]})); + + // This filters queryStats entires to just the ones entered when running above find queries. + const queryStatsResults = testDB.getSiblingDB("admin") + .aggregate([ + {$queryStats: {}}, + {$match: {"key.queryShape.filter.foo": {$exists: true}}}, + {$sort: {key: 1}}, + ]) + .toArray(); + assert.eq(queryStatsResults.length, 2, queryStatsResults); + assert.eq(queryStatsResults[0].key.queryShape.cmdNs.db, "test"); + assert.eq(queryStatsResults[0].key.queryShape.cmdNs.coll, jsTestName()); + assert.eq(queryStatsResults[0].key.client.application.name, "MongoDB Shell"); + assert.eq(queryStatsResults[1].key.queryShape.cmdNs.db, "test"); + assert.eq(queryStatsResults[1].key.queryShape.cmdNs.coll, jsTestName()); + assert.eq(queryStatsResults[1].key.client.application.name, "MongoDB Shell"); + + assert.eq(queryStatsResults[0].metrics.execCount, 1); + assert.eq(queryStatsResults[1].metrics.execCount, 1); + assert.eq(queryStatsResults[0].metrics.docsReturned.sum, fooEqBatchSize * 2); + assert.eq(queryStatsResults[1].metrics.docsReturned.sum, fooNeBatchSize); + + verifyMetrics(queryStatsResults); + + const distributionFields = ['sum', 'max', 'min', 'sumOfSquares']; + for (const field of distributionFields) { + // If there are getMore calls, queryExecMicros should be greater than or equal to + // firstResponseExecMicros. + assert(bsonWoCompare(queryStatsResults[0].metrics.totalExecMicros[field], + queryStatsResults[0].metrics.firstResponseExecMicros[field]) > 0); + + // If there is no getMore calls, firstResponseExecMicros and queryExecMicros should be + // equal. + assert.eq(queryStatsResults[1].metrics.totalExecMicros[field], + queryStatsResults[1].metrics.firstResponseExecMicros[field]); + } +} + +// Assert that options such as limit/sort create different keys, and that repeating a query shape +// ({foo: {$eq}}) aggregates metrics across executions. +{ + const query2Limit = 50; + coll.find({foo: {$eq: 0}}).batchSize(2).toArray(); + coll.find({foo: {$eq: 1}}).limit(query2Limit).batchSize(2).toArray(); + coll.find().sort({"foo": 1}).batchSize(2).toArray(); + // This filters queryStats entires to just the ones entered when running above find queries. + let queryStatsResults = + testDB.getSiblingDB("admin") + .aggregate([{$queryStats: {}}, {$match: {"key.queryShape.command": "find"}}]) + .toArray(); + assert.eq(queryStatsResults.length, 4, queryStatsResults); + + verifyMetrics(queryStatsResults); + + // This filters to just the queryStats for query coll.find().sort({"foo": 1}).batchSize(2). + queryStatsResults = + testDB.getSiblingDB("admin") + .aggregate([{$queryStats: {}}, {$match: {"key.queryShape.sort.foo": 1}}]) + .toArray(); + assert.eq(queryStatsResults.length, 1, queryStatsResults); + assert.eq(queryStatsResults[0].key.queryShape.cmdNs.db, "test"); + assert.eq(queryStatsResults[0].key.queryShape.cmdNs.coll, jsTestName()); + assert.eq(queryStatsResults[0].key.client.application.name, "MongoDB Shell"); + assert.eq(queryStatsResults[0].metrics.execCount, 1); + assert.eq(queryStatsResults[0].metrics.docsReturned.sum, numDocs); + + // This filters to just the queryStats for query coll.find({foo: {$eq: + // 1}}).limit(query2Limit).batchSize(2). + queryStatsResults = + testDB.getSiblingDB("admin") + .aggregate([{$queryStats: {}}, {$match: {"key.queryShape.limit": '?number'}}]) + .toArray(); + assert.eq(queryStatsResults.length, 1, queryStatsResults); + assert.eq(queryStatsResults[0].key.queryShape.cmdNs.db, "test"); + assert.eq(queryStatsResults[0].key.queryShape.cmdNs.coll, jsTestName()); + assert.eq(queryStatsResults[0].key.client.application.name, "MongoDB Shell"); + assert.eq(queryStatsResults[0].metrics.execCount, 1); + assert.eq(queryStatsResults[0].metrics.docsReturned.sum, query2Limit); + + // This filters to just the queryStats for query coll.find({foo: {$eq: 0}}).batchSize(2). + queryStatsResults = testDB.getSiblingDB("admin") + .aggregate([ + {$queryStats: {}}, + { + $match: { + "key.queryShape.filter.foo": {$eq: {$eq: "?number"}}, + "key.queryShape.limit": {$exists: false}, + "key.queryShape.sort": {$exists: false} + } + } + ]) + .toArray(); + assert.eq(queryStatsResults.length, 1, queryStatsResults); + assert.eq(queryStatsResults[0].key.queryShape.cmdNs.db, "test"); + assert.eq(queryStatsResults[0].key.queryShape.cmdNs.coll, jsTestName()); + assert.eq(queryStatsResults[0].key.client.application.name, "MongoDB Shell"); + assert.eq(queryStatsResults[0].metrics.execCount, 2); + assert.eq(queryStatsResults[0].metrics.docsReturned.sum, numDocs / 2 + 2 * fooEqBatchSize); + assert.eq(queryStatsResults[0].metrics.docsReturned.max, numDocs / 2); + assert.eq(queryStatsResults[0].metrics.docsReturned.min, 2 * fooEqBatchSize); +} + +MongoRunner.stopMongod(conn); +}()); diff --git a/jstests/noPassthrough/queryStats/query_stats_regex.js b/jstests/noPassthrough/queryStats/query_stats_regex.js new file mode 100644 index 00000000000..8b9553e267f --- /dev/null +++ b/jstests/noPassthrough/queryStats/query_stats_regex.js @@ -0,0 +1,43 @@ +/** + * Test that queryStats works properly for a find command that uses regex. + * @tags: [requires_fcv_60] + */ +(function() { +"use strict"; + +load("jstests/libs/query_stats_utils.js"); // For getLatestQueryStatsEntry. + +// Turn on the collecting of queryStats metrics. +let options = { + setParameter: {internalQueryStatsRateLimit: -1}, +}; + +const conn = MongoRunner.runMongod(options); +const testDB = conn.getDB('test'); +var coll = testDB[jsTestName()]; +coll.drop(); + +const bulk = coll.initializeUnorderedBulkOp(); +const numDocs = 100; +for (let i = 0; i < numDocs / 2; ++i) { + bulk.insert({foo: "ABCDE"}); + bulk.insert({foo: "CDEFG"}); +} +assert.commandWorked(bulk.execute()); + +{ + coll.find({foo: {$regex: "/^ABC/i"}}).itcount(); + const queryStats = getLatestQueryStatsEntry(testDB); + assert.eq({"foo": {"$regex": "?string"}}, queryStats.key.queryShape.filter, queryStats); +} + +{ + coll.find({foo: {$regex: ".*", $options: "m"}}).itcount(); + const queryStats = getLatestQueryStatsEntry(testDB); + assert.eq({"foo": {"$regex": "?string", "$options": "?string"}}, + queryStats.key.queryShape.filter, + queryStats); +} + +MongoRunner.stopMongod(conn); +}()); diff --git a/jstests/noPassthrough/queryStats/query_stats_sampling_rate.js b/jstests/noPassthrough/queryStats/query_stats_sampling_rate.js new file mode 100644 index 00000000000..b25fb3318d9 --- /dev/null +++ b/jstests/noPassthrough/queryStats/query_stats_sampling_rate.js @@ -0,0 +1,37 @@ +/** + * Test that calls to read from query stats store fail when sampling rate is not greater than 0 even + * if feature flag is on. + * @tags: [requires_fcv_60] + */ +load('jstests/libs/analyze_plan.js'); +load("jstests/libs/query_stats_utils.js"); + +(function() { +"use strict"; + +let options = { + setParameter: {internalQueryStatsRateLimit: 0}, +}; + +const conn = MongoRunner.runMongod(options); +const testdb = conn.getDB('test'); +var coll = testdb[jsTestName()]; +coll.drop(); +for (var i = 0; i < 20; i++) { + coll.insert({foo: 0, bar: Math.floor(Math.random() * 3)}); +} + +coll.find({foo: 1}).batchSize(2).toArray(); + +// Reading query stats store with a sampling rate of 0 should return 0 documents. +let stats = getQueryStats(testdb); +assert.eq(stats.length, 0); + +// Reading query stats store should work now with a sampling rate of greater than 0. +assert.commandWorked(testdb.adminCommand({setParameter: 1, internalQueryStatsRateLimit: -1})); +coll.find({foo: 1}).batchSize(2).toArray(); +stats = getQueryStats(testdb); +assert.eq(stats.length, 1); + +MongoRunner.stopMongod(conn); +}()); diff --git a/jstests/noPassthrough/queryStats/query_stats_server_status_metrics.js b/jstests/noPassthrough/queryStats/query_stats_server_status_metrics.js new file mode 100644 index 00000000000..ee6498b45cc --- /dev/null +++ b/jstests/noPassthrough/queryStats/query_stats_server_status_metrics.js @@ -0,0 +1,272 @@ +/** + * Test the queryStats related serverStatus metrics. + * @tags: [requires_fcv_60] + */ +(function() { +"use strict"; + +function runTestWithMongodOptions(mongodOptions, test, testOptions) { + const conn = MongoRunner.runMongod(mongodOptions); + const testDB = conn.getDB('test'); + const coll = testDB[jsTestName()]; + + test(conn, testDB, coll, testOptions); + + MongoRunner.stopMongod(conn); +} + +// Helper to round up to the next highest power of 2 for our estimation. +function align(number) { + return Math.pow(2, Math.ceil(Math.log2(number))); +} + +function addApprox2MBOfStatsData(testDB, coll) { + const k2MB = 2 * 1024 * 1024; + + const cmdObjTemplate = { + find: coll.getName(), + filter: {foo123: {$eq: "?"}}, + }; + + const kEstimatedEntrySizeBytes = (() => { + // Metrics stored per shape. + const kNumCountersAndDates = + 4 /* top-level */ + (4 * 3) /* those with sum, min, max, sumOfSquares */; + + // Just a sample, will change based on where the test is run - shouldn't be off by too much + // though. + const kClientMetadataEst = { + client: {application: {name: "MongoDB Shell"}}, + driver: {name: "MongoDB Internal Client", version: "7.1.0-alpha"}, + os: {type: "Linux", name: "Ubuntu", architecture: "aarch64", version: "22.04"} + }; + + const kCmdNsObj = {cmdNs: {db: testDB.getName(), coll: coll.getName()}}; + + // Rough estimate of space needed for just the query stats 'Key' class members assuming + // everything is 8 bytes. + const kCxxOverhead = 96; + + // This is likely not to be exact - we are probably forgetting something. But we don't need + // to be exact, just "good enough." + return align(kNumCountersAndDates * 4 + Object.bsonsize(cmdObjTemplate) + + Object.bsonsize(kClientMetadataEst) + Object.bsonsize(kCmdNsObj) + + kCxxOverhead); + })(); + const nIterations = k2MB / kEstimatedEntrySizeBytes; + for (let i = 0; i <= nIterations; i++) { + let newQuery = {["foo" + i]: "bar"}; + const cmdObj = cmdObjTemplate; + cmdObj.filter = newQuery; + const cmdRes = assert.commandWorked(testDB.runCommand(cmdObj)); + new DBCommandCursor(testDB, cmdRes).itcount(); + } +} +/** + * Test serverStatus metric which counts the number of evicted entries. + * + * testOptions must include `resetCacheSize` bool field; e.g., { resetCacheSize : true } + */ +function evictionTest(conn, testDB, coll, testOptions) { + const evictedBefore = testDB.serverStatus().metrics.queryStats.numEvicted; + assert.eq(evictedBefore, 0); + addApprox2MBOfStatsData(testDB, coll); + if (!testOptions.resetCacheSize) { + const evictedAfter = testDB.serverStatus().metrics.queryStats.numEvicted; + assert.gt(evictedAfter, 0, testDB.serverStatus().metrics.queryStats); + return; + } + // Make sure number of evicted entries increases when the cache size is reset, which forces out + // least recently used entries to meet the new, smaller size requirement. + assert.eq(testDB.serverStatus().metrics.queryStats.numEvicted, 0); + assert.commandWorked( + testDB.adminCommand({setParameter: 1, internalQueryStatsCacheSize: "1MB"})); + const evictedAfter = testDB.serverStatus().metrics.queryStats.numEvicted; + assert.gt(evictedAfter, 0); +} + +/** + * Test serverStatus metric which counts the number of requests for which queryStats is not + * collected due to rate-limiting. + * + * testOptions must include `samplingRate` and `numRequests` number fields; + * e.g., { samplingRate: -1, numRequests: 20 } + */ +function countRateLimitedRequestsTest(conn, testDB, coll, testOptions) { + const numRateLimitedRequestsBefore = + testDB.serverStatus().metrics.queryStats.numRateLimitedRequests; + assert.eq(numRateLimitedRequestsBefore, 0); + + coll.insert({a: 0}); + + // Running numRequests / 2 times since we dispatch two requests per iteration + for (var i = 0; i < testOptions.numRequests / 2; i++) { + coll.find({a: 0}).toArray(); + coll.aggregate([{$match: {a: 1}}]); + } + + const numRateLimitedRequestsAfter = + testDB.serverStatus().metrics.queryStats.numRateLimitedRequests; + + if (testOptions.samplingRate === 0) { + // queryStats should not be collected for any requests. + assert.eq(numRateLimitedRequestsAfter, testOptions.numRequests); + } else if (testOptions.samplingRate >= testOptions.numRequests) { + // queryStats should be collected for all requests. + assert.eq(numRateLimitedRequestsAfter, 0); + } else { + // queryStats should be collected for some but not all requests. + assert.gt(numRateLimitedRequestsAfter, 0); + assert.lt(numRateLimitedRequestsAfter, testOptions.numRequests); + } +} + +function queryStatsStoreSizeEstimateTest(conn, testDB, coll, testOptions) { + assert.eq(testDB.serverStatus().metrics.queryStats.queryStatsStoreSizeEstimateBytes, 0); + let halfWayPointSize; + // Only using three digit numbers (eg 100, 101) means the string length will be the same for all + // entries and therefore the key size will be the same for all entries, which makes predicting + // the total size of the store clean and easy. + for (var i = 100; i < 200; i++) { + coll.aggregate([{$match: {["foo" + i]: "bar"}}]).itcount(); + if (i == 150) { + halfWayPointSize = + testDB.serverStatus().metrics.queryStats.queryStatsStoreSizeEstimateBytes; + } + } + // Confirm that queryStats store has grown and size is non-zero. + assert.gt(halfWayPointSize, 0); + const fullSize = testDB.serverStatus().metrics.queryStats.queryStatsStoreSizeEstimateBytes; + assert.gt(fullSize, 0); + // Make sure the final queryStats store size is twice as much as the halfway point size (+/- 5%) + assert(fullSize >= halfWayPointSize * 1.95 && fullSize <= halfWayPointSize * 2.05, + tojson({fullSize, halfWayPointSize})); +} + +function queryStatsStoreWriteErrorsTest(conn, testDB, coll, testOptions) { + const debugBuild = testDB.adminCommand('buildInfo').debug; + if (debugBuild) { + jsTestLog("Skipping queryStats store write errors test because debug build will tassert."); + return; + } + + const errorsBefore = testDB.serverStatus().metrics.queryStats.numQueryStatsStoreWriteErrors; + assert.eq(errorsBefore, 0); + for (let i = 0; i < 5; i++) { + // Command should succeed and record the error. + let query = {}; + query["foo" + i] = "bar"; + coll.aggregate([{$match: query}]).itcount(); + } + + // Make sure that we recorded a write error for each run. + assert.eq(testDB.serverStatus().metrics.queryStats.numQueryStatsStoreWriteErrors, 5); +} + +/** + * Test that running the $queryStats aggregation stage correctly does or does not impact + * serverStatus counters (whichever is applicable). + */ +function queryStatsAggregationStageTest(conn, testDB, coll) { + // First, ensure that the query stats store is empty. + assert.eq(testDB.serverStatus().metrics.queryStats.queryStatsStoreSizeEstimateBytes, 0); + assert.eq(testDB.serverStatus().metrics.queryStats.numEvicted, 0); + + // Insert some query stats data and capture "before" serverStatus metrics. + for (let i = 100; i < 200; i++) { + coll.aggregate([{$match: {["foo" + i]: "bar"}}]).itcount(); + } + + let sizeBefore = testDB.serverStatus().metrics.queryStats.queryStatsStoreSizeEstimateBytes; + const evictedBefore = testDB.serverStatus().metrics.queryStats.numEvicted; + + // Run a $queryStats pipeline. We should insert a new entry for this query. + assert.commandWorked( + testDB.adminCommand({aggregate: 1, pipeline: [{$queryStats: {}}], cursor: {}})); + + assert.eq(testDB.serverStatus().metrics.queryStats.numEvicted, + evictedBefore, + "$queryStats should not have triggered evictions"); + assert.gt(testDB.serverStatus().metrics.queryStats.queryStatsStoreSizeEstimateBytes, + sizeBefore, + "$queryStats pipeline should have been added to the query stats store"); + sizeBefore = testDB.serverStatus().metrics.queryStats.queryStatsStoreSizeEstimateBytes; + + // Now run $queryStats again. The command should be fully read-only. + assert.commandWorked( + testDB.adminCommand({aggregate: 1, pipeline: [{$queryStats: {}}], cursor: {}})); + + assert.eq(testDB.serverStatus().metrics.queryStats.numEvicted, + evictedBefore, + "$queryStats should not have triggered evictions"); + assert.eq(testDB.serverStatus().metrics.queryStats.queryStatsStoreSizeEstimateBytes, + sizeBefore, + "$queryStats pipeline should not have impacted query stats store size"); +} + +/** + * In this configuration, we insert enough entries into the queryStats store to trigger LRU + * eviction. + */ +runTestWithMongodOptions({ + setParameter: {internalQueryStatsCacheSize: "1MB", internalQueryStatsRateLimit: -1}, +}, + evictionTest, + {resetCacheSize: false}); +/** + * In this configuration, eviction is triggered only when the queryStats store size is reset. + * + * Use an 8MB upper limit since our estimated size of the query stats entry is pretty rough and + * meant to give us some wiggle room so we don't have to keep adjusting this test as we tweak it. + */ +runTestWithMongodOptions({ + setParameter: {internalQueryStatsCacheSize: "8MB", internalQueryStatsRateLimit: -1}, +}, + evictionTest, + {resetCacheSize: true}); + +/** + * In this configuration, every query is sampled, so no requests should be rate-limited. + */ +runTestWithMongodOptions({ + setParameter: {internalQueryStatsRateLimit: -1}, +}, + countRateLimitedRequestsTest, + {samplingRate: 2147483647, numRequests: 20}); + +/** + * In this configuration, the sampling rate is set so that some but not all requests are + * rate-limited. + */ +runTestWithMongodOptions({ + setParameter: {internalQueryStatsRateLimit: 10}, +}, + countRateLimitedRequestsTest, + {samplingRate: 10, numRequests: 20}); + +/** + * Sample all queries and assert that the size of queryStats store is equal to num entries * entry + * size + */ +runTestWithMongodOptions({ + setParameter: {internalQueryStatsRateLimit: -1}, +}, + queryStatsStoreSizeEstimateTest); + +/** + * Use a very small queryStats store size and assert that errors in writing to the queryStats store + * are tracked. + */ +runTestWithMongodOptions({ + setParameter: {internalQueryStatsCacheSize: "0.00001MB", internalQueryStatsRateLimit: -1}, +}, + queryStatsStoreWriteErrorsTest); + +/** + * Tests that $queryStats has expected effects (or no effect) on counters. + */ +runTestWithMongodOptions({ + setParameter: {internalQueryStatsCacheSize: "2MB", internalQueryStatsRateLimit: -1}, +}, + queryStatsAggregationStageTest); +}()); diff --git a/jstests/noPassthrough/queryStats/query_stats_sub_pipelines.js b/jstests/noPassthrough/queryStats/query_stats_sub_pipelines.js new file mode 100644 index 00000000000..7e74d66f20c --- /dev/null +++ b/jstests/noPassthrough/queryStats/query_stats_sub_pipelines.js @@ -0,0 +1,184 @@ +/** + * Test that shapification for queries with sub-pipelines happens before view resolution and + * pipeline optimization. + * @tags: [requires_fcv_60] + */ +load("jstests/libs/query_stats_utils.js"); // For getLatestQueryStatsEntry + +const conn = MongoRunner.runMongod({ + setParameter: { + internalQueryStatsRateLimit: -1, + } +}); + +const dbName = jsTestName(); +const db = conn.getDB(dbName); + +const collName = "base"; +const coll = db[collName]; +coll.drop(); +assert.commandWorked(coll.insert({x: 10, y: 20})); + +const viewName = "projection_view"; +assert.commandWorked( + db.runCommand({create: viewName, viewOn: collName, pipeline: [{$project: {_id: 1, x: 1}}]})); +const view = db[viewName]; + +// Tests a basic query on a view as a sanity check. +(function testViewQuery() { + view.aggregate([{$sort: {x: 1}}]).toArray(); + + const stats = getLatestQueryStatsEntry(db); + const key = stats.key; + + // The view should not be resolved in the key. + assert.eq({"db": `${dbName}`, "coll": `${viewName}`}, key.queryShape.cmdNs, tojson(key)); + assert.eq( + [ + {"$sort": {"x": 1}}, + ], + key.queryShape.pipeline, + tojson(key)); +})(); + +// Tests a query where a view reference is in a $lookup pipeline. +(function testViewInLookupPipeline() { + coll.aggregate([{$lookup: {from: viewName, pipeline: [{$match: {x: 10}}], as: "lookup"}}]) + .toArray(); + + const stats = getLatestQueryStatsEntry(db); + const key = stats.key; + + // The view should not be resolved in the key. + assert.eq({"db": `${dbName}`, "coll": `${collName}`}, key.queryShape.cmdNs, tojson(key)); + assert.eq( + [ + {$lookup: + { + from: viewName, + as: "lookup", + let: {}, + pipeline: [{$match: {x: {$eq: "?number"}}}], + } + } + ], + key.queryShape.pipeline, tojson(key)); +})(); + +// Tests that the $lookup x $match optimization is applied after shapification. +(function testLookupMatchOptimization() { + coll.aggregate([ + {$lookup: {from: viewName, pipeline: [{$match: {x: {$gt: 5}}}], as: "lookup"}}, + {$unwind: {path: "$lookup"}}, + {$match: {"lookup.x": 10}} + ]) + .toArray(); + + const stats = getLatestQueryStatsEntry(db); + const key = stats.key; + + // The view should not be resolved in the key. + assert.eq({"db": `${dbName}`, "coll": `${collName}`}, key.queryShape.cmdNs, tojson(key)); + assert.eq( + [ + {$lookup: + { + from: viewName, + as: "lookup", + let: {}, + pipeline: [{$match: {x: {$gt: "?number"}}}], + } + }, + {$unwind: { + path: "$lookup" + }}, + {$match: { + "lookup.x": { + $eq: "?number" + } + }} + ], + key.queryShape.pipeline, tojson(key)); +})(); + +// Tests that the $lookup x $unwind optimization is applied after shapification. +(function testLookupUnwindOptimization() { + coll.aggregate([ + {$lookup: {from: viewName, pipeline: [{$match: {x: 10}}], as: "lookup"}}, + {$unwind: {path: "$lookup"}} + ]) + .toArray(); + + const stats = getLatestQueryStatsEntry(db); + const key = stats.key; + + // The view should not be resolved in the key. + assert.eq({"db": `${dbName}`, "coll": `${collName}`}, key.queryShape.cmdNs, tojson(key)); + assert.eq( + [ + {$lookup: + { + from: viewName, + as: "lookup", + let: {}, + pipeline: [{$match: {x: {$eq: "?number"}}}], + } + }, + {$unwind: { + path: "$lookup" + }} + ], + key.queryShape.pipeline, tojson(key)); +})(); + +// Tests a query where a view reference is in a $graphLookup pipeline. +(function testViewInGraphLookupPipeline() { + coll.aggregate([{$graphLookup: {from: viewName, startWith: "$x", connectFromField: "x", connectToField: "x", as: "lookup"}}]).toArray(); + + const stats = getLatestQueryStatsEntry(db); + const key = stats.key; + + // The view should not be resolved in the key. + assert.eq({"db": `${dbName}`, "coll": `${collName}`}, key.queryShape.cmdNs, tojson(key)); + assert.eq( + [ + {$graphLookup: + { + from: viewName, + as: "lookup", + connectToField: "x", + connectFromField: "x", + startWith: "$x" + } + } + ], + key.queryShape.pipeline, tojson(key)); +})(); + +// Tests a query where a view reference is in a $unionWith. +(function testViewInUnionWith() { + coll.aggregate([{$unionWith: viewName}]).toArray(); + + const stats = getLatestQueryStatsEntry(db); + const key = stats.key; + + // The view should not be resolved in the key. + assert.eq({"db": `${dbName}`, "coll": `${collName}`}, key.queryShape.cmdNs, tojson(key)); + assert.eq([{$unionWith: {coll: viewName, pipeline: []}}], key.queryShape.pipeline, tojson(key)); +})(); + +// Tests a query where a view reference is in a $unionWith with a sub-pipeline. +(function testViewInUnionWithPipeline() { + coll.aggregate([{$unionWith: {coll: viewName, pipeline: [{$sort: {x: 1}}]}}]).toArray(); + + const stats = getLatestQueryStatsEntry(db); + const key = stats.key; + + // The view should not be resolved in the key. + assert.eq({"db": `${dbName}`, "coll": `${collName}`}, key.queryShape.cmdNs, tojson(key)); + assert.eq([{$unionWith: {coll: viewName, pipeline: [{$sort: {x: 1}}]}}], + key.queryShape.pipeline, + tojson(key)); +})(); + +MongoRunner.stopMongod(conn); diff --git a/jstests/noPassthrough/queryStats/query_stats_upgrade.js b/jstests/noPassthrough/queryStats/query_stats_upgrade.js new file mode 100644 index 00000000000..de23b157e99 --- /dev/null +++ b/jstests/noPassthrough/queryStats/query_stats_upgrade.js @@ -0,0 +1,45 @@ +/** + * Test that query stats doesn't work on a lower FCV version but works after an FCV upgrade. + * @tags: [ + * requires_fcv_60, + * # Re-uses FCV state in the dbpath. + * requires_persistence + * ] + */ +load('jstests/libs/analyze_plan.js'); +load("jstests/libs/feature_flag_util.js"); + +(function() { +"use strict"; + +const dbpath = MongoRunner.dataPath + jsTestName(); +let conn = MongoRunner.runMongod({dbpath: dbpath}); +let testDB = conn.getDB(jsTestName()); + +function testLower(restart = false) { + let adminDB = conn.getDB("admin"); + assert.commandWorked( + adminDB.runCommand({setFeatureCompatibilityVersion: binVersionToFCV("last-lts")})); + if (restart) { + MongoRunner.stopMongod(conn); + conn = MongoRunner.runMongod({dbpath: dbpath, noCleanData: true}); + testDB = conn.getDB(jsTestName()); + adminDB = conn.getDB("admin"); + } + + assert.commandFailedWithCode( + testDB.adminCommand({aggregate: 1, pipeline: [{$queryStats: {}}], cursor: {}}), + ErrorCodes.QueryFeatureNotAllowed); + + // Upgrade FCV. + assert.commandWorked( + adminDB.runCommand({setFeatureCompatibilityVersion: binVersionToFCV("latest")})); + + // We should be able to run a query stats pipeline now that the FCV is correct. + assert.commandWorked( + testDB.adminCommand({aggregate: 1, pipeline: [{$queryStats: {}}], cursor: {}})); +} +testLower(true); +testLower(false); +MongoRunner.stopMongod(conn); +})();
\ No newline at end of file diff --git a/jstests/noPassthrough/queryStats/redact_queries_with_nonobject_fields.js b/jstests/noPassthrough/queryStats/redact_queries_with_nonobject_fields.js new file mode 100644 index 00000000000..7bc0737f699 --- /dev/null +++ b/jstests/noPassthrough/queryStats/redact_queries_with_nonobject_fields.js @@ -0,0 +1,76 @@ +/** + * Test that query stats key generation works for queries with non-object fields. + * @tags: [requires_fcv_60] + */ +load('jstests/libs/analyze_plan.js'); + +(function() { +"use strict"; + +// Turn on the collecting of query stats metrics. +let options = { + setParameter: {internalQueryStatsRateLimit: -1}, +}; + +const conn = MongoRunner.runMongod(options); +const testDB = conn.getDB('test'); +var collA = testDB[jsTestName()]; +var collB = testDB[jsTestName() + 'Two']; +collA.drop(); +collB.drop(); + +for (var i = 0; i < 200; i++) { + collA.insert({foo: 0, bar: Math.floor(Math.random() * 3)}); + collA.insert({foo: 1, bar: Math.floor(Math.random() * -2)}); + collB.insert({foo: Math.floor(Math.random() * 2), bar: Math.floor(Math.random() * 2)}); +} + +function confirmAggSuccess(collName, pipeline) { + const command = {aggregate: collName, cursor: {}}; + command.pipeline = pipeline; + assert.commandWorked(testDB.runCommand(command)); +} +// Test with non-object fields $limit and $skip. +confirmAggSuccess(collA.getName(), [{$sort: {bar: -1}}, {$limit: 2}, {$match: {foo: {$lte: 2}}}]); +confirmAggSuccess(collA.getName(), [{$sort: {bar: -1}}, {$skip: 50}, {$match: {foo: {$lte: 2}}}]); +confirmAggSuccess(collA.getName(), + [{$sort: {bar: -1}}, {$limit: 2}, {$skip: 50}, {$match: {foo: 0}}]); + +// Test non-object field, $unionWith. +confirmAggSuccess(collA.getName(), [{$unionWith: collB.getName()}]); + +// Test $limit in $setWindowFields for good measure. +confirmAggSuccess(collA.getName(), [ + {$_internalInhibitOptimization: {}}, + { + $setWindowFields: { + sortBy: {foo: 1}, + output: {sum: {$sum: "$bar", window: {documents: ["unbounded", "current"]}}} + } + }, + {$sort: {foo: 1}}, + {$limit: 5} +]); +// Test find commands containing non-object fields +assert.commandWorked(testDB.runCommand({find: collA.getName(), limit: 20})); +assert.commandWorked(testDB.runCommand({find: collA.getName(), skip: 199})); +collA.find().skip(100); + +// findOne has a nonobject field, $limit. +collB.findOne(); +collB.findOne({foo: 1}); + +// Test non-object field $unwind +confirmAggSuccess( + collA.getName(), [{ + "$facet": { + "productOfJoin": [ + {"$lookup": {"from": collB.getName(), "pipeline": [{"$match": {}}], "as": "join"}}, + {"$unwind": "$join"}, + {"$project": {"str": 1}} + ] + } + }]); + +MongoRunner.stopMongod(conn); +}()); diff --git a/jstests/noPassthrough/queryStats/redact_sensitive_fields_in_log.js b/jstests/noPassthrough/queryStats/redact_sensitive_fields_in_log.js new file mode 100644 index 00000000000..498603ba5da --- /dev/null +++ b/jstests/noPassthrough/queryStats/redact_sensitive_fields_in_log.js @@ -0,0 +1,60 @@ +/** + * Test that the queryStats HMAC key is not logged. + * @tags: [requires_fcv_60] + */ + +(function() { +'use strict'; + +load('jstests/libs/query_stats_utils.js'); // For getQueryStatsFindCmd + +const checkLogForHmacKey = function(conn) { + const coll = conn.getCollection("test.foo"); + assert.commandWorked(coll.insert({_id: 1})); + assert.neq(coll.findOne({_id: 1}), null); + + assert.neq(getQueryStatsFindCmd(conn, { + transformIdentifiers: true, + hmacKey: BinData(8, "YW4gYXJiaXRyYXJ5IEhNQUNrZXkgZm9yIHRlc3Rpbmc=") + }), + null); + + print(`Checking ${conn.fullOptions.logFile} for query stats message`); + const log = cat(conn.fullOptions.logFile); + + // Make sure there is no unredacted HMAC key + const predicate = /"hmacKey":"[^#"]+"/; + assert(!predicate.test(log), + "Found an unredacted HMAC key in log file!\n" + + "Log file contents: " + conn.fullOptions.logFile + + "\n************************************************************\n" + log + + "\n************************************************************"); +}; + +// Test MongoD +const testMongoD = function() { + const conn = + MongoRunner.runMongod({setParameter: {internalQueryStatsRateLimit: -1}, useLogFiles: true}); + assert.neq(null, conn, 'mongod was unable to start up'); + + checkLogForHmacKey(conn); + + MongoRunner.stopMongod(conn); +}; + +// Test MongoS +const testMongoS = function() { + const options = { + mongosOptions: {setParameter: {internalQueryStatsRateLimit: -1}, useLogFiles: true}, + }; + + const st = new ShardingTest({shards: 1, mongos: 1, other: options}); + + checkLogForHmacKey(st.s0); + + st.stop(); +}; + +testMongoD(); +testMongoS(); +})(); diff --git a/jstests/noPassthrough/queryStats/redact_sensitive_fields_in_profile.js b/jstests/noPassthrough/queryStats/redact_sensitive_fields_in_profile.js new file mode 100644 index 00000000000..1b37a0ad94a --- /dev/null +++ b/jstests/noPassthrough/queryStats/redact_sensitive_fields_in_profile.js @@ -0,0 +1,63 @@ +/** + * Test that the queryStats HMAC key is not leaked during profiling. + * @tags: [requires_fcv_60] + */ +(function() { +"use strict"; + +load("jstests/libs/profiler.js"); // For getLatestProfilerEntry. +load("jstests/libs/query_stats_utils.js"); // For getQueryStatsFindCmd + +const conn = MongoRunner.runMongod({setParameter: {internalQueryStatsRateLimit: -1}, profile: 2}); +const adminDB = conn.getDB("admin"); +const testDB = conn.getDB("test"); +const coll = testDB[jsTestName()]; + +// Prepopulate +coll.drop(); +assert.commandWorked(coll.insert([{foo: 0}, {foo: 1}])); + +const nsProfilerFilter = { + ns: coll.getFullName() +}; + +// Run a few find commands +for (const index of Array(10).keys()) { + if (index < 2) { + assert.neq(coll.findOne({foo: index}), null, `{foo: ${index}} should be extant`); + } else { + assert.isnull(coll.findOne({foo: index}), `{foo: ${index}} should be null`); + } +} + +// This returns `null` when there are no entries, as opposed to erroring when getLatestProfilerEntry +// encounters an empty profile. +const getLastAdminEntry = () => { + const cursor = + adminDB.system.profile.find({ns: "admin.$cmd.aggregate"}).sort({$natural: -1}).limit(1); + return [...cursor.toArray(), null][0]; +}; + +const lastTestEntry = getLatestProfilerEntry(testDB, nsProfilerFilter); +const lastAdminEntry = getLastAdminEntry(); +const hmacKey = BinData(8, "YW4gYXJiaXRyYXJ5IEhNQUNrZXkgZm9yIHRlc3Rpbmc="); + +getQueryStatsFindCmd(conn, {transformIdentifiers: true, hmacKey: hmacKey}); + +// Check that the queryStats command is not profiled. +assert.eq(getLatestProfilerEntry(testDB, nsProfilerFilter), lastTestEntry); + +// Check that the queryStats command is profiled in the admin log either. +const adminEntry = getLastAdminEntry(); +assert.neq(adminEntry, lastAdminEntry); + +// Check that the HMAC key is redacted. +const loggedHmacKey = adminEntry.command.pipeline[0].$queryStats.transformIdentifiers.hmacKey; +assert.neq(loggedHmacKey, hmacKey); + +// This is somewhat implementation dependent. If the redaction string ever changes, this will need +// to be updated as well. +assert.eq(loggedHmacKey, "###"); + +MongoRunner.stopMongod(conn); +}()); diff --git a/jstests/noPassthrough/queryStats/repl_set_query_stats_key.js b/jstests/noPassthrough/queryStats/repl_set_query_stats_key.js new file mode 100644 index 00000000000..309e0b9ff75 --- /dev/null +++ b/jstests/noPassthrough/queryStats/repl_set_query_stats_key.js @@ -0,0 +1,108 @@ +/** + * This test confirms that queryStats store key fields specific to replica sets (readConcern and + * readPreference) are included and correctly shapified. General command fields related to api + * versioning are included for good measure. + * @tags: [requires_fcv_60] + */ +load("jstests/libs/query_stats_utils.js"); // For getLatestQueryStatsEntry +(function() { +"use strict"; + +const replTest = new ReplSetTest({ + name: 'queryStatsTest', + nodes: [ + {rsConfig: {tags: {dc: "east"}}}, + {rsConfig: {tags: {dc: "west"}}}, + ] +}); + +// Turn on the collecting of query stats metrics. +replTest.startSet({setParameter: {internalQueryStatsRateLimit: -1}}); +replTest.initiate(); + +const primary = replTest.getPrimary(); + +const dbName = jsTestName(); +const collName = "foobar"; +const primaryDB = primary.getDB(dbName); +const primaryColl = primaryDB.getCollection(collName); + +primaryColl.drop(); + +const clusterTime = + assert.commandWorked(primaryDB.runCommand({insert: collName, documents: [{a: 1000}]})) + .operationTime; + +replTest.awaitReplication(); + +function confirmCommandFieldsPresent(queryStatsKey, commandObj) { + for (const field in queryStatsKey) { + if (field == "queryShape" || field == "client" || field == "command") { + continue; + } + assert(commandObj.hasOwnProperty(field), + `${field} is present in the query stats key but not present in command obj: ${ + tojson(queryStatsKey)}, ${tojson(commandObj)}`); + } + assert.eq(Object.keys(queryStatsKey).length, Object.keys(commandObj).length, queryStatsKey); +} + +let commandObj = { + find: collName, + filter: {v: {$eq: 2}}, + readConcern: {level: "local", afterClusterTime: new Timestamp(0, 1)}, + $readPreference: {mode: "nearest", tags: [{some: "tag"}, {dc: "north pole"}, {dc: "east"}]}, + apiDeprecationErrors: false, + apiVersion: "1", + apiStrict: false, +}; +const replSetConn = new Mongo(replTest.getURL()); +assert.commandWorked(replSetConn.getDB(dbName).runCommand(commandObj)); +let stats = getLatestQueryStatsEntry(replSetConn, {collName: collName}); +delete stats.key["collectionType"]; +confirmCommandFieldsPresent(stats.key, commandObj); +// Check that readConcern afterClusterTime is normalized. +assert.eq(stats.key.readConcern.afterClusterTime, "?timestamp", tojson(stats.key.readConcern)); + +// Check that $readPreference.tags are sorted. +assert.eq(stats.key.$readPreference.tags, + [{dc: "east"}, {dc: "north pole"}, {some: "tag"}], + tojson(stats.key.$readPreference)); + +// Check that readConcern just has an afterClusterTime field. +commandObj["readConcern"] = { + afterClusterTime: new Timestamp(1, 0) +}; +delete commandObj["$readPreference"]; +assert.commandWorked(replSetConn.getDB(dbName).runCommand(commandObj)); +stats = getLatestQueryStatsEntry(replSetConn, {collName}); +// We're not concerned with this field here. +delete stats.key["collectionType"]; +confirmCommandFieldsPresent(stats.key, commandObj); +assert.eq(stats.key["readConcern"], {"afterClusterTime": "?timestamp"}); + +// Check that readConcern has no afterClusterTime and fields related to api usage are not present. +commandObj["readConcern"] = { + level: "local" +}; +delete commandObj["apiDeprecationErrors"]; +delete commandObj["apiVersion"]; +delete commandObj["apiStrict"]; +assert.commandWorked(replSetConn.getDB(dbName).runCommand(commandObj)); +stats = getLatestQueryStatsEntry(replSetConn, {collName: collName}); +assert.eq(stats.key["readConcern"], {level: "local"}); +// We're not concerned with this field here. +delete stats.key["collectionType"]; +confirmCommandFieldsPresent(stats.key, commandObj); + +// Check that the 'atClusterTime' parameter is shapified correctly. +commandObj.readConcern = { + level: "snapshot", + atClusterTime: clusterTime +}; +assert.commandWorked(replSetConn.getDB(dbName).runCommand(commandObj)); +stats = getLatestQueryStatsEntry(replSetConn, {collName: collName}); +assert.eq(stats.key["readConcern"], {level: "snapshot", atClusterTime: "?timestamp"}); + +replTest.stopSet(); +})(); diff --git a/jstests/noPassthrough/queryStats/single_batch_on_mongod_agg_cmd.js b/jstests/noPassthrough/queryStats/single_batch_on_mongod_agg_cmd.js new file mode 100644 index 00000000000..d3c605c61d8 --- /dev/null +++ b/jstests/noPassthrough/queryStats/single_batch_on_mongod_agg_cmd.js @@ -0,0 +1,61 @@ +/** + * Test that the queryStats metrics are aggregated properly for queries run on a mongod where the + * results fit into a single batch (and thus don't require a cursor), for agg commands. + * @tags: [requires_fcv_60] + */ +load("jstests/libs/query_stats_utils.js"); // For verifyMetrics and getQueryStatsAggCmd. + +(function() { +"use strict"; + +// Turn on the collecting of queryStats metrics. +let options = { + setParameter: {internalQueryStatsRateLimit: -1}, +}; + +const conn = MongoRunner.runMongod(options); +const testDB = conn.getDB('test'); +var coll = testDB[jsTestName()]; +coll.drop(); + +// Bulk insert documents to reduces roundtrips and make timeout on a slow machine less likely. +const bulk = coll.initializeUnorderedBulkOp(); +const numDocs = 100; +for (let i = 0; i < numDocs / 2; ++i) { + bulk.insert({foo: 0, bar: Math.floor(Math.random() * 3)}); + bulk.insert({foo: 1, bar: Math.floor(Math.random() * -2)}); +} +assert.commandWorked(bulk.execute()); + +// Assert that two agg queries with identical structures are represented by the same key. + +// Note that toArray is necessary to guarantee the query finishes executing on the server (at +// which point an entry is finally written to the queryStats store). +coll.aggregate([{$match: {foo: 1}}]).toArray(); +coll.aggregate([{$match: {foo: 0}}]).toArray(); + +// This command will return all queryStats store entires. +const queryStatsResults = getQueryStatsAggCmd(testDB); +// Assert there is only one entry. +assert.eq(queryStatsResults.length, 1, queryStatsResults); +const queryStatsEntry = queryStatsResults[0]; +assert.eq(queryStatsEntry.key.queryShape.cmdNs.db, "test"); +assert.eq(queryStatsEntry.key.queryShape.cmdNs.coll, jsTestName()); +assert.eq(queryStatsEntry.key.client.application.name, "MongoDB Shell"); + +// Assert we update execution count for identically shaped queries. +assert.eq(queryStatsEntry.metrics.execCount, 2); + +// Assert queryStats values are accurate for the two above queries. +assert.eq(queryStatsEntry.metrics.docsReturned.sum, numDocs); +assert.eq(queryStatsEntry.metrics.docsReturned.min, numDocs / 2); +assert.eq(queryStatsEntry.metrics.docsReturned.max, numDocs / 2); + +// The total size of documents in the collection should ensure that the queries in this test can +// be executed without requiring multiple batches, but we verify that by looking at the +// timestamps. +assert.eq(queryStatsEntry.metrics.firstResponseExecMicros, queryStatsEntry.metrics.totalExecMicros); + +verifyMetrics(queryStatsResults); +MongoRunner.stopMongod(conn); +}()); diff --git a/jstests/noPassthrough/queryStats/single_batch_on_mongod_find_cmd.js b/jstests/noPassthrough/queryStats/single_batch_on_mongod_find_cmd.js new file mode 100644 index 00000000000..84c13b942e3 --- /dev/null +++ b/jstests/noPassthrough/queryStats/single_batch_on_mongod_find_cmd.js @@ -0,0 +1,59 @@ +/** + * Test that the queryStats metrics are aggregated properly for queries run on a mongod where the + * results fit into a single batch (and thus don't require a cursor), for find commands. + * @tags: [requires_fcv_60] + */ +load("jstests/libs/query_stats_utils.js"); // For verifyMetrics and getQueryStatsAggCmd. + +(function() { +"use strict"; + +// Turn on the collecting of queryStats metrics. +let options = { + setParameter: {internalQueryStatsRateLimit: -1}, +}; + +const conn = MongoRunner.runMongod(options); +const testDB = conn.getDB('test'); +var coll = testDB[jsTestName()]; +coll.drop(); + +// Bulk insert documents to reduces roundtrips and make timeout on a slow machine less likely. +const bulk = coll.initializeUnorderedBulkOp(); +const numDocs = 100; +for (let i = 0; i < numDocs / 2; ++i) { + bulk.insert({foo: 0, bar: Math.floor(Math.random() * 3)}); + bulk.insert({foo: 1, bar: Math.floor(Math.random() * -2)}); +} +assert.commandWorked(bulk.execute()); + +// Note that toArray is necessary to guarantee the query finishes executing on the server (at +// which point an entry is finally written to the queryStats store). +coll.find({foo: {$eq: 0}}).toArray(); +coll.find({foo: {$eq: 1}}).toArray(); + +// This command will return all queryStats store entires. +const queryStatsResults = getQueryStatsFindCmd(testDB); +// Assert there is only one entry. +assert.eq(queryStatsResults.length, 1, queryStatsResults); +const queryStatsEntry = queryStatsResults[0]; +assert.eq(queryStatsEntry.key.queryShape.cmdNs.db, "test"); +assert.eq(queryStatsEntry.key.queryShape.cmdNs.coll, jsTestName()); +assert.eq(queryStatsEntry.key.client.application.name, "MongoDB Shell"); + +// Assert we update execution count for identically shaped queries. +assert.eq(queryStatsEntry.metrics.execCount, 2); + +// Assert queryStats values are accurate for the two above queries. +assert.eq(queryStatsEntry.metrics.docsReturned.sum, numDocs); +assert.eq(queryStatsEntry.metrics.docsReturned.min, numDocs / 2); +assert.eq(queryStatsEntry.metrics.docsReturned.max, numDocs / 2); + +// The total size of documents in the collection should ensure that the queries in this test can +// be executed without requiring multiple batches, but we verify that by looking at the +// timestamps. +assert.eq(queryStatsEntry.metrics.firstResponseExecMicros, queryStatsEntry.metrics.totalExecMicros); +verifyMetrics(queryStatsResults); + +MongoRunner.stopMongod(conn); +}()); |