|
mdcallag, I went back to rc4 and I do see the temporary hangs in some operations, most notably show collections. Therefore I'm going to mark this ticket as "fixed" in rc5 – thanks for your report!
|
|
Nevermind – it was pointed out to me I have a typo in my index build command, which turns it into a foreground index build and hence blocks other operations. I'm not able to reproduce hangs in either rc5 or master right now, so I'm going to resolve this ticket. Apologies for the pilot error, and thanks for your all your help mdcallag.
|
|
Thanks for reproducing this.
Now I easily get the hang in rc4 for this, but my longer running test did not get it for rc5
db.purchases_index.ensureIndex({"price":1, "customerid":1}, {"background":true});
|
And these are all of the ensureIndex commands
db.purchases_index.ensureIndex({"price":1, "customerid":1}, {"background":true});
|
db.purchases_index.ensureIndex({"cashregisterid" : 1, "price" : 1, "customerid" : 1}, {"background":true});
|
db.purchases_index.ensureIndex({"price" : 1, "dateandtime" : 1, "customerid" : 1}, {"background":true});
|
Thread stacks from an rc4 hang
1 select,mongo::Listener::initAndListen,_initAndListen,mongo::initAndListen,mongoDbMain,main
|
1 __rec_row_leaf,__wt_reconcile,__evict_review,__wt_evict,__wt_evict_page,__wt_evict_lru_page,__evict_lru_pages,__evict_server_work,__evict_pass,__evict_server,start_thread,clone
|
1 pthread_cond_wait@@GLIBC_2.3.2,wait<boost::unique_lock<boost::timed_mutex>,mongo::DeadlineMonitor<mongo::V8Scope>::deadlineMonitorThread,boost::(anonymous,start_thread,clone
|
1 pthread_cond_timedwait@@GLIBC_2.3.2,__wt_cond_wait,__sweep_server,start_thread,clone
|
1 pthread_cond_timedwait@@GLIBC_2.3.2,__wt_cond_wait,__log_server,start_thread,clone
|
1 pthread_cond_timedwait@@GLIBC_2.3.2,__wt_cond_wait,__ckpt_server,start_thread,clone
|
1 pthread_cond_timedwait@@GLIBC_2.3.2,timed_wait,timed_wait<boost::date_time::subsecond_duration<boost::posix_time::time_duration,,mongo::CondVarLockGrantNotification::wait,mongo::LockerImpl<false>::lockComplete,mongo::Lock::DBLock::DBLock,mongo::AutoGetDb::AutoGetDb,mongo::CmdListCollections::run,mongo::_execCommand,mongo::Command::execCommand,mongo::_runCommands,runCommands,mongo::runQuery,receivedQuery,mongo::assembleResponse,mongo::MyMessageHandler::process,mongo::PortMessageServer::handleIncomingMsg,start_thread,clone
|
1 pthread_cond_timedwait@@GLIBC_2.3.2,timed_wait<boost::unique_lock<boost::timed_mutex>,timed_wait<boost::unique_lock<boost::timed_mutex>,,mongo::RangeDeleter::doWork,boost::(anonymous,start_thread,clone
|
1 pthread_cond_timedwait@@GLIBC_2.3.2,boost::condition_variable_any::timed_wait<boost::unique_lock<boost::timed_mutex>,timed_wait<boost::unique_lock<boost::timed_mutex>,,timed_wait<boost::unique_lock<boost::timed_mutex>,,mongo::(anonymous,mongo::BackgroundJob::jobBody,boost::(anonymous,start_thread,clone
|
1 nanosleep,mongo::sleepsecs,mongo::TTLMonitor::run,mongo::BackgroundJob::jobBody,boost::(anonymous,start_thread,clone
|
1 nanosleep,mongo::sleepsecs,mongo::ClientCursorMonitor::run,mongo::BackgroundJob::jobBody,boost::(anonymous,start_thread,clone
|
1 mongo::IndexEntryComparison::compare,Compare,mongo::(anonymous,__wt_compare,__wt_row_search,__cursor_row_search,__wt_btcur_insert,__curfile_insert,mongo::WiredTigerIndexStandard::_insert,mongo::WiredTigerIndex::insert,mongo::BtreeBasedAccessMethod::insert,mongo::MultiIndexBlock::insert,mongo::MultiIndexBlock::insertAllDocumentsInCollection,mongo::CmdCreateIndex::run,mongo::_execCommand,mongo::Command::execCommand,mongo::_runCommands,runCommands,mongo::runQuery,receivedQuery,mongo::assembleResponse,mongo::MyMessageHandler::process,mongo::PortMessageServer::handleIncomingMsg,start_thread,clone
|
And db.currentOp output from an rc4 hang
{
|
"inprog" : [
|
{
|
"desc" : "conn11",
|
"threadId" : "0x7f471c6371c0",
|
"connectionId" : 11,
|
"opid" : 21000592,
|
"active" : true,
|
"secs_running" : 24,
|
"microsecs_running" : NumberLong(24965946),
|
"op" : "query",
|
"ns" : "iibench.$cmd",
|
"query" : {
|
"createIndexes" : "purchases_index",
|
"indexes" : [
|
{
|
"key" : {
|
"price" : 1,
|
"customerid" : 1
|
},
|
"name" : "price_1_customerid_1",
|
"background" : true
|
}
|
]
|
},
|
"client" : "127.0.0.1:23499",
|
"msg" : "Index Build (background) Index Build (background): 1047370/10000000 10%",
|
"progress" : {
|
"done" : 1047371,
|
"total" : 10000000
|
},
|
"locks" : {
|
"Global" : "w",
|
"Database" : "w",
|
"Collection" : "w"
|
},
|
"waitingForLock" : false,
|
"lockStats" : {
|
|
}
|
},
|
{
|
"desc" : "conn3",
|
"threadId" : "0x7f47dcc1a1c0",
|
"connectionId" : 3,
|
"opid" : 21000593,
|
"active" : true,
|
"secs_running" : 22,
|
"microsecs_running" : NumberLong(22056485),
|
"op" : "query",
|
"ns" : "iibench.$cmd",
|
"query" : {
|
"listCollections" : 1,
|
"cursor" : {
|
|
}
|
},
|
"client" : "127.0.0.1:19927",
|
"locks" : {
|
"Global" : "r",
|
"Database" : "R"
|
},
|
"waitingForLock" : true,
|
"lockStats" : {
|
|
}
|
}
|
]
|
}
|
|
|
mdcallag, what index where you building? I tried:
db.purchases_index.ensureIndex({dateandtime: 1, customerid: 1, price: 1}, {background:true})
|
and operations like show collections or db.purchases_index.getIndexes() would complete immediately. But when I try:
db.purchases_index.ensureIndex({productid:1, price:1}, {backtround:true})
|
the operations listed above, along with db.purchases_index.insert({foo:1}) hang. Here's the output of db.currentOp():
MongoDB shell version: 2.8.0-rc6-pre-
|
connecting to: test
|
{
|
"inprog" : [
|
{
|
"desc" : "conn29",
|
"threadId" : "0x13316c820",
|
"connectionId" : 29,
|
"opid" : 111863625,
|
"active" : true,
|
"secs_running" : 10,
|
"microsecs_running" : NumberLong(10965280),
|
"op" : "query",
|
"ns" : "iibench2.$cmd",
|
"query" : {
|
"listIndexes" : "purchases_index"
|
},
|
"client" : "127.0.0.1:50927",
|
"numYields" : 0,
|
"locks" : {
|
"Global" : "r",
|
"Database" : "r"
|
},
|
"waitingForLock" : true,
|
"lockStats" : {
|
"Global" : {
|
"acquireCount" : {
|
"r" : NumberLong(1),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
},
|
"acquireWaitCount" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
},
|
"timeAcquiringMicros" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
},
|
"deadlockCount" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
}
|
},
|
"MMAPV1Journal" : {
|
"acquireCount" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
},
|
"acquireWaitCount" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
},
|
"timeAcquiringMicros" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
},
|
"deadlockCount" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
}
|
},
|
"Database" : {
|
"acquireCount" : {
|
"r" : NumberLong(1),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
},
|
"acquireWaitCount" : {
|
"r" : NumberLong(1),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
},
|
"timeAcquiringMicros" : {
|
"r" : NumberLong(115516275),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
},
|
"deadlockCount" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
}
|
},
|
"Collection" : {
|
"acquireCount" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
},
|
"acquireWaitCount" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
},
|
"timeAcquiringMicros" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
},
|
"deadlockCount" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
}
|
},
|
"Metadata" : {
|
"acquireCount" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
},
|
"acquireWaitCount" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
},
|
"timeAcquiringMicros" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
},
|
"deadlockCount" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
}
|
},
|
"oplog" : {
|
"acquireCount" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
},
|
"acquireWaitCount" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
},
|
"timeAcquiringMicros" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
},
|
"deadlockCount" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
}
|
}
|
}
|
},
|
{
|
"desc" : "conn27",
|
"threadId" : "0x13316d040",
|
"connectionId" : 27,
|
"opid" : 111863610,
|
"active" : true,
|
"secs_running" : 286,
|
"microsecs_running" : NumberLong(286416042),
|
"op" : "query",
|
"ns" : "iibench2.$cmd",
|
"query" : {
|
"listCollections" : 1
|
},
|
"client" : "127.0.0.1:50668",
|
"numYields" : 0,
|
"locks" : {
|
"Global" : "r",
|
"Database" : "R"
|
},
|
"waitingForLock" : true,
|
"lockStats" : {
|
"Global" : {
|
"acquireCount" : {
|
"r" : NumberLong(1),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
},
|
"acquireWaitCount" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
},
|
"timeAcquiringMicros" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
},
|
"deadlockCount" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
}
|
},
|
"MMAPV1Journal" : {
|
"acquireCount" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
},
|
"acquireWaitCount" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
},
|
"timeAcquiringMicros" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
},
|
"deadlockCount" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
}
|
},
|
"Database" : {
|
"acquireCount" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(1),
|
"W" : NumberLong(0)
|
},
|
"acquireWaitCount" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(1),
|
"W" : NumberLong(0)
|
},
|
"timeAcquiringMicros" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong("81949279334"),
|
"W" : NumberLong(0)
|
},
|
"deadlockCount" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
}
|
},
|
"Collection" : {
|
"acquireCount" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
},
|
"acquireWaitCount" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
},
|
"timeAcquiringMicros" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
},
|
"deadlockCount" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
}
|
},
|
"Metadata" : {
|
"acquireCount" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
},
|
"acquireWaitCount" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
},
|
"timeAcquiringMicros" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
},
|
"deadlockCount" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
}
|
},
|
"oplog" : {
|
"acquireCount" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
},
|
"acquireWaitCount" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
},
|
"timeAcquiringMicros" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
},
|
"deadlockCount" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
}
|
}
|
}
|
},
|
{
|
"desc" : "conn18",
|
"threadId" : "0x1deca6be0",
|
"connectionId" : 18,
|
"opid" : 111863613,
|
"active" : true,
|
"secs_running" : 236,
|
"microsecs_running" : NumberLong(236683745),
|
"op" : "insert",
|
"ns" : "iibench2.puchases_index",
|
"insert" : {
|
"_id" : ObjectId("54c106d1ef312bda7f783775"),
|
"foo" : 1
|
},
|
"client" : "127.0.0.1:50045",
|
"numYields" : 0,
|
"locks" : {
|
"Global" : "w",
|
"Database" : "w"
|
},
|
"waitingForLock" : true,
|
"lockStats" : {
|
"Global" : {
|
"acquireCount" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(4),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
},
|
"acquireWaitCount" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
},
|
"timeAcquiringMicros" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
},
|
"deadlockCount" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
}
|
},
|
"MMAPV1Journal" : {
|
"acquireCount" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
},
|
"acquireWaitCount" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
},
|
"timeAcquiringMicros" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
},
|
"deadlockCount" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
}
|
},
|
"Database" : {
|
"acquireCount" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(3),
|
"R" : NumberLong(0),
|
"W" : NumberLong(1)
|
},
|
"acquireWaitCount" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(2),
|
"R" : NumberLong(0),
|
"W" : NumberLong(1)
|
},
|
"timeAcquiringMicros" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong("139156501043"),
|
"R" : NumberLong(0),
|
"W" : NumberLong(11817)
|
},
|
"deadlockCount" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
}
|
},
|
"Collection" : {
|
"acquireCount" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(2),
|
"R" : NumberLong(0),
|
"W" : NumberLong(1)
|
},
|
"acquireWaitCount" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
},
|
"timeAcquiringMicros" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
},
|
"deadlockCount" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
}
|
},
|
"Metadata" : {
|
"acquireCount" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
},
|
"acquireWaitCount" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
},
|
"timeAcquiringMicros" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
},
|
"deadlockCount" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
}
|
},
|
"oplog" : {
|
"acquireCount" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
},
|
"acquireWaitCount" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
},
|
"timeAcquiringMicros" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
},
|
"deadlockCount" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
}
|
}
|
}
|
},
|
{
|
"desc" : "conn13",
|
"threadId" : "0xb91fbee0",
|
"connectionId" : 13,
|
"opid" : 111863603,
|
"active" : true,
|
"secs_running" : 296,
|
"microsecs_running" : NumberLong(296788833),
|
"op" : "query",
|
"ns" : "iibench2.$cmd",
|
"query" : {
|
"createIndexes" : "purchases_index",
|
"indexes" : [
|
{
|
"key" : {
|
"productid" : 1,
|
"price" : 1
|
},
|
"name" : "productid_1_price_1",
|
"backtround" : true
|
}
|
]
|
},
|
"client" : "127.0.0.1:44017",
|
"msg" : "Index Build Index Build: 53049457/55902311 94%",
|
"progress" : {
|
"done" : 53049457,
|
"total" : 55902311
|
},
|
"numYields" : 0,
|
"locks" : {
|
"Global" : "w",
|
"Database" : "W",
|
"Collection" : "w"
|
},
|
"waitingForLock" : false,
|
"lockStats" : {
|
"Global" : {
|
"acquireCount" : {
|
"r" : NumberLong(11),
|
"w" : NumberLong(7),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
},
|
"acquireWaitCount" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
},
|
"timeAcquiringMicros" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
},
|
"deadlockCount" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
}
|
},
|
"MMAPV1Journal" : {
|
"acquireCount" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
},
|
"acquireWaitCount" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
},
|
"timeAcquiringMicros" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
},
|
"deadlockCount" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
}
|
},
|
"Database" : {
|
"acquireCount" : {
|
"r" : NumberLong(8),
|
"w" : NumberLong(1),
|
"R" : NumberLong(3),
|
"W" : NumberLong(6)
|
},
|
"acquireWaitCount" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(2),
|
"W" : NumberLong(3)
|
},
|
"timeAcquiringMicros" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(22225),
|
"W" : NumberLong(4211)
|
},
|
"deadlockCount" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
}
|
},
|
"Collection" : {
|
"acquireCount" : {
|
"r" : NumberLong(4),
|
"w" : NumberLong(3),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
},
|
"acquireWaitCount" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
},
|
"timeAcquiringMicros" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
},
|
"deadlockCount" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
}
|
},
|
"Metadata" : {
|
"acquireCount" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
},
|
"acquireWaitCount" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
},
|
"timeAcquiringMicros" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
},
|
"deadlockCount" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
}
|
},
|
"oplog" : {
|
"acquireCount" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
},
|
"acquireWaitCount" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
},
|
"timeAcquiringMicros" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
},
|
"deadlockCount" : {
|
"r" : NumberLong(0),
|
"w" : NumberLong(0),
|
"R" : NumberLong(0),
|
"W" : NumberLong(0)
|
}
|
}
|
}
|
}
|
]
|
}
|
And this is my startup log (I forgot to remove the direct_io config string after all):
2015-01-21T22:48:51.920-0500 I CONTROL [initandlisten] MongoDB starting : pid=29650 port=27017 dbpath=/home/rf/tmp/SERVER-169
|
80/db 64-bit host=tab
|
2015-01-21T22:48:51.920-0500 I CONTROL [initandlisten]
|
2015-01-21T22:48:51.921-0500 I CONTROL [initandlisten] db version v2.8.0-rc6-pre-
|
2015-01-21T22:48:51.921-0500 I CONTROL [initandlisten] git version: fc0d56be2cc3ba75fecd7d9047942cf686815dfe
|
2015-01-21T22:48:51.921-0500 I CONTROL [initandlisten] build info: Linux tab 3.13.0-36-generic #63-Ubuntu SMP Wed Sep 3 21:30
|
:07 UTC 2014 x86_64 BOOST_LIB_VERSION=1_49
|
2015-01-21T22:48:51.921-0500 I CONTROL [initandlisten] allocator: tcmalloc
|
2015-01-21T22:48:51.921-0500 I CONTROL [initandlisten] options: { processManagement: { fork: true }, storage: { dbPath: "/hom
|
e/rf/tmp/SERVER-16980/db", engine: "wiredTiger", wiredTiger: { engineConfig: { cacheSizeGB: 8, configString: "direct_io=[data]
|
" } } }, systemLog: { destination: "file", logAppend: true, path: "/home/rf/tmp/SERVER-16980/mongod.log" } }
|
2015-01-21T22:48:51.921-0500 I STORAGE [initandlisten] wiredtiger_open config: create,cache_size=8G,session_max=20000,evictio
|
n=(threads_max=4),statistics=(fast),log=(enabled=true,archive=true,path=journal,compressor=snappy),checkpoint=(wait=60,log_siz
|
e=2GB),statistics_log=(wait=0),direct_io=[data]
|
2015-01-21T22:48:51.996-0500 I NETWORK [initandlisten] waiting for connections on port 27017
|
|
|
Ran index builds that took a few hours with "show collections" and "db.purchases_index.getIndexes()" running in a loop. Was unable to reproduce the hang.
|
|
In Kal's commit 8f83ff2335ea0e2dd0dc2fc79b6509c4f8f2d4fc, traditional lock yielding was activated for all document-level-locking storage engines. It's part of rc5, so you might see better behavior versus rc4.
|
|
Thanks mdcallag, that's what I was looking for.
|
|
Here is mongo.conf. The log is huge especially from the too frequent background index build status messages.
processManagement:
|
fork: true
|
systemLog:
|
destination: file
|
path: /data/mysql/mongo.280rc4/log
|
logAppend: true
|
storage:
|
syncPeriodSecs: 60
|
dbPath: /data/mysql/mongo.280rc4/data
|
journal:
|
enabled: true
|
mmapv1:
|
journal:
|
commitIntervalMs: 100
|
storage.wiredTiger.collectionConfig.blockCompressor: snappy
|
storage.wiredTiger.engineConfig.journalCompressor: snappy
|
operationProfiling.slowOpThresholdMs: 2000
|
This is the log from server start.
2015-01-21T16:14:32.142-0800 I CONTROL [initandlisten] MongoDB starting : pid=22092 port=27017 dbpath=/data/mysql/mongo.280rc4/data 64-bit host=X
|
2015-01-21T16:14:32.142-0800 I CONTROL [initandlisten] ** WARNING: You are running this process as the root user, which is not recommended.
|
2015-01-21T16:14:32.142-0800 I CONTROL [initandlisten]
|
2015-01-21T16:14:32.143-0800 I CONTROL [initandlisten] db version v2.8.0-rc5
|
2015-01-21T16:14:32.143-0800 I CONTROL [initandlisten] git version: nogitversion
|
2015-01-21T16:14:32.143-0800 I CONTROL [initandlisten] build info: Linux dev1434.prn1.facebook.com 3.2.51-103_fbk20_00350_gbc67779 #103 SMP Mon Dec 2 10:44:28 PST 2013 x86_64 BOOST_LIB_VERSION=1_49
|
2015-01-21T16:14:32.143-0800 I CONTROL [initandlisten] allocator: system
|
2015-01-21T16:14:32.143-0800 I CONTROL [initandlisten] options: { config: "/data/mysql/mongo.280rc4/mongo.conf", operationProfiling: { slowOpThresholdMs: 2000 }, processManagement: { fork: true }, storage: { dbPath: "/data/mysql/mongo.280rc4/data", engine: "wiredTiger", journal: { enabled: true }, mmapv1: { journal: { commitIntervalMs: 100 } }, syncPeriodSecs: 60.0, wiredTiger: { collectionConfig: { blockCompressor: "snappy" }, engineConfig: { cacheSizeGB: 4, journalCompressor: "snappy" } } }, systemLog: { destination: "file", logAppend: true, path: "/data/mysql/mongo.280rc4/log" } }
|
2015-01-21T16:14:32.143-0800 W STORAGE [initandlisten] Detected configuration for non-active storage engine mmapv1 when current storage engine is wiredTiger
|
2015-01-21T16:14:32.144-0800 I STORAGE [initandlisten] wiredtiger_open config: create,cache_size=4G,session_max=20000,eviction=(threads_max=4),statistics=(fast),log=(enabled=true,archive=true,path=journal,compressor=snappy),checkpoint=(wait=60,log_size=2GB),statistics_log=(wait=0),
|
2015-01-21T16:14:32.168-0800 I NETWORK [initandlisten] waiting for connections on port 27017
|
2015-01-21T17:11:35.914-0800 I NETWORK [initandlisten] connection accepted from 127.0.0.1:45914 #1 (1 connection now open)
|
2015-01-21T17:11:42.677-0800 I NETWORK [conn1] end connection 127.0.0.1:45914 (0 connections now open)
|
2015-01-21T17:15:45.495-0800 I NETWORK [initandlisten] connection accepted from 127.0.0.1:48359 #2 (1 connection now open)
|
2015-01-21T17:15:45.497-0800 I COMMAND [conn2] CMD: dropIndexes iibench.purchases_index
|
2015-01-21T17:15:47.107-0800 I COMMAND [conn2] CMD: dropIndexes iibench.purchases_index
|
2015-01-21T17:15:48.333-0800 I COMMAND [conn2] CMD: dropIndexes iibench.purchases_index
|
2015-01-21T17:15:49.463-0800 I NETWORK [conn2] end connection 127.0.0.1:48359 (0 connections now open)
|
2015-01-21T17:16:03.357-0800 I NETWORK [initandlisten] connection accepted from 127.0.0.1:48569 #3 (1 connection now open)
|
2015-01-21T17:16:20.194-0800 I NETWORK [initandlisten] connection accepted from 127.0.0.1:48767 #4 (2 connections now open)
|
2015-01-21T17:16:20.199-0800 I INDEX [conn4] build index on: iibench.purchases_index properties: { v: 1, key: { price: 1.0, dateandtime: 1.0, customerid: 1.0 }, name: "price_1_dateandtime_1_customerid_1", ns: "iibench.purchases_index", background: true }
|
2015-01-21T17:16:23.001-0800 I - [conn4] Index Build (background): 99000/100000000 0%
|
2015-01-21T17:16:26.002-0800 I - [conn4] Index Build (background): 202700/100000000 0%
|
|
|
mdcallag, can you post the full logs or the options you started mongod with in the WiredTiger case? Are you also using direct_io=[data] like in other tickets? Also, is this a stand-alone server or a replicaset?
Thanks,
Ramón.
|
|
But looking at output I pasted from db.currentOp() shows that background:true was used. Still trying to reproduce this. I had stacks for more threads from the first (and only) time I hit the problem. At a high level there are several background threads blocked trying to get a lock in IS mode and the listCollections thread is blocked trying to get it in S mode.
1 pthread_cond_timedwait@@GLIBC_2.3.2,timed_wait,timed_wait<boost::date_time::subsecond_duration<boost::posix_time::time_duration,,mongo::CondVarLockGrantNotification::wait,mongo::LockerImpl<false>::lockComplete,mongo::Lock::DBLock::DBLock,mongo::TTLMonitor::getTTLIndexesForDB,mongo::TTLMonitor::run,mongo::BackgroundJob::jobBody,boost::(anonymous,start_thread,clone
|
1 pthread_cond_timedwait@@GLIBC_2.3.2,timed_wait,timed_wait<boost::date_time::subsecond_duration<boost::posix_time::time_duration,,mongo::CondVarLockGrantNotification::wait,mongo::LockerImpl<false>::lockComplete,mongo::Lock::DBLock::DBLock,mongo::AutoGetDb::AutoGetDb,mongo::CmdListCollections::run,mongo::_execCommand,mongo::Command::execCommand,mongo::_runCommands,runCommands,mongo::runQuery,receivedQuery,mongo::assembleResponse,mongo::MyMessageHandler::process,mongo::PortMessageServer::handleIncomingMsg,start_thread,clone
|
1 pthread_cond_timedwait@@GLIBC_2.3.2,timed_wait,timed_wait<boost::date_time::subsecond_duration<boost::posix_time::time_duration,,mongo::CondVarLockGrantNotification::wait,mongo::LockerImpl<false>::lockComplete,mongo::Lock::DBLock::DBLock,mongo::AutoGetDb::AutoGetDb,mongo::AutoGetCollectionForRead::AutoGetCollectionForRead,mongo::GlobalCursorIdCache::timeoutCursors,mongo::CursorManager::timeoutCursorsGlobal,mongo::ClientCursorMonitor::run,mongo::BackgroundJob::jobBody,boost::(anonymous,start_thread,clone
|
1 pthread_cond_timedwait@@GLIBC_2.3.2,timed_wait<boost::unique_lock<boost::timed_mutex>,timed_wait<boost::unique_lock<boost::timed_mutex>,,mongo::RangeDeleter::doWork,boost::(anonymous,start_thread,clone
|
1 pthread_cond_timedwait@@GLIBC_2.3.2,boost::condition_variable_any::timed_wait<boost::unique_lock<boost::timed_mutex>,timed_wait<boost::unique_lock<boost::timed_mutex>,,timed_wait<boost::unique_lock<boost::timed_mutex>,,mongo::(anonymous,mongo::BackgroundJob::jobBody,boost::(anonymous,start_thread,clone
|
1 mongo::BSONObj::woCompare,mongo::BtreeExternalSortComparison::operator(),operator(),std::__move_merge<std::pair<mongo::BSONObj,,__merge_sort_loop<std::pair<mongo::BSONObj,,std::__merge_sort_with_buffer<std::_Deque_iterator<std::pair<mongo::BSONObj,,std::__stable_sort_adaptive<std::_Deque_iterator<std::pair<mongo::BSONObj,,stable_sort<std::_Deque_iterator<std::pair<mongo::BSONObj,,mongo::sorter::NoLimitSorter<mongo::BSONObj,,mongo::sorter::NoLimitSorter<mongo::BSONObj,,mongo::sorter::NoLimitSorter<mongo::BSONObj,,mongo::BtreeBasedBulkAccessMethod::insert,mongo::MultiIndexBlock::insert,mongo::MultiIndexBlock::insertAllDocumentsInCollection,mongo::CmdCreateIndex::run,mongo::_execCommand,mongo::Command::execCommand,mongo::_runCommands,runCommands,mongo::runQuery,receivedQuery,mongo::assembleResponse,mongo::MyMessageHandler::process,mongo::PortMessageServer::handleIncomingMsg,start_thread,clone
|
With much more detail in...
|
Thread 7 (Thread 0x7f91afbff700 (LWP 9408)):
|
#0 0x00007f91bc6837ae in pthread_cond_timedwait@@GLIBC_2.3.2 () from /usr/local/fbcode/gcc-4.8.1-glibc-2.17/lib/libpthread.so.0
|
#1 0x0000000000c44956 in timed_wait<boost::unique_lock<boost::timed_mutex> > (wait_until=..., m=..., this=0x7f91bb871e10) at src/third_party/boost/boost/thread/pthread/condition_variable.hpp:161
|
#2 timed_wait<boost::unique_lock<boost::timed_mutex>, boost::date_time::subsecond_duration<boost::posix_time::time_duration, 1000l> > (wait_duration=..., m=..., this=0x7f91bb871e10) at src/third_party/boost/boost/thread/pthread/condition_variable.hpp:183
|
#3 mongo::RangeDeleter::doWork (this=0x7f91bb871d80) at src/mongo/db/range_deleter.cpp:458
|
#4 0x0000000000feb354 in boost::(anonymous namespace)::thread_proxy (param=<optimized out>) at src/third_party/boost/libs/thread/src/pthread/thread.cpp:121
|
#5 0x00007f91bc67efa8 in start_thread () from /usr/local/fbcode/gcc-4.8.1-glibc-2.17/lib/libpthread.so.0
|
#6 0x00007f91bc3a15ad in clone () from /usr/local/fbcode/gcc-4.8.1-glibc-2.17/lib/libc.so.6
|
|
Thread 6 (Thread 0x7f91af3fe700 (LWP 9409)):
|
#0 0x00007f91bc6837ae in pthread_cond_timedwait@@GLIBC_2.3.2 () from /usr/local/fbcode/gcc-4.8.1-glibc-2.17/lib/libpthread.so.0
|
#1 0x0000000000a0ff1e in timed_wait (wait_until=..., m=..., this=0x7f91acc171d0) at src/third_party/boost/boost/thread/pthread/condition_variable.hpp:74
|
#2 timed_wait<boost::date_time::subsecond_duration<boost::posix_time::time_duration, 1000l> > (wait_duration=..., m=..., this=0x7f91acc171d0) at src/third_party/boost/boost/thread/pthread/condition_variable_fwd.hpp:72
|
#3 mongo::CondVarLockGrantNotification::wait (this=this@entry=0x7f91acc171a0, timeoutMs=<optimized out>) at src/mongo/db/concurrency/lock_state.cpp:254
|
#4 0x0000000000a17613 in mongo::LockerImpl<false>::lockComplete (this=0x7f91acc16c00, resId=..., mode=mongo::MODE_IS, timeoutMs=4294967295, checkDeadlock=false) at src/mongo/db/concurrency/lock_state.cpp:688
|
#5 0x0000000000a07fe1 in mongo::Lock::DBLock::DBLock (this=0x7f91af3fd730, lockState=0x7f91acc16c00, db=..., mode=<optimized out>) at src/mongo/db/concurrency/d_concurrency.cpp:150
|
#6 0x0000000000dd5a12 in mongo::TTLMonitor::getTTLIndexesForDB (this=this@entry=0x7f91bbbb8d00, txn=txn@entry=0x7f91af3fd810, dbName=..., indexes=indexes@entry=0x7f91af3fd7f0) at src/mongo/db/ttl.cpp:142
|
#7 0x0000000000dd6e82 in mongo::TTLMonitor::run (this=0x7f91bbbb8d00) at src/mongo/db/ttl.cpp:115
|
#8 0x0000000000f32880 in mongo::BackgroundJob::jobBody (this=0x7f91bbbb8d00) at src/mongo/util/background.cpp:163
|
#9 0x0000000000feb354 in boost::(anonymous namespace)::thread_proxy (param=<optimized out>) at src/third_party/boost/libs/thread/src/pthread/thread.cpp:121
|
#10 0x00007f91bc67efa8 in start_thread () from /usr/local/fbcode/gcc-4.8.1-glibc-2.17/lib/libpthread.so.0
|
#11 0x00007f91bc3a15ad in clone () from /usr/local/fbcode/gcc-4.8.1-glibc-2.17/lib/libc.so.6
|
|
Thread 5 (Thread 0x7f91ae3ff700 (LWP 9410)):
|
#0 0x00007f91bc6837ae in pthread_cond_timedwait@@GLIBC_2.3.2 () from /usr/local/fbcode/gcc-4.8.1-glibc-2.17/lib/libpthread.so.0
|
#1 0x0000000000a0ff1e in timed_wait (wait_until=..., m=..., this=0x7f91ac8171d0) at src/third_party/boost/boost/thread/pthread/condition_variable.hpp:74
|
#2 timed_wait<boost::date_time::subsecond_duration<boost::posix_time::time_duration, 1000l> > (wait_duration=..., m=..., this=0x7f91ac8171d0) at src/third_party/boost/boost/thread/pthread/condition_variable_fwd.hpp:72
|
#3 mongo::CondVarLockGrantNotification::wait (this=this@entry=0x7f91ac8171a0, timeoutMs=<optimized out>) at src/mongo/db/concurrency/lock_state.cpp:254
|
#4 0x0000000000a17613 in mongo::LockerImpl<false>::lockComplete (this=0x7f91ac816c00, resId=..., mode=mongo::MODE_IS, timeoutMs=4294967295, checkDeadlock=false) at src/mongo/db/concurrency/lock_state.cpp:688
|
#5 0x0000000000a07fe1 in mongo::Lock::DBLock::DBLock (this=0x7f91ae3fe7a8, lockState=0x7f91ac816c00, db=..., mode=<optimized out>) at src/mongo/db/concurrency/d_concurrency.cpp:150
|
#6 0x00000000009803b0 in mongo::AutoGetDb::AutoGetDb (this=0x7f91ae3fe7a8, txn=0x7f91ae3fe850, ns=..., mode=mongo::MODE_IS) at src/mongo/db/client.cpp:209
|
#7 0x0000000000980540 in mongo::AutoGetCollectionForRead::AutoGetCollectionForRead (this=0x7f91ae3fe790, txn=0x7f91ae3fe850, ns=...) at src/mongo/db/client.cpp:237
|
#8 0x0000000000969dbc in mongo::GlobalCursorIdCache::timeoutCursors (this=0x7f91bbba7200, txn=txn@entry=0x7f91ae3fe850, millisSinceLastCall=4000) at src/mongo/db/catalog/cursor_manager.cpp:265
|
#9 0x0000000000969e7c in mongo::CursorManager::timeoutCursorsGlobal (txn=txn@entry=0x7f91ae3fe850, millisSinceLastCall=<optimized out>) at src/mongo/db/catalog/cursor_manager.cpp:289
|
#10 0x0000000000983235 in mongo::ClientCursorMonitor::run (this=<optimized out>) at src/mongo/db/clientcursor.cpp:290
|
#11 0x0000000000f32880 in mongo::BackgroundJob::jobBody (this=0x1caeb00 <mongo::(anonymous namespace)::clientCursorMonitor>) at src/mongo/util/background.cpp:163
|
#12 0x0000000000feb354 in boost::(anonymous namespace)::thread_proxy (param=<optimized out>) at src/third_party/boost/libs/thread/src/pthread/thread.cpp:121
|
#13 0x00007f91bc67efa8 in start_thread () from /usr/local/fbcode/gcc-4.8.1-glibc-2.17/lib/libpthread.so.0
|
#14 0x00007f91bc3a15ad in clone () from /usr/local/fbcode/gcc-4.8.1-glibc-2.17/lib/libc.so.6
|
|
Thread 4 (Thread 0x7f91adbfe700 (LWP 9411)):
|
#0 0x00007f91bc6837ae in pthread_cond_timedwait@@GLIBC_2.3.2 () from /usr/local/fbcode/gcc-4.8.1-glibc-2.17/lib/libpthread.so.0
|
#1 0x0000000000f35736 in boost::condition_variable_any::timed_wait<boost::unique_lock<boost::timed_mutex> > (this=this@entry=0x7f91bb986048, m=..., wait_until=...) at src/third_party/boost/boost/thread/pthread/condition_variable.hpp:161
|
#2 0x0000000000f333f6 in timed_wait<boost::unique_lock<boost::timed_mutex>, std::function<bool()> > (pred=..., wait_until=..., m=..., this=0x7f91bb986048) at src/third_party/boost/boost/thread/pthread/condition_variable.hpp:191
|
#3 timed_wait<boost::unique_lock<boost::timed_mutex>, std::function<bool()> > (pred=..., wait_until=..., m=..., this=0x7f91bb986048) at src/third_party/boost/boost/thread/pthread/condition_variable.hpp:200
|
#4 mongo::(anonymous namespace)::PeriodicTaskRunner::run (this=0x7f91bb986020) at src/mongo/util/background.cpp:338
|
#5 0x0000000000f32880 in mongo::BackgroundJob::jobBody (this=0x7f91bb986020) at src/mongo/util/background.cpp:163
|
#6 0x0000000000feb354 in boost::(anonymous namespace)::thread_proxy (param=<optimized out>) at src/third_party/boost/libs/thread/src/pthread/thread.cpp:121
|
#7 0x00007f91bc67efa8 in start_thread () from /usr/local/fbcode/gcc-4.8.1-glibc-2.17/lib/libpthread.so.0
|
#8 0x00007f91bc3a15ad in clone () from /usr/local/fbcode/gcc-4.8.1-glibc-2.17/lib/libc.so.6
|
|
Thread 3 (Thread 0x7f91bc19c700 (LWP 32318)):
|
#0 mongo::BSONObj::woCompare (this=this@entry=0x7f82c1400490, r=..., o=..., considerFieldName=considerFieldName@entry=false) at src/mongo/bson/bsonobj.cpp:125
|
#1 0x0000000000ad6d70 in mongo::BtreeExternalSortComparison::operator() (this=<optimized out>, l=..., r=...) at src/mongo/db/index/btree_based_bulk_access_method.cpp:68
|
#2 0x0000000000addfc7 in operator() (rhs=..., lhs=..., this=<synthetic pointer>) at src/mongo/db/sorter/sorter.cpp:436
|
#3 std::__move_merge<std::pair<mongo::BSONObj, mongo::RecordId>*, std::pair<mongo::BSONObj, mongo::RecordId>*, std::_Deque_iterator<std::pair<mongo::BSONObj, mongo::RecordId>, std::pair<mongo::BSONObj, mongo::RecordId>&, std::pair<mongo::BSONObj, mongo::RecordId>*>, mongo::sorter::NoLimitSorter<mongo::BSONObj, mongo::RecordId, mongo::BtreeExternalSortComparison>::STLComparator> (__first1=0x7f82c13eb9e8, __last1=__last1@entry=0x7f82c13f5000, __first2=0x7f82c1400490, __first2@entry=0x7f82c13f5000, __last2=__last2@entry=0x7f82c140a000, __result=..., __comp=__comp@entry=...) at /mnt/gvfs/third-party2/gcc/1ec615e23800f0815d474478ba476a0adc3fe788/4.8.1/centos6-native/cc6c9dc/include/c++/4.8.1/bits/stl_algo.h:3305
|
#4 0x0000000000ade59c in __merge_sort_loop<std::pair<mongo::BSONObj, mongo::RecordId>*, std::_Deque_iterator<std::pair<mongo::BSONObj, mongo::RecordId>, std::pair<mongo::BSONObj, mongo::RecordId>&, std::pair<mongo::BSONObj, mongo::RecordId>*>, long, mongo::sorter::NoLimitSorter<mongo::BSONObj, mongo::RecordId, mongo::BtreeExternalSortComparison>::STLComparator> (__comp=..., __step_size=3584, __result=..., __last=0x7f82c26aaab8, __first=<optimized out>) at /mnt/gvfs/third-party2/gcc/1ec615e23800f0815d474478ba476a0adc3fe788/4.8.1/centos6-native/cc6c9dc/include/c++/4.8.1/bits/stl_algo.h:3357
|
#5 std::__merge_sort_with_buffer<std::_Deque_iterator<std::pair<mongo::BSONObj, mongo::RecordId>, std::pair<mongo::BSONObj, mongo::RecordId>&, std::pair<mongo::BSONObj, mongo::RecordId>*>, std::pair<mongo::BSONObj, mongo::RecordId>*, mongo::sorter::NoLimitSorter<mongo::BSONObj, mongo::RecordId, mongo::BtreeExternalSortComparison>::STLComparator> (__first=..., __last=..., __buffer=__buffer@entry=0x7f82c0c00000, __comp=__comp@entry=...) at /mnt/gvfs/third-party2/gcc/1ec615e23800f0815d474478ba476a0adc3fe788/4.8.1/centos6-native/cc6c9dc/include/c++/4.8.1/bits/stl_algo.h:3444
|
#6 0x0000000000adf9d1 in std::__stable_sort_adaptive<std::_Deque_iterator<std::pair<mongo::BSONObj, mongo::RecordId>, std::pair<mongo::BSONObj, mongo::RecordId>&, std::pair<mongo::BSONObj, mongo::RecordId>*>, std::pair<mongo::BSONObj, mongo::RecordId>*, long, mongo::sorter::NoLimitSorter<mongo::BSONObj, mongo::RecordId, mongo::BtreeExternalSortComparison>::STLComparator> (__first=..., __last=..., __buffer=0x7f82c0c00000, __buffer_size=2330169, __comp=__comp@entry=...) at /mnt/gvfs/third-party2/gcc/1ec615e23800f0815d474478ba476a0adc3fe788/4.8.1/centos6-native/cc6c9dc/include/c++/4.8.1/bits/stl_algo.h:3496
|
#7 0x0000000000adfd0d in stable_sort<std::_Deque_iterator<std::pair<mongo::BSONObj, mongo::RecordId>, std::pair<mongo::BSONObj, mongo::RecordId>&, std::pair<mongo::BSONObj, mongo::RecordId>*>, mongo::sorter::NoLimitSorter<mongo::BSONObj, mongo::RecordId, mongo::BtreeExternalSortComparison>::STLComparator> (__comp=..., __last=..., __first=...) at /mnt/gvfs/third-party2/gcc/1ec615e23800f0815d474478ba476a0adc3fe788/4.8.1/centos6-native/cc6c9dc/include/c++/4.8.1/bits/stl_algo.h:5726
|
#8 mongo::sorter::NoLimitSorter<mongo::BSONObj, mongo::RecordId, mongo::BtreeExternalSortComparison>::sort (this=this@entry=0x7f91abcc8f40) at src/mongo/db/sorter/sorter.cpp:444
|
#9 0x0000000000adfdd0 in mongo::sorter::NoLimitSorter<mongo::BSONObj, mongo::RecordId, mongo::BtreeExternalSortComparison>::spill (this=this@entry=0x7f91abcc8f40) at src/mongo/db/sorter/sorter.cpp:467
|
#10 0x0000000000ae0067 in mongo::sorter::NoLimitSorter<mongo::BSONObj, mongo::RecordId, mongo::BtreeExternalSortComparison>::add (this=0x7f91abcc8f40, key=..., val=...) at src/mongo/db/sorter/sorter.cpp:413
|
#11 0x0000000000ad5715 in mongo::BtreeBasedBulkAccessMethod::insert (this=0x7f8d89cdbd40, txn=<optimized out>, obj=..., loc=..., options=..., numInserted=0x7f91bc199fe0) at src/mongo/db/index/btree_based_bulk_access_method.cpp:108
|
#12 0x000000000097b505 in mongo::MultiIndexBlock::insert (this=this@entry=0x7f91bc19a2e0, doc=..., loc=...) at src/mongo/db/catalog/index_create.cpp:286
|
#13 0x000000000097c56c in mongo::MultiIndexBlock::insertAllDocumentsInCollection (this=this@entry=0x7f91bc19a2e0, dupsOut=dupsOut@entry=0x0) at src/mongo/db/catalog/index_create.cpp:239
|
#14 0x00000000009a3f3b in mongo::CmdCreateIndex::run (this=<optimized out>, txn=0x7f91bc19b680, dbname=..., cmdObj=..., options=<optimized out>, errmsg=..., result=..., fromRepl=false) at src/mongo/db/commands/create_indexes.cpp:198
|
#15 0x0000000000a23964 in mongo::_execCommand (txn=txn@entry=0x7f91bc19b680, c=c@entry=0x1caf6a0 <mongo::cmdCreateIndex>, dbname=..., cmdObj=..., queryOptions=queryOptions@entry=0, errmsg=..., result=..., fromRepl=fromRepl@entry=false) at src/mongo/db/dbcommands.cpp:1252
|
#16 0x0000000000a248a3 in mongo::Command::execCommand (txn=txn@entry=0x7f91bc19b680, c=c@entry=0x1caf6a0 <mongo::cmdCreateIndex>, queryOptions=queryOptions@entry=0, cmdns=cmdns@entry=0x7f91abc6e414 "iibench.$cmd", cmdObj=..., result=..., fromRepl=fromRepl@entry=false) at src/mongo/db/dbcommands.cpp:1468
|
#17 0x0000000000a2535b in mongo::_runCommands (txn=txn@entry=0x7f91bc19b680, ns=0x7f91abc6e414 "iibench.$cmd", _cmdobj=..., b=..., anObjBuilder=..., fromRepl=fromRepl@entry=false, queryOptions=0) at src/mongo/db/dbcommands.cpp:1543
|
#18 0x0000000000bee415 in runCommands (fromRepl=false, queryOptions=<optimized out>, anObjBuilder=..., b=..., curop=..., jsobj=..., ns=<optimized out>, txn=0x7f91bc19b680) at src/mongo/db/query/find.cpp:135
|
#19 mongo::runQuery (txn=txn@entry=0x7f91bc19b680, m=..., q=..., nss=..., curop=..., result=..., fromDBDirectClient=fromDBDirectClient@entry=false) at src/mongo/db/query/find.cpp:567
|
#20 0x0000000000b0320a in receivedQuery (fromDBDirectClient=false, m=..., dbresponse=..., c=..., txn=0x7f91bc19b680) at src/mongo/db/instance.cpp:217
|
#21 mongo::assembleResponse (txn=txn@entry=0x7f91bc19b680, m=..., dbresponse=..., remote=..., fromDBDirectClient=fromDBDirectClient@entry=false) at src/mongo/db/instance.cpp:400
|
#22 0x0000000000857880 in mongo::MyMessageHandler::process (this=<optimized out>, m=..., port=0x7f91b4fe9600, le=0x7f91abc22060) at src/mongo/db/db.cpp:197
|
#23 0x0000000000f5e8c1 in mongo::PortMessageServer::handleIncomingMsg (arg=0x7f91b4fe9600) at src/mongo/util/net/message_server_port.cpp:225
|
#24 0x00007f91bc67efa8 in start_thread () from /usr/local/fbcode/gcc-4.8.1-glibc-2.17/lib/libpthread.so.0
|
#25 0x00007f91bc3a15ad in clone () from /usr/local/fbcode/gcc-4.8.1-glibc-2.17/lib/libc.so.6
|
|
|
Thread 2 (Thread 0x7f91bdb1e700 (LWP 15103)):
|
#0 0x00007f91bc6837ae in pthread_cond_timedwait@@GLIBC_2.3.2 () from /usr/local/fbcode/gcc-4.8.1-glibc-2.17/lib/libpthread.so.0
|
#1 0x0000000000a0ff1e in timed_wait (wait_until=..., m=..., this=0x7f85544091d0) at src/third_party/boost/boost/thread/pthread/condition_variable.hpp:74
|
#2 timed_wait<boost::date_time::subsecond_duration<boost::posix_time::time_duration, 1000l> > (wait_duration=..., m=..., this=0x7f85544091d0) at src/third_party/boost/boost/thread/pthread/condition_variable_fwd.hpp:72
|
#3 mongo::CondVarLockGrantNotification::wait (this=this@entry=0x7f85544091a0, timeoutMs=<optimized out>) at src/mongo/db/concurrency/lock_state.cpp:254
|
#4 0x0000000000a17613 in mongo::LockerImpl<false>::lockComplete (this=0x7f8554408c00, resId=..., mode=mongo::MODE_S, timeoutMs=4294967295, checkDeadlock=false) at src/mongo/db/concurrency/lock_state.cpp:688
|
#5 0x0000000000a07fe1 in mongo::Lock::DBLock::DBLock (this=0x7f91bdb1c340, lockState=0x7f8554408c00, db=..., mode=<optimized out>) at src/mongo/db/concurrency/d_concurrency.cpp:150
|
#6 0x00000000009803b0 in mongo::AutoGetDb::AutoGetDb (this=0x7f91bdb1c340, txn=0x7f91bdb1d680, ns=..., mode=mongo::MODE_S) at src/mongo/db/client.cpp:209
|
#7 0x00000000009bb0d0 in mongo::CmdListCollections::run (this=0x1caffa0 <mongo::cmdListCollections>, txn=0x7f91bdb1d680, dbname=..., jsobj=..., errmsg=..., result=...) at src/mongo/db/commands/list_collections.cpp:104
|
#8 0x0000000000a23964 in mongo::_execCommand (txn=txn@entry=0x7f91bdb1d680, c=c@entry=0x1caffa0 <mongo::cmdListCollections>, dbname=..., cmdObj=..., queryOptions=queryOptions@entry=0, errmsg=..., result=..., fromRepl=fromRepl@entry=false) at src/mongo/db/dbcommands.cpp:1252
|
#9 0x0000000000a248a3 in mongo::Command::execCommand (txn=txn@entry=0x7f91bdb1d680, c=c@entry=0x1caffa0 <mongo::cmdListCollections>, queryOptions=queryOptions@entry=0, cmdns=cmdns@entry=0x7f81432a4814 "iibench.$cmd", cmdObj=..., result=..., fromRepl=fromRepl@entry=false) at src/mongo/db/dbcommands.cpp:1468
|
#10 0x0000000000a2535b in mongo::_runCommands (txn=txn@entry=0x7f91bdb1d680, ns=0x7f81432a4814 "iibench.$cmd", _cmdobj=..., b=..., anObjBuilder=..., fromRepl=fromRepl@entry=false, queryOptions=0) at src/mongo/db/dbcommands.cpp:1543
|
#11 0x0000000000bee415 in runCommands (fromRepl=false, queryOptions=<optimized out>, anObjBuilder=..., b=..., curop=..., jsobj=..., ns=<optimized out>, txn=0x7f91bdb1d680) at src/mongo/db/query/find.cpp:135
|
#12 mongo::runQuery (txn=txn@entry=0x7f91bdb1d680, m=..., q=..., nss=..., curop=..., result=..., fromDBDirectClient=fromDBDirectClient@entry=false) at src/mongo/db/query/find.cpp:567
|
#13 0x0000000000b0320a in receivedQuery (fromDBDirectClient=false, m=..., dbresponse=..., c=..., txn=0x7f91bdb1d680) at src/mongo/db/instance.cpp:217
|
#14 mongo::assembleResponse (txn=txn@entry=0x7f91bdb1d680, m=..., dbresponse=..., remote=..., fromDBDirectClient=fromDBDirectClient@entry=false) at src/mongo/db/instance.cpp:400
|
#15 0x0000000000857880 in mongo::MyMessageHandler::process (this=<optimized out>, m=..., port=0x7f91b4c422e0, le=0x7f90d9b95060) at src/mongo/db/db.cpp:197
|
#16 0x0000000000f5e8c1 in mongo::PortMessageServer::handleIncomingMsg (arg=0x7f91b4c422e0) at src/mongo/util/net/message_server_port.cpp:225
|
#17 0x00007f91bc67efa8 in start_thread () from /usr/local/fbcode/gcc-4.8.1-glibc-2.17/lib/libpthread.so.0
|
#18 0x00007f91bc3a15ad in clone () from /usr/local/fbcode/gcc-4.8.1-glibc-2.17/lib/libc.so.6
|
|
Thread 1 (Thread 0x7f91bdb20cc0 (LWP 9402)):
|
#0 0x00007f91bc398233 in select () from /usr/local/fbcode/gcc-4.8.1-glibc-2.17/lib/libc.so.6
|
#1 0x0000000000f57fb2 in mongo::Listener::initAndListen (this=0x7f91b4c56508) at src/mongo/util/net/listen.cpp:264
|
#2 0x0000000000852ff3 in _initAndListen (listenPort=<optimized out>) at src/mongo/db/db.cpp:621
|
#3 mongo::initAndListen (listenPort=<optimized out>) at src/mongo/db/db.cpp:626
|
#4 0x00000000008568a4 in mongoDbMain (envp=<optimized out>, argv=0x7fff4c0491c8, argc=<optimized out>) at src/mongo/db/db.cpp:872
|
#5 main (argc=7, argv=0x7fff4c0491c8, envp=<optimized out>) at src/mongo/db/db.cpp:675
|
Detaching from program: /data/mysql/mongo.280rc4/bin/mongod.rc5.jem.dbg, process 9402
|
|
|
Hi mdcallag, thanks for letting us know. I wasn't able to reproduce on master either using a synthetic, insert-only workload. Want to give this another try tomorrow morning to be on the safe side though.
|
|
And now I can't reproduce this which makes me think my original test was using background:false
|
|
Thread stacks from another hang:
Thread 4 (Thread 0x7f06bf5fa700 (LWP 6585)):
|
#0 0x00007f06be15f7ae in pthread_cond_timedwait@@GLIBC_2.3.2 () from /usr/local/fbcode/gcc-4.8.1-glibc-2.17/lib/libpthread.so.0
|
#1 0x000000000137668f in __wt_cond_wait (session=session@entry=0x7f06b440a000, cond=0x7f06bd7a74a0, usecs=usecs@entry=100000) at src/third_party/wiredtiger/src/os_posix/os_mtx_cond.c:77
|
#2 0x00000000013a183e in __wt_cache_full_check (session=0x7f06b440a000) at src/third_party/wiredtiger/src/include/cache.i:166
|
#3 __session_begin_transaction (wt_session=0x7f06b440a000, config=<optimized out>) at src/third_party/wiredtiger/src/session/session_api.c:743
|
#4 0x0000000000db62f8 in mongo::WiredTigerRecoveryUnit::_txnOpen (this=this@entry=0x7f0563e8de60) at src/mongo/db/storage/wiredtiger/wiredtiger_recovery_unit.cpp:219
|
#5 0x0000000000db6440 in mongo::WiredTigerRecoveryUnit::getSession (this=0x7f0563e8de60) at src/mongo/db/storage/wiredtiger/wiredtiger_recovery_unit.cpp:183
|
#6 0x0000000000db6480 in mongo::WiredTigerCursor::_init (this=0x7f06bf5f7d70, uri=..., id=25, ru=<optimized out>) at src/mongo/db/storage/wiredtiger/wiredtiger_recovery_unit.cpp:251
|
#7 0x0000000000da89e0 in mongo::WiredTigerIndex::insert (this=0x7f05cedeb060, txn=<optimized out>, key=..., loc=..., dupsAllowed=<optimized out>) at src/mongo/db/storage/wiredtiger/wiredtiger_index.cpp:362
|
#8 0x0000000000ad038b in mongo::BtreeBasedAccessMethod::insert (this=0x7f0561eb3ee0, txn=0x7f06bf5f9660, obj=..., loc=..., options=..., numInserted=0x7f06bf5f7f20) at src/mongo/db/index/btree_based_access_method.cpp:86
|
#9 0x0000000000979285 in mongo::MultiIndexBlock::insert (this=this@entry=0x7f06bf5f8220, doc=..., loc=...) at src/mongo/db/catalog/index_create.cpp:281
|
#10 0x000000000097a2c7 in mongo::MultiIndexBlock::insertAllDocumentsInCollection (this=this@entry=0x7f06bf5f8220, dupsOut=dupsOut@entry=0x0) at src/mongo/db/catalog/index_create.cpp:234
|
#11 0x00000000009a1bfe in mongo::CmdCreateIndex::run (this=<optimized out>, txn=0x7f06bf5f9660, dbname=..., cmdObj=..., options=<optimized out>, errmsg=..., result=..., fromRepl=false) at src/mongo/db/commands/create_indexes.cpp:198
|
#12 0x0000000000a1d3e4 in mongo::_execCommand (txn=txn@entry=0x7f06bf5f9660, c=c@entry=0x1c92a00 <mongo::cmdCreateIndex>, dbname=..., cmdObj=..., queryOptions=queryOptions@entry=0, errmsg=..., result=..., fromRepl=fromRepl@entry=false) at src/mongo/db/dbcommands.cpp:125
|
2
|
#13 0x0000000000a1e323 in mongo::Command::execCommand (txn=txn@entry=0x7f06bf5f9660, c=c@entry=0x1c92a00 <mongo::cmdCreateIndex>, queryOptions=queryOptions@entry=0, cmdns=cmdns@entry=0x7f0573322414 "iibench.$cmd", cmdObj=..., result=..., fromRepl=fromRepl@entry=false) a
|
t src/mongo/db/dbcommands.cpp:1468
|
#14 0x0000000000a1eddb in mongo::_runCommands (txn=txn@entry=0x7f06bf5f9660, ns=0x7f0573322414 "iibench.$cmd", _cmdobj=..., b=..., anObjBuilder=..., fromRepl=fromRepl@entry=false, queryOptions=0) at src/mongo/db/dbcommands.cpp:1543
|
#15 0x0000000000be9b8a in runCommands (fromRepl=false, queryOptions=<optimized out>, anObjBuilder=..., b=..., curop=..., jsobj=..., ns=<optimized out>, txn=0x7f06bf5f9660) at src/mongo/db/query/find.cpp:131
|
#16 mongo::runQuery (txn=txn@entry=0x7f06bf5f9660, m=..., q=..., curop=..., result=..., fromDBDirectClient=fromDBDirectClient@entry=false) at src/mongo/db/query/find.cpp:565
|
#17 0x0000000000afe8d5 in receivedQuery (fromDBDirectClient=false, m=..., dbresponse=..., c=..., txn=0x7f06bf5f9660) at src/mongo/db/instance.cpp:224
|
#18 mongo::assembleResponse (txn=txn@entry=0x7f06bf5f9660, m=..., dbresponse=..., remote=..., fromDBDirectClient=fromDBDirectClient@entry=false) at src/mongo/db/instance.cpp:394
|
#19 0x00000000008562a0 in mongo::MyMessageHandler::process (this=<optimized out>, m=..., port=0x7f06b6442d80, le=0x7f057db5a650) at src/mongo/db/db.cpp:195
|
#20 0x0000000000f4b7e1 in mongo::PortMessageServer::handleIncomingMsg (arg=0x7f06bd46a550) at src/mongo/util/net/message_server_port.cpp:234
|
#21 0x00007f06be15afa8 in start_thread () from /usr/local/fbcode/gcc-4.8.1-glibc-2.17/lib/libpthread.so.0
|
#22 0x00007f06bde7d5ad in clone () from /usr/local/fbcode/gcc-4.8.1-glibc-2.17/lib/libc.so.6
|
|
Thread 3 (Thread 0x7f06bdd79700 (LWP 36558)):
|
#0 0x00007f06be15f7ae in pthread_cond_timedwait@@GLIBC_2.3.2 () from /usr/local/fbcode/gcc-4.8.1-glibc-2.17/lib/libpthread.so.0
|
#1 0x0000000000a0da6e in timed_wait (wait_until=..., m=..., this=0x7f0531026bd0) at src/third_party/boost/boost/thread/pthread/condition_variable.hpp:74
|
#2 timed_wait<boost::date_time::subsecond_duration<boost::posix_time::time_duration, 1000l> > (wait_duration=..., m=..., this=0x7f0531026bd0) at src/third_party/boost/boost/thread/pthread/condition_variable_fwd.hpp:72
|
#3 mongo::CondVarLockGrantNotification::wait (this=this@entry=0x7f0531026ba0, timeoutMs=<optimized out>) at src/mongo/db/concurrency/lock_state.cpp:189
|
#4 0x0000000000a14fd2 in mongo::LockerImpl<false>::lockComplete (this=0x7f0531026600, resId=..., timeoutMs=4294967295, checkDeadlock=false) at src/mongo/db/concurrency/lock_state.cpp:607
|
#5 0x0000000000a05bb1 in mongo::Lock::DBLock::DBLock (this=0x7f06bdd77280, lockState=0x7f0531026600, db=..., mode=<optimized out>) at src/mongo/db/concurrency/d_concurrency.cpp:147
|
#6 0x000000000097e1d0 in mongo::AutoGetDb::AutoGetDb (this=0x7f06bdd77280, txn=0x7f06bdd78660, ns=..., mode=mongo::MODE_S) at src/mongo/db/client.cpp:209
|
#7 0x00000000009b9154 in mongo::CmdListCollections::run (this=0x1c93300 <mongo::cmdListCollections>, txn=0x7f06bdd78660, dbname=..., jsobj=..., errmsg=..., result=...) at src/mongo/db/commands/list_collections.cpp:77
|
#8 0x0000000000a1d3e4 in mongo::_execCommand (txn=txn@entry=0x7f06bdd78660, c=c@entry=0x1c93300 <mongo::cmdListCollections>, dbname=..., cmdObj=..., queryOptions=queryOptions@entry=0, errmsg=..., result=..., fromRepl=fromRepl@entry=false) at src/mongo/db/dbcommands.cpp:1252
|
#9 0x0000000000a1e323 in mongo::Command::execCommand (txn=txn@entry=0x7f06bdd78660, c=c@entry=0x1c93300 <mongo::cmdListCollections>, queryOptions=queryOptions@entry=0, cmdns=cmdns@entry=0x7f053105f414 "iibench.$cmd", cmdObj=..., result=..., fromRepl=fromRepl@entry=false) at src/mongo/db/dbcommands.cpp:1468
|
#10 0x0000000000a1eddb in mongo::_runCommands (txn=txn@entry=0x7f06bdd78660, ns=0x7f053105f414 "iibench.$cmd", _cmdobj=..., b=..., anObjBuilder=..., fromRepl=fromRepl@entry=false, queryOptions=0) at src/mongo/db/dbcommands.cpp:1543
|
#11 0x0000000000be9b8a in runCommands (fromRepl=false, queryOptions=<optimized out>, anObjBuilder=..., b=..., curop=..., jsobj=..., ns=<optimized out>, txn=0x7f06bdd78660) at src/mongo/db/query/find.cpp:131
|
#12 mongo::runQuery (txn=txn@entry=0x7f06bdd78660, m=..., q=..., curop=..., result=..., fromDBDirectClient=fromDBDirectClient@entry=false) at src/mongo/db/query/find.cpp:565
|
#13 0x0000000000afe8d5 in receivedQuery (fromDBDirectClient=false, m=..., dbresponse=..., c=..., txn=0x7f06bdd78660) at src/mongo/db/instance.cpp:224
|
#14 mongo::assembleResponse (txn=txn@entry=0x7f06bdd78660, m=..., dbresponse=..., remote=..., fromDBDirectClient=fromDBDirectClient@entry=false) at src/mongo/db/instance.cpp:394
|
#15 0x00000000008562a0 in mongo::MyMessageHandler::process (this=<optimized out>, m=..., port=0x7f06b6442380, le=0x7f0531022060) at src/mongo/db/db.cpp:195
|
#16 0x0000000000f4b7e1 in mongo::PortMessageServer::handleIncomingMsg (arg=0x7f06bd46a760) at src/mongo/util/net/message_server_port.cpp:234
|
#17 0x00007f06be15afa8 in start_thread () from /usr/local/fbcode/gcc-4.8.1-glibc-2.17/lib/libpthread.so.0
|
#18 0x00007f06bde7d5ad in clone () from /usr/local/fbcode/gcc-4.8.1-glibc-2.17/lib/libc.so.6
|
|
Thread 2 (Thread 0x7f06b6a1c700 (LWP 38547)):
|
#0 0x00007f06be15f7ae in pthread_cond_timedwait@@GLIBC_2.3.2 () from /usr/local/fbcode/gcc-4.8.1-glibc-2.17/lib/libpthread.so.0
|
#1 0x0000000000a0da6e in timed_wait (wait_until=..., m=..., this=0x7f0533027bd0) at src/third_party/boost/boost/thread/pthread/condition_variable.hpp:74
|
#2 timed_wait<boost::date_time::subsecond_duration<boost::posix_time::time_duration, 1000l> > (wait_duration=..., m=..., this=0x7f0533027bd0) at src/third_party/boost/boost/thread/pthread/condition_variable_fwd.hpp:72
|
#3 mongo::CondVarLockGrantNotification::wait (this=this@entry=0x7f0533027ba0, timeoutMs=<optimized out>) at src/mongo/db/concurrency/lock_state.cpp:189
|
#4 0x0000000000a14fd2 in mongo::LockerImpl<false>::lockComplete (this=0x7f0533027600, resId=..., timeoutMs=4294967295, checkDeadlock=false) at src/mongo/db/concurrency/lock_state.cpp:607
|
#5 0x0000000000a05bb1 in mongo::Lock::DBLock::DBLock (this=0x7f0533024190, lockState=0x7f0533027600, db=..., mode=<optimized out>) at src/mongo/db/concurrency/d_concurrency.cpp:147
|
#6 0x00000000009fb652 in mongo::WriteBatchExecutor::ExecInsertsState::_lockAndCheckImpl (this=this@entry=0x7f06b6a19df0, result=result@entry=0x7f06b6a187f0, intentLock=intentLock@entry=false) at src/mongo/db/commands/write_commands/batch_executor.cpp:971
|
#7 0x00000000009fb944 in mongo::WriteBatchExecutor::ExecInsertsState::_lockAndCheckImpl (this=this@entry=0x7f06b6a19df0, result=result@entry=0x7f06b6a187f0, intentLock=<optimized out>, intentLock@entry=true) at src/mongo/db/commands/write_commands/batch_executor.cpp:1003
|
#8 0x00000000009fcc50 in lockAndCheck (result=0x7f06b6a187f0, this=0x7f06b6a19df0) at src/mongo/db/commands/write_commands/batch_executor.cpp:1026
|
#9 insertOne (result=0x7f06b6a187f0, state=0x7f06b6a19df0) at src/mongo/db/commands/write_commands/batch_executor.cpp:1054
|
#10 mongo::WriteBatchExecutor::execOneInsert (this=this@entry=0x7f06b6a1a2b0, state=state@entry=0x7f06b6a19df0, error=error@entry=0x7f06b6a19dd0) at src/mongo/db/commands/write_commands/batch_executor.cpp:1083
|
#11 0x00000000009fd828 in mongo::WriteBatchExecutor::execInserts (this=this@entry=0x7f06b6a1a2b0, request=..., errors=errors@entry=0x7f06b6a1a0c0) at src/mongo/db/commands/write_commands/batch_executor.cpp:874
|
#12 0x00000000009fef74 in mongo::WriteBatchExecutor::bulkExecute (this=this@entry=0x7f06b6a1a2b0, request=..., upsertedIds=upsertedIds@entry=0x7f06b6a1a0e0, errors=errors@entry=0x7f06b6a1a0c0) at src/mongo/db/commands/write_commands/batch_executor.cpp:757
|
#13 0x00000000009ff675 in mongo::WriteBatchExecutor::executeBatch (this=this@entry=0x7f06b6a1a2b0, request=..., response=response@entry=0x7f06b6a1a2f0) at src/mongo/db/commands/write_commands/batch_executor.cpp:266
|
#14 0x0000000000a0164d in mongo::WriteCmd::run (this=<optimized out>, txn=0x7f06b6a1b660, dbName=..., cmdObj=..., options=<optimized out>, errMsg=..., result=..., fromRepl=false) at src/mongo/db/commands/write_commands/write_commands.cpp:144
|
#15 0x0000000000a1d3e4 in mongo::_execCommand (txn=txn@entry=0x7f06b6a1b660, c=c@entry=0x7f06bd7a75f0, dbname=..., cmdObj=..., queryOptions=queryOptions@entry=0, errmsg=..., result=..., fromRepl=fromRepl@entry=false) at src/mongo/db/dbcommands.cpp:1252
|
#16 0x0000000000a1e323 in mongo::Command::execCommand (txn=txn@entry=0x7f06b6a1b660, c=c@entry=0x7f06bd7a75f0, queryOptions=queryOptions@entry=0, cmdns=cmdns@entry=0x7f0533071414 "iibench.$cmd", cmdObj=..., result=..., fromRepl=fromRepl@entry=false) at src/mongo/db/dbcommands.cpp:1468
|
#17 0x0000000000a1eddb in mongo::_runCommands (txn=txn@entry=0x7f06b6a1b660, ns=0x7f0533071414 "iibench.$cmd", _cmdobj=..., b=..., anObjBuilder=..., fromRepl=fromRepl@entry=false, queryOptions=0) at src/mongo/db/dbcommands.cpp:1543
|
#18 0x0000000000be9b8a in runCommands (fromRepl=false, queryOptions=<optimized out>, anObjBuilder=..., b=..., curop=..., jsobj=..., ns=<optimized out>, txn=0x7f06b6a1b660) at src/mongo/db/query/find.cpp:131
|
#19 mongo::runQuery (txn=txn@entry=0x7f06b6a1b660, m=..., q=..., curop=..., result=..., fromDBDirectClient=fromDBDirectClient@entry=false) at src/mongo/db/query/find.cpp:565
|
#20 0x0000000000afe8d5 in receivedQuery (fromDBDirectClient=false, m=..., dbresponse=..., c=..., txn=0x7f06b6a1b660) at src/mongo/db/instance.cpp:224
|
#21 mongo::assembleResponse (txn=txn@entry=0x7f06b6a1b660, m=..., dbresponse=..., remote=..., fromDBDirectClient=fromDBDirectClient@entry=false) at src/mongo/db/instance.cpp:394
|
#22 0x00000000008562a0 in mongo::MyMessageHandler::process (this=<optimized out>, m=..., port=0x7f06b6442dd0, le=0x7f0533023060) at src/mongo/db/db.cpp:195
|
#23 0x0000000000f4b7e1 in mongo::PortMessageServer::handleIncomingMsg (arg=0x7f06bd46a7e0) at src/mongo/util/net/message_server_port.cpp:234
|
#24 0x00007f06be15afa8 in start_thread () from /usr/local/fbcode/gcc-4.8.1-glibc-2.17/lib/libpthread.so.0
|
#25 0x00007f06bde7d5ad in clone () from /usr/local/fbcode/gcc-4.8.1-glibc-2.17/lib/libc.so.6
|
|
|
Output from "db.currentOp()"
{
|
"desc" : "conn22",
|
"threadId" : "0x7f05cfba61c0",
|
"connectionId" : 22,
|
"opid" : 127,
|
"active" : true,
|
"secs_running" : 2068,
|
"microsecs_running" : NumberLong(2068470297),
|
"op" : "query",
|
"ns" : "iibench.$cmd",
|
"query" : {
|
"createIndexes" : "purchases_index",
|
"indexes" : [
|
{
|
"key" : {
|
"price" : 1,
|
"dateandtime" : 1,
|
"customerid" : 1
|
},
|
"name" : "price_1_dateandtime_1_customerid_1",
|
"background" : true
|
}
|
]
|
},
|
"client" : "127.0.0.1:58927",
|
"msg" : "Index Build (background) Index Build (background): 69799031/87019600 80%",
|
"progress" : {
|
"done" : 69799032,
|
"total" : 87019600
|
},
|
"locks" : {
|
"Global" : "w",
|
"Database" : "w",
|
"Collection" : "w"
|
},
|
"waitingForLock" : false,
|
"lockStats" : {
|
|
}
|
},
|
{
|
"desc" : "conn23",
|
"threadId" : "0x7f053101a1c0",
|
"connectionId" : 23,
|
"opid" : 133,
|
"active" : true,
|
"secs_running" : 150,
|
"microsecs_running" : NumberLong(150361708),
|
"op" : "query",
|
"ns" : "iibench.$cmd",
|
"query" : {
|
"listCollections" : 1,
|
"cursor" : {
|
|
}
|
},
|
"client" : "127.0.0.1:30444",
|
"killPending" : true,
|
"locks" : {
|
"Global" : "r",
|
"Database" : "R"
|
},
|
"waitingForLock" : true,
|
"lockStats" : {
|
|
}
|
}
|
]
|
}
|
|
Generated at Thu Feb 08 03:42:53 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.