[SERVER-20295] Power cycle test - mongod fails to start with invalid object size in storage.bson Created: 04/Sep/15  Updated: 14/Apr/16  Resolved: 17/Nov/15

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

Type: Bug Priority: Major - P3
Reporter: Jonathan Abrahams Assignee: Jonathan Abrahams
Resolution: Cannot Reproduce Votes: 0
Labels: 32powercycle, 32qa
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Backwards Compatibility: Fully Compatible
Operating System: ALL
Steps To Reproduce:

Using powercycle script, failure happened after the first power cycle.

powertest.sh -s Administrator@10.4.124.128 -r wt-318-2 -C virsh -S "-t 10.4.112.154" -R -F /Users/jonathan/mongodb/mongo -N 40 -l 100 -A -p

Sprint: QuInt A (10/12/15), QuInt B (11/02/15), TIG C (11/20/15)
Participants:

 Description   

During a power cycle test, on Windows, mongod failed to start after system reboot.

2015-09-04T12:55:47.087-0700 I CONTROL  [main] ***** SERVER RESTARTED *****
2015-09-04T12:55:47.293-0700 I CONTROL  [main] Trying to install Windows service 'mongod-wt-318-2'
2015-09-04T12:55:47.298-0700 I CONTROL  [main] Service 'mongod-wt-318-2' (mongod-wt-318-2) installed with command line 'C:\cygwin64\home\Administrator\wt-318-2\MongoDB\Server\3.1\bin\mongod.exe --storageEngine wiredTiger --logpath C:\\cygwin64\\home\\Administrator\\wt-318-2\\logs\\mongod-wiredTiger-recovery.log --logappend --dbpath C:\\cygwin64\\home\\Administrator\\wt-318-2\\data\\wiredTiger --port 37017 --setParameter enableTestCommands=1 -replSet pc --service'
2015-09-04T12:55:47.298-0700 I CONTROL  [main] Service can be started from the command line with 'net start mongod-wt-318-2'
2015-09-04T12:55:47.369-0700 I CONTROL  [main] ***** SERVER RESTARTED *****
2015-09-04T12:55:47.550-0700 I CONTROL  [main] Trying to start Windows service 'MongoDB'
2015-09-04T12:55:47.551-0700 I STORAGE  [thread1] Service running
2015-09-04T12:55:47.567-0700 I -        [initandlisten] Assertion: 10334:BSONObj size: 0 (0x0) is invalid. Size must be between 0 and 16793600(16MB) First element: EOO
2015-09-04T12:55:51.581-0700 I CONTROL  [initandlisten] mongod.exe    ...\src\mongo\util\stacktrace_windows.cpp(174)             mongo::printStackTrace+0x43
2015-09-04T12:55:51.581-0700 I CONTROL  [initandlisten] mongod.exe    ...\src\mongo\util\log.cpp(134)                            mongo::logContext+0xac
2015-09-04T12:55:51.581-0700 I CONTROL  [initandlisten] mongod.exe    ...\src\mongo\util\assert_util.cpp(223)                    mongo::msgasserted+0xfa
2015-09-04T12:55:51.581-0700 I CONTROL  [initandlisten] mongod.exe    ...\src\mongo\util\assert_util.cpp(215)                    mongo::msgasserted+0x13
2015-09-04T12:55:51.581-0700 I CONTROL  [initandlisten] mongod.exe    ...\src\mongo\bson\bsonobj.cpp(75)                         mongo::BSONObj::_assertInvalid+0x40d
2015-09-04T12:55:51.581-0700 I CONTROL  [initandlisten] mongod.exe    ...\src\mongo\bson\bsonobj.h(112)                          mongo::BSONObj::BSONObj+0x31
2015-09-04T12:55:51.581-0700 I CONTROL  [initandlisten] mongod.exe    ...\src\mongo\db\storage\storage_engine_metadata.cpp(166)  mongo::StorageEngineMetadata::read+0xaf8
2015-09-04T12:55:51.581-0700 I CONTROL  [initandlisten] mongod.exe    ...\src\mongo\db\storage\storage_engine_metadata.cpp(70)   mongo::StorageEngineMetadata::forPath+0x1ca
2015-09-04T12:55:51.581-0700 I CONTROL  [initandlisten] mongod.exe    ...\src\mongo\db\storage\storage_engine_metadata.cpp(82)   mongo::StorageEngineMetadata::getStorageEngineForPath+0x3e
2015-09-04T12:55:51.581-0700 I CONTROL  [initandlisten] mongod.exe    ...\src\mongo\db\service_context_d.cpp(83)                 mongo::ServiceContextMongoD::initializeGlobalStorageEngine+0xb1
2015-09-04T12:55:51.582-0700 I CONTROL  [initandlisten] mongod.exe    ...\src\mongo\db\db.cpp(419)                               mongo::_initAndListen+0x1a2
2015-09-04T12:55:51.582-0700 I CONTROL  [initandlisten] mongod.exe    ...\src\mongo\db\db.cpp(602)                               mongo::initAndListen+0x27
2015-09-04T12:55:51.582-0700 I CONTROL  [initandlisten] mongod.exe    ...\src\mongo\db\db.cpp(623)                               mongo::initService+0x93
2015-09-04T12:55:51.582-0700 I CONTROL  [initandlisten] mongod.exe    ...\src\mongo\util\ntservice.cpp(563)                      mongo::ntservice::initService+0x53
2015-09-04T12:55:51.582-0700 I CONTROL  [initandlisten] sechost.dll                                                              GetIdentityProviderInfoByGUID+0x231
2015-09-04T12:55:51.582-0700 I CONTROL  [initandlisten] KERNEL32.DLL                                                             BaseThreadInitThunk+0xd
2015-09-04T12:55:51.582-0700 I CONTROL  [initandlisten]
2015-09-04T12:55:51.628-0700 E STORAGE  [initandlisten] Unable to read the storage engine metadata file: FailedToParse Failed to convert data in C:\\cygwin64\\home\\Administrator\\wt-318-2\\data\\wiredTiger\storage.bson to BSON: BSONObj size: 0 (0x0) is invalid. Size must be between 0 and 16793600(16MB) First element: EOO
2015-09-04T12:55:51.628-0700 I -        [initandlisten] Fatal Assertion 28661
2015-09-04T12:55:51.628-0700 I -        [initandlisten]
 
***aborting after fassert() failure
 
 
2015-09-04T12:55:52.231-0700 I CONTROL  [initandlisten] mongod.exe    ...\src\mongo\util\stacktrace_windows.cpp(174)            mongo::printStackTrace+0x43
2015-09-04T12:55:52.231-0700 I CONTROL  [initandlisten] mongod.exe    ...\src\mongo\util\signal_handlers_synchronous.cpp(180)   mongo::`anonymous namespace'::printSignalAndBacktrace+0x74
2015-09-04T12:55:52.231-0700 I CONTROL  [initandlisten] mongod.exe    ...\src\mongo\util\signal_handlers_synchronous.cpp(236)   mongo::`anonymous namespace'::abruptQuit+0x76
2015-09-04T12:55:52.231-0700 I CONTROL  [initandlisten] MSVCR120.dll                                                            raise+0x1e9
2015-09-04T12:55:52.232-0700 I CONTROL  [initandlisten] MSVCR120.dll                                                            abort+0x18
2015-09-04T12:55:52.232-0700 I CONTROL  [initandlisten] mongod.exe    ...\src\mongo\util\assert_util.cpp(172)                   mongo::fassertFailed+0xf0
2015-09-04T12:55:52.232-0700 I CONTROL  [initandlisten] mongod.exe    ...\src\mongo\db\storage\storage_engine_metadata.cpp(73)  mongo::StorageEngineMetadata::forPath+0x25b
2015-09-04T12:55:52.232-0700 I CONTROL  [initandlisten] mongod.exe    ...\src\mongo\db\storage\storage_engine_metadata.cpp(82)  mongo::StorageEngineMetadata::getStorageEngineForPath+0x3e
2015-09-04T12:55:52.232-0700 I CONTROL  [initandlisten] mongod.exe    ...\src\mongo\db\service_context_d.cpp(83)                mongo::ServiceContextMongoD::initializeGlobalStorageEngine+0xb1
2015-09-04T12:55:52.232-0700 I CONTROL  [initandlisten] mongod.exe    ...\src\mongo\db\db.cpp(419)                              mongo::_initAndListen+0x1a2
2015-09-04T12:55:52.232-0700 I CONTROL  [initandlisten] mongod.exe    ...\src\mongo\db\db.cpp(602)                              mongo::initAndListen+0x27
2015-09-04T12:55:52.232-0700 I CONTROL  [initandlisten] mongod.exe    ...\src\mongo\db\db.cpp(623)                              mongo::initService+0x93
2015-09-04T12:55:52.232-0700 I CONTROL  [initandlisten] mongod.exe    ...\src\mongo\util\ntservice.cpp(563)                     mongo::ntservice::initService+0x53
2015-09-04T12:55:52.232-0700 I CONTROL  [initandlisten] sechost.dll                                                             GetIdentityProviderInfoByGUID+0x231
2015-09-04T12:55:52.232-0700 I CONTROL  [initandlisten] KERNEL32.DLL                                                            BaseThreadInitThunk+0xd
2015-09-04T12:55:52.232-0700 F -        [initandlisten] Got signal: 22 (SIGABRT).
2015-09-04T12:55:52.263-0700 I CONTROL  [initandlisten] writing minidump diagnostic file C:\cygwin64\home\Administrator\wt-318-2\MongoDB\Server\3.2015-09-04T19-55-52.mdmp



 Comments   
Comment by Charlie Swanson [ 13/Nov/15 ]

Assigning back to Jonathan. I was unable to reproduce after 2 days. I think in order to reliably reproduce any crash like this, we need to figure out what workload was running at the time of the crash. So please include the -L option, and upload the client logs if you are able to reproduce. Thanks!

Comment by Daniel Pasette (Inactive) [ 04/Sep/15 ]

This is above the storage engine recovery layer.

Generated at Thu Feb 08 03:53:46 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.