diff options
Diffstat (limited to 'src/mongo/db/query/query_planner.cpp')
| -rw-r--r-- | src/mongo/db/query/query_planner.cpp | 112 |
1 files changed, 80 insertions, 32 deletions
diff --git a/src/mongo/db/query/query_planner.cpp b/src/mongo/db/query/query_planner.cpp index d95ff7dd03f..966fb61275e 100644 --- a/src/mongo/db/query/query_planner.cpp +++ b/src/mongo/db/query/query_planner.cpp @@ -54,6 +54,7 @@ #include "mongo/db/query/planner_ixselect.h" #include "mongo/db/query/query_planner_common.h" #include "mongo/db/query/query_solution.h" +#include "mongo/logv2/log.h" #include "mongo/util/log.h" namespace mongo { @@ -475,10 +476,12 @@ StatusWith<std::unique_ptr<QuerySolution>> QueryPlanner::planFromCache( // Create a copy of the expression tree. We use cachedSoln to annotate this with indices. unique_ptr<MatchExpression> clone = query.root()->shallowClone(); - LOG(5) << "Tagging the match expression according to cache data: " << endl - << "Filter:" << endl - << redact(clone->debugString()) << "Cache data:" << endl - << redact(winnerCacheData.toString()); + LOGV2_DEBUG(20963, + 5, + "Tagging the match expression according to cache data: " + "\nFilter:\n{clone_debugString}Cache data:\n{winnerCacheData}", + "clone_debugString"_attr = redact(clone->debugString()), + "winnerCacheData"_attr = redact(winnerCacheData.toString())); stdx::unordered_set<string> fields; QueryPlannerIXSelect::getFields(query.root(), &fields); @@ -492,7 +495,11 @@ StatusWith<std::unique_ptr<QuerySolution>> QueryPlanner::planFromCache( const auto insertionRes = indexMap.insert(std::make_pair(ie.identifier, i)); // Be sure the key was not already in the map. invariant(insertionRes.second); - LOG(5) << "Index " << i << ": " << ie.identifier; + LOGV2_DEBUG(20964, + 5, + "Index {i}: {ie_identifier}", + "i"_attr = i, + "ie_identifier"_attr = ie.identifier); } Status s = tagAccordingToCache(clone.get(), winnerCacheData.tree.get(), indexMap); @@ -503,7 +510,10 @@ StatusWith<std::unique_ptr<QuerySolution>> QueryPlanner::planFromCache( // The MatchExpression tree is in canonical order. We must order the nodes for access planning. prepareForAccessPlanning(clone.get()); - LOG(5) << "Tagged tree:" << endl << redact(clone->debugString()); + LOGV2_DEBUG(20965, + 5, + "Tagged tree:\n{clone_debugString}", + "clone_debugString"_attr = redact(clone->debugString())); // Use the cached index assignments to build solnRoot. std::unique_ptr<QuerySolutionNode> solnRoot(QueryPlannerAccess::buildIndexedDataAccess( @@ -522,21 +532,30 @@ StatusWith<std::unique_ptr<QuerySolution>> QueryPlanner::planFromCache( << "Failed to analyze plan from cache. Query: " << query.toStringShort()); } - LOG(5) << "Planner: solution constructed from the cache:\n" << redact(soln->toString()); + LOGV2_DEBUG(20966, + 5, + "Planner: solution constructed from the cache:\n{soln}", + "soln"_attr = redact(soln->toString())); return {std::move(soln)}; } // static StatusWith<std::vector<std::unique_ptr<QuerySolution>>> QueryPlanner::plan( const CanonicalQuery& query, const QueryPlannerParams& params) { - LOG(5) << "Beginning planning..." << endl - << "=============================" << endl - << "Options = " << optionString(params.options) << endl - << "Canonical query:" << endl - << redact(query.toString()) << "============================="; + LOGV2_DEBUG( + 20967, + 5, + "Beginning planning...\n=============================\nOptions = " + "{optionString_params_options}\nCanonical query:\n{query}=============================", + "optionString_params_options"_attr = optionString(params.options), + "query"_attr = redact(query.toString())); for (size_t i = 0; i < params.indices.size(); ++i) { - LOG(5) << "Index " << i << " is " << params.indices[i].toString(); + LOGV2_DEBUG(20968, + 5, + "Index {i} is {params_indices_i}", + "i"_attr = i, + "params_indices_i"_attr = params.indices[i].toString()); } const bool canTableScan = !(params.options & QueryPlannerParams::NO_TABLE_SCAN); @@ -572,7 +591,7 @@ StatusWith<std::vector<std::unique_ptr<QuerySolution>>> QueryPlanner::plan( BSONElement naturalHint = dps::extractElementAtPath(hintObj, "$natural"); if (naturalHint) { - LOG(5) << "Forcing a table scan due to hinted $natural"; + LOGV2_DEBUG(20969, 5, "Forcing a table scan due to hinted $natural"); if (!canTableScan) { return Status(ErrorCodes::NoQueryExecutionPlans, "hint $natural is not allowed, because 'notablescan' is enabled"); @@ -632,7 +651,7 @@ StatusWith<std::vector<std::unique_ptr<QuerySolution>>> QueryPlanner::plan( stdx::unordered_set<string> fields; QueryPlannerIXSelect::getFields(query.root(), &fields); for (auto&& field : fields) { - LOG(5) << "Predicate over field '" << field << "'"; + LOGV2_DEBUG(20970, 5, "Predicate over field '{field}'", "field"_attr = field); } fullIndexList = QueryPlannerIXSelect::expandIndexes(fields, std::move(fullIndexList)); @@ -706,7 +725,11 @@ StatusWith<std::vector<std::unique_ptr<QuerySolution>>> QueryPlanner::plan( } for (size_t i = 0; i < relevantIndices.size(); ++i) { - LOG(2) << "Relevant index " << i << " is " << relevantIndices[i].toString(); + LOGV2_DEBUG(20971, + 2, + "Relevant index {i} is {relevantIndices_i}", + "i"_attr = i, + "relevantIndices_i"_attr = relevantIndices[i].toString()); } // Figure out how useful each index is to each predicate. @@ -728,7 +751,10 @@ StatusWith<std::vector<std::unique_ptr<QuerySolution>>> QueryPlanner::plan( } // query.root() is now annotated with RelevantTag(s). - LOG(5) << "Rated tree:" << endl << redact(query.root()->debugString()); + LOGV2_DEBUG(20972, + 5, + "Rated tree:\n{query_root_debugString}", + "query_root_debugString"_attr = redact(query.root()->debugString())); // If there is a GEO_NEAR it must have an index it can use directly. const MatchExpression* gnNode = nullptr; @@ -736,14 +762,17 @@ StatusWith<std::vector<std::unique_ptr<QuerySolution>>> QueryPlanner::plan( // No index for GEO_NEAR? No query. RelevantTag* tag = static_cast<RelevantTag*>(gnNode->getTag()); if (!tag || (0 == tag->first.size() && 0 == tag->notFirst.size())) { - LOG(5) << "Unable to find index for $geoNear query."; + LOGV2_DEBUG(20973, 5, "Unable to find index for $geoNear query."); // Don't leave tags on query tree. query.root()->resetTag(); return Status(ErrorCodes::NoQueryExecutionPlans, "unable to find index for $geoNear query"); } - LOG(5) << "Rated tree after geonear processing:" << redact(query.root()->debugString()); + LOGV2_DEBUG(20974, + 5, + "Rated tree after geonear processing:{query_root_debugString}", + "query_root_debugString"_attr = redact(query.root()->debugString())); } // Likewise, if there is a TEXT it must have an index it can use directly. @@ -780,7 +809,10 @@ StatusWith<std::vector<std::unique_ptr<QuerySolution>>> QueryPlanner::plan( // assigned to it. invariant(1 == tag->first.size() + tag->notFirst.size()); - LOG(5) << "Rated tree after text processing:" << redact(query.root()->debugString()); + LOGV2_DEBUG(20975, + 5, + "Rated tree after text processing:{query_root_debugString}", + "query_root_debugString"_attr = redact(query.root()->debugString())); } std::vector<std::unique_ptr<QuerySolution>> out; @@ -798,8 +830,10 @@ StatusWith<std::vector<std::unique_ptr<QuerySolution>>> QueryPlanner::plan( unique_ptr<MatchExpression> nextTaggedTree; while ((nextTaggedTree = isp.getNext()) && (out.size() < params.maxIndexedSolutions)) { - LOG(5) << "About to build solntree from tagged tree:" << endl - << redact(nextTaggedTree->debugString()); + LOGV2_DEBUG(20976, + 5, + "About to build solntree from tagged tree:\n{nextTaggedTree_debugString}", + "nextTaggedTree_debugString"_attr = redact(nextTaggedTree->debugString())); // Store the plan cache index tree before calling prepareForAccessingPlanning(), so that // the PlanCacheIndexTree has the same sort as the MatchExpression used to generate the @@ -808,8 +842,11 @@ StatusWith<std::vector<std::unique_ptr<QuerySolution>>> QueryPlanner::plan( std::unique_ptr<PlanCacheIndexTree> cacheData; auto statusWithCacheData = cacheDataFromTaggedTree(clone.get(), relevantIndices); if (!statusWithCacheData.isOK()) { - LOG(5) << "Query is not cachable: " - << redact(statusWithCacheData.getStatus().reason()); + LOGV2_DEBUG(20977, + 5, + "Query is not cachable: {statusWithCacheData_getStatus_reason}", + "statusWithCacheData_getStatus_reason"_attr = + redact(statusWithCacheData.getStatus().reason())); } else { cacheData = std::move(statusWithCacheData.getValue()); } @@ -828,7 +865,10 @@ StatusWith<std::vector<std::unique_ptr<QuerySolution>>> QueryPlanner::plan( auto soln = QueryPlannerAnalysis::analyzeDataAccess(query, params, std::move(solnRoot)); if (soln) { - LOG(5) << "Planner: adding solution:" << endl << redact(soln->toString()); + LOGV2_DEBUG(20978, + 5, + "Planner: adding solution:\n{soln}", + "soln"_attr = redact(soln->toString())); if (statusWithCacheData.isOK()) { SolutionCacheData* scd = new SolutionCacheData(); scd->tree = std::move(cacheData); @@ -842,7 +882,8 @@ StatusWith<std::vector<std::unique_ptr<QuerySolution>>> QueryPlanner::plan( // Don't leave tags on query tree. query.root()->resetTag(); - LOG(5) << "Planner: outputted " << out.size() << " indexed solutions."; + LOGV2_DEBUG( + 20979, 5, "Planner: outputted {out_size} indexed solutions.", "out_size"_attr = out.size()); // Produce legible error message for failed OR planning with a TEXT child. // TODO: support collection scan for non-TEXT children of OR. @@ -877,7 +918,7 @@ StatusWith<std::vector<std::unique_ptr<QuerySolution>>> QueryPlanner::plan( return Status(ErrorCodes::NoQueryExecutionPlans, "Failed to build whole-index solution for $hint"); } - LOG(5) << "Planner: outputting soln that uses hinted index as scan."; + LOGV2_DEBUG(20980, 5, "Planner: outputting soln that uses hinted index as scan."); std::vector<std::unique_ptr<QuerySolution>> out; out.push_back(std::move(soln)); return {std::move(out)}; @@ -938,7 +979,8 @@ StatusWith<std::vector<std::unique_ptr<QuerySolution>>> QueryPlanner::plan( const BSONObj kp = QueryPlannerAnalysis::getSortPattern(index.keyPattern); if (providesSort(query, kp)) { - LOG(5) << "Planner: outputting soln that uses index to provide sort."; + LOGV2_DEBUG( + 20981, 5, "Planner: outputting soln that uses index to provide sort."); auto soln = buildWholeIXSoln(fullIndexList[i], query, params); if (soln) { PlanCacheIndexTree* indexTree = new PlanCacheIndexTree(); @@ -953,8 +995,10 @@ StatusWith<std::vector<std::unique_ptr<QuerySolution>>> QueryPlanner::plan( } } if (providesSort(query, QueryPlannerCommon::reverseSortObj(kp))) { - LOG(5) << "Planner: outputting soln that uses (reverse) index " - << "to provide sort."; + LOGV2_DEBUG( + 20982, + 5, + "Planner: outputting soln that uses (reverse) index to provide sort."); auto soln = buildWholeIXSoln(fullIndexList[i], query, params, -1); if (soln) { PlanCacheIndexTree* indexTree = new PlanCacheIndexTree(); @@ -988,7 +1032,8 @@ StatusWith<std::vector<std::unique_ptr<QuerySolution>>> QueryPlanner::plan( QueryPlannerParams paramsForCoveredIxScan; auto soln = buildWholeIXSoln(index, query, paramsForCoveredIxScan); if (soln && !soln->root->fetched()) { - LOG(5) << "Planner: outputting soln that uses index to provide projection."; + LOGV2_DEBUG( + 20983, 5, "Planner: outputting soln that uses index to provide projection."); PlanCacheIndexTree* indexTree = new PlanCacheIndexTree(); indexTree->setIndexEntry(index); @@ -1030,7 +1075,10 @@ StatusWith<std::vector<std::unique_ptr<QuerySolution>>> QueryPlanner::plan( "Failed to build collection scan soln"); } if (collscan) { - LOG(5) << "Planner: outputting a collscan:" << endl << redact(collscan->toString()); + LOGV2_DEBUG(20984, + 5, + "Planner: outputting a collscan:\n{collscan}", + "collscan"_attr = redact(collscan->toString())); SolutionCacheData* scd = new SolutionCacheData(); scd->solnType = SolutionCacheData::COLLSCAN_SOLN; collscan->cacheData.reset(scd); |