Loading...

Type: Bug
Resolution: Won't Fix
Priority: Major - P3
Fix Version/s: None
Affects Version/s: None
Component/s: MMAPv1
Labels:
None
Environment:

Hide
[jenkins@ip-10-118-21-122 ec2-user]$ cat /etc/*release
Amazon Linux AMI release 2013.03
[jenkins@ip-10-118-21-122 ec2-user]$ mongod --version
db version v2.5.4-pre-
2013-10-30T16:33:41.267+0000 git version: 45178f5933e1104083d790fe6a901db7a3291423 modules: subscription
2013-10-30T16:33:41.268+0000 OpenSSL version: OpenSSL 1.0.1e-fips 11 Feb 2013

Show
[ jenkins@ip-10-118-21-122 ec2-user]$ cat /etc/*release Amazon Linux AMI release 2013.03 [ jenkins@ip-10-118-21-122 ec2-user]$ mongod --version db version v2.5.4-pre- 2013-10-30T16:33:41.267+0000 git version: 45178f5933e1104083d790fe6a901db7a3291423 modules: subscription 2013-10-30T16:33:41.268+0000 OpenSSL version: OpenSSL 1.0.1e-fips 11 Feb 2013

Assigned Teams:

Storage Execution
Operating System:
ALL
Steps To Reproduce:

Hide

I don't have a simple script to reproduce this, but it happens consistently on Jenkins with the Java driver 3.0.x tests with this release, and the same tests pass consistently with 2.4.

Show
I don't have a simple script to reproduce this, but it happens consistently on Jenkins with the Java driver 3.0.x tests with this release, and the same tests pass consistently with 2.4.
CAR Domain/s:
None

Aha! Reference:
None
Tracking Level:
None
Risk Status:
None
Exec Notes:
None
Goal Name(s):
None
Goal Link:
None

Java driver tests consistently hang on multiple Jenkins slaves. The test that hangs is inserting 10 documents, and it will hang for over 30 minutes waiting for a getlasterror response.

> db.currentOp()
{
	"inprog" : [
		{
			"opid" : 11662,
			"active" : false,
			"op" : "query",
			"ns" : "",
			"query" : {
				"expireAfterSeconds" : {
					"$exists" : true
				}
			},
			"client" : "0.0.0.0:0",
			"desc" : "TTLMonitor",
			"threadId" : "0x7fa3dae2e700",
			"locks" : {
				"^DriverTest-406368717001567" : "R"
			},
			"waitingForLock" : true,
			"numYields" : 0,
			"lockStats" : {
				"timeLockedMicros" : {

				},
				"timeAcquiringMicros" : {

				}
			}
		},
		{
			"opid" : 11629,
			"active" : true,
			"secs_running" : 835,
			"op" : "insert",
			"ns" : "DriverTest-406368717001567.com.mongodb.DBCursorTest406374021052232",
			"insert" : {

			},
			"client" : "127.0.0.1:52879",
			"desc" : "conn41",
			"threadId" : "0x7fa3d1429700",
			"connectionId" : 41,
			"locks" : {
				"^" : "w",
				"^DriverTest-406368717001567" : "W"
			},
			"waitingForLock" : false,
			"msg" : "index: (1/3) external sort",
			"numYields" : 0,
			"lockStats" : {
				"timeLockedMicros" : {

				},
				"timeAcquiringMicros" : {
					"r" : NumberLong(0),
					"w" : NumberLong(6)
				}
			}
		}
	]
}

[jenkins@ip-10-118-21-122 ec2-user]$ grep conn41 mongo.log | tail
2013-10-30T16:20:05.627+0000 [conn41] CMD: drop DriverTest-406368717001567.com.mongodb.DBCursorTest406373994841307
2013-10-30T16:20:05.627+0000 [conn41] dropCollection: DriverTest-406368717001567.com.mongodb.DBCursorTest406373994841307
2013-10-30T16:20:05.627+0000 [conn41]   d->nIndexes was 1
2013-10-30T16:20:05.627+0000 [conn41] 	 dropIndexes done
2013-10-30T16:20:05.627+0000 [conn41] command DriverTest-406368717001567.$cmd command: { drop: "com.mongodb.DBCursorTest406373994841307" } ntoreturn:1 keyUpdates:0 locks(micros) w:509 reslen:129 0ms
2013-10-30T16:20:05.631+0000 [conn41] Database::_addNamespaceToCatalog ns: DriverTest-406368717001567.com.mongodb.DBCursorTest406374021052232
2013-10-30T16:20:05.631+0000 [conn41] ExtentManager::increaseStorageSize ns:DriverTest-406368717001567.com.mongodb.DBCursorTest406374021052232 desiredSize:4096 fromFreeList: 1 eloc: 0:31000
2013-10-30T16:20:05.631+0000 [conn41] _reuse extent was:DriverTest-406368717001567.com.mongodb.DBCursorTest406373994841307 now:DriverTest-406368717001567.com.mongodb.DBCursorTest406374021052232
2013-10-30T16:20:05.631+0000 [conn41] creating index with info @ 0:3d558
2013-10-30T16:20:05.631+0000 [conn41] build index on: DriverTest-406368717001567.com.mongodb.DBCursorTest406374021052232 properties: { "v" : 1, "key" : { "_id" : 1 }, "name" : "_id_", "ns" : "DriverTest-406368717001567.com.mongodb.DBCursorTest406374021052232" }

(gdb) info threads
  16 Thread 0x7fa3dee36700 (LWP 19687)  0x00007fa3eae2a627 in do_sigwait () from /lib64/libpthread.so.0
  15 Thread 0x7fa3de635700 (LWP 19688)  0x00007fa3eae2a15d in nanosleep () from /lib64/libpthread.so.0
  14 Thread 0x7fa3dde34700 (LWP 19689)  0x00007fa3eae268ec in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
  13 Thread 0x7fa3dd633700 (LWP 19691)  0x00007fa3eae268ec in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
  12 Thread 0x7fa3dce32700 (LWP 19692)  0x00007fa3eae268ec in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
  11 Thread 0x7fa3dc631700 (LWP 19693)  0x00007fa3eae2a15d in nanosleep () from /lib64/libpthread.so.0
  10 Thread 0x7fa3dbe30700 (LWP 19694)  0x00007fa3eae2a15d in nanosleep () from /lib64/libpthread.so.0
  9 Thread 0x7fa3db62f700 (LWP 19695)  0x00007fa3eae2a15d in nanosleep () from /lib64/libpthread.so.0
  8 Thread 0x7fa3dae2e700 (LWP 19696)  0x00007fa3eae268ec in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
  7 Thread 0x7fa3da62d700 (LWP 19697)  0x00007fa3eae26c6b in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
  6 Thread 0x7fa3ec120700 (LWP 19838)  0x00007fa3eae28b80 in sem_wait () from /lib64/libpthread.so.0
  5 Thread 0x7fa3d562b700 (LWP 19954)  0x00007fa3eae29d7c in recv () from /lib64/libpthread.so.0
  4 Thread 0x7fa3c9328700 (LWP 19957)  0x00007fa3eae29d7c in recv () from /lib64/libpthread.so.0
  3 Thread 0x7fa3c9126700 (LWP 19958)  0x00007fa3eae29d7c in recv () from /lib64/libpthread.so.0
  2 Thread 0x7fa3d1429700 (LWP 19961)  0x00007fa3e9b9394d in write () from /lib64/libc.so.6
* 1 Thread 0x7fa3ec22ac40 (LWP 19686)  0x00007fa3e9b997b3 in select () from /lib64/libc.so.6
(gdb) thread 2
[Switching to thread 2 (Thread 0x7fa3d1429700 (LWP 19961))]#0  0x00007fa3e9b9394d in write () from /lib64/libc.so.6
(gdb) bt
#0  0x00007fa3e9b9394d in write () from /lib64/libc.so.6
#1  0x00007fa3e9b32333 in _IO_new_file_write () from /lib64/libc.so.6
#2  0x00007fa3e9b321fa in new_do_write () from /lib64/libc.so.6
#3  0x00007fa3e9b33825 in _IO_new_do_write () from /lib64/libc.so.6
#4  0x00007fa3e9b32870 in _IO_new_file_sync () from /lib64/libc.so.6
#5  0x00007fa3e9b2792b in fflush () from /lib64/libc.so.6
#6  0x00007fa3ea37a28e in std::basic_ostream<char, std::char_traits<char> >::flush() () from /usr/lib64/libstdc++.so.6
#7  0x0000000000eae75f in mongo::printMemInfo(char const*) ()
#8  0x0000000000a8286c in mongo::BtreeBasedBuilder::fastBuildIndex(char const*, mongo::NamespaceDetails*, mongo::IndexDetails&, bool, int) ()
#9  0x00000000008d17c3 in mongo::buildAnIndex(mongo::Collection*, mongo::IndexDetails&, bool) ()
#10 0x00000000008cbafa in mongo::IndexCatalog::createIndex(mongo::BSONObj, bool) ()
#11 0x00000000008cc92a in mongo::IndexCatalog::ensureHaveIdIndex() ()
#12 0x0000000000b908dc in mongo::ensureIdIndexForNewNs(mongo::Collection*) ()
#13 0x0000000000b92c5a in mongo::DataFileMgr::insert(char const*, void const*, int, bool, bool, bool, bool*) ()
#14 0x0000000000b9306c in mongo::DataFileMgr::insertWithObjMod(char const*, mongo::BSONObj&, bool, bool) ()
#15 0x0000000000aad213 in mongo::checkAndInsert(char const*, mongo::BSONObj&) ()
#16 0x0000000000ab4421 in mongo::receivedInsert(mongo::Message&, mongo::CurOp&) ()
#17 0x0000000000ab8b52 in mongo::assembleResponse(mongo::Message&, mongo::DbResponse&, mongo::HostAndPort const&) ()
#18 0x000000000079789f in mongo::MyMessageHandler::process(mongo::Message&, mongo::AbstractMessagingPort*, mongo::LastError*) ()
#19 0x0000000000ebab09 in mongo::PortMessageServer::handleIncomingMsg(void*) ()
#20 0x00007fa3eae22c6b in start_thread () from /lib64/libpthread.so.0
#21 0x00007fa3e9ba05ed in clone () from /lib64/libc.so.6

Details

Description

Attachments

Activity

People

Dates