diff options
Diffstat (limited to 'src/mongo/db/repl/sync_source_resolver.cpp')
| -rw-r--r-- | src/mongo/db/repl/sync_source_resolver.cpp | 117 |
1 files changed, 84 insertions, 33 deletions
diff --git a/src/mongo/db/repl/sync_source_resolver.cpp b/src/mongo/db/repl/sync_source_resolver.cpp index a6c87de8731..8ecdad2ebe4 100644 --- a/src/mongo/db/repl/sync_source_resolver.cpp +++ b/src/mongo/db/repl/sync_source_resolver.cpp @@ -39,6 +39,7 @@ #include "mongo/db/repl/oplog_entry.h" #include "mongo/db/repl/replication_process.h" #include "mongo/db/repl/sync_source_selector.h" +#include "mongo/logv2/log.h" #include "mongo/rpc/get_status_from_command_result.h" #include "mongo/util/assert_util.h" #include "mongo/util/destructor_guard.h" @@ -224,8 +225,11 @@ Status SyncSourceResolver::_scheduleFetcher(std::unique_ptr<Fetcher> fetcher) { _shuttingDownFetcher = std::move(_fetcher); _fetcher = std::move(fetcher); } else { - error() << "Error scheduling fetcher to evaluate host as sync source, host:" - << fetcher->getSource() << ", error: " << status; + LOGV2_ERROR(21776, + "Error scheduling fetcher to evaluate host as sync source, " + "host:{fetcher_getSource}, error: {status}", + "fetcher_getSource"_attr = fetcher->getSource(), + "status"_attr = status); } return status; } @@ -235,8 +239,12 @@ OpTime SyncSourceResolver::_parseRemoteEarliestOpTime(const HostAndPort& candida if (queryResponse.documents.empty()) { // Remote oplog is empty. const auto until = _taskExecutor->now() + kOplogEmptyBlacklistDuration; - log() << "Blacklisting " << candidate << " due to empty oplog for " - << kOplogEmptyBlacklistDuration << " until: " << until; + LOGV2(21766, + "Blacklisting {candidate} due to empty oplog for {kOplogEmptyBlacklistDuration} " + "until: {until}", + "candidate"_attr = candidate, + "kOplogEmptyBlacklistDuration"_attr = kOplogEmptyBlacklistDuration, + "until"_attr = until); _syncSourceSelector->blacklistSyncSource(candidate, until); return OpTime(); } @@ -245,8 +253,13 @@ OpTime SyncSourceResolver::_parseRemoteEarliestOpTime(const HostAndPort& candida if (firstObjFound.isEmpty()) { // First document in remote oplog is empty. const auto until = _taskExecutor->now() + kFirstOplogEntryEmptyBlacklistDuration; - log() << "Blacklisting " << candidate << " due to empty first document for " - << kFirstOplogEntryEmptyBlacklistDuration << " until: " << until; + LOGV2(21767, + "Blacklisting {candidate} due to empty first document for " + "{kFirstOplogEntryEmptyBlacklistDuration} until: {until}", + "candidate"_attr = candidate, + "kFirstOplogEntryEmptyBlacklistDuration"_attr = + kFirstOplogEntryEmptyBlacklistDuration, + "until"_attr = until); _syncSourceSelector->blacklistSyncSource(candidate, until); return OpTime(); } @@ -254,10 +267,16 @@ OpTime SyncSourceResolver::_parseRemoteEarliestOpTime(const HostAndPort& candida const auto remoteEarliestOpTime = OpTime::parseFromOplogEntry(firstObjFound); if (!remoteEarliestOpTime.isOK()) { const auto until = _taskExecutor->now() + kFirstOplogEntryNullTimestampBlacklistDuration; - log() << "Blacklisting " << candidate << " due to error parsing OpTime from the oldest" - << " oplog entry for " << kFirstOplogEntryNullTimestampBlacklistDuration - << " until: " << until << ". Error: " << remoteEarliestOpTime.getStatus() - << ", Entry: " << redact(firstObjFound); + LOGV2(21768, + "Blacklisting {candidate} due to error parsing OpTime from the oldest oplog entry " + "for {kFirstOplogEntryNullTimestampBlacklistDuration} until: {until}. Error: " + "{remoteEarliestOpTime_getStatus}, Entry: {firstObjFound}", + "candidate"_attr = candidate, + "kFirstOplogEntryNullTimestampBlacklistDuration"_attr = + kFirstOplogEntryNullTimestampBlacklistDuration, + "until"_attr = until, + "remoteEarliestOpTime_getStatus"_attr = remoteEarliestOpTime.getStatus(), + "firstObjFound"_attr = redact(firstObjFound)); _syncSourceSelector->blacklistSyncSource(candidate, until); return OpTime(); } @@ -265,8 +284,13 @@ OpTime SyncSourceResolver::_parseRemoteEarliestOpTime(const HostAndPort& candida if (remoteEarliestOpTime.getValue().isNull()) { // First document in remote oplog is empty. const auto until = _taskExecutor->now() + kFirstOplogEntryNullTimestampBlacklistDuration; - log() << "Blacklisting " << candidate << " due to null timestamp in first document for " - << kFirstOplogEntryNullTimestampBlacklistDuration << " until: " << until; + LOGV2(21769, + "Blacklisting {candidate} due to null timestamp in first document for " + "{kFirstOplogEntryNullTimestampBlacklistDuration} until: {until}", + "candidate"_attr = candidate, + "kFirstOplogEntryNullTimestampBlacklistDuration"_attr = + kFirstOplogEntryNullTimestampBlacklistDuration, + "until"_attr = until); _syncSourceSelector->blacklistSyncSource(candidate, until); return OpTime(); } @@ -295,8 +319,13 @@ void SyncSourceResolver::_firstOplogEntryFetcherCallback( if (!queryResult.isOK()) { // We got an error. const auto until = _taskExecutor->now() + kFetcherErrorBlacklistDuration; - log() << "Blacklisting " << candidate << " due to error: '" << queryResult.getStatus() - << "' for " << kFetcherErrorBlacklistDuration << " until: " << until; + LOGV2(21770, + "Blacklisting {candidate} due to error: '{queryResult_getStatus}' for " + "{kFetcherErrorBlacklistDuration} until: {until}", + "candidate"_attr = candidate, + "queryResult_getStatus"_attr = queryResult.getStatus(), + "kFetcherErrorBlacklistDuration"_attr = kFetcherErrorBlacklistDuration, + "until"_attr = until); _syncSourceSelector->blacklistSyncSource(candidate, until); _chooseAndProbeNextSyncSource(earliestOpTimeSeen).transitional_ignore(); @@ -316,11 +345,16 @@ void SyncSourceResolver::_firstOplogEntryFetcherCallback( const auto blacklistDuration = kTooStaleBlacklistDuration; const auto until = _taskExecutor->now() + Minutes(1); - log() << "We are too stale to use " << candidate << " as a sync source. " - << "Blacklisting this sync source" - << " because our last fetched timestamp: " << _lastOpTimeFetched.getTimestamp() - << " is before their earliest timestamp: " << remoteEarliestOpTime.getTimestamp() - << " for " << blacklistDuration << " until: " << until; + LOGV2(21771, + "We are too stale to use {candidate} as a sync source. Blacklisting this sync source " + "because our last fetched timestamp: {lastOpTimeFetched_getTimestamp} is before " + "their earliest timestamp: {remoteEarliestOpTime_getTimestamp} for " + "{blacklistDuration} until: {until}", + "candidate"_attr = candidate, + "lastOpTimeFetched_getTimestamp"_attr = _lastOpTimeFetched.getTimestamp(), + "remoteEarliestOpTime_getTimestamp"_attr = remoteEarliestOpTime.getTimestamp(), + "blacklistDuration"_attr = blacklistDuration, + "until"_attr = until); _syncSourceSelector->blacklistSyncSource(candidate, until); @@ -386,8 +420,13 @@ void SyncSourceResolver::_rbidRequestCallback( rbid = rbidReply.response.data["rbid"].Int(); } catch (const DBException& ex) { const auto until = _taskExecutor->now() + kFetcherErrorBlacklistDuration; - log() << "Blacklisting " << candidate << " due to error: '" << ex << "' for " - << kFetcherErrorBlacklistDuration << " until: " << until; + LOGV2(21772, + "Blacklisting {candidate} due to error: '{ex}' for {kFetcherErrorBlacklistDuration} " + "until: {until}", + "candidate"_attr = candidate, + "ex"_attr = ex, + "kFetcherErrorBlacklistDuration"_attr = kFetcherErrorBlacklistDuration, + "until"_attr = until); _syncSourceSelector->blacklistSyncSource(candidate, until); _chooseAndProbeNextSyncSource(earliestOpTimeSeen).transitional_ignore(); return; @@ -456,9 +495,15 @@ void SyncSourceResolver::_requiredOpTimeFetcherCallback( if (!queryResult.isOK()) { // We got an error. const auto until = _taskExecutor->now() + kFetcherErrorBlacklistDuration; - log() << "Blacklisting " << candidate << " due to required optime fetcher error: '" - << queryResult.getStatus() << "' for " << kFetcherErrorBlacklistDuration - << " until: " << until << ". required optime: " << _requiredOpTime; + LOGV2(21773, + "Blacklisting {candidate} due to required optime fetcher error: " + "'{queryResult_getStatus}' for {kFetcherErrorBlacklistDuration} until: {until}. " + "required optime: {requiredOpTime}", + "candidate"_attr = candidate, + "queryResult_getStatus"_attr = queryResult.getStatus(), + "kFetcherErrorBlacklistDuration"_attr = kFetcherErrorBlacklistDuration, + "until"_attr = until, + "requiredOpTime"_attr = _requiredOpTime); _syncSourceSelector->blacklistSyncSource(candidate, until); _chooseAndProbeNextSyncSource(earliestOpTimeSeen).transitional_ignore(); @@ -469,13 +514,18 @@ void SyncSourceResolver::_requiredOpTimeFetcherCallback( auto status = _compareRequiredOpTimeWithQueryResponse(queryResponse); if (!status.isOK()) { const auto until = _taskExecutor->now() + kNoRequiredOpTimeBlacklistDuration; - warning() << "We cannot use " << candidate.toString() - << " as a sync source because it does not contain the necessary " - "operations for us to reach a consistent state: " - << status << " last fetched optime: " << _lastOpTimeFetched - << ". required optime: " << _requiredOpTime - << ". Blacklisting this sync source for " << kNoRequiredOpTimeBlacklistDuration - << " until: " << until; + LOGV2_WARNING( + 21774, + "We cannot use {candidate} as a sync source because it does not contain the necessary " + "operations for us to reach a consistent state: {status} last fetched optime: " + "{lastOpTimeFetched}. required optime: {requiredOpTime}. Blacklisting this sync source " + "for {kNoRequiredOpTimeBlacklistDuration} until: {until}", + "candidate"_attr = candidate.toString(), + "status"_attr = status, + "lastOpTimeFetched"_attr = _lastOpTimeFetched, + "requiredOpTime"_attr = _requiredOpTime, + "kNoRequiredOpTimeBlacklistDuration"_attr = kNoRequiredOpTimeBlacklistDuration, + "until"_attr = until); _syncSourceSelector->blacklistSyncSource(candidate, until); _chooseAndProbeNextSyncSource(earliestOpTimeSeen).transitional_ignore(); @@ -532,8 +582,9 @@ Status SyncSourceResolver::_finishCallback(const SyncSourceResolverResponse& res try { _onCompletion(response); } catch (...) { - warning() << "sync source resolver finish callback threw exception: " - << exceptionToStatus(); + LOGV2_WARNING(21775, + "sync source resolver finish callback threw exception: {exceptionToStatus}", + "exceptionToStatus"_attr = exceptionToStatus()); } stdx::lock_guard<Latch> lock(_mutex); |