[SERVER-36040] WiredTiger.wt File corrupted , Server cannot start Created: 10/Jul/18  Updated: 27/Jul/18  Resolved: 16/Jul/18

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

Type: Bug Priority: Major - P3
Reporter: lh83mail Assignee: Nick Brewer
Resolution: Done Votes: 0
Labels: envns, rpo, rpu, trcf, wtc
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Attachments: HTML File WiredTiger     File WiredTiger.turtle     File WiredTiger.wt     File WiredTigerLAS.wt     File _mdb_catalog.wt     File repair-attempt.tar.gz     File sizeStorer.wt    
Operating System: Windows
Participants:

 Description   

After an unexpected shutdown, mongodb does not start properly. I have tried the --repair run with mongo:3.4.6, But not work.

os : windows server

start log is:

2018-07-10T09:24:35.661+0800 I CONTROL  [initandlisten] options: { storage: { dbPath: "E:\servers\mongodb\data" } }
2018-07-10T09:24:35.661+0800 W -        [initandlisten] Detected unclean shutdown - E:\servers\mongodb\data\mongod.lock is not empty.
2018-07-10T09:24:35.662+0800 I -        [initandlisten] Detected data files in E:\servers\mongodb\data created by the 'wiredTiger' storage engine, so
setting the active storage engine to 'wiredTiger'.
2018-07-10T09:24:35.663+0800 W STORAGE  [initandlisten] Recovering data from the last clean checkpoint.
2018-07-10T09:24:35.663+0800 I STORAGE  [initandlisten] wiredtiger_open config: create,cache_size=32199M,session_max=20000,eviction=(threads_min=4,thr
eads_max=4),config_base=false,statistics=(fast),log=(enabled=true,archive=true,path=journal,compressor=snappy),file_manager=(close_idle_time=100000),c
heckpoint=(wait=60,log_size=2GB),statistics_log=(wait=0),
2018-07-10T09:24:35.672+0800 E STORAGE  [initandlisten] WiredTiger error (-31802) [1531185875:672589][4124:1991524064], file:WiredTiger.wt, connection
: unable to read root page from file:WiredTiger.wt: WT_ERROR: non-specific WiredTiger error
2018-07-10T09:24:35.673+0800 E STORAGE  [initandlisten] WiredTiger error (0) [1531185875:673589][4124:1991524064], file:WiredTiger.wt, connection: Wir
edTiger has failed to open its metadata
2018-07-10T09:24:35.673+0800 E STORAGE  [initandlisten] WiredTiger error (0) [1531185875:673589][4124:1991524064], file:WiredTiger.wt, connection: Thi
s may be due to the database files being encrypted, being from an older version or due to corruption on disk
2018-07-10T09:24:35.674+0800 E STORAGE  [initandlisten] WiredTiger error (0) [1531185875:674589][4124:1991524064], file:WiredTiger.wt, connection: You
 should confirm that you have opened the database with the correct options including all encryption and compression options
2018-07-10T09:24:35.675+0800 I -        [initandlisten] Assertion: 28595:-31802: WT_ERROR: non-specific WiredTiger error src\mongo\db\storage\wiredtig
er\wiredtiger_kv_engine.cpp 269
2018-07-10T09:24:35.676+0800 I STORAGE  [initandlisten] exception in initAndListen: 28595 -31802: WT_ERROR: non-specific WiredTiger error, terminating2018-07-10T09:24:35.676+0800 I NETWORK  [initandlisten] shutdown: going to close listening sockets...
2018-07-10T09:24:35.677+0800 I NETWORK  [initandlisten] shutdown: going to flush diaglog...
2018-07-10T09:24:35.677+0800 I CONTROL  [initandlisten] now exiting
2018-07-10T09:24:35.677+0800 I CONTROL  [initandlisten] shutting down with code:100



 Comments   
Comment by Nick Brewer [ 16/Jul/18 ]

lh83mail

Unfortunately, this error indicates that there was corruption on the disk, most often caused by a faulty storage layer. In this situation, our best recommendation would be to resync the affected node if it is a member of a replica set, or restore from a backup if possible.

To prevent this type of problem in the future please take note of the following guidelines to help mitigate any issues related to unreliable storage layers or server failures:

Regards,
Nick

Comment by lh83mail [ 11/Jul/18 ]

Thanks for your reply. and i got another exception after extract the files. 

2018-07-11T08:55:08.297+0800 I CONTROL  [initandlisten] targetMinOS: Windows 7/Windows Server 2008 R2
2018-07-11T08:55:08.298+0800 I CONTROL  [initandlisten] db version v3.4.6
2018-07-11T08:55:08.298+0800 I CONTROL  [initandlisten] git version: c55eb86ef46ee7aede3b1e2a5d184a7df4bfb5b5
2018-07-11T08:55:08.298+0800 I CONTROL  [initandlisten] OpenSSL version: OpenSSL 1.0.1u-fips  22 Sep 2016
2018-07-11T08:55:08.299+0800 I CONTROL  [initandlisten] allocator: tcmalloc
2018-07-11T08:55:08.299+0800 I CONTROL  [initandlisten] modules: none
2018-07-11T08:55:08.299+0800 I CONTROL  [initandlisten] build environment:
2018-07-11T08:55:08.300+0800 I CONTROL  [initandlisten]     distmod: 2008plus-ssl
2018-07-11T08:55:08.300+0800 I CONTROL  [initandlisten]     distarch: x86_64
2018-07-11T08:55:08.300+0800 I CONTROL  [initandlisten]     target_arch: x86_64
2018-07-11T08:55:08.301+0800 I CONTROL  [initandlisten] options: { net: { port: 27027 }, repair: true, storage: { dbPath: "data" } }
2018-07-11T08:55:08.301+0800 W -        [initandlisten] Detected unclean shutdown - data\mongod.lock is not empty.
2018-07-11T08:55:08.302+0800 I -        [initandlisten] Detected data files in data created by the 'wiredTiger' storage engine, so setting the active
storage engine to 'wiredTiger'.
2018-07-11T08:55:08.303+0800 W STORAGE  [initandlisten] Recovering data from the last clean checkpoint.
2018-07-11T08:55:08.303+0800 I STORAGE  [initandlisten] Detected WT journal files.  Running recovery from last checkpoint.
2018-07-11T08:55:08.303+0800 I STORAGE  [initandlisten] journal to nojournal transition config: create,cache_size=32199M,session_max=20000,eviction=(threads_min=4,threads_max=4),config_base=false,statistics=(fast),log=(enabled=true,archive=true,path=journal,compressor=snappy),file_manager=(close_idle_time=100000),checkpoint=(wait=60,log_size=2GB),statistics_log=(wait=0),
2018-07-11T08:55:08.459+0800 E STORAGE  [initandlisten] WiredTiger error (0) [1531270508:459147][3588:1991524064], file:collection-6-3553168189418485199.wt, txn-recover: read checksum error for 4096B block at offset 1486589952: block header checksum of 808464432 doesn't match expected checksum of 17210113082018-07-11T08:55:08.460+0800 E STORAGE  [initandlisten] WiredTiger error (0) [1531270508:460147][3588:1991524064], file:collection-6-3553168189418485199.wt, txn-recover: collection-6-3553168189418485199.wt: encountered an illegal file format or internal value 2018-07-11T08:55:08.461+0800 E STORAGE  [initandlisten] WiredTiger error (-31804) [1531270508:461148][3588:1991524064], file:collection-6-3553168189418485199.wt, txn-recover: the process must exit and restart: WT_PANIC: WiredTiger library panic 
2018-07-11T08:55:08.461+0800 I -        [initandlisten] Fatal Assertion 28558 at src\mongo\db\storage\wiredtiger\wiredtiger_util.cpp 361
2018-07-11T08:55:08.462+0800 I -        [initandlisten]***aborting after fassert() failure
2018-07-11T08:55:08.605+0800 I CONTROL  [initandlisten] mongod.exe    ...\src\mongo\util\stacktrace_windows.cpp(239)                     mongo::printStackTrace+0x43
2018-07-11T08:55:08.606+0800 I CONTROL  [initandlisten] mongod.exe    ...\src\mongo\util\signal_handlers_synchronous.cpp(180)            mongo::`anonymous namespace'::printSignalAndBacktrace+0x74
2018-07-11T08:55:08.606+0800 I CONTROL  [initandlisten] mongod.exe    ...\src\mongo\util\signal_handlers_synchronous.cpp(236)            mongo::`anonymous namespace'::abruptQuit+0x85
2018-07-11T08:55:08.607+0800 I CONTROL  [initandlisten] ucrtbase.DLL                                                                     raise+0x1e8
2018-07-11T08:55:08.607+0800 I CONTROL  [initandlisten] ucrtbase.DLL                                                                     abort+0x31
2018-07-11T08:55:08.609+0800 I CONTROL  [initandlisten] mongod.exe    ...\src\mongo\util\assert_util.cpp(172)                            mongo::fasser tFailedWithLocation+0x181
2018-07-11T08:55:08.610+0800 I CONTROL  [initandlisten] mongod.exe    ...\src\mongo\db\storage\wiredtiger\wiredtiger_util.cpp(361)       mongo::`anony mous namespace'::mdb_handle_error+0x205
2018-07-11T08:55:08.611+0800 I CONTROL  [initandlisten] mongod.exe    ...\src\third_party\wiredtiger\src\support\err.c(275)              __wt_eventv+0 x376
2018-07-11T08:55:08.611+0800 I CONTROL  [initandlisten] mongod.exe    ...\src\third_party\wiredtiger\src\support\err.c(317)              __wt_err+0x32 
2018-07-11T08:55:08.612+0800 I CONTROL  [initandlisten] mongod.exe    ...\src\third_party\wiredtiger\src\support\err.c(530)              __wt_illegal_value+0x5e
2018-07-11T08:55:08.612+0800 I CONTROL  [initandlisten] mongod.exe    ...\src\third_party\wiredtiger\src\block\block_read.c(225)         __wt_block_read_off+0x1c2
2018-07-11T08:55:08.613+0800 I CONTROL  [initandlisten] mongod.exe    ...\src\third_party\wiredtiger\src\block\block_ext.c(1178)         __wt_block_extlist_read+0x85
2018-07-11T08:55:08.614+0800 I CONTROL  [initandlisten] mongod.exe    ...\src\third_party\wiredtiger\src\block\block_ext.c(1141)         __wt_block_extlist_read_avail+0x24
2018-07-11T08:55:08.614+0800 I CONTROL  [initandlisten] mongod.exe    ...\src\third_party\wiredtiger\src\block\block_ckpt.c(128)         __wt_block_checkpoint_load+0x1b1
2018-07-11T08:55:08.615+0800 I CONTROL  [initandlisten] mongod.exe    ...\src\third_party\wiredtiger\src\block\block_mgr.c(97)           __bm_checkpoint_load+0x51
2018-07-11T08:55:08.616+0800 I CONTROL  [initandlisten] mongod.exe    ...\src\third_party\wiredtiger\src\btree\bt_handle.c(153)          __wt_btree_open+0x201
2018-07-11T08:55:08.616+0800 I CONTROL  [initandlisten] mongod.exe    ...\src\third_party\wiredtiger\src\conn\conn_dhandle.c(352)        __wt_conn_btree_open+0x93
2018-07-11T08:55:08.617+0800 I CONTROL  [initandlisten] mongod.exe    ...\src\third_party\wiredtiger\src\session\session_dhandle.c(542)  __wt_session_get_btree+0x113
2018-07-11T08:55:08.617+0800 I CONTROL  [initandlisten] mongod.exe    ...\src\third_party\wiredtiger\src\session\session_dhandle.c(534)  __wt_session_get_btree+0x1d5
2018-07-11T08:55:08.618+0800 I CONTROL  [initandlisten] mongod.exe    ...\src\third_party\wiredtiger\src\session\session_dhandle.c(347)  __wt_session_get_btree_ckpt+0xc4
2018-07-11T08:55:08.619+0800 I CONTROL  [initandlisten] mongod.exe    ...\src\third_party\wiredtiger\src\cursor\cur_file.c(567)          __wt_curfile_open+0x1dd
2018-07-11T08:55:08.619+0800 I CONTROL  [initandlisten] mongod.exe    ...\src\third_party\wiredtiger\src\session\session_api.c(388)      __session_open_cursor_int+0x2f7
2018-07-11T08:55:08.620+0800 I CONTROL  [initandlisten] mongod.exe    ...\src\third_party\wiredtiger\src\session\session_api.c(443)      __wt_open_cursor+0x1b
2018-07-11T08:55:08.621+0800 I CONTROL  [initandlisten] mongod.exe    ...\src\third_party\wiredtiger\src\txn\txn_recover.c(73)           __recovery_cursor+0xd2
2018-07-11T08:55:08.621+0800 I CONTROL  [initandlisten] mongod.exe    ...\src\third_party\wiredtiger\src\txn\txn_recover.c(175)          __txn_op_apply+0x38e
2018-07-11T08:55:08.622+0800 I CONTROL  [initandlisten] mongod.exe    ...\src\third_party\wiredtiger\src\txn\txn_recover.c(295)          __txn_log_recover+0xb8
2018-07-11T08:55:08.622+0800 I CONTROL  [initandlisten] mongod.exe    ...\src\third_party\wiredtiger\src\log\log.c(1862)                 __wt_log_scan+0x74f
2018-07-11T08:55:08.623+0800 I CONTROL  [initandlisten] mongod.exe    ...\src\third_party\wiredtiger\src\txn\txn_recover.c(543)          __wt_txn_recover+0x2d4
2018-07-11T08:55:08.624+0800 I CONTROL  [initandlisten] mongod.exe    ...\src\third_party\wiredtiger\src\conn\conn_open.c(240)           __wt_connection_workers+0x30
2018-07-11T08:55:08.624+0800 I CONTROL  [initandlisten] mongod.exe    ...\src\third_party\wiredtiger\src\conn\conn_api.c(2457)           wiredtiger_open+0xb1b
2018-07-11T08:55:08.625+0800 I CONTROL  [initandlisten] mongod.exe    ...\src\mongo\db\storage\wiredtiger\wiredtiger_kv_engine.cpp(249)  mongo::WiredTigerKVEngine::WiredTigerKVEngine+0x7d2
2018-07-11T08:55:08.625+0800 I CONTROL  [initandlisten] mongod.exe    ...\src\mongo\db\storage\wiredtiger\wiredtiger_init.cpp(91)        mongo::`anonymous namespace'::WiredTigerFactory::create+0x12f
2018-07-11T08:55:08.626+0800 I CONTROL  [initandlisten] mongod.exe    ...\src\mongo\db\service_context_d.cpp(202)                        mongo::ServiceContextMongoD::initializeGlobalStorageEngine+0x59c
2018-07-11T08:55:08.627+0800 I CONTROL  [initandlisten] mongod.exe    ...\src\mongo\db\db.cpp(599)                                       mongo::`anonymous namespace'::_initAndListen+0x77b
2018-07-11T08:55:08.627+0800 I CONTROL  [initandlisten] mongod.exe    ...\src\mongo\db\db.cpp(841)                                       mongo::`anonymous namespace'::initAndListen+0x27
2018-07-11T08:55:08.628+0800 I CONTROL  [initandlisten] mongod.exe    ...\src\mongo\db\db.cpp(1191)                                      mongoDbMain+0x227
2018-07-11T08:55:08.628+0800 I CONTROL  [initandlisten] mongod.exe    ...\src\mongo\db\db.cpp(879)                                       wmain+0x35 
2018-07-11T08:55:08.629+0800 I CONTROL  [initandlisten] mongod.exe    f:\dd\vctools\crt\vcstartup\src\startup\exe_common.inl(253)        __scrt_common_main_seh+0x11d
2018-07-11T08:55:08.629+0800 I CONTROL  [initandlisten] kernel32.dll                                                                     BaseThreadInitThunk+0xd
2018-07-11T08:55:08.630+0800 F -        [initandlisten] Got signal: 22 (SIGABRT).
2018-07-11T08:55:08.631+0800 I CONTROL  [initandlisten] *** unhandled exception 0x0000000E at 0x000007FEFCB29E5D, terminating
2018-07-11T08:55:08.631+0800 I CONTROL  [initandlisten] *** stack trace for unhandled exception:
2018-07-11T08:55:08.669+0800 I CONTROL  [initandlisten] KERNELBASE.dll                                                                     RaiseException+0x3d
2018-07-11T08:55:08.669+0800 I CONTROL  [initandlisten] mongod.exe      ...\src\mongo\util\signal_handlers_synchronous.cpp(237)            mongo::`anonymous namespace'::abruptQuit+0x9d
2018-07-11T08:55:08.670+0800 I CONTROL  [initandlisten] ucrtbase.DLL                                                                       raise+0x1e8
2018-07-11T08:55:08.671+0800 I CONTROL  [initandlisten] ucrtbase.DLL                                                                       abort+0x31
2018-07-11T08:55:08.671+0800 I CONTROL  [initandlisten] mongod.exe      ...\src\mongo\util\assert_util.cpp(172)                            mongo::fassertFailedWithLocation+0x181
2018-07-11T08:55:08.672+0800 I CONTROL  [initandlisten] mongod.exe      ...\src\mongo\db\storage\wiredtiger\wiredtiger_util.cpp(361)       mongo::`anonymous namespace'::mdb_handle_error+0x205
2018-07-11T08:55:08.672+0800 I CONTROL  [initandlisten] mongod.exe      ...\src\third_party\wiredtiger\src\support\err.c(275)              __wt_eventv+0x376
2018-07-11T08:55:08.673+0800 I CONTROL  [initandlisten] mongod.exe      ...\src\third_party\wiredtiger\src\support\err.c(317)              __wt_err+0x32
2018-07-11T08:55:08.674+0800 I CONTROL  [initandlisten] mongod.exe      ...\src\third_party\wiredtiger\src\support\err.c(530)              __wt_illegal_value+0x5e
2018-07-11T08:55:08.674+0800 I CONTROL  [initandlisten] mongod.exe      ...\src\third_party\wiredtiger\src\block\block_read.c(225)         __wt_block_read_off+0x1c2
2018-07-11T08:55:08.675+0800 I CONTROL  [initandlisten] mongod.exe      ...\src\third_party\wiredtiger\src\block\block_ext.c(1178)         __wt_block_extlist_read+0x85
2018-07-11T08:55:08.675+0800 I CONTROL  [initandlisten] mongod.exe      ...\src\third_party\wiredtiger\src\block\block_ext.c(1141)         __wt_block_extlist_read_avail+0x24
2018-07-11T08:55:08.676+0800 I CONTROL  [initandlisten] mongod.exe      ...\src\third_party\wiredtiger\src\block\block_ckpt.c(128)         __wt_block_checkpoint_load+0x1b1
2018-07-11T08:55:08.677+0800 I CONTROL  [initandlisten] mongod.exe      ...\src\third_party\wiredtiger\src\block\block_mgr.c(97)           __bm_checkpoint_load+0x51
2018-07-11T08:55:08.677+0800 I CONTROL  [initandlisten] mongod.exe      ...\src\third_party\wiredtiger\src\btree\bt_handle.c(153)          __wt_btree_open+0x201
2018-07-11T08:55:08.678+0800 I CONTROL  [initandlisten] mongod.exe      ...\src\third_party\wiredtiger\src\conn\conn_dhandle.c(352)        __wt_conn_btree_open+0x93
2018-07-11T08:55:08.678+0800 I CONTROL  [initandlisten] mongod.exe      ...\src\third_party\wiredtiger\src\session\session_dhandle.c(542)  __wt_session_get_btree+0x113
2018-07-11T08:55:08.679+0800 I CONTROL  [initandlisten] mongod.exe      ...\src\third_party\wiredtiger\src\session\session_dhandle.c(534)  __wt_session_get_btree+0x1d5
2018-07-11T08:55:08.680+0800 I CONTROL  [initandlisten] mongod.exe      ...\src\third_party\wiredtiger\src\session\session_dhandle.c(347)  __wt_session_get_btree_ckpt+0xc4
2018-07-11T08:55:08.680+0800 I CONTROL  [initandlisten] mongod.exe      ...\src\third_party\wiredtiger\src\cursor\cur_file.c(567)          __wt_curfile_open+0x1dd
2018-07-11T08:55:08.681+0800 I CONTROL  [initandlisten] mongod.exe      ...\src\third_party\wiredtiger\src\session\session_api.c(388)      __session_open_cursor_int+0x2f7
2018-07-11T08:55:08.682+0800 I CONTROL  [initandlisten] mongod.exe      ...\src\third_party\wiredtiger\src\session\session_api.c(443)      __wt_open_cursor+0x1b
2018-07-11T08:55:08.682+0800 I CONTROL  [initandlisten] mongod.exe      ...\src\third_party\wiredtiger\src\txn\txn_recover.c(73)           __recovery_cursor+0xd2
2018-07-11T08:55:08.683+0800 I CONTROL  [initandlisten] mongod.exe      ...\src\third_party\wiredtiger\src\txn\txn_recover.c(175)          __txn_op_apply+0x38e
2018-07-11T08:55:08.683+0800 I CONTROL  [initandlisten] mongod.exe      ...\src\third_party\wiredtiger\src\txn\txn_recover.c(295)          __txn_log_recover+0xb8
2018-07-11T08:55:08.684+0800 I CONTROL  [initandlisten] mongod.exe      ...\src\third_party\wiredtiger\src\log\log.c(1862)                 __wt_log_scan+0x74f
2018-07-11T08:55:08.685+0800 I CONTROL  [initandlisten] mongod.exe      ...\src\third_party\wiredtiger\src\txn\txn_recover.c(543)          __wt_txn_recover+0x2d4
2018-07-11T08:55:08.685+0800 I CONTROL  [initandlisten] mongod.exe      ...\src\third_party\wiredtiger\src\conn\conn_open.c(240)           __wt_connection_workers+0x30
2018-07-11T08:55:08.686+0800 I CONTROL  [initandlisten] mongod.exe      ...\src\third_party\wiredtiger\src\conn\conn_api.c(2457)           wiredtiger_open+0xb1b
2018-07-11T08:55:08.686+0800 I CONTROL  [initandlisten] mongod.exe      ...\src\mongo\db\storage\wiredtiger\wiredtiger_kv_engine.cpp(249)  mongo::WiredTigerKVEngine::WiredTigerKVEngine+0x7d2
2018-07-11T08:55:08.687+0800 I CONTROL  [initandlisten] mongod.exe      ...\src\mongo\db\storage\wiredtiger\wiredtiger_init.cpp(91)        mongo::`anonymous namespace'::WiredTigerFactory::create+0x12f
2018-07-11T08:55:08.688+0800 I CONTROL  [initandlisten] mongod.exe      ...\src\mongo\db\service_context_d.cpp(202)                        mongo::ServiceContextMongoD::initializeGlobalStorageEngine+0x59c
2018-07-11T08:55:08.688+0800 I CONTROL  [initandlisten] mongod.exe      ...\src\mongo\db\db.cpp(599)                                       mongo::`anonymous namespace'::_initAndListen+0x77b
2018-07-11T08:55:08.689+0800 I CONTROL  [initandlisten] mongod.exe      ...\src\mongo\db\db.cpp(841)                                       mongo::`anonymous namespace'::initAndListen+0x27
2018-07-11T08:55:08.689+0800 I CONTROL  [initandlisten] mongod.exe      ...\src\mongo\db\db.cpp(1191)                                      mongoDbMain+0x227
2018-07-11T08:55:08.690+0800 I CONTROL  [initandlisten] mongod.exe      ...\src\mongo\db\db.cpp(879)                                       wmain+0x35
2018-07-11T08:55:08.690+0800 I CONTROL  [initandlisten] mongod.exe      f:\dd\vctools\crt\vcstartup\src\startup\exe_common.inl(253)        __scrt_common_main_seh+0x11d
2018-07-11T08:55:08.700+0800 I CONTROL  [initandlisten] kernel32.dll                                                                       BaseThreadInitThunk+0xd
2018-07-11T08:55:08.700+0800 I -        [initandlisten]
2018-07-11T08:55:08.701+0800 I CONTROL  [initandlisten] writing minidump diagnostic file E:\servers\mongodb\bin\mongod.2018-07-11T00-55-08.mdmp
2018-07-11T08:55:08.767+0800 I CONTROL  [initandlisten] *** immediate exit due to unhandled exception

 

Comment by Nick Brewer [ 10/Jul/18 ]

Hi,

I've attached the files after a repair attempt. Would you please extract these files, substitute them for the current ones in your $dbpath, and let us know if it resolves the issue?

Thanks,

Nick

repair-attempt.tar.gz

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