From 019afd89c77629a3cabf93803314dd77f451276b Mon Sep 17 00:00:00 2001 From: Amirsaman Memaripour Date: Tue, 24 Mar 2020 17:41:29 -0400 Subject: SERVER-47077 Clean up log lines in 'mongo/db' Cleaning up log lines to adhere to the LOGV2 style guide. --- src/mongo/db/curop.cpp | 31 +++++++++++++++++++------------ src/mongo/db/mirror_maestro.cpp | 18 +++++------------- src/mongo/db/operation_context.cpp | 6 ++---- src/mongo/db/service_context.cpp | 8 ++++---- 4 files changed, 30 insertions(+), 33 deletions(-) diff --git a/src/mongo/db/curop.cpp b/src/mongo/db/curop.cpp index c295d787ea4..429d870f33d 100644 --- a/src/mongo/db/curop.cpp +++ b/src/mongo/db/curop.cpp @@ -385,9 +385,10 @@ void CurOp::setGenericOpRequestDetails(OperationContext* opCtx, void CurOp::setMessage_inlock(StringData message) { if (_progressMeter.isActive()) { LOGV2_ERROR(20527, - "old _message: {message} new message:{message2}", - "message"_attr = redact(_message), - "message2"_attr = redact(message)); + "Changing message from {old} to {new}", + "Updating message", + "old"_attr = redact(_message), + "new"_attr = redact(message)); verify(!_progressMeter.isActive()); } _message = message.toString(); // copy @@ -474,16 +475,22 @@ bool CurOp::completeAndLogOperation(OperationContext* opCtx, if (lk.isLocked()) { _debug.storageStats = opCtx->recoveryUnit()->getOperationStatistics(); } else { - LOGV2_WARNING_OPTIONS(20525, - {component}, - "Unable to gather storage statistics for a slow " - "operation due to lock aquire timeout"); + LOGV2_WARNING_OPTIONS( + 20525, + {component}, + "Failed to gather storage statistics for {opId} due to {reason}", + "Failed to gather storage statistics for slow operation", + "opId"_attr = opCtx->getOpID(), + "reason"_attr = "lock acquire timeout"_sd); } - } catch (const ExceptionForCat&) { - LOGV2_WARNING_OPTIONS(20526, - {component}, - "Unable to gather storage statistics for a slow " - "operation due to interrupt"); + } catch (const ExceptionForCat& ex) { + LOGV2_WARNING_OPTIONS( + 20526, + {component}, + "Failed to gather storage statistics for {opId} due to {reason}", + "Failed to gather storage statistics for slow operation", + "opId"_attr = opCtx->getOpID(), + "reason"_attr = redact(ex)); } } diff --git a/src/mongo/db/mirror_maestro.cpp b/src/mongo/db/mirror_maestro.cpp index b7018659edf..3471820ed75 100644 --- a/src/mongo/db/mirror_maestro.cpp +++ b/src/mongo/db/mirror_maestro.cpp @@ -310,11 +310,8 @@ void MirrorMaestroImpl::_mirror(std::vector hosts, invariant(args.response.isOK()); gMirroredReadsSection.resolved.fetchAndAdd(1); - LOGV2_DEBUG(31457, - 4, - "Received response from {host}, response: {response}", - "host"_attr = host, - "response"_attr = args.response); + LOGV2_DEBUG( + 31457, 4, "Response received", "host"_attr = host, "response"_attr = args.response); }; auto newRequest = executor::RemoteCommandRequest( @@ -324,11 +321,7 @@ void MirrorMaestroImpl::_mirror(std::vector hosts, newRequest.fireAndForgetMode = executor::RemoteCommandRequest::FireAndForgetMode::kOn; } - LOGV2_DEBUG(31455, - 4, - "Mirroring to {host}, request: {request}", - "host"_attr = host, - "request"_attr = newRequest); + LOGV2_DEBUG(31455, 4, "About to mirror", "host"_attr = host, "request"_attr = newRequest); auto status = _executor->scheduleRemoteCommand(newRequest, std::move(mirrorResponseCallback)) @@ -339,7 +332,7 @@ void MirrorMaestroImpl::_mirror(std::vector hosts, } } catch (const DBException& e) { // TODO SERVER-44570 Invariant this only in testing - LOGV2_DEBUG(31456, 2, "Failed to mirror read command due to an error", "error"_attr = e); + LOGV2_DEBUG(31456, 2, "Mirroring failed", "reason"_attr = e); } void MirrorMaestroImpl::init(ServiceContext* serviceContext) noexcept { @@ -357,8 +350,7 @@ void MirrorMaestroImpl::init(ServiceContext* serviceContext) noexcept { return; } break; case Liveness::kShutdown: { - LOGV2_DEBUG( - 31453, 2, "MirrorMaestro cannot initialize as it has already been shutdown"); + LOGV2_DEBUG(31453, 2, "Cannot initialize an already shutdown MirrorMaestro"); return; } break; }; diff --git a/src/mongo/db/operation_context.cpp b/src/mongo/db/operation_context.cpp index a0bee37b49b..3553a4f0f64 100644 --- a/src/mongo/db/operation_context.cpp +++ b/src/mongo/db/operation_context.cpp @@ -230,9 +230,7 @@ Status OperationContext::checkForInterruptNoAssert() noexcept { checkForInterruptFail.executeIf( [&](auto&&) { - LOGV2(20882, - "set pending kill on op {getOpID}, for checkForInterruptFail", - "getOpID"_attr = getOpID()); + LOGV2(20882, "Marking operation as killed for failpoint", "opId"_attr = getOpID()); markKilled(); }, [&](auto&& data) { return opShouldFail(getClient(), data); }); @@ -333,7 +331,7 @@ void OperationContext::markKilled(ErrorCodes::Error killCode) { invariant(!ErrorExtraInfo::parserFor(killCode)); if (killCode == ErrorCodes::ClientDisconnect) { - LOGV2(20883, "operation was interrupted because a client disconnected"); + LOGV2(20883, "Interrupted operation as its client disconnected", "opId"_attr = getOpID()); } if (auto status = ErrorCodes::OK; _killCode.compareAndSwap(&status, killCode)) { diff --git a/src/mongo/db/service_context.cpp b/src/mongo/db/service_context.cpp index 9e261ba5b0e..b4eda7a9b3d 100644 --- a/src/mongo/db/service_context.cpp +++ b/src/mongo/db/service_context.cpp @@ -111,10 +111,10 @@ ServiceContext::~ServiceContext() { stdx::lock_guard lk(_mutex); for (const auto& client : _clients) { LOGV2_ERROR(23828, - "Client {client_desc} still exists while destroying " - "ServiceContext@{reinterpret_cast_uint64_t_this}", - "client_desc"_attr = client->desc(), - "reinterpret_cast_uint64_t_this"_attr = reinterpret_cast(this)); + "{client} exists while destroying {serviceContext}", + "Non-empty client list when destroying service context", + "client"_attr = client->desc(), + "serviceContext"_attr = reinterpret_cast(this)); } invariant(_clients.empty()); } -- cgit v1.2.1