diff options
author | Henrik Edin <henrik.edin@mongodb.com> | 2020-05-12 18:33:13 -0400 |
---|---|---|
committer | Evergreen Agent <no-reply@evergreen.mongodb.com> | 2020-05-15 14:07:54 +0000 |
commit | 0da349c13b0e1e23e1d10631ca462f1b92a911e9 (patch) | |
tree | cf22b5ecca6feaced9e74cbdc5e518e496b3aa1f | |
parent | 0e88ea0eccab014918f014b5c858189b1eede4fb (diff) | |
download | mongo-0da349c13b0e1e23e1d10631ca462f1b92a911e9.tar.gz |
SERVER-48148 Log cleanup in db/storage/wiredtiger
10 files changed, 142 insertions, 112 deletions
diff --git a/jstests/replsets/oplog_slow_sampling_logging.js b/jstests/replsets/oplog_slow_sampling_logging.js index 241bdfdcdf6..a2bf9ed17f9 100644 --- a/jstests/replsets/oplog_slow_sampling_logging.js +++ b/jstests/replsets/oplog_slow_sampling_logging.js @@ -52,8 +52,7 @@ assert.commandWorked(replSet.getPrimary().getDB(testDB).serverStatus()); const maxSamplesPerLog = Math.ceil(kLoggingIntervalSeconds / kOplogSampleReadDelay); const minExpectedLogs = Math.floor(kNumOplogSamples / maxSamplesPerLog); -checkLog.containsWithAtLeastCount( - replSet.getPrimary(), "Oplog sampling progress:", minExpectedLogs); +checkLog.containsWithAtLeastCount(replSet.getPrimary(), "Oplog sampling progress", minExpectedLogs); assert(checkLog.checkContainsOnce(replSet.getPrimary(), "Oplog sampling complete")); replSet.stopSet(); diff --git a/src/mongo/db/storage/wiredtiger/wiredtiger_cursor.cpp b/src/mongo/db/storage/wiredtiger/wiredtiger_cursor.cpp index 35f229d80b9..380ed460f25 100644 --- a/src/mongo/db/storage/wiredtiger/wiredtiger_cursor.cpp +++ b/src/mongo/db/storage/wiredtiger/wiredtiger_cursor.cpp @@ -66,8 +66,7 @@ WiredTigerCursor::WiredTigerCursor(const std::string& uri, _cursor = _session->getCachedCursor(uri, tableID, config.c_str()); } } catch (const ExceptionFor<ErrorCodes::CursorNotFound>& ex) { - LOGV2_ERROR(23719, "{ex}", "ex"_attr = ex); - fassertFailedNoTrace(50883); + LOGV2_FATAL_NOTRACE(50883, "{ex}", "Cursor not found", "error"_attr = ex); } } diff --git a/src/mongo/db/storage/wiredtiger/wiredtiger_index.cpp b/src/mongo/db/storage/wiredtiger/wiredtiger_index.cpp index cd4f6ed7113..19a08c40a4b 100644 --- a/src/mongo/db/storage/wiredtiger/wiredtiger_index.cpp +++ b/src/mongo/db/storage/wiredtiger/wiredtiger_index.cpp @@ -584,6 +584,7 @@ protected: LOGV2_WARNING(51783, "failed to create WiredTiger bulk cursor: {error} falling back to non-bulk " "cursor for index {index}", + "Failed to create WiredTiger bulk cursor, falling back to non-bulk", "error"_attr = wiredtiger_strerror(err), "index"_attr = idx->uri()); @@ -1144,6 +1145,7 @@ protected: LOGV2(51790, "WTIndex::updatePosition -- the new key ({newKey}) is less than the previous " "key ({prevKey}), which is a bug.", + "WTIndex::updatePosition -- new key is less than previous key", "newKey"_attr = redact(toHex(item.data, item.size)), "prevKey"_attr = redact(_key.toString())); @@ -1338,6 +1340,7 @@ private: LOGV2_FATAL(28608, "Unique index cursor seeing multiple records for key {key} in index " "{index} ({uri}) belonging to collection {collection}", + "Unique index cursor seeing multiple records for key in index", "key"_attr = redact(curr(kWantKey)->key), "index"_attr = _idx.indexName(), "uri"_attr = _idx.uri(), @@ -1710,8 +1713,9 @@ void WiredTigerIndexUnique::_unindexTimestampUnsafe(OperationContext* opCtx, if (!foundId) { auto key = KeyString::toBson(keyString, _ordering); LOGV2_WARNING(51797, - "{id} not found in index for key {key}", - "id"_attr = id, + "{record} not found in index for key {key}", + "Record not found in index", + "recordId"_attr = id, "key"_attr = redact(key)); return; // nothing to do } diff --git a/src/mongo/db/storage/wiredtiger/wiredtiger_init.cpp b/src/mongo/db/storage/wiredtiger/wiredtiger_init.cpp index 51188726eda..4edee81f671 100644 --- a/src/mongo/db/storage/wiredtiger/wiredtiger_init.cpp +++ b/src/mongo/db/storage/wiredtiger/wiredtiger_init.cpp @@ -79,15 +79,10 @@ public: int ret = statfs(params.dbpath.c_str(), &fs_stats); if (ret == 0 && fs_stats.f_type == EXT4_SUPER_MAGIC) { - LOGV2_OPTIONS(22296, {logv2::LogTag::kStartupWarnings}, ""); - LOGV2_OPTIONS( - 22297, - {logv2::LogTag::kStartupWarnings}, - "** WARNING: Using the XFS filesystem is strongly recommended with the " - "WiredTiger storage engine"); - LOGV2_OPTIONS(22298, + LOGV2_OPTIONS(22297, {logv2::LogTag::kStartupWarnings}, - "** See " + "Using the XFS filesystem is strongly recommended with the " + "WiredTiger storage engine. See " "http://dochub.mongodb.org/core/prodnotes-filesystem"); } } @@ -98,17 +93,10 @@ public: ProcessInfo p; if (p.supported()) { if (cacheMB > memoryThresholdPercentage * p.getMemSizeMB()) { - LOGV2_OPTIONS(22299, {logv2::LogTag::kStartupWarnings}, ""); LOGV2_OPTIONS(22300, {logv2::LogTag::kStartupWarnings}, - "** WARNING: The configured WiredTiger cache size is more than " - "{memoryThresholdPercentage_100}% of available RAM.", - "memoryThresholdPercentage_100"_attr = - memoryThresholdPercentage * 100); - LOGV2_OPTIONS(22301, - {logv2::LogTag::kStartupWarnings}, - "** See " - "http://dochub.mongodb.org/core/faq-memory-diagnostics-wt"); + "The configured WiredTiger cache size is more than 80% of available " + "RAM. See http://dochub.mongodb.org/core/faq-memory-diagnostics-wt"); } } const bool ephemeral = false; diff --git a/src/mongo/db/storage/wiredtiger/wiredtiger_kv_engine.cpp b/src/mongo/db/storage/wiredtiger/wiredtiger_kv_engine.cpp index b9749e79eab..38a155af7d9 100644 --- a/src/mongo/db/storage/wiredtiger/wiredtiger_kv_engine.cpp +++ b/src/mongo/db/storage/wiredtiger/wiredtiger_kv_engine.cpp @@ -529,10 +529,11 @@ WiredTigerKVEngine::WiredTigerKVEngine(const std::string& canonicalName, try { boost::filesystem::create_directory(journalPath); } catch (std::exception& e) { - LOGV2(22312, - "error creating journal dir {journalPath_string} {e_what}", - "journalPath_string"_attr = journalPath.string(), - "e_what"_attr = e.what()); + LOGV2_ERROR(22312, + "error creating journal dir {directory} {error}", + "Error creating journal directory", + "directory"_attr = journalPath.generic_string(), + "error"_attr = e.what()); throw; } } @@ -625,9 +626,10 @@ WiredTigerKVEngine::WiredTigerKVEngine(const std::string& canonicalName, boost::filesystem::remove_all(journalPath); } catch (std::exception& e) { LOGV2_ERROR(22355, - "error removing journal dir {journalPath_string} {e_what}", - "journalPath_string"_attr = journalPath.string(), - "e_what"_attr = e.what()); + "error removing journal dir {directory} {error}", + "Error removing journal directory", + "directory"_attr = journalPath.generic_string(), + "error"_attr = e.what()); throw; } } @@ -799,7 +801,7 @@ void WiredTigerKVEngine::_openWiredTiger(const std::string& path, const std::str } if (!_inRepairMode) { - LOGV2_FATAL_NOTRACE(28595, "Terminating.", "Reason"_attr = wtRCToStatus(ret).reason()); + LOGV2_FATAL_NOTRACE(28595, "Terminating.", "reason"_attr = wtRCToStatus(ret).reason()); } // Always attempt to salvage metadata regardless of error code when in repair mode. @@ -813,8 +815,8 @@ void WiredTigerKVEngine::_openWiredTiger(const std::string& path, const std::str } LOGV2_FATAL_NOTRACE(50947, - "Failed to salvage WiredTiger metadata.", - "Details"_attr = wtRCToStatus(ret).reason()); + "Failed to salvage WiredTiger metadata", + "details"_attr = wtRCToStatus(ret).reason()); } void WiredTigerKVEngine::cleanShutdown() { @@ -975,9 +977,10 @@ Status WiredTigerKVEngine::_rebuildIdent(WT_SESSION* session, const char* uri) { if (filePath) { const boost::filesystem::path corruptFile(filePath->string() + ".corrupt"); LOGV2_WARNING(22352, - "Moving data file {filePath_string} to backup as {corruptFile_string}", - "filePath_string"_attr = filePath->string(), - "corruptFile_string"_attr = corruptFile.string()); + "Moving data file {file} to backup as {backup}", + "Moving data file to backup", + "file"_attr = filePath->generic_string(), + "backup"_attr = corruptFile.generic_string()); auto status = fsyncRename(filePath.get(), corruptFile); if (!status.isOK()) { @@ -985,29 +988,42 @@ Status WiredTigerKVEngine::_rebuildIdent(WT_SESSION* session, const char* uri) { } } - LOGV2_WARNING(22353, "Rebuilding ident {identName}", "identName"_attr = identName); + LOGV2_WARNING(22353, "Rebuilding ident {ident}", "Rebuilding ident", "ident"_attr = identName); // This is safe to call after moving the file because it only reads from the metadata, and not // the data file itself. auto swMetadata = WiredTigerUtil::getMetadataCreate(session, uri); if (!swMetadata.isOK()) { - LOGV2_ERROR(22357, "Failed to get metadata for {uri}", "uri"_attr = uri); - return swMetadata.getStatus(); + auto status = swMetadata.getStatus(); + LOGV2_ERROR(22357, + "Failed to get metadata for {uri}", + "Rebuilding ident failed: failed to get metadata", + "uri"_attr = uri, + "error"_attr = status); + return status; } int rc = session->drop(session, uri, nullptr); if (rc != 0) { - LOGV2_ERROR(22358, "Failed to drop {uri}", "uri"_attr = uri); - return wtRCToStatus(rc); + auto status = wtRCToStatus(rc); + LOGV2_ERROR(22358, + "Failed to drop {uri}", + "Rebuilding ident failed: failed to drop", + "uri"_attr = uri, + "error"_attr = status); + return status; } rc = session->create(session, uri, swMetadata.getValue().c_str()); if (rc != 0) { + auto status = wtRCToStatus(rc); LOGV2_ERROR(22359, - "Failed to create {uri} with config: {swMetadata_getValue}", + "Failed to create {uri} with config: {config}", + "Rebuilding ident failed: failed to create with config", "uri"_attr = uri, - "swMetadata_getValue"_attr = swMetadata.getValue()); - return wtRCToStatus(rc); + "config"_attr = swMetadata.getValue(), + "error"_attr = status); + return status; } LOGV2(22329, "Successfully re-created table", "uri"_attr = uri); return {ErrorCodes::DataModifiedByRepair, @@ -1469,19 +1485,20 @@ Status WiredTigerKVEngine::recoverOrphanedIdent(OperationContext* opCtx, tmpFile += ".tmp"; LOGV2(22332, - "{Renaming_data_file_identFilePath_string_to_temporary_file_tmpFile_string}", - "Renaming_data_file_identFilePath_string_to_temporary_file_tmpFile_string"_attr = - "Renaming data file " + identFilePath->string() + " to temporary file " + - tmpFile.string()); + "Renaming data file {file} to temporary file {temporary}", + "Renaming data file to temporary", + "file"_attr = identFilePath->generic_string(), + "temporary"_attr = tmpFile.generic_string()); auto status = fsyncRename(identFilePath.get(), tmpFile); if (!status.isOK()) { return status; } LOGV2(22333, - "Creating new RecordStore for collection {nss} with UUID: {options_uuid}", - "nss"_attr = nss, - "options_uuid"_attr = options.uuid); + "Creating new RecordStore for collection {namespace} with UUID: {uuid}", + "Creating new RecordStore", + "namespace"_attr = nss, + "uuid"_attr = options.uuid); status = createGroupedRecordStore(opCtx, nss.ns(), ident, options, KVPrefix::kNotPrefixed); if (!status.isOK()) { @@ -1489,9 +1506,9 @@ Status WiredTigerKVEngine::recoverOrphanedIdent(OperationContext* opCtx, } LOGV2(22334, - "{Moving_orphaned_data_file_back_as_identFilePath_string}", - "Moving_orphaned_data_file_back_as_identFilePath_string"_attr = - "Moving orphaned data file back as " + identFilePath->string()); + "Moving orphaned data file back as {file}", + "Restoring orphaned data file" + "file"_attr = identFilePath->generic_string()); boost::filesystem::remove(*identFilePath, ec); if (ec) { @@ -1507,9 +1524,7 @@ Status WiredTigerKVEngine::recoverOrphanedIdent(OperationContext* opCtx, return status; } - LOGV2(22335, - "{Salvaging_ident_ident}", - "Salvaging_ident_ident"_attr = "Salvaging ident " + ident); + LOGV2(22335, "Salvaging ident {ident}", "Salvaging ident", "ident"_attr = ident); WiredTigerSession sessionWrapper(_conn); WT_SESSION* session = sessionWrapper.getSession(); @@ -1521,7 +1536,9 @@ Status WiredTigerKVEngine::recoverOrphanedIdent(OperationContext* opCtx, } LOGV2_WARNING(22354, "Could not salvage data. Rebuilding ident: {status_reason}", - "status_reason"_attr = status.reason()); + "Could not salvage data. Rebuilding ident", + "ident"_attr = ident, + "error"_attr = status.reason()); // If the data is unsalvageable, we should completely rebuild the ident. return _rebuildIdent(session, _uri(ident).c_str()); @@ -1887,9 +1904,10 @@ void WiredTigerKVEngine::_ensureIdentPath(StringData ident) { boost::filesystem::create_directory(subdir); } catch (const std::exception& e) { LOGV2_ERROR(22361, - "error creating path {subdir_string} {e_what}", - "subdir_string"_attr = subdir.string(), - "e_what"_attr = e.what()); + "error creating path {directory} {error}", + "Error creating directory", + "directory"_attr = subdir.string(), + "error"_attr = e.what()); throw; } } diff --git a/src/mongo/db/storage/wiredtiger/wiredtiger_parameters.cpp b/src/mongo/db/storage/wiredtiger/wiredtiger_parameters.cpp index ef648e32d8c..84d5ff1a18f 100644 --- a/src/mongo/db/storage/wiredtiger/wiredtiger_parameters.cpp +++ b/src/mongo/db/storage/wiredtiger/wiredtiger_parameters.cpp @@ -55,15 +55,20 @@ Status WiredTigerEngineRuntimeConfigParameter::setFromString(const std::string& } LOGV2(22376, - "Reconfiguring WiredTiger storage engine with config string: \"{str}\"", - "str"_attr = str); + "Reconfiguring WiredTiger storage engine with config string: \"{config}\"", + "Reconfiguring WiredTiger storage engine", + "config"_attr = str); invariant(_data.second); int ret = _data.second->reconfigure(str.c_str()); if (ret != 0) { + const char* errorStr = wiredtiger_strerror(ret); string result = (str::stream() << "WiredTiger reconfiguration failed with error code (" - << ret << "): " << wiredtiger_strerror(ret)); - LOGV2_ERROR(22378, "{result}", "result"_attr = result); + << ret << "): " << errorStr); + LOGV2_ERROR(22378, + "WiredTiger reconfiguration failed", + "error"_attr = ret, + "message"_attr = errorStr); return Status(ErrorCodes::BadValue, result); } diff --git a/src/mongo/db/storage/wiredtiger/wiredtiger_record_store.cpp b/src/mongo/db/storage/wiredtiger/wiredtiger_record_store.cpp index b5cf62e76dd..d418022194c 100644 --- a/src/mongo/db/storage/wiredtiger/wiredtiger_record_store.cpp +++ b/src/mongo/db/storage/wiredtiger/wiredtiger_record_store.cpp @@ -394,8 +394,9 @@ void WiredTigerRecordStore::OplogStones::_calculateStones(OperationContext* opCt ON_BLOCK_EXIT([&] { auto waitTime = curTimeMicros64() - startWaitTime; LOGV2(22382, - "WiredTiger record store oplog processing took {waitTime_1000}ms", - "waitTime_1000"_attr = waitTime / 1000); + "WiredTiger record store oplog processing took {duration}ms", + "WiredTiger record store oplog processing finished", + "duration"_attr = Milliseconds(static_cast<int64_t>(waitTime / 1000))); _totalTimeProcessing.fetchAndAdd(waitTime); }); long long numRecords = _rs->numRecords(opCtx); @@ -404,6 +405,7 @@ void WiredTigerRecordStore::OplogStones::_calculateStones(OperationContext* opCt LOGV2(22383, "The size storer reports that the oplog contains {numRecords} records totaling to " "{dataSize} bytes", + "The size storer reports that the oplog contains", "numRecords"_attr = numRecords, "dataSize"_attr = dataSize); @@ -505,20 +507,22 @@ void WiredTigerRecordStore::OplogStones::_calculateStonesBySampling(OperationCon } LOGV2(22389, - "Sampling from the oplog between {earliestOpTime_Pretty} and {latestOpTime_Pretty} to " + "Sampling from the oplog between {from} and {to} to " "determine where to place markers for truncation", - "earliestOpTime_Pretty"_attr = earliestOpTime.toStringPretty(), - "latestOpTime_Pretty"_attr = latestOpTime.toStringPretty()); + "Sampling from the oplog to determine where to place markers for truncation", + "from"_attr = earliestOpTime, + "to"_attr = latestOpTime); int64_t wholeStones = _rs->numRecords(opCtx) / estRecordsPerStone; int64_t numSamples = kRandomSamplesPerStone * _rs->numRecords(opCtx) / estRecordsPerStone; LOGV2(22390, "Taking {numSamples} samples and assuming that each section of oplog contains " - "approximately {estRecordsPerStone} records totaling to {estBytesPerStone} bytes", + "approximately {containsNumRecords} records totaling to {containsNumBytes} bytes", + "Taking samples and assuming each oplog section contains", "numSamples"_attr = numSamples, - "estRecordsPerStone"_attr = estRecordsPerStone, - "estBytesPerStone"_attr = estBytesPerStone); + "containsNumRecords"_attr = estRecordsPerStone, + "containsNumBytes"_attr = estBytesPerStone); // Inform the random cursor of the number of samples we intend to take. This allows it to // account for skew in the tree shape. @@ -552,9 +556,10 @@ void WiredTigerRecordStore::OplogStones::_calculateStonesBySampling(OperationCon if (samplingLogIntervalSeconds > 0 && now - lastProgressLog >= Seconds(samplingLogIntervalSeconds)) { LOGV2(22392, - "Oplog sampling progress: {i_1} of {numSamples} samples taken", - "i_1"_attr = (i + 1), - "numSamples"_attr = numSamples); + "Oplog sampling progress: {current} of {total} samples taken", + "Oplog sampling progress", + "completed"_attr = (i + 1), + "total"_attr = numSamples); lastProgressLog = now; } } @@ -1411,7 +1416,8 @@ void WiredTigerRecordStore::reclaimOplog(OperationContext* opCtx, Timestamp mayT _truncateCount.fetchAndAdd(1); LOGV2(22402, "WiredTiger record store oplog truncation finished in: {elapsedMillis}ms", - "elapsedMillis"_attr = elapsedMillis); + "WiredTiger record store oplog truncation finished", + "duration"_attr = Milliseconds(elapsedMillis)); } Status WiredTigerRecordStore::insertRecords(OperationContext* opCtx, @@ -1737,15 +1743,22 @@ void WiredTigerRecordStore::validate(OperationContext* opCtx, << "This is a transient issue as the collection was actively " "in use by other operations."; - LOGV2_WARNING(22408, "{msg}", "msg"_attr = msg); + LOGV2_WARNING(22408, + "Could not complete validation, This is a transient issue as the collection " + "was actively in use by other operations", + "uri"_attr = _uri); results->warnings.push_back(msg); return; } - std::string msg = str::stream() << "verify() returned " << wiredtiger_strerror(err) << ". " + const char* errorStr = wiredtiger_strerror(err); + std::string msg = str::stream() << "verify() returned " << errorStr << ". " << "This indicates structural damage. " << "Not examining individual documents."; - LOGV2_ERROR(22409, "{msg}", "msg"_attr = msg); + LOGV2_ERROR(22409, + "Verification returned error. This indicates structural damage. Not examining " + "individual documents", + "error"_attr = errorStr); results->errors.push_back(msg); results->valid = false; } @@ -2121,10 +2134,11 @@ boost::optional<Record> WiredTigerRecordStoreCursorBase::next() { if (_forward && _lastReturnedId >= id) { LOGV2(22406, - "WTCursor::next -- c->next_key ( {id}) was not greater than _lastReturnedId " - "({lastReturnedId}) which is a bug.", - "id"_attr = id, - "lastReturnedId"_attr = _lastReturnedId); + "WTCursor::next -- c->next_key ( {next}) was not greater than _lastReturnedId " + "({last}) which is a bug.", + "WTCursor::next -- next was not greater than last which is a bug", + "next"_attr = id, + "last"_attr = _lastReturnedId); // Crash when test commands are enabled. invariant(!getTestCommandsEnabled()); diff --git a/src/mongo/db/storage/wiredtiger/wiredtiger_recovery_unit.cpp b/src/mongo/db/storage/wiredtiger/wiredtiger_recovery_unit.cpp index 8d6e087a86f..685bb979a60 100644 --- a/src/mongo/db/storage/wiredtiger/wiredtiger_recovery_unit.cpp +++ b/src/mongo/db/storage/wiredtiger/wiredtiger_recovery_unit.cpp @@ -288,8 +288,9 @@ void WiredTigerRecoveryUnit::assertInActiveTxn() const { return; } LOGV2_FATAL(28575, - "Recovery unit is not active. Current state: {getState}", - "getState"_attr = toString(_getState())); + "Recovery unit is not active. Current state: {currentState}", + "Recovery unit is not active.", + "currentState"_attr = _getState()); } boost::optional<int64_t> WiredTigerRecoveryUnit::getOplogVisibilityTs() { diff --git a/src/mongo/db/storage/wiredtiger/wiredtiger_session_cache.cpp b/src/mongo/db/storage/wiredtiger/wiredtiger_session_cache.cpp index eb13562bfb7..94b1fb2a5f0 100644 --- a/src/mongo/db/storage/wiredtiger/wiredtiger_session_cache.cpp +++ b/src/mongo/db/storage/wiredtiger/wiredtiger_session_cache.cpp @@ -92,20 +92,21 @@ void _openCursor(WT_SESSION* session, } if (ret != 0) { + auto status = wtRCToStatus(ret); std::string cursorErrMsg = str::stream() - << "Failed to open a WiredTiger cursor. Reason: " << wtRCToStatus(ret) - << ", uri: " << uri << ", config: " << config; + << "Failed to open a WiredTiger cursor. Reason: " << status << ", uri: " << uri + << ", config: " << config; if (ret == ENOENT) { uasserted(ErrorCodes::CursorNotFound, cursorErrMsg); } - LOGV2_ERROR(22421, "{cursorErrMsg}", "cursorErrMsg"_attr = cursorErrMsg); - LOGV2_ERROR(22422, - "This may be due to data corruption. {kWTRepairMsg}", - "kWTRepairMsg"_attr = kWTRepairMsg); - - fassertFailedNoTrace(50882); + LOGV2_FATAL_NOTRACE(50882, + "Failed to open WiredTiger cursor. This may be due to data corruption", + "uri"_attr = uri, + "config"_attr = config, + "error"_attr = status, + "message"_attr = kWTRepairMsg); } } } // namespace diff --git a/src/mongo/db/storage/wiredtiger/wiredtiger_util.cpp b/src/mongo/db/storage/wiredtiger/wiredtiger_util.cpp index 2b8f2d667fe..5ea3b744bab 100644 --- a/src/mongo/db/storage/wiredtiger/wiredtiger_util.cpp +++ b/src/mongo/db/storage/wiredtiger/wiredtiger_util.cpp @@ -144,8 +144,7 @@ StatusWith<std::string> WiredTigerUtil::getMetadataCreate(OperationContext* opCt cursor = session->getCachedCursor( "metadata:create", WiredTigerSession::kMetadataCreateTableId, NULL); } catch (const ExceptionFor<ErrorCodes::CursorNotFound>& ex) { - LOGV2_ERROR(22433, "{ex}", "ex"_attr = ex); - fassertFailedNoTrace(51257); + LOGV2_FATAL_NOTRACE(51257, "Cursor not found", "error"_attr = ex); } invariant(cursor); auto releaser = makeGuard( @@ -171,8 +170,7 @@ StatusWith<std::string> WiredTigerUtil::getMetadata(OperationContext* opCtx, Str try { cursor = session->getCachedCursor("metadata:", WiredTigerSession::kMetadataTableId, NULL); } catch (const ExceptionFor<ErrorCodes::CursorNotFound>& ex) { - LOGV2_ERROR(22434, "{ex}", "ex"_attr = ex); - fassertFailedNoTrace(31293); + LOGV2_FATAL_NOTRACE(31293, "Cursor not found", "error"_attr = ex); } invariant(cursor); auto releaser = @@ -400,9 +398,10 @@ size_t WiredTigerUtil::getCacheSizeMB(double requestedCacheSizeGB) { } if (cacheSizeMB > kMaxSizeCacheMB) { LOGV2(22429, - "Requested cache size: {cacheSizeMB}MB exceeds max; setting to {kMaxSizeCacheMB}MB", - "cacheSizeMB"_attr = cacheSizeMB, - "kMaxSizeCacheMB"_attr = kMaxSizeCacheMB); + "Requested cache size: {requestedMB}MB exceeds max; setting to {maximumMB}MB", + "Requested cache size exceeds max, setting to maximum", + "requestedMB"_attr = cacheSizeMB, + "maximumMB"_attr = kMaxSizeCacheMB); cacheSizeMB = kMaxSizeCacheMB; } return static_cast<size_t>(cacheSizeMB); @@ -435,10 +434,10 @@ int mdb_handle_error_with_startup_suppression(WT_EVENT_HANDLER* handler, } } LOGV2_ERROR(22435, - "WiredTiger error ({errorCode}) {message} Raw: {message2}", - "errorCode"_attr = errorCode, - "message"_attr = redact(message), - "message2"_attr = message); + "WiredTiger error ({error}) {message}", + "WiredTiger error", + "error"_attr = errorCode, + "message"_attr = message); // Don't abort on WT_PANIC when repairing, as the error will be handled at a higher layer. if (storageGlobalParams.repair) { @@ -458,7 +457,8 @@ int mdb_handle_error(WT_EVENT_HANDLER* handler, try { LOGV2_ERROR(22436, "WiredTiger error ({errorCode}) {message}", - "errorCode"_attr = errorCode, + "WiredTiger error", + "error"_attr = errorCode, "message"_attr = redact(message)); // Don't abort on WT_PANIC when repairing, as the error will be handled at a higher layer. @@ -636,13 +636,14 @@ Status WiredTigerUtil::setTableLogging(WT_SESSION* session, const std::string& u int ret = session->alter(session, uri.c_str(), setting.c_str()); if (ret) { LOGV2_FATAL(50756, - "Failed to update log setting. Uri: {uri} Enable? {on} Ret: {ret} MD: " - "{existingMetadata} Msg: {session_strerror_session_ret}", + "Failed to update log setting. Uri: {uri} Enable? {enable} Ret: {error} MD: " + "{metadata} Msg: {message}", + "Failed to update log setting", "uri"_attr = uri, - "on"_attr = on, - "ret"_attr = ret, - "existingMetadata"_attr = redact(existingMetadata), - "session_strerror_session_ret"_attr = session->strerror(session, ret)); + "enable"_attr = on, + "error"_attr = ret, + "metadata"_attr = redact(existingMetadata), + "message"_attr = session->strerror(session, ret)); } return Status::OK(); |