[SERVER-968] Crash from DataFileSync and dropDatabase Created: 05/Apr/10  Updated: 12/Jul/16  Resolved: 25/Sep/10

Status: Closed
Project: Core Server
Component/s: None
Affects Version/s: None
Fix Version/s: 1.7.1

Type: Bug Priority: Major - P3
Reporter: Mathias Stearn Assignee: Eliot Horowitz (Inactive)
Resolution: Done Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Participants:

 Description   

while (1) { db.c.insert({}); db.dropDatabase() }

Crashes on master with --syncdelay 1
Works on master with --syncdelay 0
Works on 1.4.0 with --syncdelay 1



 Comments   
Comment by Eliot Horowitz (Inactive) [ 25/Sep/10 ]

I think was actually fixed sooner - but not sure.

Comment by Mathias Stearn [ 05/Apr/10 ]

$ ./mongod --syncdelay 1
Mon Apr 5 23:20:36 Mongo DB : starting : pid = 1659 port = 27017 dbpath = /data/db/ master = 0 slave = 0 64-bit
****
WARNING: This is development version of MongoDB. Not recommended for production.
****
Mon Apr 5 23:20:36 db version v1.5.0-pre-, pdfile version 4.5
Mon Apr 5 23:20:36 git version: bbabbd2fedd4bcdfebc92ba7f5e38e4c7973d754
Mon Apr 5 23:20:36 sys info: Linux redbeard 2.6.32-ARCH #1 SMP PREEMPT Mon Mar 15 20:44:03 CET 2010 x86_64 BOOST_LIB_VERSION=1_41
Mon Apr 5 23:20:36 waiting for connections on port 27017
Mon Apr 5 23:20:36 web admin interface listening on port 28017
Mon Apr 5 23:20:41 connection accepted from 127.0.0.1:51830 #1
Mon Apr 5 23:20:51 allocating new datafile /data/db/test.ns, filling with zeroes...
Mon Apr 5 23:20:51 done allocating datafile /data/db/test.ns, size: 16MB, took 0.005 secs
Mon Apr 5 23:20:51 allocating new datafile /data/db/test.0, filling with zeroes...
Mon Apr 5 23:20:51 done allocating datafile /data/db/test.0, size: 64MB, took 0.021 secs
Mon Apr 5 23:20:51 building new index on

{ _id: 1 }

for test.c
Mon Apr 5 23:20:51 Buildindex test.c idxNo:0 { name: "id", ns: "test.c", key:

{ _id: 1 }

}
Mon Apr 5 23:20:51 done for 0 records 0secs
Mon Apr 5 23:20:51 dropDatabase test.$cmd
Mon Apr 5 23:20:51 allocating new datafile /data/db/test.ns, filling with zeroes...
Mon Apr 5 23:20:51 done allocating datafile /data/db/test.ns, size: 16MB, took 0.005 secs
Mon Apr 5 23:20:51 allocating new datafile /data/db/test.0, filling with zeroes...
Mon Apr 5 23:20:51 done allocating datafile /data/db/test.0, size: 64MB, took 0.023 secs
Mon Apr 5 23:20:51 building new index on

{ _id: 1 }

for test.c
Mon Apr 5 23:20:51 Buildindex test.c idxNo:0 { name: "id", ns: "test.c", key:

{ _id: 1 }

}
Mon Apr 5 23:20:51 done for 0 records 0secs
Mon Apr 5 23:20:51 dropDatabase test.$cmd
pure virtual method called
Mon Apr 5 23:20:51 terminate() called, printing stack:
0x632e90 0x7f8d95cf26f6 0x7f8d95cf2723 0x7f8d95cf2fff 0x4cd992 0x640746 0x4cc1e0 0x7f8d9581c147 0x7f8d95f4288a 0x7f8d945919ed
./mongod(_ZN5mongo11myterminateEv+0x50) [0x632e90]
/usr/lib/libstdc++.so.6(+0xca6f6) [0x7f8d95cf26f6]
/usr/lib/libstdc++.so.6(+0xca723) [0x7f8d95cf2723]
/usr/lib/libstdc++.so.6(+0xcafff) [0x7f8d95cf2fff]
./mongod(_ZN5mongo9MongoFile8flushAllEb+0x62) [0x4cd992]
./mongod(_ZN5mongo12DataFileSync3runEv+0x186) [0x640746]
./mongod(_ZN5mongo13BackgroundJob3thrEv+0x40) [0x4cc1e0]
/usr/lib/libboost_thread-mt.so.1.41.0(thread_proxy+0x77) [0x7f8d9581c147]
/lib/libpthread.so.0(+0x688a) [0x7f8d95f4288a]
/lib/libc.so.6(clone+0x6d) [0x7f8d945919ed]
Mon Apr 5 23:20:51 Got signal: 6 (Aborted).
Mon Apr 5 23:20:51 Backtrace:
0x633aa9 0x7f8d944f5050 0x7f8d944f4fd5 0x7f8d944f63f0 0x632f8d 0x7f8d95cf26f6 0x7f8d95cf2723 0x7f8d95cf2fff 0x4cd992 0x640746 0x4cc1e0 0x7f8d9581c147 0x7f8d95f4288a 0x7f8d945919ed
./mongod(_ZN5mongo10abruptQuitEi+0x3d9) [0x633aa9]
/lib/libc.so.6(+0x32050) [0x7f8d944f5050]
/lib/libc.so.6(gsignal+0x35) [0x7f8d944f4fd5]
/lib/libc.so.6(abort+0x180) [0x7f8d944f63f0]
./mongod(_ZN5mongo11myterminateEv+0x14d) [0x632f8d]
/usr/lib/libstdc++.so.6(+0xca6f6) [0x7f8d95cf26f6]
/usr/lib/libstdc++.so.6(+0xca723) [0x7f8d95cf2723]
/usr/lib/libstdc++.so.6(+0xcafff) [0x7f8d95cf2fff]
./mongod(_ZN5mongo9MongoFile8flushAllEb+0x62) [0x4cd992]
./mongod(_ZN5mongo12DataFileSync3runEv+0x186) [0x640746]
./mongod(_ZN5mongo13BackgroundJob3thrEv+0x40) [0x4cc1e0]
/usr/lib/libboost_thread-mt.so.1.41.0(thread_proxy+0x77) [0x7f8d9581c147]
/lib/libpthread.so.0(+0x688a) [0x7f8d95f4288a]
/lib/libc.so.6(clone+0x6d) [0x7f8d945919ed]
Mon Apr 5 23:20:51 dbexit:
Mon Apr 5 23:20:51 shutdown: going to close listening sockets...
Mon Apr 5 23:20:51 going to close listening socket: 5
Mon Apr 5 23:20:51 going to close listening socket: 6
Mon Apr 5 23:20:51 going to close listening socket: 7
Mon Apr 5 23:20:51 going to close listening socket: 8
Mon Apr 5 23:20:51 going to close listening socket: 9
Mon Apr 5 23:20:51 going to close listening socket: 10
Mon Apr 5 23:20:51 shutdown: going to flush oplog...
Mon Apr 5 23:20:51 shutdown: going to close sockets...
Mon Apr 5 23:20:51 shutdown: waiting for fs preallocator...
Mon Apr 5 23:20:51 shutdown: closing all files...
pure virtual method called
Mon Apr 5 23:20:51 terminate() called, printing stack:
0x632e90 0x7f8d95cf26f6 0x7f8d95cf2723 0x7f8d95cf2fff 0x4ce43d 0x59f12f 0x59f863 0x633bda 0x7f8d944f5050 0x7f8d944f4fd5 0x7f8d944f63f0 0x632f8d 0x7f8d95cf26f6 0x7f8d95cf2723 0x7f8d95cf2fff 0x4cd992 0x640746 0x4cc1e0 0x7f8d9581c147 0x7f8d95f4288a
./mongod(_ZN5mongo11myterminateEv+0x50) [0x632e90]
/usr/lib/libstdc++.so.6(+0xca6f6) [0x7f8d95cf26f6]
/usr/lib/libstdc++.so.6(+0xca723) [0x7f8d95cf2723]
/usr/lib/libstdc++.so.6(+0xcafff) [0x7f8d95cf2fff]
./mongod(_ZN5mongo9MongoFile13closeAllFilesERSt18basic_stringstreamIcSt11char_traitsIcESaIcEE+0x6d) [0x4ce43d]
./mongod(_ZN5mongo8shutdownEv+0x50f) [0x59f12f]
./mongod(_ZN5mongo6dbexitENS_8ExitCodeEPKc+0x1c3) [0x59f863]
./mongod(_ZN5mongo10abruptQuitEi+0x50a) [0x633bda]
/lib/libc.so.6(+0x32050) [0x7f8d944f5050]
/lib/libc.so.6(gsignal+0x35) [0x7f8d944f4fd5]
/lib/libc.so.6(abort+0x180) [0x7f8d944f63f0]
./mongod(_ZN5mongo11myterminateEv+0x14d) [0x632f8d]
/usr/lib/libstdc++.so.6(+0xca6f6) [0x7f8d95cf26f6]
/usr/lib/libstdc++.so.6(+0xca723) [0x7f8d95cf2723]
/usr/lib/libstdc++.so.6(+0xcafff) [0x7f8d95cf2fff]
./mongod(_ZN5mongo9MongoFile8flushAllEb+0x62) [0x4cd992]
./mongod(_ZN5mongo12DataFileSync3runEv+0x186) [0x640746]
./mongod(_ZN5mongo13BackgroundJob3thrEv+0x40) [0x4cc1e0]
/usr/lib/libboost_thread-mt.so.1.41.0(thread_proxy+0x77) [0x7f8d9581c147]
/lib/libpthread.so.0(+0x688a) [0x7f8d95f4288a]
Mon Apr 5 23:20:51 Got signal: 6 (Aborted).
Mon Apr 5 23:20:51 Backtrace:
0x633aa9 0x7f8d944f5050 0x7f8d944f4fd5 0x7f8d944f63f0 0x632f8d 0x7f8d95cf26f6 0x7f8d95cf2723 0x7f8d95cf2fff 0x4ce43d 0x59f12f 0x59f863 0x633bda 0x7f8d944f5050 0x7f8d944f4fd5 0x7f8d944f63f0 0x632f8d 0x7f8d95cf26f6 0x7f8d95cf2723 0x7f8d95cf2fff 0x4cd992
./mongod(_ZN5mongo10abruptQuitEi+0x3d9) [0x633aa9]
/lib/libc.so.6(+0x32050) [0x7f8d944f5050]
/lib/libc.so.6(gsignal+0x35) [0x7f8d944f4fd5]
/lib/libc.so.6(abort+0x180) [0x7f8d944f63f0]
./mongod(_ZN5mongo11myterminateEv+0x14d) [0x632f8d]
/usr/lib/libstdc++.so.6(+0xca6f6) [0x7f8d95cf26f6]
/usr/lib/libstdc++.so.6(+0xca723) [0x7f8d95cf2723]
/usr/lib/libstdc++.so.6(+0xcafff) [0x7f8d95cf2fff]
./mongod(_ZN5mongo9MongoFile13closeAllFilesERSt18basic_stringstreamIcSt11char_traitsIcESaIcEE+0x6d) [0x4ce43d]
./mongod(_ZN5mongo8shutdownEv+0x50f) [0x59f12f]
./mongod(_ZN5mongo6dbexitENS_8ExitCodeEPKc+0x1c3) [0x59f863]
./mongod(_ZN5mongo10abruptQuitEi+0x50a) [0x633bda]
/lib/libc.so.6(+0x32050) [0x7f8d944f5050]
/lib/libc.so.6(gsignal+0x35) [0x7f8d944f4fd5]
/lib/libc.so.6(abort+0x180) [0x7f8d944f63f0]
./mongod(_ZN5mongo11myterminateEv+0x14d) [0x632f8d]
/usr/lib/libstdc++.so.6(+0xca6f6) [0x7f8d95cf26f6]
/usr/lib/libstdc++.so.6(+0xca723) [0x7f8d95cf2723]
/usr/lib/libstdc++.so.6(+0xcafff) [0x7f8d95cf2fff]
./mongod(_ZN5mongo9MongoFile8flushAllEb+0x62) [0x4cd992]
Mon Apr 5 23:20:51 dbexit: ; exiting immediately

Comment by Eliot Horowitz (Inactive) [ 05/Apr/10 ]

not happening for me.
can you attach a trace.
sync seems to get the right lock

Comment by Dwight Merriman [ 05/Apr/10 ]

i'm going to guess this is eliot's and the change just made it manifest

is sync outside of a lock?

Comment by Mathias Stearn [ 05/Apr/10 ]

Git bisect fingered this change: http://github.com/mongodb/mongo/commit/666fb52

Generated at Thu Feb 08 02:55:41 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.