-
Type:
Improvement
-
Resolution: Unresolved
-
Priority:
Critical - P2
-
None
-
Affects Version/s: None
-
Component/s: None
-
Query Optimization
-
None
-
None
-
None
-
None
-
None
-
None
-
None
matt.boros@mongodb.com found that we unconditionally log MatchExpressions here. We should do this lazily and respect the EnableLogging logging level:
If CBR is invoked for large index bounds or match expressions (for example a large $in list), the cost of toString() calls could add up. I had it explore a bit more and for the $in case it found an example where planning time goes from 34ms to 22ms if we lazily call toString()
We should also audit the other places we log during CBR for similar issues
repro:
// $in size, 1000 // n=5, 19ms (with log()) -> 17ms (without log()) // n=20, 24ms -> 20ms // $in size, 5000 // n=5, 25ms -> 19ms // n=20, 45ms -> 23ms // $in size, 10000 // n=5, 33ms -> 22ms // n=20, 72ms -> 28ms const inSize = 1000; const numIndexes = 5; const coll = db[jsTestName()]; coll.drop(); assert.commandWorked(coll.insertMany(Array.from({length: 10000}, (_, i) => ({a: i, c: i})))); assert.commandWorked( coll.createIndexes(Array.from({length: numIndexes}, (_, k) => ({a: 1, ["f" + k]: 1}))), ); const query = {a: {$lt: 5000}, c: {$in: Array.from({length: inSize}, (_, i) => i + 4000)}}; for (let r = 0; r < 10; r++) { coll.getPlanCache().clear(); const start = Date.now(); coll.find(query).itcount(); jsTest.log.info("Query time (ms)", {ms: Date.now() - start}); }