-
Type:
Bug
-
Resolution: Done
-
Priority:
Major - P3
-
Affects Version/s: None
-
Component/s: Concurrency, Replication
-
Labels:
-
ALL
Running sysbench and profiling with VTune, the lock protecting canAccpetWritesForDatabase resulted very contented, even if mongod is
run as standalone.
bool ReplicationCoordinatorImpl::canAcceptWritesForDatabase(const StringData& dbName) { // we must check _settings since getReplicationMode() isn't aware of modeReplSet // until a valid replica set config has been loaded boost::lock_guard<boost::mutex> lk(_mutex); if (_settings.usingReplSets()) { if (_getReplicationMode_inlock() == modeReplSet && _getCurrentMemberState_inlock().primary() && !_isWaitingForDrainToComplete) { return true; } return dbName == "local"; }
Code inspection shows up that, some functions, e.g. newRunQuery() call replication code unconditionally, i.e.
// uassert if we are not on a primary, and not a secondary with SlaveOk query parameter set.
bool slaveOK = pq.getOptions().slaveOk || pq.hasReadPref();
status = repl::getGlobalReplicationCoordinator()->checkCanServeReadsFor(
txn,
NamespaceString(cq->ns()),
slaveOK);
uassertStatusOK(status);
Hence, during high load that mutex might become a bottleneck.
Vtune stacktraces, together with lock percentages:
Waiting Call Stack 1 of 7: 43.4% (493.236s of 1135.355s) mongod!boost::mutex::lock+0x17 - mutex.hpp:59 mongod!lock_guard+0xb - locks.hpp:257 mongod!mongo::repl::ReplicationCoordinatorImpl::canAcceptWritesForDatabase+0xe - repl_coordinator_impl.cpp:1195 mongod!mongo::repl::ReplicationCoordinatorImpl::checkCanServeReadsFor+0x4a - repl_coordinator_impl.cpp:1227 mongod!mongo::newRunQuery+0x74d - new_find.cpp:672 mongod!receivedQuery+0x1f2 - instance.cpp:220 mongod!mongo::assembleResponse+0x9d0 - instance.cpp:393 mongod!mongo::MyMessageHandler::process+0xdf - db.cpp:185 mongod!mongo::PortMessageServer::handleIncomingMsg+0x420 - message_server_port.cpp:234 libpthread-2.18.so!start_thread+0xc2 - [Unknown]:[Unknown] libc-2.18.so!__clone+0x6c - [Unknown]:[Unknown]
Waiting Call Stack 2 of 7: 23.0% (261.345s of 1135.355s) mongod!boost::mutex::lock+0x17 - mutex.hpp:59 mongod!lock_guard+0xb - locks.hpp:257 mongod!mongo::repl::ReplicationCoordinatorImpl::canAcceptWritesForDatabase+0xe - repl_coordinator_impl.cpp:1195 mongod!mongo::Command::execCommand+0x5da - dbcommands.cpp:1319 mongod!mongo::_runCommands+0x221 - dbcommands.cpp:1464 mongod!runCommands+0x23 - new_find.cpp:131 mongod!mongo::newRunQuery+0xff9 - new_find.cpp:551 mongod!receivedQuery+0x1f2 - instance.cpp:220 mongod!mongo::assembleResponse+0x9d0 - instance.cpp:393 mongod!mongo::MyMessageHandler::process+0xdf - db.cpp:185 mongod!mongo::PortMessageServer::handleIncomingMsg+0x420 - message_server_port.cpp:234 libpthread-2.18.so!start_thread+0xc2 - [Unknown]:[Unknown] libc-2.18.so!__clone+0x6c - [Unknown]:[Unknown]
Waiting Call Stack 3 of 7: 12.4% (140.897s of 1135.355s) mongod!boost::mutex::lock+0x17 - mutex.hpp:59 mongod!lock_guard+0xb - locks.hpp:257 mongod!mongo::repl::ReplicationCoordinatorImpl::canAcceptWritesForDatabase+0xe - repl_coordinator_impl.cpp:1195 mongod!mongo::UpdateStage::restoreUpdateState+0xb4 - update.cpp:831 mongod!mongo::UpdateStage::restoreState+0x2f - update.cpp:858 mongod!mongo::UpdateStage::work+0x2b9 - update.cpp:786 mongod!mongo::PlanExecutor::getNext+0x99 - plan_executor.cpp:288 mongod!mongo::PlanExecutor::executePlan+0x3c - plan_executor.cpp:400 mongod!mongo::UpdateExecutor::execute+0x130 - update_executor.cpp:214 mongod!multiUpdate+0x498 - batch_executor.cpp:1273 mongod!mongo::WriteBatchExecutor::execUpdate+0x79 - batch_executor.cpp:880 mongod!mongo::WriteBatchExecutor::bulkExecute+0x1f1 - batch_executor.cpp:761 mongod!mongo::WriteBatchExecutor::executeBatch+0x3a4 - batch_executor.cpp:263 mongod!mongo::WriteCmd::run+0x168 - write_commands.cpp:143 mongod!mongo::_execCommand+0x33 - dbcommands.cpp:1174 mongod!mongo::Command::execCommand+0xca0 - dbcommands.cpp:1388 mongod!mongo::_runCommands+0x221 - dbcommands.cpp:1464 mongod!runCommands+0x23 - new_find.cpp:131 mongod!mongo::newRunQuery+0xff9 - new_find.cpp:551 mongod!receivedQuery+0x1f2 - instance.cpp:220 mongod!mongo::assembleResponse+0x9d0 - instance.cpp:393 mongod!mongo::MyMessageHandler::process+0xdf - db.cpp:185 mongod!mongo::PortMessageServer::handleIncomingMsg+0x420 - message_server_port.cpp:234 libpthread-2.18.so!start_thread+0xc2 - [Unknown]:[Unknown] libc-2.18.so!__clone+0x6c - [Unknown]:[Unknown]
Waiting Call Stack 4 of 7: 7.5% (85.389s of 1135.355s) mongod!boost::mutex::lock+0x17 - mutex.hpp:59 mongod!lock_guard+0xb - locks.hpp:257 mongod!mongo::repl::ReplicationCoordinatorImpl::canAcceptWritesForDatabase+0xe - repl_coordinator_impl.cpp:1195 mongod!mongo::UpdateExecutor::prepareInLock+0x2df - update_executor.cpp:154 mongod!mongo::UpdateExecutor::execute+0xfe - update_executor.cpp:206 mongod!multiUpdate+0x498 - batch_executor.cpp:1273 mongod!mongo::WriteBatchExecutor::execUpdate+0x79 - batch_executor.cpp:880 mongod!mongo::WriteBatchExecutor::bulkExecute+0x1f1 - batch_executor.cpp:761 mongod!mongo::WriteBatchExecutor::executeBatch+0x3a4 - batch_executor.cpp:263 mongod!mongo::WriteCmd::run+0x168 - write_commands.cpp:143 mongod!mongo::_execCommand+0x33 - dbcommands.cpp:1174 mongod!mongo::Command::execCommand+0xca0 - dbcommands.cpp:1388 mongod!mongo::_runCommands+0x221 - dbcommands.cpp:1464 mongod!runCommands+0x23 - new_find.cpp:131 mongod!mongo::newRunQuery+0xff9 - new_find.cpp:551 mongod!receivedQuery+0x1f2 - instance.cpp:220 mongod!mongo::assembleResponse+0x9d0 - instance.cpp:393 mongod!mongo::MyMessageHandler::process+0xdf - db.cpp:185 mongod!mongo::PortMessageServer::handleIncomingMsg+0x420 - message_server_port.cpp:234 libpthread-2.18.so!start_thread+0xc2 - [Unknown]:[Unknown] libc-2.18.so!__clone+0x6c - [Unknown]:[Unknown]
Waiting Call Stack 5 of 7: 5.8% (66.230s of 1135.355s) mongod!boost::mutex::lock+0x17 - mutex.hpp:59 mongod!lock_guard+0xb - locks.hpp:257 mongod!mongo::repl::ReplicationCoordinatorImpl::canAcceptWritesForDatabase+0xe - repl_coordinator_impl.cpp:1195 mongod!mongo::DeleteStage::restoreState+0x7c - delete.cpp:172 mongod!mongo::DeleteStage::work+0x28e - delete.cpp:131 mongod!mongo::PlanExecutor::getNext+0x99 - plan_executor.cpp:288 mongod!mongo::PlanExecutor::executePlan+0x3c - plan_executor.cpp:400 mongod!mongo::DeleteExecutor::execute+0x59 - delete_executor.cpp:185 mongod!multiRemove+0x267 - batch_executor.cpp:1358 mongod!mongo::WriteBatchExecutor::execRemove+0x74 - batch_executor.cpp:909 mongod!mongo::WriteBatchExecutor::bulkExecute+0xf4 - batch_executor.cpp:782 mongod!mongo::WriteBatchExecutor::executeBatch+0x3a4 - batch_executor.cpp:263 mongod!mongo::WriteCmd::run+0x168 - write_commands.cpp:143 mongod!mongo::_execCommand+0x33 - dbcommands.cpp:1174 mongod!mongo::Command::execCommand+0xca0 - dbcommands.cpp:1388 mongod!mongo::_runCommands+0x221 - dbcommands.cpp:1464 mongod!runCommands+0x23 - new_find.cpp:131 mongod!mongo::newRunQuery+0xff9 - new_find.cpp:551 mongod!receivedQuery+0x1f2 - instance.cpp:220 mongod!mongo::assembleResponse+0x9d0 - instance.cpp:393 mongod!mongo::MyMessageHandler::process+0xdf - db.cpp:185 mongod!mongo::PortMessageServer::handleIncomingMsg+0x420 - message_server_port.cpp:234 libpthread-2.18.so!start_thread+0xc2 - [Unknown]:[Unknown] libc-2.18.so!__clone+0x6c - [Unknown]:[Unknown]
Waiting Call Stack 6 of 7: 3.9% (44.155s of 1135.355s) mongod!boost::mutex::lock+0x17 - mutex.hpp:59 mongod!lock_guard+0xb - locks.hpp:257 mongod!mongo::repl::ReplicationCoordinatorImpl::canAcceptWritesForDatabase+0xe - repl_coordinator_impl.cpp:1195 mongod!checkIsMasterForDatabase+0x7e - batch_executor.cpp:461 mongod!mongo::WriteBatchExecutor::ExecInsertsState::_lockAndCheckImpl+0x2f4 - batch_executor.cpp:966 mongod!lockAndCheck+0x119 - batch_executor.cpp:1009 mongod!insertOne+0x8f - batch_executor.cpp:1037 mongod!mongo::WriteBatchExecutor::execOneInsert+0x5f - batch_executor.cpp:1065 mongod!mongo::WriteBatchExecutor::execInserts+0x22c - batch_executor.cpp:860 mongod!mongo::WriteBatchExecutor::bulkExecute+0x33 - batch_executor.cpp:754 mongod!mongo::WriteBatchExecutor::executeBatch+0x3a4 - batch_executor.cpp:263 mongod!mongo::WriteCmd::run+0x168 - write_commands.cpp:143 mongod!mongo::_execCommand+0x33 - dbcommands.cpp:1174 mongod!mongo::Command::execCommand+0xca0 - dbcommands.cpp:1388 mongod!mongo::_runCommands+0x221 - dbcommands.cpp:1464 mongod!runCommands+0x23 - new_find.cpp:131 mongod!mongo::newRunQuery+0xff9 - new_find.cpp:551 mongod!receivedQuery+0x1f2 - instance.cpp:220 mongod!mongo::assembleResponse+0x9d0 - instance.cpp:393 mongod!mongo::MyMessageHandler::process+0xdf - db.cpp:185 mongod!mongo::PortMessageServer::handleIncomingMsg+0x420 - message_server_port.cpp:234 libpthread-2.18.so!start_thread+0xc2 - [Unknown]:[Unknown] libc-2.18.so!__clone+0x6c - [Unknown]:[Unknown]
