Details
-
Bug
-
Resolution: Cannot Reproduce
-
Major - P3
-
None
-
1.8.0-rc1
-
None
-
Windows 7 sp1, 64 bit build, i5 dual core 2.67GHz, 8GB RAM
-
ALL
Description
I was working with the script in https://github.com/mongodb/scratch/blob/master/testing/1.8/lotsaupdates/setup.js. This script defines several functions that were being used for testing updates with durability on.
Config file in use:
- config file for MongoDB
- quickie pointers for a single instance
dbpath = c:/cygwin/home/cwestin/sandbox/dbfiles
logpath = c:/cygwin/home/cwestin/sandbox/mongodb.log
#replSet = foo
dur = true
directoryperdb = true
logappend = true
rest = true
I had previously loaded a large database with 10M rows, using loadData(10000000); This was then shutdown and restarted. Then I set out to test updates. Here is the shell transcript:
$ ./mongo
MongoDB shell version: 1.9.0-pre-
connecting to: test
> var setup = '../scratch/testing/1.8/lotsaupdates/setup.js';
> load(setup);
> shuffleData(1000);
> checkData(10000000);
Tue Mar 08 14:27:46 MessagingPort recv() errno:10054 An existing connection was
forcibly closed by the remote host. 127.0.0.1:27017
Tue Mar 08 14:27:46 SocketException: remote: error: 9001 socket exception [1]
Tue Mar 08 14:27:46 DBClientCursor::init call() failed
Tue Mar 08 14:27:46 query failed : testdb.$cmd
to: 127.0.0
.1
Tue Mar 08 14:27:46 Error: error doing query: failed shell/collection.js:150
Tue Mar 08 14:27:46 trying reconnect to 127.0.0.1
Tue Mar 08 14:27:47 reconnect 127.0.0.1 failed couldn't connect to server 127.0.
0.1
>
Here is what appeared in the log around the time of the crash:
....
Tue Mar 08 14:24:51 [conn1] query testdb.testdata ntoreturn:1 reslen:115 nscanned:1
nreturned:1 900ms
Tue Mar 08 14:24:52 [conn1] update testdb.testdata query:
961ms
Tue Mar 08 14:25:08 [dur] lsn set 1009511
Tue Mar 08 14:25:30 [conn1] CMD: validate testdb.testdata
Tue Mar 08 14:25:33 [dur] lsn set 1069441
Tue Mar 08 14:26:33 [dur] lsn set 1129331
Tue Mar 08 14:27:33 [dur] lsn set 1189291
Tue Mar 08 14:27:46 [conn1] query testdb.$cmd ntoreturn:1 command:
reslen:727 136137ms
Tue Mar 08 14:27:46 [conn1] CMD: dropIndexes testdb.testdata
Tue Mar 08 14:27:46 [conn1] query testdb.$cmd ntoreturn:1 command:
reslen:74 162ms
Tue Mar 08 14:27:46 [conn1] building new index on
for testdb.testdata
Tue Mar 08 14:27:46 [conn1] ERROR: Uncaught std::exception: boost::filesystem::create_directory: Access is denied: "c:\cygwin\home\cwestin\sandbox\dbfiles_tmp", terminating
Tue Mar 08 14:27:46 dbexit:
Tue Mar 08 14:27:46 [conn1] shutdown: going to close listening sockets...
Tue Mar 08 14:27:46 [conn1] closing listening socket: 304
Tue Mar 08 14:27:46 [conn1] closing listening socket: 308
Tue Mar 08 14:27:46 [initandlisten] now exiting
Tue Mar 08 14:27:46 Tue Mar 08 14:27:46 [conn1] shutdown: going to flush diaglog...
dbexit: ; exiting immediately
Tue Mar 08 14:27:46 [conn1] shutdown: going to close sockets...
Tue Mar 08 14:27:46 [conn1] shutdown: waiting for fs preallocator...
Tue Mar 08 14:27:46 [conn1] shutdown: lock for final commit...
....
The operations in the log can easily be matched up with the operations in the checkData() function in setup.js. If I run checkData() again, I can get the same result repeatedly.