-
Type:
Bug
-
Resolution: Done
-
Priority:
Major - P3
-
Affects Version/s: 2.8.0-rc2
-
Component/s: Concurrency, Performance, Storage
-
Fully Compatible
-
ALL
As the title suggests. It's the hottest mutex in mongo-WT at the time of writing for some workloads (e.g. sysbench). I'm attaching some stacktraces to give better sense of the caller(s), together with percentages of time the lock is held.
Also, the VTune attached output shows up how the wait time on this lock is more than an order on magnitude than the second more contested lock.
Waiting Call Stack 1 of 22: 27.1% (1977.143s of 7292.660s) mongod!lock+0x7 - mutex.hpp:59 mongod!lock+0 - locks.hpp:412 mongod!unique_lock+0 - locks.hpp:290 mongod!unlock_shared+0 - shared_mutex.hpp:108 mongod!~shared_lock+0 - locks.hpp:656 mongod!mongo::WiredTigerSessionCache::releaseSession+0x2c8 - wiredtiger_session_cache.cpp:187 mongod!mongo::WiredTigerRecoveryUnit::~WiredTigerRecoveryUnit+0x34 - wiredtiger_recovery_unit.cpp:90 mongod!mongo::WiredTigerRecoveryUnit::~WiredTigerRecoveryUnit+0x8 - wiredtiger_recovery_unit.cpp:93 mongod!~auto_ptr+0xe - auto_ptr.h:170 mongod!mongo::OperationContextImpl::~OperationContextImpl+0x2c - operation_context_impl.cpp:69 mongod!mongo::MyMessageHandler::process+0x5c2 - db.cpp:223 mongod!mongo::PortMessageServer::handleIncomingMsg+0x410 - 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 22: 23.5% (1716.518s of 7292.660s) mongod!lock+0x7 - mutex.hpp:59 mongod!lock+0 - locks.hpp:412 mongod!unique_lock+0xe - locks.hpp:290 mongod!lock_shared+0x18 - shared_mutex.hpp:60 mongod!lock+0 - locks.hpp:665 mongod!shared_lock+0 - locks.hpp:545 mongod!mongo::WiredTigerSessionCache::releaseSession+0x2a - wiredtiger_session_cache.cpp:181 mongod!mongo::WiredTigerRecoveryUnit::~WiredTigerRecoveryUnit+0x34 - wiredtiger_recovery_unit.cpp:90 mongod!mongo::WiredTigerRecoveryUnit::~WiredTigerRecoveryUnit+0x8 - wiredtiger_recovery_unit.cpp:93 mongod!~auto_ptr+0xe - auto_ptr.h:170 mongod!mongo::OperationContextImpl::~OperationContextImpl+0x2c - operation_context_impl.cpp:69 mongod!mongo::MyMessageHandler::process+0x5c2 - db.cpp:223 mongod!mongo::PortMessageServer::handleIncomingMsg+0x410 - 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 22: 14.9% (1085.382s of 7292.660s) mongod!lock+0x7 - mutex.hpp:59 mongod!lock+0 - locks.hpp:412 mongod!unique_lock+0 - locks.hpp:290 mongod!~shared_lock+0 - locks.hpp:656 mongod!mongo::WiredTigerSessionCache::getSession+0x327 - wiredtiger_session_cache.cpp:174 mongod!mongo::WiredTigerRecoveryUnit::getSession+0x38 - wiredtiger_recovery_unit.cpp:179 mongod!mongo::WiredTigerCursor::_init+0x1f - wiredtiger_recovery_unit.cpp:251 mongod!mongo::WiredTigerIndex::IndexCursor::IndexCursor+0x32 - wiredtiger_index.cpp:603 mongod!mongo::WiredTigerIndex::newCursor+0x39 - wiredtiger_index.cpp:397 mongod!mongo::BtreeBasedAccessMethod::findSingle+0x24 - btree_based_access_method.cpp:210 mongod!mongo::IDHackStage::work+0xeb - idhack.cpp:123 mongod!mongo::ProjectionStage::work+0x4d - projection.cpp:208 mongod!mongo::PlanExecutor::getNext+0x99 - plan_executor.cpp:288 mongod!mongo::runQuery+0xa93 - find.cpp:713 mongod!receivedQuery+0x1e4 - instance.cpp:221 mongod!mongo::assembleResponse+0x940 - instance.cpp:391 mongod!mongo::MyMessageHandler::process+0xdf - db.cpp:194 mongod!mongo::PortMessageServer::handleIncomingMsg+0x410 - 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 22: 13.1% (955.371s of 7292.660s) mongod!lock+0x7 - mutex.hpp:59 mongod!lock+0 - locks.hpp:412 mongod!unique_lock+0xe - locks.hpp:290 mongod!lock_shared+0x23 - shared_mutex.hpp:60 mongod!lock+0 - locks.hpp:665 mongod!shared_lock+0 - locks.hpp:545 mongod!mongo::WiredTigerSessionCache::getSession+0x7 - wiredtiger_session_cache.cpp:157 mongod!mongo::WiredTigerRecoveryUnit::getSession+0x38 - wiredtiger_recovery_unit.cpp:179 mongod!mongo::WiredTigerCursor::_init+0x1f - wiredtiger_recovery_unit.cpp:251 mongod!mongo::WiredTigerIndex::IndexCursor::IndexCursor+0x32 - wiredtiger_index.cpp:603 mongod!mongo::WiredTigerIndex::newCursor+0x39 - wiredtiger_index.cpp:397 mongod!mongo::BtreeBasedAccessMethod::findSingle+0x24 - btree_based_access_method.cpp:210 mongod!mongo::IDHackStage::work+0xeb - idhack.cpp:123 mongod!mongo::ProjectionStage::work+0x4d - projection.cpp:208 mongod!mongo::PlanExecutor::getNext+0x99 - plan_executor.cpp:288 mongod!mongo::runQuery+0xa93 - find.cpp:713 mongod!receivedQuery+0x1e4 - instance.cpp:221 mongod!mongo::assembleResponse+0x940 - instance.cpp:391 mongod!mongo::MyMessageHandler::process+0xdf - db.cpp:194 mongod!mongo::PortMessageServer::handleIncomingMsg+0x410 - 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 22: 2.7% (194.191s of 7292.660s) mongod!lock+0x7 - mutex.hpp:59 mongod!lock+0 - locks.hpp:412 mongod!unique_lock+0 - locks.hpp:290 mongod!~shared_lock+0 - locks.hpp:656 mongod!mongo::WiredTigerSessionCache::getSession+0x327 - wiredtiger_session_cache.cpp:174 mongod!mongo::WiredTigerRecoveryUnit::getSession+0x38 - wiredtiger_recovery_unit.cpp:179 mongod!mongo::WiredTigerCursor::_init+0x1f - wiredtiger_recovery_unit.cpp:251 mongod!mongo::WiredTigerIndex::IndexCursor::IndexCursor+0x32 - wiredtiger_index.cpp:603 mongod!mongo::WiredTigerIndex::newCursor+0x39 - wiredtiger_index.cpp:397 mongod!mongo::BtreeBasedAccessMethod::findSingle+0x24 - btree_based_access_method.cpp:210 mongod!mongo::IDHackStage::work+0xeb - idhack.cpp:123 mongod!mongo::UpdateStage::work+0x7b - update.cpp:706 mongod!mongo::PlanExecutor::getNext+0x99 - plan_executor.cpp:288 mongod!mongo::PlanExecutor::executePlan+0x3c - plan_executor.cpp:400 mongod!mongo::UpdateExecutor::execute+0x131 - update_executor.cpp:237 mongod!multiUpdate+0x411 - batch_executor.cpp:1277 mongod!mongo::WriteBatchExecutor::execUpdate+0x79 - batch_executor.cpp:891 mongod!mongo::WriteBatchExecutor::bulkExecute+0x1f1 - batch_executor.cpp:761 mongod!mongo::WriteBatchExecutor::executeBatch+0x394 - batch_executor.cpp:262 mongod!mongo::WriteCmd::run+0x172 - write_commands.cpp:144 mongod!mongo::_execCommand+0x33 - dbcommands.cpp:1231 mongod!mongo::Command::execCommand+0xc24 - dbcommands.cpp:1445 mongod!mongo::_runCommands+0x289 - dbcommands.cpp:1520 mongod!runCommands+0x32 - find.cpp:131 mongod!mongo::runQuery+0x4a - find.cpp:527 mongod!receivedQuery+0x1e4 - instance.cpp:221 mongod!mongo::assembleResponse+0x940 - instance.cpp:391 mongod!mongo::MyMessageHandler::process+0xdf - db.cpp:194 mongod!mongo::PortMessageServer::handleIncomingMsg+0x410 - message_server_port.cpp:234 libpthread-2.18.so!start_thread+0xc2 - [Unknown]:[Unknown] libc-2.18.so!__clone+0x6c - [Unknown]:[Unknown]
