diff options
Diffstat (limited to 'src/mongo/db/query/find.cpp')
| -rw-r--r-- | src/mongo/db/query/find.cpp | 59 |
1 files changed, 42 insertions, 17 deletions
diff --git a/src/mongo/db/query/find.cpp b/src/mongo/db/query/find.cpp index a87df84a6df..197475a9173 100644 --- a/src/mongo/db/query/find.cpp +++ b/src/mongo/db/query/find.cpp @@ -63,6 +63,7 @@ #include "mongo/db/stats/top.h" #include "mongo/db/storage/storage_options.h" #include "mongo/db/views/view_catalog.h" +#include "mongo/logv2/log.h" #include "mongo/s/chunk_version.h" #include "mongo/s/stale_exception.h" #include "mongo/util/fail_point.h" @@ -203,8 +204,10 @@ void generateBatch(int ntoreturn, switch (*state) { // Log an error message and then perform the cleanup. case PlanExecutor::FAILURE: { - error() << "getMore executor error, stats: " - << redact(Explain::getWinningPlanStats(exec)); + LOGV2_ERROR(20918, + "getMore executor error, stats: {Explain_getWinningPlanStats_exec}", + "Explain_getWinningPlanStats_exec"_attr = + redact(Explain::getWinningPlanStats(exec))); // We should always have a valid status object by this point. auto status = WorkingSetCommon::getMemberObjectStatus(doc); invariant(!status.isOK()); @@ -244,7 +247,7 @@ Message getMore(OperationContext* opCtx, bool* isCursorAuthorized) { invariant(ntoreturn >= 0); - LOG(5) << "Running getMore, cursorid: " << cursorid; + LOGV2_DEBUG(20909, 5, "Running getMore, cursorid: {cursorid}", "cursorid"_attr = cursorid); CurOp& curOp = *CurOp::get(opCtx); curOp.ensureStarted(); @@ -525,8 +528,11 @@ Message getMore(OperationContext* opCtx, cursorid = 0; curOp.debug().cursorExhausted = true; - LOG(5) << "getMore NOT saving client cursor, ended with state " - << PlanExecutor::statestr(state); + LOGV2_DEBUG( + 20910, + 5, + "getMore NOT saving client cursor, ended with state {PlanExecutor_statestr_state}", + "PlanExecutor_statestr_state"_attr = PlanExecutor::statestr(state)); } else { cursorFreer.dismiss(); // Continue caching the ClientCursor. @@ -534,7 +540,10 @@ Message getMore(OperationContext* opCtx, cursorPin->incNBatches(); exec->saveState(); exec->detachFromOperationContext(); - LOG(5) << "getMore saving client cursor ended with state " << PlanExecutor::statestr(state); + LOGV2_DEBUG(20911, + 5, + "getMore saving client cursor ended with state {PlanExecutor_statestr_state}", + "PlanExecutor_statestr_state"_attr = PlanExecutor::statestr(state)); // Set 'exhaust' if the client requested exhaust and the cursor is not exhausted. *exhaust = opCtx->isExhaust(); @@ -567,7 +576,8 @@ Message getMore(OperationContext* opCtx, qr.setCursorId(cursorid); qr.setStartingFrom(startingResult); qr.setNReturned(numResults); - LOG(5) << "getMore returned " << numResults << " results\n"; + LOGV2_DEBUG( + 20912, 5, "getMore returned {numResults} results\n", "numResults"_attr = numResults); return Message(bb.release()); } @@ -605,8 +615,9 @@ bool runQuery(OperationContext* opCtx, "Can't canonicalize query"); invariant(cq.get()); - LOG(5) << "Running query:\n" << redact(cq->toString()); - LOG(2) << "Running query: " << redact(cq->toStringShort()); + LOGV2_DEBUG(20913, 5, "Running query:\n{cq}", "cq"_attr = redact(cq->toString())); + LOGV2_DEBUG( + 20914, 2, "Running query: {cq_Short}", "cq_Short"_attr = redact(cq->toStringShort())); // Parse, canonicalize, plan, transcribe, and get a plan executor. AutoGetCollectionForReadCommand ctx(opCtx, nss, AutoGetCollection::ViewMode::kViewsForbidden); @@ -704,17 +715,25 @@ bool runQuery(OperationContext* opCtx, ++numResults; if (FindCommon::enoughForFirstBatch(qr, numResults)) { - LOG(5) << "Enough for first batch, wantMore=" << qr.wantMore() - << " ntoreturn=" << qr.getNToReturn().value_or(0) - << " numResults=" << numResults; + LOGV2_DEBUG(20915, + 5, + "Enough for first batch, wantMore={qr_wantMore} " + "ntoreturn={qr_getNToReturn_value_or_0} numResults={numResults}", + "qr_wantMore"_attr = qr.wantMore(), + "qr_getNToReturn_value_or_0"_attr = qr.getNToReturn().value_or(0), + "numResults"_attr = numResults); break; } } // Caller expects exceptions thrown in certain cases. if (PlanExecutor::FAILURE == state) { - error() << "Plan executor error during find: " << PlanExecutor::statestr(state) - << ", stats: " << redact(Explain::getWinningPlanStats(exec.get())); + LOGV2_ERROR(20919, + "Plan executor error during find: {PlanExecutor_statestr_state}, stats: " + "{Explain_getWinningPlanStats_exec_get}", + "PlanExecutor_statestr_state"_attr = PlanExecutor::statestr(state), + "Explain_getWinningPlanStats_exec_get"_attr = + redact(Explain::getWinningPlanStats(exec.get()))); uassertStatusOKWithContext(WorkingSetCommon::getMemberObjectStatus(doc), "Executor error during OP_QUERY find"); MONGO_UNREACHABLE; @@ -746,8 +765,11 @@ bool runQuery(OperationContext* opCtx, }); ccId = pinnedCursor.getCursor()->cursorid(); - LOG(5) << "caching executor with cursorid " << ccId << " after returning " << numResults - << " results"; + LOGV2_DEBUG(20916, + 5, + "caching executor with cursorid {ccId} after returning {numResults} results", + "ccId"_attr = ccId, + "numResults"_attr = numResults); // Set curOp.debug().exhaust if the client requested exhaust and the cursor is not // exhausted. @@ -768,7 +790,10 @@ bool runQuery(OperationContext* opCtx, endQueryOp(opCtx, collection, *pinnedCursor.getCursor()->getExecutor(), numResults, ccId); } else { - LOG(5) << "Not caching executor but returning " << numResults << " results."; + LOGV2_DEBUG(20917, + 5, + "Not caching executor but returning {numResults} results.", + "numResults"_attr = numResults); endQueryOp(opCtx, collection, *exec, numResults, ccId); } |