summaryrefslogtreecommitdiff
path: root/src/mongo/s/client
diff options
context:
space:
mode:
Diffstat (limited to 'src/mongo/s/client')
-rw-r--r--src/mongo/s/client/parallel.cpp238
-rw-r--r--src/mongo/s/client/shard.cpp28
-rw-r--r--src/mongo/s/client/shard_connection.cpp19
-rw-r--r--src/mongo/s/client/shard_registry.cpp79
-rw-r--r--src/mongo/s/client/shard_remote.cpp9
-rw-r--r--src/mongo/s/client/sharding_connection_hook.cpp3
-rw-r--r--src/mongo/s/client/version_manager.cpp30
7 files changed, 285 insertions, 121 deletions
diff --git a/src/mongo/s/client/parallel.cpp b/src/mongo/s/client/parallel.cpp
index fae0d1c7c47..83360c2f958 100644
--- a/src/mongo/s/client/parallel.cpp
+++ b/src/mongo/s/client/parallel.cpp
@@ -39,6 +39,7 @@
#include "mongo/client/replica_set_monitor.h"
#include "mongo/db/bson/dotted_path_support.h"
#include "mongo/db/query/query_request.h"
+#include "mongo/logv2/log.h"
#include "mongo/rpc/get_status_from_command_result.h"
#include "mongo/s/catalog_cache.h"
#include "mongo/s/client/shard_connection.h"
@@ -376,9 +377,11 @@ void ParallelSortClusteredCursor::setupVersionAndHandleSlaveOk(
if (sampler.tick()) {
const DBClientReplicaSet* repl = dynamic_cast<const DBClientReplicaSet*>(rawConn);
dassert(repl);
- warning() << "Primary for " << repl->getServerAddress()
- << " was down before, bypassing setShardVersion."
- << " The local replica set view and targeting may be stale.";
+ LOGV2_WARNING(
+ 22695,
+ "Primary for {repl_getServerAddress} was down before, bypassing "
+ "setShardVersion. The local replica set view and targeting may be stale.",
+ "repl_getServerAddress"_attr = repl->getServerAddress());
}
return;
@@ -387,8 +390,11 @@ void ParallelSortClusteredCursor::setupVersionAndHandleSlaveOk(
try {
if (state->conn->setVersion()) {
- LOG(2) << "pcursor: needed to set remote version on connection to value "
- << "compatible with " << vinfo;
+ LOGV2_DEBUG(22678,
+ 2,
+ "pcursor: needed to set remote version on connection to value compatible "
+ "with {vinfo}",
+ "vinfo"_attr = vinfo);
}
} catch (const DBException& dbExcep) {
auto errCode = dbExcep.code();
@@ -403,9 +409,10 @@ void ParallelSortClusteredCursor::setupVersionAndHandleSlaveOk(
const DBClientReplicaSet* repl =
dynamic_cast<const DBClientReplicaSet*>(state->conn->getRawConn());
dassert(repl);
- warning() << "Cannot contact primary for " << repl->getServerAddress()
- << " to check shard version."
- << " The local replica set view and targeting may be stale.";
+ LOGV2_WARNING(22696,
+ "Cannot contact primary for {repl_getServerAddress} to check shard "
+ "version. The local replica set view and targeting may be stale.",
+ "repl_getServerAddress"_attr = repl->getServerAddress());
}
} else {
throw;
@@ -425,7 +432,12 @@ void ParallelSortClusteredCursor::startInit(OperationContext* opCtx) {
prefix = "creating";
}
}
- LOG(2) << "pcursor: " << prefix << " pcursor over " << _qSpec << " and " << _cInfo;
+ LOGV2_DEBUG(22679,
+ 2,
+ "pcursor: {prefix} pcursor over {qSpec} and {cInfo}",
+ "prefix"_attr = prefix,
+ "qSpec"_attr = _qSpec,
+ "cInfo"_attr = _cInfo);
shared_ptr<ChunkManager> manager;
shared_ptr<Shard> primary;
@@ -470,14 +482,22 @@ void ParallelSortClusteredCursor::startInit(OperationContext* opCtx) {
const auto& shardId = cmEntry.first;
if (shardIds.find(shardId) == shardIds.end()) {
- LOG(2) << "pcursor: closing cursor on shard " << shardId
- << " as the connection is no longer required by " << vinfo;
+ LOGV2_DEBUG(22680,
+ 2,
+ "pcursor: closing cursor on shard {shardId} as the connection is no longer "
+ "required by {vinfo}",
+ "shardId"_attr = shardId,
+ "vinfo"_attr = vinfo);
cmEntry.second.cleanup(true);
}
}
- LOG(2) << "pcursor: initializing over " << shardIds.size() << " shards required by " << vinfo;
+ LOGV2_DEBUG(22681,
+ 2,
+ "pcursor: initializing over {shardIds_size} shards required by {vinfo}",
+ "shardIds_size"_attr = shardIds.size(),
+ "vinfo"_attr = vinfo);
// Don't retry indefinitely for whatever reason
_totalTries++;
@@ -486,8 +506,11 @@ void ParallelSortClusteredCursor::startInit(OperationContext* opCtx) {
for (const ShardId& shardId : shardIds) {
auto& mdata = _cursorMap[shardId];
- LOG(2) << "pcursor: initializing on shard " << shardId << ", current connection state is "
- << mdata.toBSON();
+ LOGV2_DEBUG(22682,
+ 2,
+ "pcursor: initializing on shard {shardId}, current connection state is {mdata}",
+ "shardId"_attr = shardId,
+ "mdata"_attr = mdata.toBSON());
// This may be the first time connecting to this shard, if so we can get an error here
try {
@@ -500,11 +523,11 @@ void ParallelSortClusteredCursor::startInit(OperationContext* opCtx) {
bool compatibleManager = true;
if (primary && !state->primary)
- warning() << "Collection becoming unsharded detected";
+ LOGV2_WARNING(22697, "Collection becoming unsharded detected");
if (manager && !state->manager)
- warning() << "Collection becoming sharded detected";
+ LOGV2_WARNING(22698, "Collection becoming sharded detected");
if (primary && state->primary && primary != state->primary)
- warning() << "Weird shift of primary detected";
+ LOGV2_WARNING(22699, "Weird shift of primary detected");
compatiblePrimary = primary && state->primary && primary == state->primary;
compatibleManager =
@@ -609,9 +632,14 @@ void ParallelSortClusteredCursor::startInit(OperationContext* opCtx) {
mdata.finished = true;
}
- LOG(2) << "pcursor: initialized " << (isCommand() ? "command " : "query ")
- << (lazyInit ? "(lazily) " : "(full) ") << "on shard " << shardId
- << ", current connection state is " << mdata.toBSON();
+ LOGV2_DEBUG(22683,
+ 2,
+ "pcursor: initialized {isCommand_command_query}{lazyInit_lazily_full}on "
+ "shard {shardId}, current connection state is {mdata}",
+ "isCommand_command_query"_attr = (isCommand() ? "command " : "query "),
+ "lazyInit_lazily_full"_attr = (lazyInit ? "(lazily) " : "(full) "),
+ "shardId"_attr = shardId,
+ "mdata"_attr = mdata.toBSON());
} catch (StaleConfigException& e) {
// Our version isn't compatible with the current version anymore on at least one shard,
// need to retry immediately
@@ -623,21 +651,32 @@ void ParallelSortClusteredCursor::startInit(OperationContext* opCtx) {
->invalidateShardOrEntireCollectionEntryForShardedCollection(
opCtx, nss, e->getVersionWanted(), e->getVersionReceived(), e->getShardId());
- LOG(1) << "stale config of ns " << staleNS << " during initialization, will retry"
- << causedBy(redact(e));
+ LOGV2_DEBUG(
+ 22684,
+ 1,
+ "stale config of ns {staleNS} during initialization, will retry{causedBy_e}",
+ "staleNS"_attr = staleNS,
+ "causedBy_e"_attr = causedBy(redact(e)));
// This is somewhat strange
if (staleNS != nss) {
- warning() << "versioned ns " << nss.ns() << " doesn't match stale config namespace "
- << staleNS;
+ LOGV2_WARNING(
+ 22700,
+ "versioned ns {nss_ns} doesn't match stale config namespace {staleNS}",
+ "nss_ns"_attr = nss.ns(),
+ "staleNS"_attr = staleNS);
}
// Restart with new chunk manager
startInit(opCtx);
return;
} catch (NetworkException& e) {
- warning() << "socket exception when initializing on " << shardId
- << ", current connection state is " << mdata.toBSON() << causedBy(redact(e));
+ LOGV2_WARNING(22701,
+ "socket exception when initializing on {shardId}, current connection "
+ "state is {mdata}{causedBy_e}",
+ "shardId"_attr = shardId,
+ "mdata"_attr = mdata.toBSON(),
+ "causedBy_e"_attr = causedBy(redact(e)));
mdata.errored = true;
if (returnPartial) {
mdata.cleanup(true);
@@ -645,8 +684,12 @@ void ParallelSortClusteredCursor::startInit(OperationContext* opCtx) {
}
throw;
} catch (DBException& e) {
- warning() << "db exception when initializing on " << shardId
- << ", current connection state is " << mdata.toBSON() << causedBy(redact(e));
+ LOGV2_WARNING(22702,
+ "db exception when initializing on {shardId}, current connection state "
+ "is {mdata}{causedBy_e}",
+ "shardId"_attr = shardId,
+ "mdata"_attr = mdata.toBSON(),
+ "causedBy_e"_attr = causedBy(redact(e)));
mdata.errored = true;
if (returnPartial && e.code() == 15925 /* From above! */) {
mdata.cleanup(true);
@@ -654,13 +697,20 @@ void ParallelSortClusteredCursor::startInit(OperationContext* opCtx) {
}
throw;
} catch (std::exception& e) {
- warning() << "exception when initializing on " << shardId
- << ", current connection state is " << mdata.toBSON() << causedBy(e);
+ LOGV2_WARNING(22703,
+ "exception when initializing on {shardId}, current connection state is "
+ "{mdata}{causedBy_e}",
+ "shardId"_attr = shardId,
+ "mdata"_attr = mdata.toBSON(),
+ "causedBy_e"_attr = causedBy(e));
mdata.errored = true;
throw;
} catch (...) {
- warning() << "unknown exception when initializing on " << shardId
- << ", current connection state is " << mdata.toBSON();
+ LOGV2_WARNING(22704,
+ "unknown exception when initializing on {shardId}, current connection "
+ "state is {mdata}",
+ "shardId"_attr = shardId,
+ "mdata"_attr = mdata.toBSON());
mdata.errored = true;
throw;
}
@@ -709,14 +759,20 @@ void ParallelSortClusteredCursor::finishInit(OperationContext* opCtx) {
bool retry = false;
map<string, StaleConfigException> staleNSExceptions;
- LOG(2) << "pcursor: finishing over " << _cursorMap.size() << " shards";
+ LOGV2_DEBUG(22685,
+ 2,
+ "pcursor: finishing over {cursorMap_size} shards",
+ "cursorMap_size"_attr = _cursorMap.size());
for (auto& cmEntry : _cursorMap) {
const auto& shardId = cmEntry.first;
auto& mdata = cmEntry.second;
- LOG(2) << "pcursor: finishing on shard " << shardId << ", current connection state is "
- << mdata.toBSON();
+ LOGV2_DEBUG(22686,
+ 2,
+ "pcursor: finishing on shard {shardId}, current connection state is {mdata}",
+ "shardId"_attr = shardId,
+ "mdata"_attr = mdata.toBSON());
// Ignore empty conns for now
if (!mdata.pcState)
@@ -763,8 +819,12 @@ void ParallelSortClusteredCursor::finishInit(OperationContext* opCtx) {
// Finalize state
state->cursor->attach(state->conn.get()); // Closes connection for us
- LOG(2) << "pcursor: finished on shard " << shardId
- << ", current connection state is " << mdata.toBSON();
+ LOGV2_DEBUG(
+ 22687,
+ 2,
+ "pcursor: finished on shard {shardId}, current connection state is {mdata}",
+ "shardId"_attr = shardId,
+ "mdata"_attr = mdata.toBSON());
}
} catch (StaleConfigException& e) {
retry = true;
@@ -778,8 +838,12 @@ void ParallelSortClusteredCursor::finishInit(OperationContext* opCtx) {
mdata.cleanup(true);
continue;
} catch (NetworkException& e) {
- warning() << "socket exception when finishing on " << shardId
- << ", current connection state is " << mdata.toBSON() << causedBy(redact(e));
+ LOGV2_WARNING(22705,
+ "socket exception when finishing on {shardId}, current connection state "
+ "is {mdata}{causedBy_e}",
+ "shardId"_attr = shardId,
+ "mdata"_attr = mdata.toBSON(),
+ "causedBy_e"_attr = causedBy(redact(e)));
mdata.errored = true;
if (returnPartial) {
mdata.cleanup(true);
@@ -790,9 +854,12 @@ void ParallelSortClusteredCursor::finishInit(OperationContext* opCtx) {
// NOTE: RECV() WILL NOT THROW A SOCKET EXCEPTION - WE GET THIS AS ERROR 15988 FROM
// ABOVE
if (e.code() == 15988) {
- warning() << "exception when receiving data from " << shardId
- << ", current connection state is " << mdata.toBSON()
- << causedBy(redact(e));
+ LOGV2_WARNING(22706,
+ "exception when receiving data from {shardId}, current connection "
+ "state is {mdata}{causedBy_e}",
+ "shardId"_attr = shardId,
+ "mdata"_attr = mdata.toBSON(),
+ "causedBy_e"_attr = causedBy(redact(e)));
mdata.errored = true;
if (returnPartial) {
@@ -804,23 +871,36 @@ void ParallelSortClusteredCursor::finishInit(OperationContext* opCtx) {
// the InvalidBSON exception indicates that the BSON is malformed ->
// don't print/call "mdata.toBSON()" to avoid unexpected errors e.g. a segfault
if (e.code() == ErrorCodes::InvalidBSON)
- warning() << "bson is malformed :: db exception when finishing on " << shardId
- << causedBy(redact(e));
+ LOGV2_WARNING(
+ 22707,
+ "bson is malformed :: db exception when finishing on {shardId}{causedBy_e}",
+ "shardId"_attr = shardId,
+ "causedBy_e"_attr = causedBy(redact(e)));
else
- warning() << "db exception when finishing on " << shardId
- << ", current connection state is " << mdata.toBSON()
- << causedBy(redact(e));
+ LOGV2_WARNING(22708,
+ "db exception when finishing on {shardId}, current connection "
+ "state is {mdata}{causedBy_e}",
+ "shardId"_attr = shardId,
+ "mdata"_attr = mdata.toBSON(),
+ "causedBy_e"_attr = causedBy(redact(e)));
mdata.errored = true;
throw;
}
} catch (std::exception& e) {
- warning() << "exception when finishing on " << shardId
- << ", current connection state is " << mdata.toBSON() << causedBy(e);
+ LOGV2_WARNING(22709,
+ "exception when finishing on {shardId}, current connection state is "
+ "{mdata}{causedBy_e}",
+ "shardId"_attr = shardId,
+ "mdata"_attr = mdata.toBSON(),
+ "causedBy_e"_attr = causedBy(e));
mdata.errored = true;
throw;
} catch (...) {
- warning() << "unknown exception when finishing on " << shardId
- << ", current connection state is " << mdata.toBSON();
+ LOGV2_WARNING(22710,
+ "unknown exception when finishing on {shardId}, current connection state "
+ "is {mdata}",
+ "shardId"_attr = shardId,
+ "mdata"_attr = mdata.toBSON());
mdata.errored = true;
throw;
}
@@ -844,13 +924,20 @@ void ParallelSortClusteredCursor::finishInit(OperationContext* opCtx) {
staleNS, *ex->getShardId());
}
- LOG(1) << "stale config of ns " << staleNS << " on finishing query, will retry"
- << causedBy(redact(ex));
+ LOGV2_DEBUG(
+ 22688,
+ 1,
+ "stale config of ns {staleNS} on finishing query, will retry{causedBy_ex}",
+ "staleNS"_attr = staleNS,
+ "causedBy_ex"_attr = causedBy(redact(ex)));
// This is somewhat strange
if (staleNS.ns() != ns) {
- warning() << "versioned ns " << ns << " doesn't match stale config namespace "
- << staleNS;
+ LOGV2_WARNING(
+ 22711,
+ "versioned ns {ns} doesn't match stale config namespace {staleNS}",
+ "ns"_attr = ns,
+ "staleNS"_attr = staleNS);
}
}
}
@@ -867,7 +954,7 @@ void ParallelSortClusteredCursor::finishInit(OperationContext* opCtx) {
// Erase empty stuff
if (!mdata.pcState) {
- log() << "PCursor erasing empty state " << mdata.toBSON();
+ LOGV2(22689, "PCursor erasing empty state {mdata}", "mdata"_attr = mdata.toBSON());
_cursorMap.erase(i++);
continue;
} else {
@@ -957,13 +1044,16 @@ void ParallelSortClusteredCursor::_oldInit(OperationContext* opCtx) {
bool firstPass = retryQueries.size() == 0;
if (!firstPass) {
- log() << "retrying " << (returnPartial ? "(partial) " : "")
- << "parallel connection to ";
+ LOGV2(22690,
+ "retrying {returnPartial_partial}parallel connection to ",
+ "returnPartial_partial"_attr = (returnPartial ? "(partial) " : ""));
for (set<int>::const_iterator it = retryQueries.begin(); it != retryQueries.end();
++it) {
- log() << serverHosts[*it] << ", ";
+ LOGV2(22691, "{serverHosts_it}, ", "serverHosts_it"_attr = serverHosts[*it]);
}
- log() << finishedQueries << " finished queries.";
+ LOGV2(22692,
+ "{finishedQueries} finished queries.",
+ "finishedQueries"_attr = finishedQueries);
}
size_t num = 0;
@@ -1008,9 +1098,15 @@ void ParallelSortClusteredCursor::_oldInit(OperationContext* opCtx) {
break;
}
- LOG(5) << "ParallelSortClusteredCursor::init server:" << serverHost << " ns:" << _ns
- << " query:" << redact(_query) << " fields:" << redact(_fields)
- << " options: " << _options;
+ LOGV2_DEBUG(22693,
+ 5,
+ "ParallelSortClusteredCursor::init server:{serverHost} ns:{ns} "
+ "query:{query} fields:{fields} options: {options}",
+ "serverHost"_attr = serverHost,
+ "ns"_attr = _ns,
+ "query"_attr = redact(_query),
+ "fields"_attr = redact(_fields),
+ "options"_attr = _options);
if (!_cursors[i].get())
_cursors[i].reset(
@@ -1061,8 +1157,10 @@ void ParallelSortClusteredCursor::_oldInit(OperationContext* opCtx) {
try {
if (!_cursors[i].get()->initLazyFinish(retry)) {
- warning() << "invalid result from " << conns[i]->getHost()
- << (retry ? ", retrying" : "");
+ LOGV2_WARNING(22712,
+ "invalid result from {conns_i_getHost}{retry_retrying}",
+ "conns_i_getHost"_attr = conns[i]->getHost(),
+ "retry_retrying"_attr = (retry ? ", retrying" : ""));
_cursors[i].reset(nullptr, nullptr);
if (!retry) {
@@ -1166,12 +1264,14 @@ void ParallelSortClusteredCursor::_oldInit(OperationContext* opCtx) {
} else if (throwException) {
uasserted(14827, errMsg.str());
} else {
- warning() << redact(errMsg.str());
+ LOGV2_WARNING(22713, "{errMsg_str}", "errMsg_str"_attr = redact(errMsg.str()));
}
}
if (retries > 0)
- log() << "successfully finished parallel query after " << retries << " retries";
+ LOGV2(22694,
+ "successfully finished parallel query after {retries} retries",
+ "retries"_attr = retries);
}
bool ParallelSortClusteredCursor::more() {
@@ -1264,9 +1364,9 @@ void ParallelConnectionMetadata::cleanup(bool full) {
bool retry = false;
pcState->cursor->initLazyFinish(retry);
} catch (std::exception&) {
- warning() << "exception closing cursor";
+ LOGV2_WARNING(22714, "exception closing cursor");
} catch (...) {
- warning() << "unknown exception closing cursor";
+ LOGV2_WARNING(22715, "unknown exception closing cursor");
}
}
}
diff --git a/src/mongo/s/client/shard.cpp b/src/mongo/s/client/shard.cpp
index 0ee5444dc5a..f76216b1c4a 100644
--- a/src/mongo/s/client/shard.cpp
+++ b/src/mongo/s/client/shard.cpp
@@ -38,6 +38,7 @@
#include "mongo/s/write_ops/batched_command_request.h"
#include "mongo/s/write_ops/batched_command_response.h"
+#include "mongo/logv2/log.h"
#include "mongo/util/log.h"
namespace mongo {
@@ -125,9 +126,12 @@ StatusWith<Shard::CommandResponse> Shard::runCommand(OperationContext* opCtx,
auto swResponse = _runCommand(opCtx, readPref, dbName, maxTimeMSOverride, cmdObj);
auto status = CommandResponse::getEffectiveStatus(swResponse);
if (isRetriableError(status.code(), retryPolicy)) {
- LOG(2) << "Command " << redact(cmdObj)
- << " failed with retriable error and will be retried"
- << causedBy(redact(status));
+ LOGV2_DEBUG(
+ 22719,
+ 2,
+ "Command {cmdObj} failed with retriable error and will be retried{causedBy_status}",
+ "cmdObj"_attr = redact(cmdObj),
+ "causedBy_status"_attr = causedBy(redact(status)));
continue;
}
@@ -162,9 +166,12 @@ StatusWith<Shard::CommandResponse> Shard::runCommandWithFixedRetryAttempts(
auto swResponse = _runCommand(opCtx, readPref, dbName, maxTimeMSOverride, cmdObj);
auto status = CommandResponse::getEffectiveStatus(swResponse);
if (retry < kOnErrorNumRetries && isRetriableError(status.code(), retryPolicy)) {
- LOG(2) << "Command " << redact(cmdObj)
- << " failed with retriable error and will be retried"
- << causedBy(redact(status));
+ LOGV2_DEBUG(
+ 22720,
+ 2,
+ "Command {cmdObj} failed with retriable error and will be retried{causedBy_status}",
+ "cmdObj"_attr = redact(cmdObj),
+ "causedBy_status"_attr = causedBy(redact(status)));
continue;
}
@@ -207,9 +214,12 @@ BatchedCommandResponse Shard::runBatchWriteCommand(OperationContext* opCtx,
BatchedCommandResponse batchResponse;
auto writeStatus = CommandResponse::processBatchWriteResponse(swResponse, &batchResponse);
if (retry < kOnErrorNumRetries && isRetriableError(writeStatus.code(), retryPolicy)) {
- LOG(2) << "Batch write command to " << getId()
- << " failed with retriable error and will be retried"
- << causedBy(redact(writeStatus));
+ LOGV2_DEBUG(22721,
+ 2,
+ "Batch write command to {getId} failed with retriable error and will be "
+ "retried{causedBy_writeStatus}",
+ "getId"_attr = getId(),
+ "causedBy_writeStatus"_attr = causedBy(redact(writeStatus)));
continue;
}
diff --git a/src/mongo/s/client/shard_connection.cpp b/src/mongo/s/client/shard_connection.cpp
index b78e4aefeeb..55bc10c5f5f 100644
--- a/src/mongo/s/client/shard_connection.cpp
+++ b/src/mongo/s/client/shard_connection.cpp
@@ -37,6 +37,7 @@
#include "mongo/base/init.h"
#include "mongo/db/lasterror.h"
+#include "mongo/logv2/log.h"
#include "mongo/s/chunk_manager.h"
#include "mongo/s/client/shard.h"
#include "mongo/s/client/shard_connection_gen.h"
@@ -184,8 +185,10 @@ public:
const bool isConnGood = shardConnectionPool.isConnectionGood(addr, conn);
if (s->avail != nullptr) {
- warning() << "Detected additional sharded connection in the "
- << "thread local pool for " << addr;
+ LOGV2_WARNING(
+ 22717,
+ "Detected additional sharded connection in the thread local pool for {addr}",
+ "addr"_attr = addr);
if (DBException::traceExceptions.load()) {
// There shouldn't be more than one connection checked out to the same
@@ -247,8 +250,11 @@ public:
versionManager.checkShardVersionCB(opCtx, s->avail, ns, false, 1);
} catch (const DBException& ex) {
- warning() << "Problem while initially checking shard versions on"
- << " " << shardId << causedBy(redact(ex));
+ LOGV2_WARNING(
+ 22718,
+ "Problem while initially checking shard versions on {shardId}{causedBy_ex}",
+ "shardId"_attr = shardId,
+ "causedBy_ex"_attr = causedBy(redact(ex)));
// NOTE: This is only a heuristic, to avoid multiple stale version retries across
// multiple shards, and does not affect correctness.
@@ -399,8 +405,9 @@ ShardConnection::~ShardConnection() {
}
} else {
// see done() comments above for why we log this line
- log() << "sharded connection to " << _conn->getServerAddress()
- << " not being returned to the pool";
+ LOGV2(22716,
+ "sharded connection to {conn_getServerAddress} not being returned to the pool",
+ "conn_getServerAddress"_attr = _conn->getServerAddress());
kill();
}
diff --git a/src/mongo/s/client/shard_registry.cpp b/src/mongo/s/client/shard_registry.cpp
index 16b1f8bf5f4..66659121c5f 100644
--- a/src/mongo/s/client/shard_registry.cpp
+++ b/src/mongo/s/client/shard_registry.cpp
@@ -50,6 +50,7 @@
#include "mongo/executor/task_executor.h"
#include "mongo/executor/task_executor_pool.h"
#include "mongo/executor/thread_pool_task_executor.h"
+#include "mongo/logv2/log.h"
#include "mongo/platform/mutex.h"
#include "mongo/rpc/metadata/egress_metadata_hook_list.h"
#include "mongo/s/catalog/sharding_catalog_client.h"
@@ -99,7 +100,7 @@ ShardRegistry::~ShardRegistry() {
void ShardRegistry::shutdown() {
if (_executor && !_isShutdown) {
- LOG(1) << "Shutting down task executor for reloading shard registry";
+ LOGV2_DEBUG(22723, 1, "Shutting down task executor for reloading shard registry");
_executor->shutdown();
_executor->join();
_isShutdown = true;
@@ -228,28 +229,31 @@ void ShardRegistry::startup(OperationContext* opCtx) {
auto netPtr = net.get();
_executor = std::make_unique<ThreadPoolTaskExecutor>(
std::make_unique<NetworkInterfaceThreadPool>(netPtr), std::move(net));
- LOG(1) << "Starting up task executor for periodic reloading of ShardRegistry";
+ LOGV2_DEBUG(22724, 1, "Starting up task executor for periodic reloading of ShardRegistry");
_executor->startup();
auto status =
_executor->scheduleWork([this](const CallbackArgs& cbArgs) { _internalReload(cbArgs); });
if (status.getStatus() == ErrorCodes::ShutdownInProgress) {
- LOG(1) << "Cant schedule Shard Registry reload. "
- << "Executor shutdown in progress";
+ LOGV2_DEBUG(22725, 1, "Cant schedule Shard Registry reload. Executor shutdown in progress");
return;
}
if (!status.isOK()) {
- severe() << "Can't schedule ShardRegistry reload due to " << causedBy(status.getStatus());
+ LOGV2_FATAL(22737,
+ "Can't schedule ShardRegistry reload due to {causedBy_status_getStatus}",
+ "causedBy_status_getStatus"_attr = causedBy(status.getStatus()));
fassertFailed(40252);
}
}
void ShardRegistry::_internalReload(const CallbackArgs& cbArgs) {
- LOG(1) << "Reloading shardRegistry";
+ LOGV2_DEBUG(22726, 1, "Reloading shardRegistry");
if (!cbArgs.status.isOK()) {
- warning() << "cant reload ShardRegistry " << causedBy(cbArgs.status);
+ LOGV2_WARNING(22734,
+ "cant reload ShardRegistry {causedBy_cbArgs_status}",
+ "causedBy_cbArgs_status"_attr = causedBy(cbArgs.status));
return;
}
@@ -260,8 +264,11 @@ void ShardRegistry::_internalReload(const CallbackArgs& cbArgs) {
try {
reload(opCtx.get());
} catch (const DBException& e) {
- log() << "Periodic reload of shard registry failed " << causedBy(e) << "; will retry after "
- << kRefreshPeriod;
+ LOGV2(22727,
+ "Periodic reload of shard registry failed {causedBy_e}; will retry after "
+ "{kRefreshPeriod}",
+ "causedBy_e"_attr = causedBy(e),
+ "kRefreshPeriod"_attr = kRefreshPeriod);
}
// reschedule itself
@@ -270,13 +277,14 @@ void ShardRegistry::_internalReload(const CallbackArgs& cbArgs) {
[this](const CallbackArgs& cbArgs) { _internalReload(cbArgs); });
if (status.getStatus() == ErrorCodes::ShutdownInProgress) {
- LOG(1) << "Cant schedule ShardRegistry reload. "
- << "Executor shutdown in progress";
+ LOGV2_DEBUG(22728, 1, "Cant schedule ShardRegistry reload. Executor shutdown in progress");
return;
}
if (!status.isOK()) {
- severe() << "Can't schedule ShardRegistry reload due to " << causedBy(status.getStatus());
+ LOGV2_FATAL(22738,
+ "Can't schedule ShardRegistry reload due to {causedBy_status_getStatus}",
+ "causedBy_status_getStatus"_attr = causedBy(status.getStatus()));
fassertFailed(40253);
}
}
@@ -298,7 +306,10 @@ bool ShardRegistry::reload(OperationContext* opCtx) {
opCtx->waitForConditionOrInterrupt(
_inReloadCV, reloadLock, [&] { return _reloadState != ReloadState::Reloading; });
} catch (const DBException& e) {
- LOG(1) << "ShardRegistry reload is interrupted due to: " << redact(e.toStatus());
+ LOGV2_DEBUG(22729,
+ 1,
+ "ShardRegistry reload is interrupted due to: {e_toStatus}",
+ "e_toStatus"_attr = redact(e.toStatus()));
return false;
}
@@ -365,8 +376,11 @@ void ShardRegistry::updateReplicaSetOnConfigServer(ServiceContext* serviceContex
std::shared_ptr<Shard> s = grid->shardRegistry()->lookupRSName(connStr.getSetName());
if (!s) {
- LOG(1) << "shard not found for set: " << connStr
- << " when attempting to inform config servers of updated set membership";
+ LOGV2_DEBUG(22730,
+ 1,
+ "shard not found for set: {connStr} when attempting to inform config servers "
+ "of updated set membership",
+ "connStr"_attr = connStr);
return;
}
@@ -384,8 +398,11 @@ void ShardRegistry::updateReplicaSetOnConfigServer(ServiceContext* serviceContex
ShardingCatalogClient::kMajorityWriteConcern);
auto status = swWasUpdated.getStatus();
if (!status.isOK()) {
- error() << "RSChangeWatcher: could not update config db with connection string " << connStr
- << causedBy(redact(status));
+ LOGV2_ERROR(22736,
+ "RSChangeWatcher: could not update config db with connection string "
+ "{connStr}{causedBy_status}",
+ "connStr"_attr = connStr,
+ "causedBy_status"_attr = causedBy(redact(status)));
}
}
@@ -410,9 +427,12 @@ ShardRegistryData::ShardRegistryData(OperationContext* opCtx, ShardFactory* shar
auto shards = std::move(shardsAndOpTime.value);
auto reloadOpTime = std::move(shardsAndOpTime.opTime);
- LOG(1) << "found " << shards.size()
- << " shards listed on config server(s) with lastVisibleOpTime: "
- << reloadOpTime.toBSON();
+ LOGV2_DEBUG(22731,
+ 1,
+ "found {shards_size} shards listed on config server(s) with lastVisibleOpTime: "
+ "{reloadOpTime}",
+ "shards_size"_attr = shards.size(),
+ "reloadOpTime"_attr = reloadOpTime.toBSON());
// Ensure targeter exists for all shards and take shard connection string from the targeter.
// Do this before re-taking the mutex to avoid deadlock with the ReplicaSetMonitor updating
@@ -424,7 +444,10 @@ ShardRegistryData::ShardRegistryData(OperationContext* opCtx, ShardFactory* shar
// been stored (i.e., the entire getAllShards call would fail).
auto shardHostStatus = ConnectionString::parse(shardType.getHost());
if (!shardHostStatus.isOK()) {
- warning() << "Unable to parse shard host " << shardHostStatus.getStatus().toString();
+ LOGV2_WARNING(22735,
+ "Unable to parse shard host {shardHostStatus_getStatus}",
+ "shardHostStatus_getStatus"_attr =
+ shardHostStatus.getStatus().toString());
continue;
}
@@ -561,8 +584,12 @@ void ShardRegistryData::_addShard(WithLock lk,
auto oldConnString = currentShard->originalConnString();
if (oldConnString.toString() != connString.toString()) {
- log() << "Updating ShardRegistry connection string for shard " << currentShard->getId()
- << " from: " << oldConnString.toString() << " to: " << connString.toString();
+ LOGV2(22732,
+ "Updating ShardRegistry connection string for shard {currentShard_getId} from: "
+ "{oldConnString} to: {connString}",
+ "currentShard_getId"_attr = currentShard->getId(),
+ "oldConnString"_attr = oldConnString.toString(),
+ "connString"_attr = connString.toString());
}
for (const auto& host : oldConnString.getServers()) {
@@ -574,7 +601,11 @@ void ShardRegistryData::_addShard(WithLock lk,
_lookup[shard->getId()] = shard;
- LOG(3) << "Adding shard " << shard->getId() << ", with CS " << connString.toString();
+ LOGV2_DEBUG(22733,
+ 3,
+ "Adding shard {shard_getId}, with CS {connString}",
+ "shard_getId"_attr = shard->getId(),
+ "connString"_attr = connString.toString());
if (connString.type() == ConnectionString::SET) {
_rsLookup[connString.getSetName()] = shard;
} else if (connString.type() == ConnectionString::CUSTOM) {
diff --git a/src/mongo/s/client/shard_remote.cpp b/src/mongo/s/client/shard_remote.cpp
index c28a962636b..544f7e19c7e 100644
--- a/src/mongo/s/client/shard_remote.cpp
+++ b/src/mongo/s/client/shard_remote.cpp
@@ -47,6 +47,7 @@
#include "mongo/db/query/query_request.h"
#include "mongo/db/repl/read_concern_args.h"
#include "mongo/executor/task_executor_pool.h"
+#include "mongo/logv2/log.h"
#include "mongo/rpc/get_status_from_command_result.h"
#include "mongo/rpc/metadata/repl_set_metadata.h"
#include "mongo/rpc/metadata/tracking_metadata.h"
@@ -229,7 +230,9 @@ StatusWith<Shard::CommandResponse> ShardRemote::_runCommand(OperationContext* op
if (!response.status.isOK()) {
if (ErrorCodes::isExceededTimeLimitError(response.status.code())) {
- LOG(0) << "Operation timed out with status " << redact(response.status);
+ LOGV2(22739,
+ "Operation timed out with status {response_status}",
+ "response_status"_attr = redact(response.status));
}
return response.status;
}
@@ -327,7 +330,9 @@ StatusWith<Shard::QueryResponse> ShardRemote::_runExhaustiveCursorCommand(
if (!status.isOK()) {
if (ErrorCodes::isExceededTimeLimitError(status.code())) {
- LOG(0) << "Operation timed out " << causedBy(status);
+ LOGV2(22740,
+ "Operation timed out {causedBy_status}",
+ "causedBy_status"_attr = causedBy(status));
}
return status;
}
diff --git a/src/mongo/s/client/sharding_connection_hook.cpp b/src/mongo/s/client/sharding_connection_hook.cpp
index cbdad3a1257..e55396f6347 100644
--- a/src/mongo/s/client/sharding_connection_hook.cpp
+++ b/src/mongo/s/client/sharding_connection_hook.cpp
@@ -38,6 +38,7 @@
#include "mongo/bson/util/bson_extract.h"
#include "mongo/client/authenticate.h"
#include "mongo/db/client.h"
+#include "mongo/logv2/log.h"
#include "mongo/rpc/get_status_from_command_result.h"
#include "mongo/s/client/version_manager.h"
#include "mongo/util/log.h"
@@ -58,7 +59,7 @@ void ShardingConnectionHook::onCreate(DBClientBase* conn) {
// Authenticate as the first thing we do
// NOTE: Replica set authentication allows authentication against *any* online host
if (auth::isInternalAuthSet()) {
- LOG(2) << "calling onCreate auth for " << conn->toString();
+ LOGV2_DEBUG(22722, 2, "calling onCreate auth for {conn}", "conn"_attr = conn->toString());
uassertStatusOKWithContext(conn->authenticateInternalUser(),
str::stream() << "can't authenticate to server "
diff --git a/src/mongo/s/client/version_manager.cpp b/src/mongo/s/client/version_manager.cpp
index 69a4ab67b5a..a24ef43df52 100644
--- a/src/mongo/s/client/version_manager.cpp
+++ b/src/mongo/s/client/version_manager.cpp
@@ -36,6 +36,7 @@
#include "mongo/client/dbclient_cursor.h"
#include "mongo/client/dbclient_rs.h"
#include "mongo/db/namespace_string.h"
+#include "mongo/logv2/log.h"
#include "mongo/s/catalog_cache.h"
#include "mongo/s/client/shard_connection.h"
#include "mongo/s/client/shard_registry.h"
@@ -202,7 +203,7 @@ bool initShardVersionEmptyNS(OperationContext* opCtx, DBClientBase* conn_in) {
true,
result);
- LOG(3) << "initial sharding result : " << result;
+ LOGV2_DEBUG(22741, 3, "initial sharding result : {result}", "result"_attr = result);
connectionShardStatus.setSequence(conn, "", 0);
return ok;
@@ -221,8 +222,9 @@ bool initShardVersionEmptyNS(OperationContext* opCtx, DBClientBase* conn_in) {
static Occasionally sampler;
if (sampler.tick()) {
- warning() << "failed to initialize new replica set connection version, "
- << "will initialize on first use";
+ LOGV2_WARNING(22747,
+ "failed to initialize new replica set connection version, will "
+ "initialize on first use");
}
return false;
@@ -343,11 +345,19 @@ bool checkShardVersion(OperationContext* opCtx,
version = manager->getVersion(shard->getId());
}
- LOG(1) << "setting shard version of " << version << " for " << ns << " on shard "
- << shard->toString();
+ LOGV2_DEBUG(22742,
+ 1,
+ "setting shard version of {version} for {ns} on shard {shard}",
+ "version"_attr = version,
+ "ns"_attr = ns,
+ "shard"_attr = shard->toString());
- LOG(3) << "last version sent with chunk manager iteration " << sequenceNumber
- << ", current chunk manager iteration is " << officialSequenceNumber;
+ LOGV2_DEBUG(22743,
+ 3,
+ "last version sent with chunk manager iteration {sequenceNumber}, current chunk "
+ "manager iteration is {officialSequenceNumber}",
+ "sequenceNumber"_attr = sequenceNumber,
+ "officialSequenceNumber"_attr = officialSequenceNumber);
BSONObj result;
if (setShardVersion(opCtx,
@@ -358,7 +368,7 @@ bool checkShardVersion(OperationContext* opCtx,
manager.get(),
authoritative,
result)) {
- LOG(1) << " setShardVersion success: " << result;
+ LOGV2_DEBUG(22744, 1, " setShardVersion success: {result}", "result"_attr = result);
connectionShardStatus.setSequence(conn, ns, officialSequenceNumber);
return true;
}
@@ -367,7 +377,7 @@ bool checkShardVersion(OperationContext* opCtx,
int errCode = result["code"].numberInt();
uassert(errCode, result["errmsg"].String(), errCode != ErrorCodes::NoShardingEnabled);
- LOG(1) << " setShardVersion failed!\n" << result;
+ LOGV2_DEBUG(22745, 1, " setShardVersion failed!\n{result}", "result"_attr = result);
if (result["need_authoritative"].trueValue())
massert(10428, "need_authoritative set but in authoritative mode already", !authoritative);
@@ -394,7 +404,7 @@ bool checkShardVersion(OperationContext* opCtx,
string errmsg = str::stream() << "setShardVersion failed shard: " << shard->toString() << " "
<< result;
- log() << " " << errmsg;
+ LOGV2(22746, " {errmsg}", "errmsg"_attr = errmsg);
massert(10429, errmsg, 0);
return true;
}
View Lorry Controller Status