diff options
author | Anton Korshunov <anton.korshunov@mongodb.com> | 2020-11-10 14:40:26 +0000 |
---|---|---|
committer | Evergreen Agent <no-reply@evergreen.mongodb.com> | 2020-11-25 17:53:41 +0000 |
commit | fb6c08b7860412982a249d749d6405ec885179ac (patch) | |
tree | 4ce895d66b2234a023ec86dfd4b43dc4f79f032c /src | |
parent | 2d295d7b205dcac66d434929553610dd48ac0815 (diff) | |
download | mongo-fb6c08b7860412982a249d749d6405ec885179ac.tar.gz |
SERVER-51409 Support executionStats mode in SBE explain
Diffstat (limited to 'src')
51 files changed, 599 insertions, 219 deletions
diff --git a/src/mongo/db/exec/plan_stats.h b/src/mongo/db/exec/plan_stats.h index 87c57402626..66b051a18e1 100644 --- a/src/mongo/db/exec/plan_stats.h +++ b/src/mongo/db/exec/plan_stats.h @@ -156,6 +156,10 @@ struct BasePlanStageStats { // Per-stage place to stash additional information std::unique_ptr<SpecificStats> specific; + // Per-stage additional debug info which is opaque to the caller. Callers should not attempt to + // process/read this BSONObj other than for dumping the results to logs or back to the user. + BSONObj debugInfo; + // The stats of the node's children. std::vector<std::unique_ptr<BasePlanStageStats<C, T>>> children; @@ -612,8 +616,10 @@ struct ProjectionStats : public SpecificStats { struct SortStats : public SpecificStats { SortStats() = default; + SortStats(uint64_t limit, uint64_t maxMemoryUsageBytes) + : limit(limit), maxMemoryUsageBytes(maxMemoryUsageBytes) {} - SpecificStats* clone() const final { + SpecificStats* clone() const { SortStats* specific = new SortStats(*this); return specific; } diff --git a/src/mongo/db/exec/sbe/stages/branch.cpp b/src/mongo/db/exec/sbe/stages/branch.cpp index 95dcf1878d9..15db672a013 100644 --- a/src/mongo/db/exec/sbe/stages/branch.cpp +++ b/src/mongo/db/exec/sbe/stages/branch.cpp @@ -119,10 +119,12 @@ void BranchStage::open(bool reOpen) { _activeBranch = 0; _children[0]->open(reOpen && _thenOpened); _thenOpened = true; + ++_specificStats.thenBranchOpens; } else { _activeBranch = 1; _children[1]->open(reOpen && _elseOpened); _elseOpened = true; + ++_specificStats.elseBranchOpens; } } else { _activeBranch = boost::none; @@ -161,18 +163,35 @@ void BranchStage::close() { if (_thenOpened) { _children[0]->close(); _thenOpened = false; + ++_specificStats.thenBranchCloses; } if (_elseOpened) { _children[1]->close(); _elseOpened = false; + ++_specificStats.elseBranchCloses; } } -std::unique_ptr<PlanStageStats> BranchStage::getStats() const { +std::unique_ptr<PlanStageStats> BranchStage::getStats(bool includeDebugInfo) const { auto ret = std::make_unique<PlanStageStats>(_commonStats); - ret->specific = std::make_unique<FilterStats>(_specificStats); - ret->children.emplace_back(_children[0]->getStats()); - ret->children.emplace_back(_children[1]->getStats()); + ret->specific = std::make_unique<BranchStats>(_specificStats); + + if (includeDebugInfo) { + BSONObjBuilder bob; + bob.appendNumber("numTested", _specificStats.numTested); + bob.appendNumber("thenBranchOpens", _specificStats.thenBranchOpens); + bob.appendNumber("thenBranchCloses", _specificStats.thenBranchCloses); + bob.appendNumber("elseBranchOpens", _specificStats.elseBranchOpens); + bob.appendNumber("elseBranchCloses", _specificStats.elseBranchCloses); + bob.append("filter", DebugPrinter{}.print(_filter->debugPrint())); + bob.append("thenSlots", _inputThenVals); + bob.append("elseSlots", _inputElseVals); + bob.append("outputSlots", _outputVals); + ret->debugInfo = bob.obj(); + } + + ret->children.emplace_back(_children[0]->getStats(includeDebugInfo)); + ret->children.emplace_back(_children[1]->getStats(includeDebugInfo)); return ret; } diff --git a/src/mongo/db/exec/sbe/stages/branch.h b/src/mongo/db/exec/sbe/stages/branch.h index 5610221c2e0..48a8a334f6b 100644 --- a/src/mongo/db/exec/sbe/stages/branch.h +++ b/src/mongo/db/exec/sbe/stages/branch.h @@ -56,7 +56,7 @@ public: PlanState getNext() final; void close() final; - std::unique_ptr<PlanStageStats> getStats() const final; + std::unique_ptr<PlanStageStats> getStats(bool includeDebugInfo) const final; const SpecificStats* getSpecificStats() const final; std::vector<DebugPrinter::Block> debugPrint() const final; @@ -76,6 +76,6 @@ private: bool _elseOpened{false}; vm::ByteCode _bytecode; - FilterStats _specificStats; + BranchStats _specificStats; }; } // namespace mongo::sbe diff --git a/src/mongo/db/exec/sbe/stages/bson_scan.cpp b/src/mongo/db/exec/sbe/stages/bson_scan.cpp index dd59f808e4c..6de5c52b659 100644 --- a/src/mongo/db/exec/sbe/stages/bson_scan.cpp +++ b/src/mongo/db/exec/sbe/stages/bson_scan.cpp @@ -132,9 +132,20 @@ void BSONScanStage::close() { _commonStats.closes++; } -std::unique_ptr<PlanStageStats> BSONScanStage::getStats() const { +std::unique_ptr<PlanStageStats> BSONScanStage::getStats(bool includeDebugInfo) const { auto ret = std::make_unique<PlanStageStats>(_commonStats); ret->specific = std::make_unique<ScanStats>(_specificStats); + + if (includeDebugInfo) { + BSONObjBuilder bob; + if (_recordSlot) { + bob.appendIntOrLL("recordSlot", *_recordSlot); + } + bob.append("field", _fields); + bob.append("outputSlots", _vars); + ret->debugInfo = bob.obj(); + } + return ret; } diff --git a/src/mongo/db/exec/sbe/stages/bson_scan.h b/src/mongo/db/exec/sbe/stages/bson_scan.h index eaae59e3c39..d0d17856a50 100644 --- a/src/mongo/db/exec/sbe/stages/bson_scan.h +++ b/src/mongo/db/exec/sbe/stages/bson_scan.h @@ -51,7 +51,7 @@ public: PlanState getNext() final; void close() final; - std::unique_ptr<PlanStageStats> getStats() const final; + std::unique_ptr<PlanStageStats> getStats(bool includeDebugInfo) const final; const SpecificStats* getSpecificStats() const final; std::vector<DebugPrinter::Block> debugPrint() const final; diff --git a/src/mongo/db/exec/sbe/stages/check_bounds.cpp b/src/mongo/db/exec/sbe/stages/check_bounds.cpp index a0e991e37fb..539b8e3ffeb 100644 --- a/src/mongo/db/exec/sbe/stages/check_bounds.cpp +++ b/src/mongo/db/exec/sbe/stages/check_bounds.cpp @@ -126,9 +126,20 @@ void CheckBoundsStage::close() { _children[0]->close(); } -std::unique_ptr<PlanStageStats> CheckBoundsStage::getStats() const { +std::unique_ptr<PlanStageStats> CheckBoundsStage::getStats(bool includeDebugInfo) const { auto ret = std::make_unique<PlanStageStats>(_commonStats); - ret->children.emplace_back(_children[0]->getStats()); + ret->specific = std::make_unique<CheckBoundsStats>(_specificStats); + + if (includeDebugInfo) { + BSONObjBuilder bob; + bob.appendNumber("seeks", _specificStats.seeks); + bob.appendIntOrLL("inKeySlot", _inKeySlot); + bob.appendIntOrLL("inRecordIdSlot", _inRecordIdSlot); + bob.appendIntOrLL("outSlot", _outSlot); + ret->debugInfo = bob.obj(); + } + + ret->children.emplace_back(_children[0]->getStats(includeDebugInfo)); return ret; } diff --git a/src/mongo/db/exec/sbe/stages/check_bounds.h b/src/mongo/db/exec/sbe/stages/check_bounds.h index 79e066b004c..21971a612eb 100644 --- a/src/mongo/db/exec/sbe/stages/check_bounds.h +++ b/src/mongo/db/exec/sbe/stages/check_bounds.h @@ -80,7 +80,7 @@ public: PlanState getNext() final; void close() final; - std::unique_ptr<PlanStageStats> getStats() const final; + std::unique_ptr<PlanStageStats> getStats(bool includeDebugInfo) const final; const SpecificStats* getSpecificStats() const final; std::vector<DebugPrinter::Block> debugPrint() const final; @@ -97,5 +97,6 @@ private: value::OwnedValueAccessor _outAccessor; bool _isEOF{false}; + CheckBoundsStats _specificStats; }; } // namespace mongo::sbe diff --git a/src/mongo/db/exec/sbe/stages/co_scan.cpp b/src/mongo/db/exec/sbe/stages/co_scan.cpp index ca9510f6859..cfa539148ac 100644 --- a/src/mongo/db/exec/sbe/stages/co_scan.cpp +++ b/src/mongo/db/exec/sbe/stages/co_scan.cpp @@ -56,7 +56,7 @@ PlanState CoScanStage::getNext() { return PlanState::ADVANCED; } -std::unique_ptr<PlanStageStats> CoScanStage::getStats() const { +std::unique_ptr<PlanStageStats> CoScanStage::getStats(bool includeDebugInfo) const { auto ret = std::make_unique<PlanStageStats>(_commonStats); return ret; } diff --git a/src/mongo/db/exec/sbe/stages/co_scan.h b/src/mongo/db/exec/sbe/stages/co_scan.h index 38ba1adfcc3..f93dd4da699 100644 --- a/src/mongo/db/exec/sbe/stages/co_scan.h +++ b/src/mongo/db/exec/sbe/stages/co_scan.h @@ -52,7 +52,7 @@ public: PlanState getNext() final; void close() final; - std::unique_ptr<PlanStageStats> getStats() const final; + std::unique_ptr<PlanStageStats> getStats(bool includeDebugInfo) const final; const SpecificStats* getSpecificStats() const final; }; } // namespace mongo::sbe diff --git a/src/mongo/db/exec/sbe/stages/exchange.cpp b/src/mongo/db/exec/sbe/stages/exchange.cpp index b72c6c4748c..af748cb4089 100644 --- a/src/mongo/db/exec/sbe/stages/exchange.cpp +++ b/src/mongo/db/exec/sbe/stages/exchange.cpp @@ -361,9 +361,9 @@ void ExchangeConsumer::close() { } } -std::unique_ptr<PlanStageStats> ExchangeConsumer::getStats() const { +std::unique_ptr<PlanStageStats> ExchangeConsumer::getStats(bool includeDebugInfo) const { auto ret = std::make_unique<PlanStageStats>(_commonStats); - ret->children.emplace_back(_children[0]->getStats()); + ret->children.emplace_back(_children[0]->getStats(includeDebugInfo)); return ret; } @@ -560,9 +560,9 @@ void ExchangeProducer::close() { _children[0]->close(); } -std::unique_ptr<PlanStageStats> ExchangeProducer::getStats() const { +std::unique_ptr<PlanStageStats> ExchangeProducer::getStats(bool includeDebugInfo) const { auto ret = std::make_unique<PlanStageStats>(_commonStats); - ret->children.emplace_back(_children[0]->getStats()); + ret->children.emplace_back(_children[0]->getStats(includeDebugInfo)); return ret; } diff --git a/src/mongo/db/exec/sbe/stages/exchange.h b/src/mongo/db/exec/sbe/stages/exchange.h index cd3f057d46b..ca1a323e8ad 100644 --- a/src/mongo/db/exec/sbe/stages/exchange.h +++ b/src/mongo/db/exec/sbe/stages/exchange.h @@ -266,7 +266,7 @@ public: PlanState getNext() final; void close() final; - std::unique_ptr<PlanStageStats> getStats() const final; + std::unique_ptr<PlanStageStats> getStats(bool includeDebugInfo) const final; const SpecificStats* getSpecificStats() const final; std::vector<DebugPrinter::Block> debugPrint() const final; @@ -317,7 +317,7 @@ public: PlanState getNext() final; void close() final; - std::unique_ptr<PlanStageStats> getStats() const final; + std::unique_ptr<PlanStageStats> getStats(bool includeDebugInfo) const final; const SpecificStats* getSpecificStats() const final; private: diff --git a/src/mongo/db/exec/sbe/stages/filter.h b/src/mongo/db/exec/sbe/stages/filter.h index 8e103f85c0d..4d14cd1f20d 100644 --- a/src/mongo/db/exec/sbe/stages/filter.h +++ b/src/mongo/db/exec/sbe/stages/filter.h @@ -54,7 +54,7 @@ public: } std::unique_ptr<PlanStage> clone() const final { - return std::make_unique<FilterStage>( + return std::make_unique<FilterStage<IsConst, IsEof>>( _children[0]->clone(), _filter->clone(), _commonStats.nodeId); } @@ -126,10 +126,18 @@ public: } } - std::unique_ptr<PlanStageStats> getStats() const { + std::unique_ptr<PlanStageStats> getStats(bool includeDebugInfo) const { auto ret = std::make_unique<PlanStageStats>(_commonStats); ret->specific = std::make_unique<FilterStats>(_specificStats); - ret->children.emplace_back(_children[0]->getStats()); + + if (includeDebugInfo) { + BSONObjBuilder bob; + bob.appendNumber("numTested", _specificStats.numTested); + bob.append("filter", DebugPrinter{}.print(_filter->debugPrint())); + ret->debugInfo = bob.obj(); + } + + ret->children.emplace_back(_children[0]->getStats(includeDebugInfo)); return ret; } diff --git a/src/mongo/db/exec/sbe/stages/hash_agg.cpp b/src/mongo/db/exec/sbe/stages/hash_agg.cpp index c9f6da29462..18e7ee6559a 100644 --- a/src/mongo/db/exec/sbe/stages/hash_agg.cpp +++ b/src/mongo/db/exec/sbe/stages/hash_agg.cpp @@ -153,9 +153,23 @@ PlanState HashAggStage::getNext() { return trackPlanState(PlanState::ADVANCED); } -std::unique_ptr<PlanStageStats> HashAggStage::getStats() const { +std::unique_ptr<PlanStageStats> HashAggStage::getStats(bool includeDebugInfo) const { auto ret = std::make_unique<PlanStageStats>(_commonStats); - ret->children.emplace_back(_children[0]->getStats()); + + if (includeDebugInfo) { + DebugPrinter printer; + BSONObjBuilder bob; + bob.append("groupBySlots", _gbs); + if (!_aggs.empty()) { + BSONObjBuilder childrenBob(bob.subobjStart("expressions")); + for (auto&& [slot, expr] : _aggs) { + childrenBob.append(str::stream() << slot, printer.print(expr->debugPrint())); + } + } + ret->debugInfo = bob.obj(); + } + + ret->children.emplace_back(_children[0]->getStats(includeDebugInfo)); return ret; } diff --git a/src/mongo/db/exec/sbe/stages/hash_agg.h b/src/mongo/db/exec/sbe/stages/hash_agg.h index 6fe50f622d0..1edc58dafaa 100644 --- a/src/mongo/db/exec/sbe/stages/hash_agg.h +++ b/src/mongo/db/exec/sbe/stages/hash_agg.h @@ -53,7 +53,7 @@ public: PlanState getNext() final; void close() final; - std::unique_ptr<PlanStageStats> getStats() const final; + std::unique_ptr<PlanStageStats> getStats(bool includeDebugInfo) const final; const SpecificStats* getSpecificStats() const final; std::vector<DebugPrinter::Block> debugPrint() const final; diff --git a/src/mongo/db/exec/sbe/stages/hash_join.cpp b/src/mongo/db/exec/sbe/stages/hash_join.cpp index f00e01e9aa4..8e5e167f743 100644 --- a/src/mongo/db/exec/sbe/stages/hash_join.cpp +++ b/src/mongo/db/exec/sbe/stages/hash_join.cpp @@ -187,10 +187,10 @@ void HashJoinStage::close() { _children[1]->close(); } -std::unique_ptr<PlanStageStats> HashJoinStage::getStats() const { +std::unique_ptr<PlanStageStats> HashJoinStage::getStats(bool includeDebugInfo) const { auto ret = std::make_unique<PlanStageStats>(_commonStats); - ret->children.emplace_back(_children[0]->getStats()); - ret->children.emplace_back(_children[1]->getStats()); + ret->children.emplace_back(_children[0]->getStats(includeDebugInfo)); + ret->children.emplace_back(_children[1]->getStats(includeDebugInfo)); return ret; } diff --git a/src/mongo/db/exec/sbe/stages/hash_join.h b/src/mongo/db/exec/sbe/stages/hash_join.h index 79a5f7a7230..e70378962ab 100644 --- a/src/mongo/db/exec/sbe/stages/hash_join.h +++ b/src/mongo/db/exec/sbe/stages/hash_join.h @@ -53,7 +53,7 @@ public: PlanState getNext() final; void close() final; - std::unique_ptr<PlanStageStats> getStats() const final; + std::unique_ptr<PlanStageStats> getStats(bool includeDebugInfo) const final; const SpecificStats* getSpecificStats() const final; std::vector<DebugPrinter::Block> debugPrint() const final; diff --git a/src/mongo/db/exec/sbe/stages/ix_scan.cpp b/src/mongo/db/exec/sbe/stages/ix_scan.cpp index a45e25542d2..1453ed0b8c3 100644 --- a/src/mongo/db/exec/sbe/stages/ix_scan.cpp +++ b/src/mongo/db/exec/sbe/stages/ix_scan.cpp @@ -46,7 +46,7 @@ IndexScanStage::IndexScanStage(const NamespaceStringOrUUID& name, IndexKeysInclusionSet indexKeysToInclude, value::SlotVector vars, boost::optional<value::SlotId> seekKeySlotLow, - boost::optional<value::SlotId> seekKeySlotHi, + boost::optional<value::SlotId> seekKeySlotHigh, PlanYieldPolicy* yieldPolicy, TrialRunProgressTracker* tracker, PlanNodeId nodeId) @@ -59,11 +59,11 @@ IndexScanStage::IndexScanStage(const NamespaceStringOrUUID& name, _indexKeysToInclude(indexKeysToInclude), _vars(std::move(vars)), _seekKeySlotLow(seekKeySlotLow), - _seekKeySlotHi(seekKeySlotHi), + _seekKeySlotHigh(seekKeySlotHigh), _tracker(tracker) { // The valid state is when both boundaries, or none is set, or only low key is set. - invariant((_seekKeySlotLow && _seekKeySlotHi) || (!_seekKeySlotLow && !_seekKeySlotHi) || - (_seekKeySlotLow && !_seekKeySlotHi)); + invariant((_seekKeySlotLow && _seekKeySlotHigh) || (!_seekKeySlotLow && !_seekKeySlotHigh) || + (_seekKeySlotLow && !_seekKeySlotHigh)); invariant(_indexKeysToInclude.count() == _vars.size()); } @@ -77,7 +77,7 @@ std::unique_ptr<PlanStage> IndexScanStage::clone() const { _indexKeysToInclude, _vars, _seekKeySlotLow, - _seekKeySlotHi, + _seekKeySlotHigh, _yieldPolicy, _tracker, _commonStats.nodeId); @@ -101,8 +101,8 @@ void IndexScanStage::prepare(CompileCtx& ctx) { if (_seekKeySlotLow) { _seekKeyLowAccessor = ctx.getAccessor(*_seekKeySlotLow); } - if (_seekKeySlotHi) { - _seekKeyHiAccessor = ctx.getAccessor(*_seekKeySlotHi); + if (_seekKeySlotHigh) { + _seekKeyHiAccessor = ctx.getAccessor(*_seekKeySlotHigh); } } @@ -303,9 +303,31 @@ void IndexScanStage::close() { _open = false; } -std::unique_ptr<PlanStageStats> IndexScanStage::getStats() const { +std::unique_ptr<PlanStageStats> IndexScanStage::getStats(bool includeDebugInfo) const { auto ret = std::make_unique<PlanStageStats>(_commonStats); ret->specific = std::make_unique<IndexScanStats>(_specificStats); + + if (includeDebugInfo) { + BSONObjBuilder bob; + bob.appendNumber("numReads", _specificStats.numReads); + bob.appendNumber("seeks", _specificStats.seeks); + if (_recordSlot) { + bob.appendIntOrLL("recordSlot", *_recordSlot); + } + if (_recordIdSlot) { + bob.appendIntOrLL("recordIdSlot", *_recordIdSlot); + } + if (_seekKeySlotLow) { + bob.appendIntOrLL("seekKeySlotLow", *_seekKeySlotLow); + } + if (_seekKeySlotHigh) { + bob.appendIntOrLL("seekKeySlotHigh", *_seekKeySlotHigh); + } + bob.append("outputSlots", _vars); + bob.append("indexKeysToInclude", _indexKeysToInclude.to_string()); + ret->debugInfo = bob.obj(); + } + return ret; } @@ -319,8 +341,8 @@ std::vector<DebugPrinter::Block> IndexScanStage::debugPrint() const { if (_seekKeySlotLow) { DebugPrinter::addIdentifier(ret, _seekKeySlotLow.get()); - if (_seekKeySlotHi) { - DebugPrinter::addIdentifier(ret, _seekKeySlotHi.get()); + if (_seekKeySlotHigh) { + DebugPrinter::addIdentifier(ret, _seekKeySlotHigh.get()); } } if (_recordSlot) { diff --git a/src/mongo/db/exec/sbe/stages/ix_scan.h b/src/mongo/db/exec/sbe/stages/ix_scan.h index 494b799388b..b08fd2a9440 100644 --- a/src/mongo/db/exec/sbe/stages/ix_scan.h +++ b/src/mongo/db/exec/sbe/stages/ix_scan.h @@ -40,11 +40,11 @@ namespace mongo::sbe { /** * A stage that iterates the entries of a collection index, starting from a bound specified by the - * value in 'seekKeySlotLow' and ending (via IS_EOF) with the 'seekKeySlotHi' bound. (An unspecified - * 'seekKeySlowHi' scans to the end of the index. Leaving both bounds unspecified scans the index - * from beginning to end.) + * value in 'seekKeySlotLow' and ending (via IS_EOF) with the 'seekKeySlotHigh' bound. (An + * unspecified 'seekKeySlotHigh' scans to the end of the index. Leaving both bounds unspecified + * scans the index from beginning to end.) * - * The input 'seekKeySlotLow' and 'seekKeySlotHi' slots get read as part of the open (or re-open) + * The input 'seekKeySlotLow' and 'seekKeySlotHigh' slots get read as part of the open (or re-open) * call. A common use case for an IndexScanStage is to place it as the inner child of LoopJoinStage. * The outer side of the LoopJoinStage determines the bounds, and the inner IndexScanStage iterates * through all the entries within those bounds. @@ -68,7 +68,7 @@ public: IndexKeysInclusionSet indexKeysToInclude, value::SlotVector vars, boost::optional<value::SlotId> seekKeySlotLow, - boost::optional<value::SlotId> seekKeySlotHi, + boost::optional<value::SlotId> seekKeySlotHigh, PlanYieldPolicy* yieldPolicy, TrialRunProgressTracker* tracker, PlanNodeId nodeId); @@ -81,7 +81,7 @@ public: PlanState getNext() final; void close() final; - std::unique_ptr<PlanStageStats> getStats() const final; + std::unique_ptr<PlanStageStats> getStats(bool includeDebugInfo) const final; const SpecificStats* getSpecificStats() const final; std::vector<DebugPrinter::Block> debugPrint() const final; @@ -100,7 +100,7 @@ private: const IndexKeysInclusionSet _indexKeysToInclude; const value::SlotVector _vars; const boost::optional<value::SlotId> _seekKeySlotLow; - const boost::optional<value::SlotId> _seekKeySlotHi; + const boost::optional<value::SlotId> _seekKeySlotHigh; std::unique_ptr<value::ViewOfValueAccessor> _recordAccessor; std::unique_ptr<value::ViewOfValueAccessor> _recordIdAccessor; diff --git a/src/mongo/db/exec/sbe/stages/limit_skip.cpp b/src/mongo/db/exec/sbe/stages/limit_skip.cpp index 20ceac87a3b..528c9cd5cc3 100644 --- a/src/mongo/db/exec/sbe/stages/limit_skip.cpp +++ b/src/mongo/db/exec/sbe/stages/limit_skip.cpp @@ -84,10 +84,22 @@ void LimitSkipStage::close() { _children[0]->close(); } -std::unique_ptr<PlanStageStats> LimitSkipStage::getStats() const { +std::unique_ptr<PlanStageStats> LimitSkipStage::getStats(bool includeDebugInfo) const { auto ret = std::make_unique<PlanStageStats>(_commonStats); ret->specific = std::make_unique<LimitSkipStats>(_specificStats); - ret->children.emplace_back(_children[0]->getStats()); + + if (includeDebugInfo) { + BSONObjBuilder bob; + if (_limit) { + bob.appendNumber("limit", *_limit); + } + if (_skip) { + bob.appendNumber("skip", *_skip); + } + ret->debugInfo = bob.obj(); + } + + ret->children.emplace_back(_children[0]->getStats(includeDebugInfo)); return ret; } diff --git a/src/mongo/db/exec/sbe/stages/limit_skip.h b/src/mongo/db/exec/sbe/stages/limit_skip.h index 49a7b437c23..53382cb8974 100644 --- a/src/mongo/db/exec/sbe/stages/limit_skip.h +++ b/src/mongo/db/exec/sbe/stages/limit_skip.h @@ -48,7 +48,7 @@ public: PlanState getNext() final; void close() final; - std::unique_ptr<PlanStageStats> getStats() const final; + std::unique_ptr<PlanStageStats> getStats(bool includeDebugInfo) const final; const SpecificStats* getSpecificStats() const final; std::vector<DebugPrinter::Block> debugPrint() const final; diff --git a/src/mongo/db/exec/sbe/stages/loop_join.cpp b/src/mongo/db/exec/sbe/stages/loop_join.cpp index be44219aae4..b8a1b294bec 100644 --- a/src/mongo/db/exec/sbe/stages/loop_join.cpp +++ b/src/mongo/db/exec/sbe/stages/loop_join.cpp @@ -99,6 +99,7 @@ void LoopJoinStage::openInner() { // (re)open the inner side as it can see the correlated value now. _children[1]->open(_reOpenInner); _reOpenInner = true; + ++_specificStats.innerOpens; } PlanState LoopJoinStage::getNext() { @@ -117,7 +118,6 @@ PlanState LoopJoinStage::getNext() { bool pass = false; do { - state = _children[1]->getNext(); if (state == PlanState::ADVANCED) { if (!_predicateCode) { @@ -149,20 +149,35 @@ void LoopJoinStage::close() { _children[1]->close(); _reOpenInner = false; + ++_specificStats.innerCloses; } _children[0]->close(); } -std::unique_ptr<PlanStageStats> LoopJoinStage::getStats() const { +std::unique_ptr<PlanStageStats> LoopJoinStage::getStats(bool includeDebugInfo) const { auto ret = std::make_unique<PlanStageStats>(_commonStats); - ret->children.emplace_back(_children[0]->getStats()); - ret->children.emplace_back(_children[1]->getStats()); + + if (includeDebugInfo) { + BSONObjBuilder bob; + bob.appendNumber("innerOpens", _specificStats.innerOpens); + bob.appendNumber("innerCloses", _specificStats.innerCloses); + bob.append("outerProjects", _outerProjects); + bob.append("outerCorrelated", _outerCorrelated); + if (_predicate) { + bob.append("predicate", DebugPrinter{}.print(_predicate->debugPrint())); + } + + ret->debugInfo = bob.obj(); + } + + ret->children.emplace_back(_children[0]->getStats(includeDebugInfo)); + ret->children.emplace_back(_children[1]->getStats(includeDebugInfo)); return ret; } const SpecificStats* LoopJoinStage::getSpecificStats() const { - return nullptr; + return &_specificStats; } std::vector<DebugPrinter::Block> LoopJoinStage::debugPrint() const { diff --git a/src/mongo/db/exec/sbe/stages/loop_join.h b/src/mongo/db/exec/sbe/stages/loop_join.h index 38275eed66d..7c72cf21669 100644 --- a/src/mongo/db/exec/sbe/stages/loop_join.h +++ b/src/mongo/db/exec/sbe/stages/loop_join.h @@ -51,7 +51,7 @@ public: PlanState getNext() final; void close() final; - std::unique_ptr<PlanStageStats> getStats() const final; + std::unique_ptr<PlanStageStats> getStats(bool includeDebugInfo) const final; const SpecificStats* getSpecificStats() const final; std::vector<DebugPrinter::Block> debugPrint() const final; @@ -71,6 +71,7 @@ private: vm::ByteCode _bytecode; bool _reOpenInner{false}; bool _outerGetNext{false}; + LoopJoinStats _specificStats; void openInner(); }; diff --git a/src/mongo/db/exec/sbe/stages/makeobj.cpp b/src/mongo/db/exec/sbe/stages/makeobj.cpp index ba3a7c78bb8..4479fa76c95 100644 --- a/src/mongo/db/exec/sbe/stages/makeobj.cpp +++ b/src/mongo/db/exec/sbe/stages/makeobj.cpp @@ -201,9 +201,24 @@ void MakeObjStage::close() { _children[0]->close(); } -std::unique_ptr<PlanStageStats> MakeObjStage::getStats() const { +std::unique_ptr<PlanStageStats> MakeObjStage::getStats(bool includeDebugInfo) const { auto ret = std::make_unique<PlanStageStats>(_commonStats); - ret->children.emplace_back(_children[0]->getStats()); + + if (includeDebugInfo) { + BSONObjBuilder bob; + bob.appendIntOrLL("objSlot", _objSlot); + if (_rootSlot) { + bob.appendIntOrLL("rootSlot", *_rootSlot); + } + bob.append("restrictFields", _restrictFields); + bob.append("projectFields", _projectFields); + bob.append("projectSlots", _projectVars); + bob.append("forceNewObject", _forceNewObject); + bob.append("returnOldObject", _returnOldObject); + ret->debugInfo = bob.obj(); + } + + ret->children.emplace_back(_children[0]->getStats(includeDebugInfo)); return ret; } diff --git a/src/mongo/db/exec/sbe/stages/makeobj.h b/src/mongo/db/exec/sbe/stages/makeobj.h index dbcf1f97ed4..7eadb71e394 100644 --- a/src/mongo/db/exec/sbe/stages/makeobj.h +++ b/src/mongo/db/exec/sbe/stages/makeobj.h @@ -53,7 +53,7 @@ public: PlanState getNext() final; void close() final; - std::unique_ptr<PlanStageStats> getStats() const final; + std::unique_ptr<PlanStageStats> getStats(bool includeDebugInfo) const final; const SpecificStats* getSpecificStats() const final; std::vector<DebugPrinter::Block> debugPrint() const final; diff --git a/src/mongo/db/exec/sbe/stages/plan_stats.h b/src/mongo/db/exec/sbe/stages/plan_stats.h index 20c7bbaf0bc..57b99731a98 100644 --- a/src/mongo/db/exec/sbe/stages/plan_stats.h +++ b/src/mongo/db/exec/sbe/stages/plan_stats.h @@ -30,6 +30,7 @@ #pragma once #include "mongo/db/exec/plan_stats.h" +#include "mongo/db/exec/sbe/util/debug_print.h" #include "mongo/db/query/stage_types.h" namespace mongo::sbe { @@ -52,6 +53,14 @@ struct CommonStats { // PlanStages corresponds to an MQL operation specified by the user. const PlanNodeId nodeId; + // Time elapsed while working inside this stage. When this field is set to boost::none, + // timing info will not be collected during query execution. + // + // The field must be populated when running explain or when running with the profiler on. It + // must also be populated when multi planning, in order to gather stats stored in the plan + // cache. + boost::optional<long long> executionTimeMillis; + size_t advances{0}; size_t opens{0}; size_t closes{0}; @@ -92,6 +101,7 @@ struct IndexScanStats final : public SpecificStats { } size_t numReads{0}; + size_t seeks{0}; }; struct FilterStats final : public SpecificStats { @@ -128,8 +138,62 @@ struct UniqueStats : public SpecificStats { return sizeof(*this); } - unsigned int dupsTested = 0; - unsigned int dupsDropped = 0; + size_t dupsTested = 0; + size_t dupsDropped = 0; +}; + +struct BranchStats final : public SpecificStats { + SpecificStats* clone() const final { + return new BranchStats(*this); + } + + uint64_t estimateObjectSizeInBytes() const final { + return sizeof(*this); + } + + size_t numTested{0}; + size_t thenBranchOpens{0}; + size_t thenBranchCloses{0}; + size_t elseBranchOpens{0}; + size_t elseBranchCloses{0}; +}; + +struct CheckBoundsStats final : public SpecificStats { + SpecificStats* clone() const final { + return new CheckBoundsStats(*this); + } + + uint64_t estimateObjectSizeInBytes() const final { + return sizeof(*this); + } + + size_t seeks{0}; +}; + +struct LoopJoinStats final : public SpecificStats { + SpecificStats* clone() const final { + return new LoopJoinStats(*this); + } + + uint64_t estimateObjectSizeInBytes() const final { + return sizeof(*this); + } + + size_t innerOpens{0}; + size_t innerCloses{0}; +}; + +struct TraverseStats : public SpecificStats { + SpecificStats* clone() const final { + return new TraverseStats(*this); + } + + uint64_t estimateObjectSizeInBytes() const final { + return sizeof(*this); + } + + size_t innerOpens{0}; + size_t innerCloses{0}; }; /** diff --git a/src/mongo/db/exec/sbe/stages/project.cpp b/src/mongo/db/exec/sbe/stages/project.cpp index 438ad3ef857..a5ab48b1369 100644 --- a/src/mongo/db/exec/sbe/stages/project.cpp +++ b/src/mongo/db/exec/sbe/stages/project.cpp @@ -94,9 +94,19 @@ void ProjectStage::close() { _children[0]->close(); } -std::unique_ptr<PlanStageStats> ProjectStage::getStats() const { +std::unique_ptr<PlanStageStats> ProjectStage::getStats(bool includeDebugInfo) const { auto ret = std::make_unique<PlanStageStats>(_commonStats); - ret->children.emplace_back(_children[0]->getStats()); + + if (includeDebugInfo) { + DebugPrinter printer; + BSONObjBuilder bob; + for (auto&& [slot, expr] : _projects) { + bob.append(str::stream() << slot, printer.print(expr->debugPrint())); + } + ret->debugInfo = BSON("projections" << bob.obj()); + } + + ret->children.emplace_back(_children[0]->getStats(includeDebugInfo)); return ret; } diff --git a/src/mongo/db/exec/sbe/stages/project.h b/src/mongo/db/exec/sbe/stages/project.h index a9bd6c8e73f..08b8e6e2f89 100644 --- a/src/mongo/db/exec/sbe/stages/project.h +++ b/src/mongo/db/exec/sbe/stages/project.h @@ -48,7 +48,7 @@ public: PlanState getNext() final; void close() final; - std::unique_ptr<PlanStageStats> getStats() const final; + std::unique_ptr<PlanStageStats> getStats(bool includeDebugInfo) const final; const SpecificStats* getSpecificStats() const final; std::vector<DebugPrinter::Block> debugPrint() const final; diff --git a/src/mongo/db/exec/sbe/stages/scan.cpp b/src/mongo/db/exec/sbe/stages/scan.cpp index f4d428fa3ed..7556cd8ef4b 100644 --- a/src/mongo/db/exec/sbe/stages/scan.cpp +++ b/src/mongo/db/exec/sbe/stages/scan.cpp @@ -269,9 +269,26 @@ void ScanStage::close() { _open = false; } -std::unique_ptr<PlanStageStats> ScanStage::getStats() const { +std::unique_ptr<PlanStageStats> ScanStage::getStats(bool includeDebugInfo) const { auto ret = std::make_unique<PlanStageStats>(_commonStats); ret->specific = std::make_unique<ScanStats>(_specificStats); + + if (includeDebugInfo) { + BSONObjBuilder bob; + bob.appendNumber("numReads", _specificStats.numReads); + if (_recordSlot) { + bob.appendIntOrLL("recordSlot", *_recordSlot); + } + if (_recordIdSlot) { + bob.appendIntOrLL("recordIdSlot", *_recordIdSlot); + } + if (_seekKeySlot) { + bob.appendIntOrLL("seekKeySlot", *_seekKeySlot); + } + bob.append("fields", _fields); + bob.append("outputSlots", _vars); + ret->debugInfo = bob.obj(); + } return ret; } @@ -567,7 +584,7 @@ void ParallelScanStage::close() { _open = false; } -std::unique_ptr<PlanStageStats> ParallelScanStage::getStats() const { +std::unique_ptr<PlanStageStats> ParallelScanStage::getStats(bool includeDebugInfo) const { auto ret = std::make_unique<PlanStageStats>(_commonStats); return ret; } diff --git a/src/mongo/db/exec/sbe/stages/scan.h b/src/mongo/db/exec/sbe/stages/scan.h index 5c071ff32a6..30dc58edded 100644 --- a/src/mongo/db/exec/sbe/stages/scan.h +++ b/src/mongo/db/exec/sbe/stages/scan.h @@ -61,7 +61,7 @@ public: PlanState getNext() final; void close() final; - std::unique_ptr<PlanStageStats> getStats() const final; + std::unique_ptr<PlanStageStats> getStats(bool includeDebugInfo) const final; const SpecificStats* getSpecificStats() const final; std::vector<DebugPrinter::Block> debugPrint() const final; @@ -140,7 +140,7 @@ public: PlanState getNext() final; void close() final; - std::unique_ptr<PlanStageStats> getStats() const final; + std::unique_ptr<PlanStageStats> getStats(bool includeDebugInfo) const final; const SpecificStats* getSpecificStats() const final; std::vector<DebugPrinter::Block> debugPrint() const final; diff --git a/src/mongo/db/exec/sbe/stages/sort.cpp b/src/mongo/db/exec/sbe/stages/sort.cpp index d69eb016460..a37b30da60b 100644 --- a/src/mongo/db/exec/sbe/stages/sort.cpp +++ b/src/mongo/db/exec/sbe/stages/sort.cpp @@ -212,10 +212,26 @@ void SortStage::close() { _sorter.reset(); } -std::unique_ptr<PlanStageStats> SortStage::getStats() const { +std::unique_ptr<PlanStageStats> SortStage::getStats(bool includeDebugInfo) const { auto ret = std::make_unique<PlanStageStats>(_commonStats); ret->specific = std::make_unique<SortStats>(_specificStats); - ret->children.emplace_back(_children[0]->getStats()); + + if (includeDebugInfo) { + BSONObjBuilder bob; + bob.appendIntOrLL("totalDataSizeSorted", _specificStats.totalDataSizeBytes); + bob.appendBool("usedDisk", _specificStats.spills > 0); + + BSONObjBuilder childrenBob(bob.subobjStart("orderBySlots")); + for (size_t idx = 0; idx < _obs.size(); ++idx) { + childrenBob.append(str::stream() << _obs[idx], + _dirs[idx] == sbe::value::SortDirection::Ascending ? "asc" : "desc"); + } + childrenBob.doneFast(); + bob.append("outputSlots", _vals); + ret->debugInfo = bob.obj(); + } + + ret->children.emplace_back(_children[0]->getStats(includeDebugInfo)); return ret; } diff --git a/src/mongo/db/exec/sbe/stages/sort.h b/src/mongo/db/exec/sbe/stages/sort.h index e61f2e6c9ff..acb90a69050 100644 --- a/src/mongo/db/exec/sbe/stages/sort.h +++ b/src/mongo/db/exec/sbe/stages/sort.h @@ -62,7 +62,7 @@ public: PlanState getNext() final; void close() final; - std::unique_ptr<PlanStageStats> getStats() const final; + std::unique_ptr<PlanStageStats> getStats(bool includeDebugInfo) const final; const SpecificStats* getSpecificStats() const final; std::vector<DebugPrinter::Block> debugPrint() const final; diff --git a/src/mongo/db/exec/sbe/stages/sorted_merge.cpp b/src/mongo/db/exec/sbe/stages/sorted_merge.cpp index 2442484830d..9f18ea43454 100644 --- a/src/mongo/db/exec/sbe/stages/sorted_merge.cpp +++ b/src/mongo/db/exec/sbe/stages/sorted_merge.cpp @@ -143,10 +143,37 @@ void SortedMergeStage::close() { _merger->clear(); } -std::unique_ptr<PlanStageStats> SortedMergeStage::getStats() const { +std::unique_ptr<PlanStageStats> SortedMergeStage::getStats(bool includeDebugInfo) const { auto ret = std::make_unique<PlanStageStats>(_commonStats); + + if (includeDebugInfo) { + BSONObjBuilder bob; + + { + BSONArrayBuilder keysArrBob(bob.subarrayStart("inputKeySlots")); + for (auto&& slots : _inputKeys) { + BSONObjBuilder childrenBob(keysArrBob.subobjStart()); + for (size_t idx = 0; idx < slots.size(); ++idx) { + childrenBob.append(str::stream() << slots[idx], + _dirs[idx] == sbe::value::SortDirection::Ascending ? "asc" + : "desc"); + } + } + } + + { + BSONArrayBuilder valsArrBob(bob.subarrayStart("inputValSlots")); + for (auto&& slots : _inputVals) { + valsArrBob.append(slots); + } + } + + bob.append("outputSlots", _outputVals); + ret->debugInfo = bob.obj(); + } + for (auto&& child : _children) { - ret->children.emplace_back(child->getStats()); + ret->children.emplace_back(child->getStats(includeDebugInfo)); } return ret; } diff --git a/src/mongo/db/exec/sbe/stages/sorted_merge.h b/src/mongo/db/exec/sbe/stages/sorted_merge.h index 687b7d87136..a73cedac614 100644 --- a/src/mongo/db/exec/sbe/stages/sorted_merge.h +++ b/src/mongo/db/exec/sbe/stages/sorted_merge.h @@ -71,7 +71,7 @@ public: PlanState getNext() final; void close() final; - std::unique_ptr<PlanStageStats> getStats() const final; + std::unique_ptr<PlanStageStats> getStats(bool includeDebugInfo) const final; const SpecificStats* getSpecificStats() const final; std::vector<DebugPrinter::Block> debugPrint() const final; diff --git a/src/mongo/db/exec/sbe/stages/spool.cpp b/src/mongo/db/exec/sbe/stages/spool.cpp index 8093451ee3c..a5bfae94cde 100644 --- a/src/mongo/db/exec/sbe/stages/spool.cpp +++ b/src/mongo/db/exec/sbe/stages/spool.cpp @@ -115,9 +115,17 @@ void SpoolEagerProducerStage::close() { _commonStats.closes++; } -std::unique_ptr<PlanStageStats> SpoolEagerProducerStage::getStats() const { +std::unique_ptr<PlanStageStats> SpoolEagerProducerStage::getStats(bool includeDebugInfo) const { auto ret = std::make_unique<PlanStageStats>(_commonStats); - ret->children.emplace_back(_children[0]->getStats()); + + if (includeDebugInfo) { + BSONObjBuilder bob; + bob.appendIntOrLL("spoolId", _spoolId); + bob.append("outputSlots", _vals); + ret->debugInfo = bob.obj(); + } + + ret->children.emplace_back(_children[0]->getStats(includeDebugInfo)); return ret; } @@ -248,9 +256,20 @@ void SpoolLazyProducerStage::close() { _commonStats.closes++; } -std::unique_ptr<PlanStageStats> SpoolLazyProducerStage::getStats() const { +std::unique_ptr<PlanStageStats> SpoolLazyProducerStage::getStats(bool includeDebugInfo) const { auto ret = std::make_unique<PlanStageStats>(_commonStats); - ret->children.emplace_back(_children[0]->getStats()); + + if (includeDebugInfo) { + BSONObjBuilder bob; + bob.appendIntOrLL("spoolId", _spoolId); + bob.append("outputSlots", _vals); + if (_predicate) { + bob.append("filter", DebugPrinter{}.print(_predicate->debugPrint())); + } + ret->debugInfo = bob.obj(); + } + + ret->children.emplace_back(_children[0]->getStats(includeDebugInfo)); return ret; } diff --git a/src/mongo/db/exec/sbe/stages/spool.h b/src/mongo/db/exec/sbe/stages/spool.h index 7560c2ea16f..10b34939c6f 100644 --- a/src/mongo/db/exec/sbe/stages/spool.h +++ b/src/mongo/db/exec/sbe/stages/spool.h @@ -61,7 +61,7 @@ public: PlanState getNext() final; void close() final; - std::unique_ptr<PlanStageStats> getStats() const final; + std::unique_ptr<PlanStageStats> getStats(bool includeDebugInfo) const final; const SpecificStats* getSpecificStats() const final; std::vector<DebugPrinter::Block> debugPrint() const final; @@ -109,7 +109,7 @@ public: PlanState getNext() final; void close() final; - std::unique_ptr<PlanStageStats> getStats() const final; + std::unique_ptr<PlanStageStats> getStats(bool includeDebugInfo) const final; const SpecificStats* getSpecificStats() const final; std::vector<DebugPrinter::Block> debugPrint() const final; @@ -214,8 +214,16 @@ public: _commonStats.closes++; } - std::unique_ptr<PlanStageStats> getStats() const { + std::unique_ptr<PlanStageStats> getStats(bool includeDebugInfo) const { auto ret = std::make_unique<PlanStageStats>(_commonStats); + + if (includeDebugInfo) { + BSONObjBuilder bob; + bob.appendIntOrLL("spoolId", _spoolId); + bob.append("outputSlots", _vals); + ret->debugInfo = bob.obj(); + } + return ret; } diff --git a/src/mongo/db/exec/sbe/stages/stages.h b/src/mongo/db/exec/sbe/stages/stages.h index d818e6f6efe..9b84ef87bb8 100644 --- a/src/mongo/db/exec/sbe/stages/stages.h +++ b/src/mongo/db/exec/sbe/stages/stages.h @@ -169,9 +169,11 @@ public: /** * Returns a tree of stats. If the stage has any children it must propagate the request for - * stats to them. + * stats to them. If 'includeDebugInfo' is set to 'true' the stage may include some additional + * debug info, opaque to the caller, which will be available via 'PlanStageStats::debugInfo' + * member. */ - virtual std::unique_ptr<PlanStageStats> getStats() const = 0; + virtual std::unique_ptr<PlanStageStats> getStats(bool includeDebugInfo) const = 0; /** * Get stats specific to this stage. Some stages may not have specific stats, in which diff --git a/src/mongo/db/exec/sbe/stages/text_match.cpp b/src/mongo/db/exec/sbe/stages/text_match.cpp index cbfab190cd3..cd4096d202c 100644 --- a/src/mongo/db/exec/sbe/stages/text_match.cpp +++ b/src/mongo/db/exec/sbe/stages/text_match.cpp @@ -105,9 +105,17 @@ std::vector<DebugPrinter::Block> TextMatchStage::debugPrint() const { return ret; } -std::unique_ptr<PlanStageStats> TextMatchStage::getStats() const { +std::unique_ptr<PlanStageStats> TextMatchStage::getStats(bool includeDebugInfo) const { auto ret = std::make_unique<PlanStageStats>(_commonStats); - ret->children.emplace_back(_children[0]->getStats()); + + if (includeDebugInfo) { + BSONObjBuilder bob; + bob.appendIntOrLL("inputSlot", _inputSlot); + bob.appendIntOrLL("outputSlot", _outputSlot); + ret->debugInfo = bob.obj(); + } + + ret->children.emplace_back(_children[0]->getStats(includeDebugInfo)); return ret; } diff --git a/src/mongo/db/exec/sbe/stages/text_match.h b/src/mongo/db/exec/sbe/stages/text_match.h index 895ed7e7705..2fc7d98a620 100644 --- a/src/mongo/db/exec/sbe/stages/text_match.h +++ b/src/mongo/db/exec/sbe/stages/text_match.h @@ -71,7 +71,7 @@ public: std::vector<DebugPrinter::Block> debugPrint() const final; - std::unique_ptr<PlanStageStats> getStats() const final; + std::unique_ptr<PlanStageStats> getStats(bool includeDebugInfo) const final; const SpecificStats* getSpecificStats() const final { return nullptr; diff --git a/src/mongo/db/exec/sbe/stages/traverse.cpp b/src/mongo/db/exec/sbe/stages/traverse.cpp index 4ffca9b9b70..25fa70a0e70 100644 --- a/src/mongo/db/exec/sbe/stages/traverse.cpp +++ b/src/mongo/db/exec/sbe/stages/traverse.cpp @@ -261,15 +261,38 @@ void TraverseStage::close() { _children[0]->close(); } -std::unique_ptr<PlanStageStats> TraverseStage::getStats() const { +std::unique_ptr<PlanStageStats> TraverseStage::getStats(bool includeDebugInfo) const { auto ret = std::make_unique<PlanStageStats>(_commonStats); - ret->children.emplace_back(_children[0]->getStats()); - ret->children.emplace_back(_children[1]->getStats()); + ret->specific = std::make_unique<TraverseStats>(_specificStats); + + if (includeDebugInfo) { + DebugPrinter printer; + BSONObjBuilder bob; + bob.appendNumber("innerOpens", _specificStats.innerOpens); + bob.appendNumber("innerCloses", _specificStats.innerCloses); + bob.appendIntOrLL("inputSlot", _inField); + bob.appendIntOrLL("outputSlot", _outField); + bob.appendIntOrLL("outputSlotInner", _outFieldInner); + bob.append("correlatedSlots", _correlatedSlots); + if (_nestedArraysDepth) { + bob.appendNumber("nestedArraysDepth", *_nestedArraysDepth); + } + if (_fold) { + bob.append("fold", printer.print(_fold->debugPrint())); + } + if (_final) { + bob.append("final", printer.print(_final->debugPrint())); + } + ret->debugInfo = bob.obj(); + } + + ret->children.emplace_back(_children[0]->getStats(includeDebugInfo)); + ret->children.emplace_back(_children[1]->getStats(includeDebugInfo)); return ret; } const SpecificStats* TraverseStage::getSpecificStats() const { - return nullptr; + return &_specificStats; } std::vector<DebugPrinter::Block> TraverseStage::debugPrint() const { diff --git a/src/mongo/db/exec/sbe/stages/traverse.h b/src/mongo/db/exec/sbe/stages/traverse.h index e8480453498..b2dbe881372 100644 --- a/src/mongo/db/exec/sbe/stages/traverse.h +++ b/src/mongo/db/exec/sbe/stages/traverse.h @@ -66,7 +66,7 @@ public: PlanState getNext() final; void close() final; - std::unique_ptr<PlanStageStats> getStats() const final; + std::unique_ptr<PlanStageStats> getStats(bool includeDebugInfo) const final; const SpecificStats* getSpecificStats() const final; std::vector<DebugPrinter::Block> debugPrint() const final; @@ -109,5 +109,6 @@ private: bool _compiled{false}; bool _reOpenInner{false}; + TraverseStats _specificStats; }; } // namespace mongo::sbe diff --git a/src/mongo/db/exec/sbe/stages/union.cpp b/src/mongo/db/exec/sbe/stages/union.cpp index 5a9d9a38fb6..12993254c44 100644 --- a/src/mongo/db/exec/sbe/stages/union.cpp +++ b/src/mongo/db/exec/sbe/stages/union.cpp @@ -145,10 +145,22 @@ void UnionStage::close() { } } -std::unique_ptr<PlanStageStats> UnionStage::getStats() const { +std::unique_ptr<PlanStageStats> UnionStage::getStats(bool includeDebugInfo) const { auto ret = std::make_unique<PlanStageStats>(_commonStats); + + if (includeDebugInfo) { + BSONObjBuilder bob; + BSONArrayBuilder childrenBob(bob.subarrayStart("inputSlots")); + for (auto&& slots : _inputVals) { + childrenBob.append(slots); + } + childrenBob.doneFast(); + bob.append("outputSlots", _outputVals); + ret->debugInfo = bob.obj(); + } + for (auto&& child : _children) { - ret->children.emplace_back(child->getStats()); + ret->children.emplace_back(child->getStats(includeDebugInfo)); } return ret; } diff --git a/src/mongo/db/exec/sbe/stages/union.h b/src/mongo/db/exec/sbe/stages/union.h index 3f7c89dfb42..c903d0cc88a 100644 --- a/src/mongo/db/exec/sbe/stages/union.h +++ b/src/mongo/db/exec/sbe/stages/union.h @@ -49,7 +49,7 @@ public: PlanState getNext() final; void close() final; - std::unique_ptr<PlanStageStats> getStats() const final; + std::unique_ptr<PlanStageStats> getStats(bool includeDebugInfo) const final; const SpecificStats* getSpecificStats() const final; std::vector<DebugPrinter::Block> debugPrint() const final; diff --git a/src/mongo/db/exec/sbe/stages/unique.cpp b/src/mongo/db/exec/sbe/stages/unique.cpp index 586563db357..ac39588d607 100644 --- a/src/mongo/db/exec/sbe/stages/unique.cpp +++ b/src/mongo/db/exec/sbe/stages/unique.cpp @@ -87,11 +87,19 @@ void UniqueStage::close() { _children[0]->close(); } -std::unique_ptr<PlanStageStats> UniqueStage::getStats() const { +std::unique_ptr<PlanStageStats> UniqueStage::getStats(bool includeDebugInfo) const { auto ret = std::make_unique<PlanStageStats>(_commonStats); - for (auto&& child : _children) { - ret->children.emplace_back(child->getStats()); + ret->specific = std::make_unique<UniqueStats>(_specificStats); + + if (includeDebugInfo) { + BSONObjBuilder bob; + bob.appendNumber("dupsTested", _specificStats.dupsTested); + bob.appendNumber("dupsDropped", _specificStats.dupsDropped); + bob.append("keySlots", _keySlots); + ret->debugInfo = bob.obj(); } + + ret->children.emplace_back(_children[0]->getStats(includeDebugInfo)); return ret; } diff --git a/src/mongo/db/exec/sbe/stages/unique.h b/src/mongo/db/exec/sbe/stages/unique.h index 13a963285db..e641f853c18 100644 --- a/src/mongo/db/exec/sbe/stages/unique.h +++ b/src/mongo/db/exec/sbe/stages/unique.h @@ -59,7 +59,7 @@ public: PlanState getNext() final; void close() final; - std::unique_ptr<PlanStageStats> getStats() const final; + std::unique_ptr<PlanStageStats> getStats(bool includeDebugInfo) const final; const SpecificStats* getSpecificStats() const final; std::vector<DebugPrinter::Block> debugPrint() const final; diff --git a/src/mongo/db/exec/sbe/stages/unwind.cpp b/src/mongo/db/exec/sbe/stages/unwind.cpp index 6026e77cd00..e16397332c7 100644 --- a/src/mongo/db/exec/sbe/stages/unwind.cpp +++ b/src/mongo/db/exec/sbe/stages/unwind.cpp @@ -155,9 +155,19 @@ void UnwindStage::close() { _children[0]->close(); } -std::unique_ptr<PlanStageStats> UnwindStage::getStats() const { +std::unique_ptr<PlanStageStats> UnwindStage::getStats(bool includeDebugInfo) const { auto ret = std::make_unique<PlanStageStats>(_commonStats); - ret->children.emplace_back(_children[0]->getStats()); + + if (includeDebugInfo) { + BSONObjBuilder bob; + bob.appendIntOrLL("inputSlot", _inField); + bob.appendIntOrLL("outSlot", _outField); + bob.appendIntOrLL("outIndexSlot", _outIndex); + bob.appendIntOrLL("preserveNullAndEmptyArrays", _preserveNullAndEmptyArrays); + ret->debugInfo = bob.obj(); + } + + ret->children.emplace_back(_children[0]->getStats(includeDebugInfo)); return ret; } diff --git a/src/mongo/db/exec/sbe/stages/unwind.h b/src/mongo/db/exec/sbe/stages/unwind.h index 502d6fba722..17076ca881d 100644 --- a/src/mongo/db/exec/sbe/stages/unwind.h +++ b/src/mongo/db/exec/sbe/stages/unwind.h @@ -49,7 +49,7 @@ public: PlanState getNext() final; void close() final; - std::unique_ptr<PlanStageStats> getStats() const final; + std::unique_ptr<PlanStageStats> getStats(bool includeDebugInfo) const final; const SpecificStats* getSpecificStats() const final; std::vector<DebugPrinter::Block> debugPrint() const final; diff --git a/src/mongo/db/exec/sbe/util/debug_print.cpp b/src/mongo/db/exec/sbe/util/debug_print.cpp index ca7983f38e8..b659f9a7ba6 100644 --- a/src/mongo/db/exec/sbe/util/debug_print.cpp +++ b/src/mongo/db/exec/sbe/util/debug_print.cpp @@ -35,7 +35,7 @@ namespace mongo { namespace sbe { -std::string DebugPrinter::print(std::vector<Block> blocks) { +std::string DebugPrinter::print(const std::vector<Block>& blocks) { std::string ret; int ident = 0; for (auto& b : blocks) { diff --git a/src/mongo/db/exec/sbe/util/debug_print.h b/src/mongo/db/exec/sbe/util/debug_print.h index f32f4662662..7b58391e207 100644 --- a/src/mongo/db/exec/sbe/util/debug_print.h +++ b/src/mongo/db/exec/sbe/util/debug_print.h @@ -117,6 +117,7 @@ public: std::make_move_iterator(blocks.end())); } std::string print(PlanStage* s); + std::string print(const std::vector<Block>& blocks); private: bool _colorConsole; @@ -126,8 +127,6 @@ private: s.append(" "); } } - - std::string print(std::vector<Block> blocks); }; } // namespace sbe } // namespace mongo diff --git a/src/mongo/db/query/plan_explainer_sbe.cpp b/src/mongo/db/query/plan_explainer_sbe.cpp index 08d5db7b6a9..52945b9f6ad 100644 --- a/src/mongo/db/query/plan_explainer_sbe.cpp +++ b/src/mongo/db/query/plan_explainer_sbe.cpp @@ -41,13 +41,10 @@ namespace mongo { namespace { void statsToBSON(const QuerySolutionNode* node, - const sbe::PlanStageStats* stats, - ExplainOptions::Verbosity verbosity, BSONObjBuilder* bob, const BSONObjBuilder* topLevelBob) { invariant(bob); invariant(topLevelBob); - invariant(verbosity < ExplainOptions::Verbosity::kExecStats || stats); // Stop as soon as the BSON object we're building exceeds the limit. if (topLevelBob->len() > kMaxExplainStatsBSONSizeMB) { @@ -63,25 +60,8 @@ void statsToBSON(const QuerySolutionNode* node, bob->append("filter", node->filter->serialize()); } - // Some top-level exec stats get pulled out of the root stage. - if (verbosity >= ExplainOptions::Verbosity::kExecStats) { - // TODO SERVER-51409. - } - // Stage-specific stats. switch (node->getType()) { - case STAGE_AND_HASH: { - if (verbosity >= ExplainOptions::Verbosity::kExecStats) { - // TODO SERVER-51409. - } - break; - } - case STAGE_AND_SORTED: { - if (verbosity >= ExplainOptions::Verbosity::kExecStats) { - // TODO SERVER-51409. - } - break; - } case STAGE_COLLSCAN: { auto csn = static_cast<const CollectionScanNode*>(node); bob->append("direction", csn->direction > 0 ? "forward" : "backward"); @@ -91,47 +71,20 @@ void statsToBSON(const QuerySolutionNode* node, if (csn->maxTs) { bob->append("maxTs", *csn->maxTs); } - if (verbosity >= ExplainOptions::Verbosity::kExecStats) { - // TODO SERVER-51409. - } - break; - } - - case STAGE_ENSURE_SORTED: { - if (verbosity >= ExplainOptions::Verbosity::kExecStats) { - // TODO SERVER-51409. - } break; } - case STAGE_FETCH: { - if (verbosity >= ExplainOptions::Verbosity::kExecStats) { - // TODO SERVER-51409. - } - break; - } - case STAGE_GEO_NEAR_2D: { auto geo2d = static_cast<const GeoNear2DNode*>(node); - bob->append("keyPattern", geo2d->index.keyPattern); bob->append("indexName", geo2d->index.identifier.catalogName); bob->append("indexVersion", geo2d->index.version); - - if (verbosity >= ExplainOptions::Verbosity::kExecStats) { - // TODO SERVER-51409. - } break; } case STAGE_GEO_NEAR_2DSPHERE: { auto geo2dsphere = static_cast<const GeoNear2DSphereNode*>(node); - bob->append("keyPattern", geo2dsphere->index.keyPattern); bob->append("indexName", geo2dsphere->index.identifier.catalogName); bob->append("indexVersion", geo2dsphere->index.version); - - if (verbosity >= ExplainOptions::Verbosity::kExecStats) { - // TODO SERVER-51409. - } break; } case STAGE_IXSCAN: { @@ -160,16 +113,6 @@ void statsToBSON(const QuerySolutionNode* node, } else { bob->append("indexBounds", bounds); } - - if (verbosity >= ExplainOptions::Verbosity::kExecStats) { - // TODO SERVER-51409. - } - break; - } - case STAGE_OR: { - if (verbosity >= ExplainOptions::Verbosity::kExecStats) { - // TODO SERVER-51409. - } break; } case STAGE_LIMIT: { @@ -184,15 +127,10 @@ void statsToBSON(const QuerySolutionNode* node, bob->append("transformBy", projection_ast::astToDebugBSON(pn->proj.root())); break; } - case STAGE_SHARDING_FILTER: { - if (verbosity >= ExplainOptions::Verbosity::kExecStats) { - // TODO SERVER-51409. - } - break; - } case STAGE_SKIP: { auto sn = static_cast<const SkipNode*>(node); bob->appendNumber("skipAmount", sn->skip); + break; } case STAGE_SORT_SIMPLE: case STAGE_SORT_DEFAULT: { @@ -205,19 +143,11 @@ void statsToBSON(const QuerySolutionNode* node, } bob->append("type", node->getType() == STAGE_SORT_SIMPLE ? "simple" : "default"); - - if (verbosity >= ExplainOptions::Verbosity::kExecStats) { - // TODO SERVER-51409. - } break; } case STAGE_SORT_MERGE: { auto smn = static_cast<const MergeSortNode*>(node); bob->append("sortPattern", smn->sort); - - if (verbosity >= ExplainOptions::Verbosity::kExecStats) { - // TODO SERVER-51409. - } break; } case STAGE_TEXT: { @@ -229,20 +159,8 @@ void statsToBSON(const QuerySolutionNode* node, invariant(ftsQuery); bob->append("parsedTextQuery", ftsQuery->toBSON()); bob->append("textIndexVersion", tn->index.version); - } - case STAGE_TEXT_MATCH: { - if (verbosity >= ExplainOptions::Verbosity::kExecStats) { - // TODO SERVER-51409. - } break; } - case STAGE_TEXT_OR: { - if (verbosity >= ExplainOptions::Verbosity::kExecStats) { - // TODO SERVER-51409. - } - break; - } - default: break; } @@ -257,7 +175,7 @@ void statsToBSON(const QuerySolutionNode* node, // rather than 'inputStages'. if (node->children.size() == 1) { BSONObjBuilder childBob; - statsToBSON(node->children[0], stats, verbosity, &childBob, topLevelBob); + statsToBSON(node->children[0], &childBob, topLevelBob); bob->append("inputStage", childBob.obj()); return; } @@ -267,10 +185,134 @@ void statsToBSON(const QuerySolutionNode* node, BSONArrayBuilder childrenBob(bob->subarrayStart("inputStages")); for (auto&& child : node->children) { BSONObjBuilder childBob(childrenBob.subobjStart()); - statsToBSON(child, stats, verbosity, &childBob, topLevelBob); + statsToBSON(child, &childBob, topLevelBob); + } + childrenBob.doneFast(); +} + +void statsToBSON(const sbe::PlanStageStats* stats, + BSONObjBuilder* bob, + const BSONObjBuilder* topLevelBob) { + invariant(stats); + invariant(bob); + invariant(topLevelBob); + + // Stop as soon as the BSON object we're building exceeds the limit. + if (topLevelBob->len() > kMaxExplainStatsBSONSizeMB) { + bob->append("warning", "stats tree exceeded BSON size limit for explain"); + return; + } + + auto stageType = stats->common.stageType; + bob->append("stage", stageType); + bob->appendNumber("planNodeId", static_cast<size_t>(stats->common.nodeId)); + + // Some top-level exec stats get pulled out of the root stage. + bob->appendNumber("nReturned", stats->common.advances); + // Include executionTimeMillis if it was recorded. + if (stats->common.executionTimeMillis) { + bob->appendNumber("executionTimeMillisEstimate", *stats->common.executionTimeMillis); + } + bob->appendNumber("advances", stats->common.advances); + bob->appendNumber("opens", stats->common.opens); + bob->appendNumber("closes", stats->common.closes); + bob->appendNumber("saveState", stats->common.yields); + bob->appendNumber("restoreState", stats->common.unyields); + bob->appendNumber("isEOF", stats->common.isEOF); + + // Include any extra debug info if present. + bob->appendElements(stats->debugInfo); + + // We're done if there are no children. + if (stats->children.empty()) { + return; + } + + // If there's just one child (a common scenario), avoid making an array. This makes + // the output more readable by saving a level of nesting. Name the field 'inputStage' + // rather than 'inputStages'. + if (stats->children.size() == 1) { + BSONObjBuilder childBob; + statsToBSON(stats->children[0].get(), &childBob, topLevelBob); + bob->append("inputStage"_sd, childBob.obj()); + return; + } + + // For some stages we may want to output its children under different field names. + auto overridenNames = [stageType]() -> std::vector<StringData> { + if (stageType == "branch"_sd) { + return {"thenStage"_sd, "elseStage"_sd}; + } else if (stageType == "nlj"_sd || stageType == "traverse"_sd) { + return {"outerStage"_sd, "innerStage"_sd}; + } + return {}; + }(); + if (!overridenNames.empty()) { + invariant(overridenNames.size() == stats->children.size()); + + for (size_t idx = 0; idx < stats->children.size(); ++idx) { + BSONObjBuilder childBob; + statsToBSON(stats->children[idx].get(), &childBob, topLevelBob); + bob->append(overridenNames[idx], childBob.obj()); + } + return; + } + + // There is more than one child. Recursively call statsToBSON(...) on each + // of them and add them to the 'inputStages' array. + BSONArrayBuilder childrenBob(bob->subarrayStart("inputStages"_sd)); + for (auto&& child : stats->children) { + BSONObjBuilder childBob(childrenBob.subobjStart()); + statsToBSON(child.get(), &childBob, topLevelBob); } childrenBob.doneFast(); } + +PlanSummaryStats collectExecutionStatsSummary(const sbe::PlanStageStats* stats) { + invariant(stats); + + PlanSummaryStats summary; + summary.nReturned = stats->common.advances; + + if (stats->common.executionTimeMillis) { + summary.executionTimeMillisEstimate = *stats->common.executionTimeMillis; + } + + // Collect cumulative execution stats for the plan. + std::queue<const sbe::PlanStageStats*> queue; + queue.push(stats); + while (!queue.empty()) { + stats = queue.front(); + invariant(stats); + queue.pop(); + + if (stats->specific) { + stats->specific->accumulate(summary); + } + + for (auto&& child : stats->children) { + queue.push(child.get()); + } + } + + return summary; +} + +PlanExplainer::PlanStatsDetails buildPlanStatsDetails(const QuerySolutionNode* node, + const sbe::PlanStage* root, + ExplainOptions::Verbosity verbosity) { + BSONObjBuilder bob; + + if (verbosity >= ExplainOptions::Verbosity::kExecStats) { + auto stats = root->getStats(true /* includeDebugInfo */); + auto summary = collectExecutionStatsSummary(stats.get()); + statsToBSON(stats.get(), &bob, &bob); + return {bob.obj(), std::move(summary)}; + } + + statsToBSON(node, &bob, &bob); + return {bob.obj(), boost::none}; +} } // namespace std::string PlanExplainerSBE::getPlanSummary() const { @@ -420,20 +462,7 @@ PlanExplainer::PlanStatsDetails PlanExplainerSBE::getWinningPlanStats( ExplainOptions::Verbosity verbosity) const { invariant(_root); invariant(_solution); - - auto&& [stats, summary] = [&]() - -> std::pair<std::unique_ptr<sbe::PlanStageStats>, boost::optional<PlanSummaryStats>> { - if (verbosity >= ExplainOptions::Verbosity::kExecStats) { - auto stats = _root->getStats(); - // TODO: SERVER-51409 add support for PlanSummaryStats. - return {std::move(stats), PlanSummaryStats{}}; - } - return {}; - }(); - - BSONObjBuilder bob; - statsToBSON(_solution->root(), stats.get(), verbosity, &bob, &bob); - return {bob.obj(), std::move(summary)}; + return buildPlanStatsDetails(_solution->root(), _root, verbosity); } std::vector<PlanExplainer::PlanStatsDetails> PlanExplainerSBE::getRejectedPlansStats( @@ -448,19 +477,8 @@ std::vector<PlanExplainer::PlanStatsDetails> PlanExplainerSBE::getRejectedPlansS invariant(candidate.root); invariant(candidate.solution); - auto&& [stats, summary] = [&]() - -> std::pair<std::unique_ptr<sbe::PlanStageStats>, boost::optional<PlanSummaryStats>> { - if (verbosity >= ExplainOptions::Verbosity::kExecStats) { - auto stats = candidate.root->getStats(); - // TODO: SERVER-51409 add support for PlanSummaryStats. - return {std::move(stats), PlanSummaryStats{}}; - } - return {}; - }(); - - BSONObjBuilder bob; - statsToBSON(candidate.solution->root(), stats.get(), verbosity, &bob, &bob); - res.push_back({bob.obj(), std::move(summary)}); + res.push_back( + buildPlanStatsDetails(candidate.solution->root(), candidate.root.get(), verbosity)); } return res; } diff --git a/src/mongo/db/query/plan_ranker_util.h b/src/mongo/db/query/plan_ranker_util.h index 648d9c70c66..3a8c97431ba 100644 --- a/src/mongo/db/query/plan_ranker_util.h +++ b/src/mongo/db/query/plan_ranker_util.h @@ -64,7 +64,11 @@ StatusWith<std::unique_ptr<PlanRankingDecision>> pickBestPlan( // Get stat trees from each plan. std::vector<std::unique_ptr<PlanStageStatsType>> statTrees; for (size_t i = 0; i < candidates.size(); ++i) { - statTrees.push_back(candidates[i].root->getStats()); + if constexpr (std::is_same_v<PlanStageStatsType, PlanStageStats>) { + statTrees.push_back(candidates[i].root->getStats()); + } else { + statTrees.push_back(candidates[i].root->getStats(false /* includeDebugInfo */)); + } } // Holds (score, candidateIndex). @@ -85,7 +89,6 @@ StatusWith<std::unique_ptr<PlanRankingDecision>> pickBestPlan( }(); if (!candidates[i].failed) { - log_detail::logScoringPlan([&]() { return candidates[i].solution->toString(); }, [&]() { auto&& [stats, _] = explainer->getWinningPlanStats( diff --git a/src/mongo/db/query/sbe_cached_solution_planner.cpp b/src/mongo/db/query/sbe_cached_solution_planner.cpp index bfe2ebaeb77..80214e99d06 100644 --- a/src/mongo/db/query/sbe_cached_solution_planner.cpp +++ b/src/mongo/db/query/sbe_cached_solution_planner.cpp @@ -65,7 +65,7 @@ CandidatePlans CachedSolutionPlanner::plan( return replan(false); } - auto stats{candidate.root->getStats()}; + auto stats{candidate.root->getStats(false /* includeDebugInfo */)}; auto numReads{calculateNumberOfReads(stats.get())}; // If the cached plan hit EOF quickly enough, or still as efficient as before, then no need to // replan. Finalize the cached plan and return it. |