[SERVER-67095] Failure at Mongo Service Start --- WiredTiger.wt, WT_CURSOR.insert: WiredTiger.wt: encountered an illegal file format or internal value Created: 07/Jun/22  Updated: 20/Jul/22  Resolved: 20/Jul/22

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

Type: Bug Priority: Major - P3
Reporter: Devin Liu Assignee: Chris Kelly
Resolution: Done Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

Win10


Attachments: Zip Archive wired_tiger_files.zip    
Operating System: ALL
Participants:

 Description   

Hi All,
The mongo service fails to start after a power blackout. 
I found a few suggestion while searching for solution but non of them worked.
From the mongo.log, it appears that the problem is related to WiredTiger.wt and content within it.

A thread led me to here and ask for help.

How should I fix this?

Thanks!!!

 

2022-05-30T09:34:55.316+0800 I CONTROL  [initandlisten] MongoDB starting : pid=6056 port=27017 dbpath=M:\db 64-bit host=MicroWin10-1451
2022-05-30T09:34:55.317+0800 I CONTROL  [initandlisten] targetMinOS: Windows 7/Windows Server 2008 R2
2022-05-30T09:34:55.317+0800 I CONTROL  [initandlisten] db version v3.4.6
2022-05-30T09:34:55.317+0800 I CONTROL  [initandlisten] git version: c55eb86ef46ee7aede3b1e2a5d184a7df4bfb5b5
2022-05-30T09:34:55.317+0800 I CONTROL  [initandlisten] OpenSSL version: OpenSSL 1.0.1u-fips  22 Sep 2016
2022-05-30T09:34:55.317+0800 I CONTROL  [initandlisten] allocator: tcmalloc
2022-05-30T09:34:55.317+0800 I CONTROL  [initandlisten] modules: none
2022-05-30T09:34:55.317+0800 I CONTROL  [initandlisten] build environment:
2022-05-30T09:34:55.318+0800 I CONTROL  [initandlisten]     distmod: 2008plus-ssl
2022-05-30T09:34:55.318+0800 I CONTROL  [initandlisten]     distarch: x86_64
2022-05-30T09:34:55.318+0800 I CONTROL  [initandlisten]     target_arch: x86_64
2022-05-30T09:34:55.318+0800 I CONTROL  [initandlisten] options: { repair: true, storage: { dbPath: "M:\db" }, systemLog: { destination: "file", path: "M:\log\mongodb.log" } }
2022-05-30T09:34:55.319+0800 I -        [initandlisten] Detected data files in M:\db created by the 'wiredTiger' storage engine, so setting the active storage engine to 'wiredTiger'.
2022-05-30T09:34:55.319+0800 I STORAGE  [initandlisten] Detected WT journal files.  Running recovery from last checkpoint.
2022-05-30T09:34:55.319+0800 I STORAGE  [initandlisten] journal to nojournal transition config: create,cache_size=7679M,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),
2022-05-30T09:34:55.331+0800 E STORAGE  [initandlisten] WiredTiger error (0) [1653874495:331384][6056:140736224777552], file:WiredTiger.wt, WT_CURSOR.insert: read checksum error for 4096B block at offset 3686400: block header checksum of 2411337233 doesn't match expected checksum of 3176084715
2022-05-30T09:34:55.331+0800 E STORAGE  [initandlisten] WiredTiger error (0) [1653874495:331384][6056:140736224777552], file:WiredTiger.wt, WT_CURSOR.insert: WiredTiger.wt: encountered an illegal file format or internal value
2022-05-30T09:34:55.331+0800 E STORAGE  [initandlisten] WiredTiger error (-31804) [1653874495:331384][6056:140736224777552], file:WiredTiger.wt, WT_CURSOR.insert: the process must exit and restart: WT_PANIC: WiredTiger library panic
2022-05-30T09:34:55.331+0800 I -        [initandlisten] Fatal Assertion 28558 at src\mongo\db\storage\wiredtiger\wiredtiger_util.cpp 361
2022-05-30T09:34:55.331+0800 I -        [initandlisten] ***aborting after fassert() failure
2022-05-30T09:34:55.489+0800 I CONTROL  [initandlisten] mongod.exe    ...\src\mongo\util\stacktrace_windows.cpp(239)                     mongo::printStackTrace+0x43
2022-05-30T09:34:55.489+0800 I CONTROL  [initandlisten] mongod.exe    ...\src\mongo\util\signal_handlers_synchronous.cpp(180)            mongo::`anonymous namespace'::printSignalAndBacktrace+0x74
2022-05-30T09:34:55.489+0800 I CONTROL  [initandlisten] mongod.exe    ...\src\mongo\util\signal_handlers_synchronous.cpp(236)            mongo::`anonymous namespace'::abruptQuit+0x85
2022-05-30T09:34:55.489+0800 I CONTROL  [initandlisten] ucrtbase.dll                                                                     raise+0x1e1
2022-05-30T09:34:55.489+0800 I CONTROL  [initandlisten] ucrtbase.dll                                                                     abort+0x31
2022-05-30T09:34:55.489+0800 I CONTROL  [initandlisten] mongod.exe    ...\src\mongo\util\assert_util.cpp(172)                            mongo::fassertFailedWithLocation+0x181
2022-05-30T09:34:55.489+0800 I CONTROL  [initandlisten] mongod.exe    ...\src\mongo\db\storage\wiredtiger\wiredtiger_util.cpp(361)       mongo::`anonymous namespace'::mdb_handle_error+0x205
2022-05-30T09:34:55.489+0800 I CONTROL  [initandlisten] mongod.exe    ...\src\third_party\wiredtiger\src\support\err.c(275)              __wt_eventv+0x376
2022-05-30T09:34:55.489+0800 I CONTROL  [initandlisten] mongod.exe    ...\src\third_party\wiredtiger\src\support\err.c(317)              __wt_err+0x32
2022-05-30T09:34:55.489+0800 I CONTROL  [initandlisten] mongod.exe    ...\src\third_party\wiredtiger\src\support\err.c(530)              __wt_illegal_value+0x5e
2022-05-30T09:34:55.489+0800 I CONTROL  [initandlisten] mongod.exe    ...\src\third_party\wiredtiger\src\block\block_read.c(225)         __wt_block_read_off+0x1c2
2022-05-30T09:34:55.489+0800 I CONTROL  [initandlisten] mongod.exe    ...\src\third_party\wiredtiger\src\block\block_read.c(101)         __wt_bm_read+0x10b
2022-05-30T09:34:55.489+0800 I CONTROL  [initandlisten] mongod.exe    ...\src\third_party\wiredtiger\src\btree\bt_io.c(40)               __wt_bt_read+0x7b
2022-05-30T09:34:55.489+0800 I CONTROL  [initandlisten] mongod.exe    ...\src\third_party\wiredtiger\src\btree\bt_read.c(415)            __page_read+0x141
2022-05-30T09:34:55.489+0800 I CONTROL  [initandlisten] mongod.exe    ...\src\third_party\wiredtiger\src\btree\bt_read.c(525)            __wt_page_in_func+0x173
2022-05-30T09:34:55.489+0800 I CONTROL  [initandlisten] mongod.exe    ...\src\third_party\wiredtiger\src\include\btree.i(1464)           __wt_page_swap_func+0x3e
2022-05-30T09:34:55.489+0800 I CONTROL  [initandlisten] mongod.exe    ...\src\third_party\wiredtiger\src\btree\row_srch.c(446)           __wt_row_search+0x49e
2022-05-30T09:34:55.489+0800 I CONTROL  [initandlisten] mongod.exe    ...\src\third_party\wiredtiger\src\btree\bt_cursor.c(706)          __wt_btcur_insert+0x491
2022-05-30T09:34:55.489+0800 I CONTROL  [initandlisten] mongod.exe    ...\src\third_party\wiredtiger\src\cursor\cur_file.c(244)          __curfile_insert+0x161
2022-05-30T09:34:55.489+0800 I CONTROL  [initandlisten] mongod.exe    ...\src\third_party\wiredtiger\src\txn\txn_recover.c(178)          __txn_op_apply+0x40c
2022-05-30T09:34:55.489+0800 I CONTROL  [initandlisten] mongod.exe    ...\src\third_party\wiredtiger\src\txn\txn_recover.c(295)          __txn_log_recover+0xb8
2022-05-30T09:34:55.489+0800 I CONTROL  [initandlisten] mongod.exe    ...\src\third_party\wiredtiger\src\log\log.c(1862)                 __wt_log_scan+0x74f
2022-05-30T09:34:55.489+0800 I CONTROL  [initandlisten] mongod.exe    ...\src\third_party\wiredtiger\src\txn\txn_recover.c(481)          __wt_txn_recover+0x1af
2022-05-30T09:34:55.489+0800 I CONTROL  [initandlisten] mongod.exe    ...\src\third_party\wiredtiger\src\conn\conn_open.c(240)           __wt_connection_workers+0x30
2022-05-30T09:34:55.489+0800 I CONTROL  [initandlisten] mongod.exe    ...\src\third_party\wiredtiger\src\conn\conn_api.c(2457)           wiredtiger_open+0xb1b
2022-05-30T09:34:55.489+0800 I CONTROL  [initandlisten] mongod.exe    ...\src\mongo\db\storage\wiredtiger\wiredtiger_kv_engine.cpp(249)  mongo::WiredTigerKVEngine::WiredTigerKVEngine+0x7d2
2022-05-30T09:34:55.489+0800 I CONTROL  [initandlisten] mongod.exe    ...\src\mongo\db\storage\wiredtiger\wiredtiger_init.cpp(91)        mongo::`anonymous namespace'::WiredTigerFactory::create+0x12f
2022-05-30T09:34:55.490+0800 I CONTROL  [initandlisten] mongod.exe    ...\src\mongo\db\service_context_d.cpp(202)                        mongo::ServiceContextMongoD::initializeGlobalStorageEngine+0x59c
2022-05-30T09:34:55.490+0800 I CONTROL  [initandlisten] mongod.exe    ...\src\mongo\db\db.cpp(599)                                       mongo::`anonymous namespace'::_initAndListen+0x77b
2022-05-30T09:34:55.490+0800 I CONTROL  [initandlisten] mongod.exe    ...\src\mongo\db\db.cpp(841)                                       mongo::`anonymous namespace'::initAndListen+0x27
2022-05-30T09:34:55.490+0800 I CONTROL  [initandlisten] mongod.exe    ...\src\mongo\db\db.cpp(1191)                                      mongoDbMain+0x227
2022-05-30T09:34:55.490+0800 I CONTROL  [initandlisten] mongod.exe    ...\src\mongo\db\db.cpp(879)                                       wmain+0x35
2022-05-30T09:34:55.490+0800 I CONTROL  [initandlisten] mongod.exe    f:\dd\vctools\crt\vcstartup\src\startup\exe_common.inl(253)        __scrt_common_main_seh+0x11d
2022-05-30T09:34:55.490+0800 I CONTROL  [initandlisten] KERNEL32.DLL                                                                     BaseThreadInitThunk+0x14
2022-05-30T09:34:55.490+0800 F -        [initandlisten] Got signal: 22 (SIGABRT).
2022-05-30T09:34:55.490+0800 I CONTROL  [initandlisten] *** unhandled exception 0x0000000E at 0x00007FFFB3A64F69, terminating
2022-05-30T09:34:55.490+0800 I CONTROL  [initandlisten] *** stack trace for unhandled exception:
2022-05-30T09:34:55.493+0800 I CONTROL  [initandlisten] KERNELBASE.dll                                                                     RaiseException+0x69
2022-05-30T09:34:55.493+0800 I CONTROL  [initandlisten] mongod.exe      ...\src\mongo\util\signal_handlers_synchronous.cpp(237)            mongo::`anonymous namespace'::abruptQuit+0x9d
2022-05-30T09:34:55.493+0800 I CONTROL  [initandlisten] ucrtbase.dll                                                                       raise+0x1e1
2022-05-30T09:34:55.493+0800 I CONTROL  [initandlisten] ucrtbase.dll                                                                       abort+0x31
2022-05-30T09:34:55.493+0800 I CONTROL  [initandlisten] mongod.exe      ...\src\mongo\util\assert_util.cpp(172)                            mongo::fassertFailedWithLocation+0x181
2022-05-30T09:34:55.493+0800 I CONTROL  [initandlisten] mongod.exe      ...\src\mongo\db\storage\wiredtiger\wiredtiger_util.cpp(361)       mongo::`anonymous namespace'::mdb_handle_error+0x205
2022-05-30T09:34:55.493+0800 I CONTROL  [initandlisten] mongod.exe      ...\src\third_party\wiredtiger\src\support\err.c(275)              __wt_eventv+0x376
2022-05-30T09:34:55.493+0800 I CONTROL  [initandlisten] mongod.exe      ...\src\third_party\wiredtiger\src\support\err.c(317)              __wt_err+0x32
2022-05-30T09:34:55.493+0800 I CONTROL  [initandlisten] mongod.exe      ...\src\third_party\wiredtiger\src\support\err.c(530)              __wt_illegal_value+0x5e
2022-05-30T09:34:55.493+0800 I CONTROL  [initandlisten] mongod.exe      ...\src\third_party\wiredtiger\src\block\block_read.c(225)         __wt_block_read_off+0x1c2
2022-05-30T09:34:55.493+0800 I CONTROL  [initandlisten] mongod.exe      ...\src\third_party\wiredtiger\src\block\block_read.c(101)         __wt_bm_read+0x10b
2022-05-30T09:34:55.493+0800 I CONTROL  [initandlisten] mongod.exe      ...\src\third_party\wiredtiger\src\btree\bt_io.c(40)               __wt_bt_read+0x7b
2022-05-30T09:34:55.493+0800 I CONTROL  [initandlisten] mongod.exe      ...\src\third_party\wiredtiger\src\btree\bt_read.c(415)            __page_read+0x141
2022-05-30T09:34:55.493+0800 I CONTROL  [initandlisten] mongod.exe      ...\src\third_party\wiredtiger\src\btree\bt_read.c(525)            __wt_page_in_func+0x173
2022-05-30T09:34:55.493+0800 I CONTROL  [initandlisten] mongod.exe      ...\src\third_party\wiredtiger\src\include\btree.i(1464)           __wt_page_swap_func+0x3e
2022-05-30T09:34:55.493+0800 I CONTROL  [initandlisten] mongod.exe      ...\src\third_party\wiredtiger\src\btree\row_srch.c(446)           __wt_row_search+0x49e
2022-05-30T09:34:55.493+0800 I CONTROL  [initandlisten] mongod.exe      ...\src\third_party\wiredtiger\src\btree\bt_cursor.c(706)          __wt_btcur_insert+0x491
2022-05-30T09:34:55.494+0800 I CONTROL  [initandlisten] mongod.exe      ...\src\third_party\wiredtiger\src\cursor\cur_file.c(244)          __curfile_insert+0x161
2022-05-30T09:34:55.494+0800 I CONTROL  [initandlisten] mongod.exe      ...\src\third_party\wiredtiger\src\txn\txn_recover.c(178)          __txn_op_apply+0x40c
2022-05-30T09:34:55.494+0800 I CONTROL  [initandlisten] mongod.exe      ...\src\third_party\wiredtiger\src\txn\txn_recover.c(295)          __txn_log_recover+0xb8
2022-05-30T09:34:55.494+0800 I CONTROL  [initandlisten] mongod.exe      ...\src\third_party\wiredtiger\src\log\log.c(1862)                 __wt_log_scan+0x74f
2022-05-30T09:34:55.494+0800 I CONTROL  [initandlisten] mongod.exe      ...\src\third_party\wiredtiger\src\txn\txn_recover.c(481)          __wt_txn_recover+0x1af
2022-05-30T09:34:55.494+0800 I CONTROL  [initandlisten] mongod.exe      ...\src\third_party\wiredtiger\src\conn\conn_open.c(240)           __wt_connection_workers+0x30
2022-05-30T09:34:55.494+0800 I CONTROL  [initandlisten] mongod.exe      ...\src\third_party\wiredtiger\src\conn\conn_api.c(2457)           wiredtiger_open+0xb1b
2022-05-30T09:34:55.494+0800 I CONTROL  [initandlisten] mongod.exe      ...\src\mongo\db\storage\wiredtiger\wiredtiger_kv_engine.cpp(249)  mongo::WiredTigerKVEngine::WiredTigerKVEngine+0x7d2
2022-05-30T09:34:55.494+0800 I CONTROL  [initandlisten] mongod.exe      ...\src\mongo\db\storage\wiredtiger\wiredtiger_init.cpp(91)        mongo::`anonymous namespace'::WiredTigerFactory::create+0x12f
2022-05-30T09:34:55.494+0800 I CONTROL  [initandlisten] mongod.exe      ...\src\mongo\db\service_context_d.cpp(202)                        mongo::ServiceContextMongoD::initializeGlobalStorageEngine+0x59c
2022-05-30T09:34:55.494+0800 I CONTROL  [initandlisten] mongod.exe      ...\src\mongo\db\db.cpp(599)                                       mongo::`anonymous namespace'::_initAndListen+0x77b
2022-05-30T09:34:55.494+0800 I CONTROL  [initandlisten] mongod.exe      ...\src\mongo\db\db.cpp(841)                                       mongo::`anonymous namespace'::initAndListen+0x27
2022-05-30T09:34:55.494+0800 I CONTROL  [initandlisten] mongod.exe      ...\src\mongo\db\db.cpp(1191)                                      mongoDbMain+0x227
2022-05-30T09:34:55.494+0800 I CONTROL  [initandlisten] mongod.exe      ...\src\mongo\db\db.cpp(879)                                       wmain+0x35
2022-05-30T09:34:55.494+0800 I CONTROL  [initandlisten] mongod.exe      f:\dd\vctools\crt\vcstartup\src\startup\exe_common.inl(253)        __scrt_common_main_seh+0x11d
2022-05-30T09:34:55.494+0800 I CONTROL  [initandlisten] KERNEL32.DLL                                                                       BaseThreadInitThunk+0x14
2022-05-30T09:34:55.494+0800 I -        [initandlisten] 
2022-05-30T09:34:55.496+0800 I CONTROL  [initandlisten] writing minidump diagnostic file C:\everything\mongo\bin\mongod.2022-05-30T01-34-55.mdmp
2022-05-30T09:34:55.611+0800 I CONTROL  [initandlisten] *** immediate exit due to unhandled exception



 Comments   
Comment by Chris Kelly [ 20/Jul/22 ]

We haven’t heard back from you for some time, so I’m going to close this ticket. If this is still an issue for you, please provide additional information and we will reopen the ticket.

Christopher

Comment by Chris Kelly [ 01/Jul/22 ]

Did running --repair or resyncing fix your problem? If so, we can go ahead and close this ticket.

Comment by Chris Kelly [ 15/Jun/22 ]

Hello,

MongoDB 3.4 reached end of life in January of 2020. But we can provide limited guidance on this issue.
The ideal resolution is to perform a clean resync from an unaffected node.

You can also try mongod --repair using the latest patch of your version of MongoDB (3.4.24 in your case).

To avoid a problem like this in the future, it is our strong recommendation to:

Regards,

Christopher

Generated at Thu Feb 08 06:07:17 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.