|
| 1 | +/** |
| 2 | + * Tests that when "searchScore" and "vectorSearchScore" metadata fields are referenced in an |
| 3 | + * invalid way, a warning log line will occasionally be printed to the logs. |
| 4 | + * |
| 5 | + * @tags: [requires_fcv_82] |
| 6 | + */ |
| 7 | +import {iterateMatchingLogLines} from "jstests/libs/log.js"; |
| 8 | +import {ShardingTest} from "jstests/libs/shardingtest.js"; |
| 9 | + |
| 10 | +const warningLogMessage = |
| 11 | + "The query attempts to retrieve metadata at a place in the pipeline where that metadata type is not available"; |
| 12 | +const searchScoreWarningFieldMatcher = { |
| 13 | + msg: warningLogMessage, |
| 14 | + attr: {metadataType: "$search score"} |
| 15 | +}; |
| 16 | +const vectorSearchScoreWarningFieldMatcher = { |
| 17 | + msg: warningLogMessage, |
| 18 | + attr: {metadataType: "$vectorSearch score"} |
| 19 | +}; |
| 20 | + |
| 21 | +const dbName = "test"; |
| 22 | +const collName = "search_score_meta_validation"; |
| 23 | + |
| 24 | +const data = [ |
| 25 | + {a: 1, b: "foo", score: 10}, |
| 26 | + {a: 2, b: "bar", score: 20}, |
| 27 | + {a: 3, b: "baz", score: 30}, |
| 28 | + {a: 4, b: "qux", score: 40}, |
| 29 | + {a: 5, b: "quux", score: 50}, |
| 30 | +]; |
| 31 | + |
| 32 | +function checkLogs(db, warningLogFieldMatcher, numLogLines) { |
| 33 | + const globalLogs = db.adminCommand({getLog: 'global'}); |
| 34 | + const matchingLogLines = [...iterateMatchingLogLines(globalLogs.log, warningLogFieldMatcher)]; |
| 35 | + assert.eq(matchingLogLines.length, numLogLines, matchingLogLines); |
| 36 | +} |
| 37 | + |
| 38 | +/** |
| 39 | + * Tests that the metadata validation warning log line is printed when the metadata is used in an |
| 40 | + * invalid way. |
| 41 | + * |
| 42 | + * Commands are sent to db but the logs are checked in the provided logDb. For a sharded cluster, |
| 43 | + * commands will be sent to the mongos and the logs will be checked on the primary shard. |
| 44 | + */ |
| 45 | +function warningLogTest(db, warningLogFieldMatcher, metaType, logDb) { |
| 46 | + assert.commandWorked(logDb.adminCommand({clearLog: "global"})); |
| 47 | + |
| 48 | + // Assert that the warning message is not logged before the command is even run. |
| 49 | + checkLogs(logDb, warningLogFieldMatcher, 0); |
| 50 | + |
| 51 | + assert.commandWorked(db.runCommand({ |
| 52 | + aggregate: collName, |
| 53 | + pipeline: [ |
| 54 | + {$setWindowFields: {sortBy: {score: {$meta: metaType}}, output: {rank: {$rank: {}}}}}, |
| 55 | + ], |
| 56 | + cursor: {} |
| 57 | + })); |
| 58 | + |
| 59 | + // Now that we have run the command, make sure the warning message is logged once. |
| 60 | + checkLogs(logDb, warningLogFieldMatcher, 1); |
| 61 | + |
| 62 | + // It will be printed once every 64 queries (every 128 ticks, with two ticks per query since |
| 63 | + // dependency tracking is called twice per query). Now run 64 more invalid queries (4 queries * |
| 64 | + // 32 iterations) to get another log line. |
| 65 | + for (let i = 0; i < 16; i++) { |
| 66 | + assert.commandWorked(db.runCommand( |
| 67 | + {aggregate: collName, pipeline: [{$sort: {score: {$meta: metaType}}}], cursor: {}})); |
| 68 | + assert.commandWorked(db.runCommand( |
| 69 | + {aggregate: collName, pipeline: [{$set: {score: {$meta: metaType}}}], cursor: {}})); |
| 70 | + |
| 71 | + assert.commandWorked(db.runCommand({ |
| 72 | + find: collName, |
| 73 | + projection: {score: {$meta: metaType}}, |
| 74 | + })); |
| 75 | + assert.commandWorked(db.runCommand({ |
| 76 | + find: collName, |
| 77 | + sort: {score: {$meta: metaType}}, |
| 78 | + })); |
| 79 | + } |
| 80 | + |
| 81 | + // Check that we only had one more log. |
| 82 | + checkLogs(logDb, warningLogFieldMatcher, 2); |
| 83 | +} |
| 84 | + |
| 85 | +jsTest.log.info('Test standalone'); |
| 86 | +{ |
| 87 | + const mongod = MongoRunner.runMongod({}); |
| 88 | + const db = mongod.getDB(dbName); |
| 89 | + const coll = db.getCollection(collName); |
| 90 | + coll.drop(); |
| 91 | + assert.commandWorked(coll.insertMany(data)); |
| 92 | + |
| 93 | + warningLogTest(db, searchScoreWarningFieldMatcher, "searchScore", db); |
| 94 | + checkLogs(db, vectorSearchScoreWarningFieldMatcher, 0); |
| 95 | + warningLogTest(db, vectorSearchScoreWarningFieldMatcher, "vectorSearchScore", db); |
| 96 | + checkLogs(db, searchScoreWarningFieldMatcher, 0); |
| 97 | + |
| 98 | + MongoRunner.stopMongod(mongod); |
| 99 | +} |
| 100 | + |
| 101 | +jsTest.log.info('Test sharded'); |
| 102 | +{ |
| 103 | + const shardingTest = new ShardingTest({shards: 2, mongos: 1}); |
| 104 | + const session = shardingTest.s.getDB(dbName).getMongo().startSession(); |
| 105 | + const shardedDB = session.getDatabase(dbName); |
| 106 | + const primaryShardConn = shardingTest.shard0.getDB(dbName); |
| 107 | + |
| 108 | + assert.commandWorked(shardingTest.s0.adminCommand( |
| 109 | + {enableSharding: shardedDB.getName(), primaryShard: shardingTest.shard0.shardName})); |
| 110 | + |
| 111 | + const shardedColl = shardedDB.getCollection(collName); |
| 112 | + |
| 113 | + assert.commandWorked(shardedDB.createCollection(shardedColl.getName())); |
| 114 | + |
| 115 | + assert.commandWorked( |
| 116 | + shardingTest.s0.adminCommand({shardCollection: shardedColl.getFullName(), key: {_id: 1}})); |
| 117 | + |
| 118 | + assert.commandWorked(shardedColl.insert(data)); |
| 119 | + |
| 120 | + warningLogTest(shardedDB, searchScoreWarningFieldMatcher, "searchScore", primaryShardConn); |
| 121 | + checkLogs(primaryShardConn, vectorSearchScoreWarningFieldMatcher, 0); |
| 122 | + warningLogTest( |
| 123 | + shardedDB, vectorSearchScoreWarningFieldMatcher, "vectorSearchScore", primaryShardConn); |
| 124 | + checkLogs(primaryShardConn, searchScoreWarningFieldMatcher, 0); |
| 125 | + |
| 126 | + shardingTest.stop(); |
| 127 | +} |
0 commit comments