summaryrefslogtreecommitdiff
path: root/src/mongo/db
diff options
context:
space:
mode:
authorHenrik Edin <henrik.edin@mongodb.com>2020-05-14 15:38:14 -0400
committerEvergreen Agent <no-reply@evergreen.mongodb.com>2020-05-15 20:44:35 +0000
commit6b38c78843e7eb58dc344d88903727762d7d486d (patch)
treed08071ed14f728761293ec9a1ce37ccf8ac2191b /src/mongo/db
parent2c0306062f074fb35c0554e577401227a45ad811 (diff)
downloadmongo-6b38c78843e7eb58dc344d88903727762d7d486d.tar.gz
SERVER-48148 Cleanup of execution logs in db/
Diffstat (limited to 'src/mongo/db')
-rw-r--r--src/mongo/db/cloner.cpp29
-rw-r--r--src/mongo/db/curop.cpp4
-rw-r--r--src/mongo/db/cursor_manager.cpp19
-rw-r--r--src/mongo/db/db.cpp28
-rw-r--r--src/mongo/db/db_raii.cpp2
-rw-r--r--src/mongo/db/index_builds_coordinator.cpp119
-rw-r--r--src/mongo/db/index_builds_coordinator_mongod.cpp14
-rw-r--r--src/mongo/db/introspect.cpp5
-rw-r--r--src/mongo/db/keys_collection_manager.cpp2
-rw-r--r--src/mongo/db/mongod_options.cpp3
-rw-r--r--src/mongo/db/read_write_concern_defaults_cache_lookup_mongod.cpp27
-rw-r--r--src/mongo/db/repair_database_and_check_version.cpp78
-rw-r--r--src/mongo/db/system_index.cpp13
-rw-r--r--src/mongo/db/ttl.cpp46
14 files changed, 201 insertions, 188 deletions
diff --git a/src/mongo/db/cloner.cpp b/src/mongo/db/cloner.cpp
index ad7aa589bf5..1bde0f1db73 100644
--- a/src/mongo/db/cloner.cpp
+++ b/src/mongo/db/cloner.cpp
@@ -130,7 +130,7 @@ struct Cloner::Fun {
if (now - lastLog >= 60) {
// report progress
if (lastLog)
- LOGV2(20412, "clone", "ns"_attr = nss, "numSeen"_attr = numSeen);
+ LOGV2(20412, "clone", logAttrs(nss), "numSeen"_attr = numSeen);
lastLog = now;
}
opCtx->checkForInterrupt();
@@ -167,12 +167,15 @@ struct Cloner::Fun {
// decimal data even if decimal is disabled.
const Status status = validateBSON(tmp.objdata(), tmp.objsize(), BSONVersion::kLatest);
if (!status.isOK()) {
- str::stream ss;
- ss << "Cloner: found corrupt document in " << nss << ": " << redact(status);
if (gSkipCorruptDocumentsWhenCloning.load()) {
- LOGV2_WARNING(20423, "{ss_ss_str}; skipping", "ss_ss_str"_attr = ss.ss.str());
+ LOGV2_WARNING(20423,
+ "Cloner: found corrupt document; skipping",
+ logAttrs(nss),
+ "error"_attr = redact(status));
continue;
}
+ str::stream ss;
+ ss << "Cloner: found corrupt document in " << nss << ": " << redact(status);
msgasserted(28531, ss);
}
@@ -191,9 +194,10 @@ struct Cloner::Fun {
if (!status.isOK() && status.code() != ErrorCodes::DuplicateKey) {
LOGV2_ERROR(20424,
"error: exception cloning object",
- "ns"_attr = nss,
- "status"_attr = redact(status),
- "doc"_attr = redact(doc));
+ "Exception cloning document",
+ logAttrs(nss),
+ "error"_attr = redact(status),
+ "document"_attr = redact(doc));
uassertStatusOK(status);
}
if (status.isOK()) {
@@ -204,9 +208,9 @@ struct Cloner::Fun {
static Rarely sampler;
if (sampler.tick() && (time(nullptr) - saveLast > 60)) {
LOGV2(20413,
- "objects cloned so far from collection",
- "numSeen"_attr = numSeen,
- "ns"_attr = nss);
+ "Number of objects cloned so far from collection",
+ "number"_attr = numSeen,
+ logAttrs(nss));
saveLast = time(nullptr);
}
}
@@ -541,8 +545,9 @@ Status Cloner::copyDb(OperationContext* opCtx,
// now build the secondary indexes
for (auto&& params : createCollectionParams) {
LOGV2(20422,
- "copying indexes for: {params_collectionInfo}",
- "params_collectionInfo"_attr = params.collectionInfo);
+ "copying indexes for: {collectionInfo}",
+ "Copying indexes",
+ "collectionInfo"_attr = params.collectionInfo);
const NamespaceString nss(dBName, params.collectionName);
diff --git a/src/mongo/db/curop.cpp b/src/mongo/db/curop.cpp
index 8a9ef9be44d..d437ebd87e8 100644
--- a/src/mongo/db/curop.cpp
+++ b/src/mongo/db/curop.cpp
@@ -478,7 +478,7 @@ bool CurOp::completeAndLogOperation(OperationContext* opCtx,
"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);
+ "error"_attr = "lock acquire timeout"_sd);
}
} catch (const ExceptionForCat<ErrorCategory::Interruption>& ex) {
LOGV2_WARNING_OPTIONS(
@@ -487,7 +487,7 @@ bool CurOp::completeAndLogOperation(OperationContext* opCtx,
"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));
+ "error"_attr = redact(ex));
}
}
diff --git a/src/mongo/db/cursor_manager.cpp b/src/mongo/db/cursor_manager.cpp
index 7e6cf8c29e9..87b3a766fea 100644
--- a/src/mongo/db/cursor_manager.cpp
+++ b/src/mongo/db/cursor_manager.cpp
@@ -90,7 +90,10 @@ std::pair<Status, int> CursorManager::killCursorsWithMatchingSessions(
OperationContext* opCtx, const SessionKiller::Matcher& matcher) {
auto eraser = [&](CursorManager& mgr, CursorId id) {
uassertStatusOK(mgr.killCursor(opCtx, id, true));
- LOGV2(20528, "killing cursor: {id} as part of killing session(s)", "id"_attr = id);
+ LOGV2(20528,
+ "killing cursor: {id} as part of killing session(s)",
+ "Killing cursor as part of killing session(s)",
+ "cursorId"_attr = id);
};
auto bySessionCursorKiller = makeKillCursorsBySessionAdaptor(opCtx, matcher, std::move(eraser));
@@ -145,9 +148,10 @@ std::size_t CursorManager::timeoutCursors(OperationContext* opCtx, Date_t now) {
// Be careful not to dispose of cursors while holding the partition lock.
for (auto&& cursor : toDisposeWithoutMutex) {
LOGV2(20529,
- "Cursor id {cursor_cursorid} timed out, idle since {cursor_getLastUseDate}",
- "cursor_cursorid"_attr = cursor->cursorid(),
- "cursor_getLastUseDate"_attr = cursor->getLastUseDate());
+ "Cursor id {cursorId} timed out, idle since {idleSince}",
+ "Cursor timed out",
+ "cursorId"_attr = cursor->cursorid(),
+ "idleSince"_attr = cursor->getLastUseDate());
cursor->dispose(opCtx);
}
return toDisposeWithoutMutex.size();
@@ -218,9 +222,10 @@ void CursorManager::unpin(OperationContext* opCtx,
// will see the reason the cursor was killed when asking for the next batch.
if (interruptStatus == ErrorCodes::Interrupted || interruptStatus == ErrorCodes::CursorKilled) {
LOGV2(20530,
- "removing cursor {cursor_cursorid} after completing batch: {interruptStatus}",
- "cursor_cursorid"_attr = cursor->cursorid(),
- "interruptStatus"_attr = interruptStatus);
+ "removing cursor {cursor_cursorid} after completing batch: {status}",
+ "Removing cursor after completing batch",
+ "cursorId"_attr = cursor->cursorid(),
+ "status"_attr = interruptStatus);
return deregisterAndDestroyCursor(std::move(partition), opCtx, std::move(cursor));
} else if (!interruptStatus.isOK()) {
cursor->markAsKilled(interruptStatus);
diff --git a/src/mongo/db/db.cpp b/src/mongo/db/db.cpp
index bb2816ed19c..bc4554893f6 100644
--- a/src/mongo/db/db.cpp
+++ b/src/mongo/db/db.cpp
@@ -663,28 +663,12 @@ ExitCode _initAndListen(ServiceContext* serviceContext, int listenPort) {
LOGV2_WARNING_OPTIONS(
20547,
{logv2::LogTag::kStartupWarnings},
- "** WARNING: mongod started without --replSet yet document(s) are present in "
- "{namespace}",
- "Document(s) exist in replSet namespace, but started without --replSet",
- "namespace"_attr = NamespaceString::kSystemReplSetNamespace);
- LOGV2_WARNING_OPTIONS(20548,
- {logv2::LogTag::kStartupWarnings},
- "** Database contents may appear inconsistent with the "
- "oplog and may appear to not contain");
- LOGV2_WARNING_OPTIONS(20549,
- {logv2::LogTag::kStartupWarnings},
- "** writes that were visible when this node was "
- "running as part of a replica set");
- LOGV2_WARNING_OPTIONS(20550,
- {logv2::LogTag::kStartupWarnings},
- "** Restart with --replSet unless you are doing "
- "maintenance and no other clients are connected");
- LOGV2_WARNING_OPTIONS(
- 20551,
- {logv2::LogTag::kStartupWarnings},
- "** The TTL collection monitor will not start because of this");
- LOGV2(20553,
- "** For more info see http://dochub.mongodb.org/core/ttlcollections");
+ "Document(s) exist in 'system.replset', but started without --replSet. Database "
+ "contents may appear inconsistent with the writes that were visible when this node "
+ "was running as part of a replica set. Restart with --replSet unless you are doing "
+ "maintenance and no other clients are connected. The TTL collection monitor will "
+ "not start because of this. For more info see "
+ "http://dochub.mongodb.org/core/ttlcollections");
} else {
startTTLMonitor(serviceContext);
}
diff --git a/src/mongo/db/db_raii.cpp b/src/mongo/db/db_raii.cpp
index f15adadabf3..6ee5e14d142 100644
--- a/src/mongo/db/db_raii.cpp
+++ b/src/mongo/db/db_raii.cpp
@@ -195,7 +195,7 @@ AutoGetCollectionForRead::AutoGetCollectionForRead(OperationContext* opCtx,
invariant(readTimestamp);
LOGV2(20576,
"Tried reading at no-overlap time, but future catalog changes are pending. "
- "Trying again without reading at no-overlap time.",
+ "Trying again without reading at no-overlap time",
"noOverlapTimestamp"_attr = *readTimestamp,
"collection"_attr = nss.ns(),
"collectionMinSnapshot"_attr = *minSnapshot);
diff --git a/src/mongo/db/index_builds_coordinator.cpp b/src/mongo/db/index_builds_coordinator.cpp
index c2a5ebdaed8..8cb25a3c15b 100644
--- a/src/mongo/db/index_builds_coordinator.cpp
+++ b/src/mongo/db/index_builds_coordinator.cpp
@@ -63,6 +63,8 @@
#include "mongo/util/assert_util.h"
#include "mongo/util/str.h"
+#include <boost/iterator/transform_iterator.hpp>
+
namespace mongo {
MONGO_FAIL_POINT_DEFINE(hangAfterIndexBuildFirstDrain);
@@ -186,7 +188,7 @@ void removeIndexBuildEntryAfterCommitOrAbort(OperationContext* opCtx,
"Unable to remove index build from system collection. Ignoring error",
"buildUUID"_attr = replState.buildUUID,
"collectionUUID"_attr = replState.collectionUUID,
- "status"_attr = status);
+ "error"_attr = status);
}
}
@@ -273,9 +275,9 @@ void logFailure(Status status,
LOGV2(20649,
"Index build failed",
"buildUUID"_attr = replState->buildUUID,
- "collection"_attr = nss,
- "collectionUUID"_attr = replState->collectionUUID,
- "status"_attr = status);
+ "namespace"_attr = nss,
+ "uuid"_attr = replState->collectionUUID,
+ "error"_attr = status);
}
/**
@@ -438,9 +440,11 @@ Status IndexBuildsCoordinator::_startIndexBuildForRecovery(OperationContext* opC
opCtx, collection->getCatalogId(), indexNames[i])) {
LOGV2(20652,
"The index for build {buildUUID} was not found while trying to drop the "
- "index during recovery: {indexNames_i}",
+ "index during recovery: {index}",
+ "An index was not found in the catalog while trying to drop the index during "
+ "recovery",
"buildUUID"_attr = buildUUID,
- "indexNames_i"_attr = indexNames[i]);
+ "index"_attr = indexNames[i]);
continue;
}
@@ -539,12 +543,12 @@ void IndexBuildsCoordinator::waitForAllIndexBuildsToStopForShutdown(OperationCon
return;
}
+ auto indexBuildToUUID = [](const auto& indexBuild) { return indexBuild.first; };
+ auto begin = boost::make_transform_iterator(_allIndexBuilds.begin(), indexBuildToUUID);
+ auto end = boost::make_transform_iterator(_allIndexBuilds.end(), indexBuildToUUID);
LOGV2(4725201,
- "Waiting until the following index builds are finished:",
- "numIndexBuilds"_attr = _allIndexBuilds.size());
- for (const auto& indexBuild : _allIndexBuilds) {
- LOGV2(4725202, " Index build with UUID", "indexBuild_first"_attr = indexBuild.first);
- }
+ "Waiting until the following index builds are finished",
+ "indexBuilds"_attr = logv2::seqLog(begin, end));
// Wait for all the index builds to stop.
auto pred = [this]() { return _allIndexBuilds.empty(); };
@@ -557,9 +561,9 @@ std::vector<UUID> IndexBuildsCoordinator::abortCollectionIndexBuilds(
const UUID collectionUUID,
const std::string& reason) {
LOGV2(23879,
- "About to abort all index builders on collection",
- "collection"_attr = collectionNss,
- "collectionUUID"_attr = collectionUUID,
+ "About to abort all index builders",
+ "namespace"_attr = collectionNss,
+ "uuid"_attr = collectionUUID,
"reason"_attr = reason);
auto collIndexBuilds = [&]() -> std::vector<std::shared_ptr<ReplIndexBuildState>> {
@@ -812,11 +816,12 @@ boost::optional<UUID> IndexBuildsCoordinator::abortIndexBuildByIndexNames(
}
LOGV2(23880,
- "About to abort index builder: {replState_buildUUID} on collection: "
- "{collectionUUID}. First index: {replState_indexNames_front}",
- "replState_buildUUID"_attr = replState->buildUUID,
+ "About to abort index builder: {buildUUID} on collection: "
+ "{collectionUUID}. First index: {firstIndex}",
+ "About to abort index builder",
+ "buildUUID"_attr = replState->buildUUID,
"collectionUUID"_attr = collectionUUID,
- "replState_indexNames_front"_attr = replState->indexNames.front());
+ "firstIndex"_attr = replState->indexNames.front());
if (abortIndexBuildByBuildUUID(
opCtx, replState->buildUUID, IndexBuildAction::kPrimaryAbort, reason)) {
@@ -901,7 +906,7 @@ IndexBuildsCoordinator::TryAbortResult IndexBuildsCoordinator::_tryAbort(
LOGV2(4656003,
"Aborting index build",
"buildUUID"_attr = replState->buildUUID,
- "reason"_attr = reason);
+ "error"_attr = reason);
// Set the state on replState. Once set, the calling thread must complete the abort process.
auto abortTimestamp =
@@ -952,15 +957,15 @@ bool IndexBuildsCoordinator::abortIndexBuildByBuildUUID(OperationContext* opCtx,
auto replStateResult = _getIndexBuild(buildUUID);
if (!replStateResult.isOK()) {
LOGV2(20656,
- "ignoring error while aborting index build {buildUUID}: "
- "{replStateResult_getStatus}",
+ "ignoring error while aborting index build {buildUUID}: {error}",
+ "Ignoring error while aborting index build",
"buildUUID"_attr = buildUUID,
- "replStateResult_getStatus"_attr = replStateResult.getStatus());
+ "error"_attr = replStateResult.getStatus());
return false;
}
replState = replStateResult.getValue();
- LOGV2(4656010, "attempting to abort index build", "buildUUID"_attr = replState->buildUUID);
+ LOGV2(4656010, "Attempting to abort index build", "buildUUID"_attr = replState->buildUUID);
const NamespaceStringOrUUID dbAndUUID(replState->dbName, replState->collectionUUID);
Lock::DBLock dbLock(opCtx, replState->dbName, MODE_IX);
@@ -1219,7 +1224,7 @@ void IndexBuildsCoordinator::onStepUp(OperationContext* opCtx) {
}
IndexBuilds IndexBuildsCoordinator::stopIndexBuildsForRollback(OperationContext* opCtx) {
- LOGV2(20658, "stopping index builds before rollback");
+ LOGV2(20658, "Stopping index builds before rollback");
IndexBuilds buildsStopped;
@@ -1227,7 +1232,7 @@ IndexBuilds IndexBuildsCoordinator::stopIndexBuildsForRollback(OperationContext*
auto onIndexBuild = [&](std::shared_ptr<ReplIndexBuildState> replState) {
if (IndexBuildProtocol::kSinglePhase == replState->protocol) {
LOGV2(20659,
- "not stopping single phase index build",
+ "Not stopping single phase index build",
"buildUUID"_attr = replState->buildUUID);
return;
}
@@ -1503,6 +1508,7 @@ Status IndexBuildsCoordinator::_registerIndexBuild(
std::find(existingIndexBuild->indexNames.begin(),
existingIndexBuild->indexNames.end(),
name)) {
+
str::stream ss;
ss << "Index build conflict: " << replIndexBuildState->buildUUID
<< ": There's already an index with name '" << name
@@ -1510,23 +1516,30 @@ Status IndexBuildsCoordinator::_registerIndexBuild(
<< " ( " << replIndexBuildState->collectionUUID
<< " ) under an existing index build: " << existingIndexBuild->buildUUID;
auto aborted = false;
+ IndexBuildState existingIndexBuildState;
{
// We have to lock the mutex in order to read the committed/aborted state.
stdx::unique_lock<Latch> lkExisting(existingIndexBuild->mutex);
- ss << " index build state: " << existingIndexBuild->indexBuildState.toString();
- if (auto ts = existingIndexBuild->indexBuildState.getTimestamp()) {
- ss << ", timestamp: " << ts->toString();
- }
- if (existingIndexBuild->indexBuildState.isAborted()) {
- if (auto abortReason =
- existingIndexBuild->indexBuildState.getAbortReason()) {
- ss << ", abort reason: " << abortReason.get();
- }
- aborted = true;
+ existingIndexBuildState = existingIndexBuild->indexBuildState;
+ }
+ ss << " index build state: " << existingIndexBuildState.toString();
+ if (auto ts = existingIndexBuildState.getTimestamp()) {
+ ss << ", timestamp: " << ts->toString();
+ }
+ if (existingIndexBuildState.isAborted()) {
+ if (auto abortReason = existingIndexBuildState.getAbortReason()) {
+ ss << ", abort reason: " << abortReason.get();
}
+ aborted = true;
}
std::string msg = ss;
- LOGV2(20661, "{msg}", "msg"_attr = msg);
+ LOGV2(20661,
+ "Index build conflict. There's already an index with the same name being "
+ "built under an existing index build",
+ "buildUUID"_attr = replIndexBuildState->buildUUID,
+ "existingBuildUUID"_attr = existingIndexBuild->buildUUID,
+ "index"_attr = name,
+ "collectionUUID"_attr = replIndexBuildState->collectionUUID);
if (aborted) {
return {ErrorCodes::IndexBuildAborted, msg};
}
@@ -2309,7 +2322,7 @@ IndexBuildsCoordinator::CommitResult IndexBuildsCoordinator::_insertKeysFromSide
repl::UnreplicatedWritesBlock uwb(opCtx);
if (!IndexTimestampHelper::setGhostCommitTimestampForCatalogWrite(opCtx,
collection->ns())) {
- LOGV2(20672, "Did not timestamp index commit write.");
+ LOGV2(20672, "Did not timestamp index commit write");
}
return;
}
@@ -2329,8 +2342,8 @@ IndexBuildsCoordinator::CommitResult IndexBuildsCoordinator::_insertKeysFromSide
LOGV2(20663,
"Index build completed successfully",
"buildUUID"_attr = replState->buildUUID,
- "collection"_attr = collection->ns(),
- "collectionUUID"_attr = replState->collectionUUID,
+ "namespace"_attr = collection->ns(),
+ "uuid"_attr = replState->collectionUUID,
"indexesBuilt"_attr = replState->indexSpecs.size(),
"numIndexesBefore"_attr = replState->stats.numIndexesBefore,
"numIndexesAfter"_attr = replState->stats.numIndexesAfter);
@@ -2361,9 +2374,10 @@ StatusWith<std::pair<long long, long long>> IndexBuildsCoordinator::_runIndexReb
try {
LOGV2(20673,
- "Index builds manager starting: {buildUUID}: {nss}",
+ "Index builds manager starting: {buildUUID}: {namespace}",
+ "Index builds manager starting",
"buildUUID"_attr = buildUUID,
- "nss"_attr = nss);
+ logAttrs(nss));
std::tie(numRecords, dataSize) =
uassertStatusOK(_indexBuildsManager.startBuildingIndexForRecovery(
@@ -2383,23 +2397,24 @@ StatusWith<std::pair<long long, long long>> IndexBuildsCoordinator::_runIndexReb
indexCatalogStats.numIndexesAfter = getNumIndexesTotal(opCtx, collection);
LOGV2(20674,
- "Index builds manager completed successfully: {buildUUID}: {nss}. Index specs "
- "requested: {replState_indexSpecs_size}. Indexes in catalog before build: "
- "{indexCatalogStats_numIndexesBefore}. Indexes in catalog after build: "
- "{indexCatalogStats_numIndexesAfter}",
+ "Index builds manager completed successfully: {buildUUID}: {namespace}. Index specs "
+ "requested: {indexSpecsRequested}. Indexes in catalog before build: "
+ "{numIndexesBefore}. Indexes in catalog after build: {numIndexesAfter}",
+ "Index builds manager completed successfully",
"buildUUID"_attr = buildUUID,
- "nss"_attr = nss,
- "replState_indexSpecs_size"_attr = replState->indexSpecs.size(),
- "indexCatalogStats_numIndexesBefore"_attr = indexCatalogStats.numIndexesBefore,
- "indexCatalogStats_numIndexesAfter"_attr = indexCatalogStats.numIndexesAfter);
+ logAttrs(nss),
+ "indexSpecsRequested"_attr = replState->indexSpecs.size(),
+ "numIndexesBefore"_attr = indexCatalogStats.numIndexesBefore,
+ "numIndexesAfter"_attr = indexCatalogStats.numIndexesAfter);
} catch (const DBException& ex) {
status = ex.toStatus();
invariant(status != ErrorCodes::IndexAlreadyExists);
LOGV2(20675,
- "Index builds manager failed: {buildUUID}: {nss}: {status}",
+ "Index builds manager failed: {buildUUID}: {namespace}: {error}",
+ "Index builds manager failed",
"buildUUID"_attr = buildUUID,
- "nss"_attr = nss,
- "status"_attr = status);
+ logAttrs(nss),
+ "error"_attr = status);
}
// Index build is registered in manager regardless of IndexBuildsManager::setUpIndexBuild()
diff --git a/src/mongo/db/index_builds_coordinator_mongod.cpp b/src/mongo/db/index_builds_coordinator_mongod.cpp
index d60502f395a..0ce98a322e7 100644
--- a/src/mongo/db/index_builds_coordinator_mongod.cpp
+++ b/src/mongo/db/index_builds_coordinator_mongod.cpp
@@ -302,7 +302,7 @@ IndexBuildsCoordinatorMongod::startIndexBuild(OperationContext* opCtx,
CurOp::get(opCtx.get())
->completeAndLogOperation(opCtx.get(), MONGO_LOGV2_DEFAULT_COMPONENT);
} catch (const DBException& e) {
- LOGV2(4656002, "unable to log operation", "reason"_attr = e);
+ LOGV2(4656002, "unable to log operation", "error"_attr = e);
}
});
@@ -392,11 +392,12 @@ void IndexBuildsCoordinatorMongod::_sendCommitQuorumSatisfiedSignal(
auto action = replState->waitForNextAction->getFuture().get(opCtx);
LOGV2(3856200,
- "Not signaling \"{signalAction}\" as it was previously signaled with "
- "\"{signalActionSet}\" for index build: {buildUUID}",
- "signalAction"_attr =
+ "Not signaling \"{skippedAction}\" as it was previously signaled with "
+ "\"{previousAction}\" for index build: {buildUUID}",
+ "Skipping signaling as it was previously signaled for index build",
+ "skippedAction"_attr =
_indexBuildActionToString(IndexBuildAction::kCommitQuorumSatisfied),
- "signalActionSet"_attr = _indexBuildActionToString(action),
+ "previousAction"_attr = _indexBuildActionToString(action),
"buildUUID"_attr = replState->buildUUID);
}
}
@@ -425,8 +426,7 @@ void IndexBuildsCoordinatorMongod::_signalIfCommitQuorumIsSatisfied(
if (!commitQuorumSatisfied)
return;
- LOGV2(
- 3856201, "Index build commit quorum satisfied:", "indexBuildEntry"_attr = indexBuildEntry);
+ LOGV2(3856201, "Index build commit quorum satisfied", "indexBuildEntry"_attr = indexBuildEntry);
_sendCommitQuorumSatisfiedSignal(opCtx, replState);
}
diff --git a/src/mongo/db/introspect.cpp b/src/mongo/db/introspect.cpp
index a67929ff9b4..41598963c5f 100644
--- a/src/mongo/db/introspect.cpp
+++ b/src/mongo/db/introspect.cpp
@@ -203,8 +203,9 @@ Status createProfileCollection(OperationContext* opCtx, Database* db) {
// system.profile namespace doesn't exist; create it
LOGV2(20701,
- "Creating profile collection: {dbProfilingNS}",
- "dbProfilingNS"_attr = dbProfilingNS);
+ "Creating profile collection: {namespace}",
+ "Creating profile collection",
+ "namespace"_attr = dbProfilingNS);
CollectionOptions collectionOptions;
collectionOptions.capped = true;
diff --git a/src/mongo/db/keys_collection_manager.cpp b/src/mongo/db/keys_collection_manager.cpp
index 8b40033705f..dd3277bdd1b 100644
--- a/src/mongo/db/keys_collection_manager.cpp
+++ b/src/mongo/db/keys_collection_manager.cpp
@@ -182,7 +182,7 @@ void KeysCollectionManager::enableKeyGenerator(OperationContext* opCtx, bool doE
opCtx, [this](OperationContext* opCtx) { return _keysCache.refresh(opCtx); });
}
} catch (const ExceptionForCat<ErrorCategory::ShutdownError>& ex) {
- LOGV2(518091, "{ex}, doEnable = {doEnable}", "ex"_attr = ex, "doEnable"_attr = doEnable);
+ LOGV2(518091, "Exception during key generation", "error"_attr = ex, "enable"_attr = doEnable);
return;
}
diff --git a/src/mongo/db/mongod_options.cpp b/src/mongo/db/mongod_options.cpp
index df10b0ec4b9..0957953cf05 100644
--- a/src/mongo/db/mongod_options.cpp
+++ b/src/mongo/db/mongod_options.cpp
@@ -624,12 +624,9 @@ Status storeMongodOptions(const moe::Environment& params) {
// Check if we are 32 bit and have not explicitly specified any journaling options
if (sizeof(void*) == 4 && !params.count("storage.journal.enabled")) {
- // trying to make this stand out more like startup warnings
- LOGV2(20877, "");
LOGV2_WARNING(20880,
"32-bit servers don't have journaling enabled by default. Please use "
"--journal if you want durability");
- LOGV2(20878, "");
}
bool isClusterRoleShard = params.count("shardsvr");
diff --git a/src/mongo/db/read_write_concern_defaults_cache_lookup_mongod.cpp b/src/mongo/db/read_write_concern_defaults_cache_lookup_mongod.cpp
index de1d5858d87..72ed4b8e9b7 100644
--- a/src/mongo/db/read_write_concern_defaults_cache_lookup_mongod.cpp
+++ b/src/mongo/db/read_write_concern_defaults_cache_lookup_mongod.cpp
@@ -72,22 +72,17 @@ void readWriteConcernDefaultsMongodStartupChecks(OperationContext* opCtx) {
client.count(NamespaceString::kConfigSettingsNamespace,
BSON("_id" << ReadWriteConcernDefaults::kPersistedDocumentId));
if (numPersistedDocuments != 0) {
- LOGV2_OPTIONS(4615612, {logv2::LogTag::kStartupWarnings}, "");
- LOGV2_OPTIONS(4615613,
- {logv2::LogTag::kStartupWarnings},
- "** WARNING: This node is running as a shard server, but persisted "
- "Read/Write Concern (RWC) defaults");
- LOGV2_OPTIONS(4615614,
- {logv2::LogTag::kStartupWarnings},
- "** are present in {configSettingsNamespace}. This node was "
- "likely previously in an unsharded",
- "configSettingsNamespace"_attr =
- NamespaceString::kConfigSettingsNamespace);
- LOGV2_OPTIONS(4615615,
- {logv2::LogTag::kStartupWarnings},
- "** replica set or a config server. The RWC defaults on this "
- "node will not be used.");
- LOGV2_OPTIONS(4615616, {logv2::LogTag::kStartupWarnings}, "");
+ LOGV2_OPTIONS(
+ 4615613,
+ {logv2::LogTag::kStartupWarnings},
+ "This node is running as a shard server, but persisted Read/Write Concern (RWC) "
+ "defaults are present in {configSettingsNamespace}. This node was likely "
+ "previously in an unsharded replica set or a config server. The RWC defaults on "
+ "this node will not be used",
+ "This node is running as a shard server, but persisted Read/Write Concern (RWC) "
+ "defaults are present. This node was likely previously in an unsharded replica set "
+ "or a config server. The RWC defaults on this node will not be used",
+ "configSettingsNamespace"_attr = NamespaceString::kConfigSettingsNamespace);
}
}
}
diff --git a/src/mongo/db/repair_database_and_check_version.cpp b/src/mongo/db/repair_database_and_check_version.cpp
index 1dee5676265..fb7a10d7556 100644
--- a/src/mongo/db/repair_database_and_check_version.cpp
+++ b/src/mongo/db/repair_database_and_check_version.cpp
@@ -119,8 +119,8 @@ Status restoreMissingFeatureCompatibilityVersionDocument(OperationContext* opCtx
"Re-creating featureCompatibilityVersion document that was deleted. Creating new "
"document with version "
"{FeatureCompatibilityVersionParser_kVersion44}.",
- "FeatureCompatibilityVersionParser_kVersion44"_attr =
- FeatureCompatibilityVersionParser::kVersion44);
+ "Re-creating featureCompatibilityVersion document that was deleted",
+ "version"_attr = FeatureCompatibilityVersionParser::kVersion44);
BSONObj fcvObj = BSON("_id" << FeatureCompatibilityVersionParser::kParameterName
<< FeatureCompatibilityVersionParser::kVersionField
@@ -232,13 +232,15 @@ Status ensureCollectionProperties(OperationContext* opCtx,
!checkIdIndexExists(opCtx, coll->getCatalogId())) {
LOGV2(21001,
"collection {coll_ns} is missing an _id index; building it now",
- "coll_ns"_attr = coll->ns());
+ "Collection is missing an _id index; building it now",
+ logAttrs(*coll));
auto status = buildMissingIdIndex(opCtx, coll);
if (!status.isOK()) {
LOGV2_ERROR(21021,
"could not build an _id index on collection {coll_ns}: {status}",
- "coll_ns"_attr = coll->ns(),
- "status"_attr = status);
+ "Could not build an _id index on collection",
+ logAttrs(*coll),
+ "error"_attr = status);
return downgradeError;
}
}
@@ -269,10 +271,13 @@ void checkForCappedOplog(OperationContext* opCtx, Database* db) {
Collection* oplogCollection =
CollectionCatalog::get(opCtx).lookupCollectionByNamespace(opCtx, oplogNss);
if (oplogCollection && !oplogCollection->isCapped()) {
- LOGV2_FATAL_NOTRACE(40115,
- "The oplog collection {oplogNss} is not capped; a capped oplog is a "
- "requirement for replication to function.",
- "oplogNss"_attr = oplogNss);
+ LOGV2_FATAL_NOTRACE(
+ 40115,
+ "The oplog collection {oplogNamespace} is not capped; a capped oplog is a "
+ "requirement for replication to function.",
+ "The oplog collection is not capped; a capped oplog is a "
+ "requirement for replication to function.",
+ "oplogNamespace"_attr = oplogNss);
}
}
@@ -534,9 +539,12 @@ bool repairDatabasesAndCheckVersion(OperationContext* opCtx) {
LOGV2_FATAL_CONTINUE(
21023,
"Unable to start mongod due to an incompatibility with the data files and"
- " this version of mongod: {status}. Please consult our documentation when trying "
+ " this version of mongod: {error}. Please consult our documentation when trying "
"to downgrade to a previous major release",
- "status"_attr = redact(status));
+ "Unable to start mongod due to an incompatibility with the data files and"
+ " this version of mongod. Please consult our documentation when trying "
+ "to downgrade to a previous major release",
+ "error"_attr = redact(status));
quickExit(EXIT_NEED_UPGRADE);
MONGO_UNREACHABLE;
}
@@ -577,39 +585,33 @@ bool repairDatabasesAndCheckVersion(OperationContext* opCtx) {
// warning.
if (version ==
ServerGlobalParams::FeatureCompatibility::Version::kUpgradingTo46) {
- LOGV2_OPTIONS(
+ LOGV2_WARNING_OPTIONS(
21011,
{logv2::LogTag::kStartupWarnings},
- "** WARNING: A featureCompatibilityVersion upgrade did not complete. ");
- LOGV2_OPTIONS(21012,
- {logv2::LogTag::kStartupWarnings},
- "** The current featureCompatibilityVersion is "
- "{FeatureCompatibilityVersionParser_version}.",
- "FeatureCompatibilityVersionParser_version"_attr =
- FeatureCompatibilityVersionParser::toString(version));
- LOGV2_OPTIONS(
- 21013,
- {logv2::LogTag::kStartupWarnings},
- "** To fix this, use the setFeatureCompatibilityVersion "
- "command to resume upgrade to 4.6.");
+ "A featureCompatibilityVersion upgrade did not complete. The current "
+ "featureCompatibilityVersion is "
+ "{currentfeatureCompatibilityVersion}. To fix this, use the "
+ "setFeatureCompatibilityVersion command to resume upgrade to 4.6.",
+ "A featureCompatibilityVersion upgrade did not complete. To fix this, "
+ "use the "
+ "setFeatureCompatibilityVersion command to resume upgrade to 4.6",
+ "currentfeatureCompatibilityVersion"_attr =
+ FeatureCompatibilityVersionParser::toString(version));
} else if (version ==
ServerGlobalParams::FeatureCompatibility::Version::
kDowngradingTo44) {
- LOGV2_OPTIONS(21014,
- {logv2::LogTag::kStartupWarnings},
- "** WARNING: A featureCompatibilityVersion downgrade did not "
- "complete. ");
- LOGV2_OPTIONS(21015,
- {logv2::LogTag::kStartupWarnings},
- "** The current featureCompatibilityVersion is "
- "{FeatureCompatibilityVersionParser_version}.",
- "FeatureCompatibilityVersionParser_version"_attr =
- FeatureCompatibilityVersionParser::toString(version));
- LOGV2_OPTIONS(
- 21016,
+ LOGV2_WARNING_OPTIONS(
+ 21014,
{logv2::LogTag::kStartupWarnings},
- "** To fix this, use the setFeatureCompatibilityVersion "
- "command to resume downgrade to 4.4.");
+ "A featureCompatibilityVersion downgrade did not complete. The current "
+ "featureCompatibilityVersion is "
+ "{currentfeatureCompatibilityVersion}. To fix this, use the "
+ "setFeatureCompatibilityVersion command to resume downgrade to 4.4.",
+ "A featureCompatibilityVersion downgrade did not complete. To fix "
+ "this, use the setFeatureCompatibilityVersion command to resume "
+ "downgrade to 4.4",
+ "currentfeatureCompatibilityVersion"_attr =
+ FeatureCompatibilityVersionParser::toString(version));
}
}
}
diff --git a/src/mongo/db/system_index.cpp b/src/mongo/db/system_index.cpp
index 3802d0135e2..1df26d10abe 100644
--- a/src/mongo/db/system_index.cpp
+++ b/src/mongo/db/system_index.cpp
@@ -107,9 +107,11 @@ void generateSystemIndexForExistingCollection(OperationContext* opCtx,
BSONObj indexSpec = fassert(40452, indexSpecStatus);
LOGV2(22488,
- "No authorization index detected on {ns} collection. Attempting to recover by "
+ "No authorization index detected on {namespace} collection. Attempting to recover by "
"creating an index with spec: {indexSpec}",
- "ns"_attr = ns,
+ "No authorization index detected. Attempting to recover by "
+ "creating an index",
+ logAttrs(ns),
"indexSpec"_attr = indexSpec);
auto indexConstraints = IndexBuildsManager::IndexConstraints::kEnforce;
@@ -118,9 +120,10 @@ void generateSystemIndexForExistingCollection(OperationContext* opCtx,
opCtx, collectionUUID, {indexSpec}, indexConstraints, fromMigrate);
} catch (const DBException& e) {
LOGV2_FATAL_CONTINUE(22490,
- "Failed to regenerate index for {ns}. Exception: {e_what}",
- "ns"_attr = ns,
- "e_what"_attr = e.what());
+ "Failed to regenerate index for {namespace}. Exception: {error}",
+ "Failed to regenerate index",
+ logAttrs(ns),
+ "error"_attr = e.what());
throw;
}
}
diff --git a/src/mongo/db/ttl.cpp b/src/mongo/db/ttl.cpp
index a47dad89f0c..1e5be6b1900 100644
--- a/src/mongo/db/ttl.cpp
+++ b/src/mongo/db/ttl.cpp
@@ -240,13 +240,15 @@ private:
LOGV2_WARNING(22537,
"TTLMonitor was interrupted, waiting {ttlMonitorSleepSecs_load} "
"seconds before doing another pass",
- "ttlMonitorSleepSecs_load"_attr = ttlMonitorSleepSecs.load());
+ "TTLMonitor was interrupted, waiting before doing another pass",
+ "wait"_attr = Milliseconds(Seconds(ttlMonitorSleepSecs.load())));
return;
} catch (const DBException& dbex) {
LOGV2_ERROR(22538,
"Error processing ttl index: {it_second} -- {dbex}",
- "it_second"_attr = it.second,
- "dbex"_attr = dbex.toString());
+ "Error processing TTL index",
+ "index"_attr = it.second,
+ "error"_attr = dbex);
// Continue on to the next index.
continue;
}
@@ -264,9 +266,10 @@ private:
if (!userAllowedWriteNS(collectionNSS).isOK()) {
LOGV2_ERROR(
22539,
- "namespace '{collectionNSS}' doesn't allow deletes, skipping ttl job for: {idx}",
- "collectionNSS"_attr = collectionNSS,
- "idx"_attr = idx);
+ "namespace '{namespace}' doesn't allow deletes, skipping ttl job for: {index}",
+ "Namespace doesn't allow deletes, skipping TTL job",
+ logAttrs(collectionNSS),
+ "index"_attr = idx);
return;
}
@@ -274,8 +277,9 @@ private:
const StringData name = idx["name"].valueStringData();
if (key.nFields() != 1) {
LOGV2_ERROR(22540,
- "key for ttl index can only have 1 field, skipping ttl job for: {idx}",
- "idx"_attr = idx);
+ "key for ttl index can only have 1 field, skipping ttl job for: {index}",
+ "Key for ttl index can only have 1 field, skipping TTL job",
+ "index"_attr = idx);
return;
}
@@ -319,20 +323,21 @@ private:
if (IndexType::INDEX_BTREE != IndexNames::nameToType(desc->getAccessMethodName())) {
LOGV2_ERROR(22541,
- "special index can't be used as a ttl index, skipping ttl job for: {idx}",
- "idx"_attr = idx);
+ "special index can't be used as a ttl index, skipping ttl job for: {index}",
+ "Special index can't be used as a TTL index, skipping TTL job",
+ "index"_attr = idx);
return;
}
BSONElement secondsExpireElt = idx[IndexDescriptor::kExpireAfterSecondsFieldName];
if (!secondsExpireElt.isNumber()) {
- LOGV2_ERROR(
- 22542,
- "ttl indexes require the {secondsExpireField} field to be numeric but received a "
- "type of {typeName_secondsExpireElt_type}, skipping ttl job for: {idx}",
- "secondsExpireField"_attr = IndexDescriptor::kExpireAfterSecondsFieldName,
- "typeName_secondsExpireElt_type"_attr = typeName(secondsExpireElt.type()),
- "idx"_attr = idx);
+ LOGV2_ERROR(22542,
+ "ttl indexes require the {expireField} field to be numeric but received a "
+ "type of {typeName_secondsExpireElt_type}, skipping ttl job for: {idx}",
+ "TTL indexes require the expire field to be numeric, skipping TTL job",
+ "field"_attr = IndexDescriptor::kExpireAfterSecondsFieldName,
+ "type"_attr = typeName(secondsExpireElt.type()),
+ "index"_attr = idx);
return;
}
@@ -376,9 +381,10 @@ private:
Status result = exec->executePlan();
if (!result.isOK()) {
LOGV2_ERROR(22543,
- "ttl query execution for index {idx} failed with status: {result}",
- "idx"_attr = idx,
- "result"_attr = redact(result));
+ "ttl query execution for index {index} failed with status: {error}",
+ "TTL query execution failed",
+ "index"_attr = idx,
+ "error"_attr = redact(result));
return;
}