[SERVER-16975] UnsupportedFormat fatal assertion in wiredTiger following Created: 21/Jan/15  Updated: 21/Jan/15  Resolved: 21/Jan/15

Status: Closed
Project: Core Server
Component/s: Storage, WiredTiger
Affects Version/s: 2.8.0-rc5
Fix Version/s: None

Type: Bug Priority: Major - P3
Reporter: Chad Kreimendahl Assignee: Ramon Fernandez Marina
Resolution: Duplicate Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Issue Links:
Duplicate
duplicates SERVER-16632 Change WiredTiger index key format to... Closed
Operating System: ALL
Participants:

 Description   

Following an unclean service shutdown, upon resume of the server, a fatal assertion is thrown (28579): Fatal assertion 28579 UnsupportedFormat Application metadata for table:SomeDatabase/index/3192--6589984641143232768 has unsupported format version 1

2015-01-19T09:49:29.220-0600 I CONTROL  Trying to start Windows service 'MongoDB'
2015-01-19T09:49:29.223-0600 I STORAGE  Service running
2015-01-19T09:49:29.224-0600 I CONTROL  [initandlisten] MongoDB starting : pid=10432 port=27017 dbpath=C:\MongoDB\data\wiredTiger 64-bit host=pre-web01
2015-01-19T09:49:29.224-0600 I CONTROL  [initandlisten] targetMinOS: Windows 7/Windows Server 2008 R2
2015-01-19T09:49:29.224-0600 I CONTROL  [initandlisten] db version v2.8.0-rc5
2015-01-19T09:49:29.225-0600 I CONTROL  [initandlisten] git version: 74b351de21c84438b12a83b28e155f5e69e3c1eb
2015-01-19T09:49:29.225-0600 I CONTROL  [initandlisten] build info: windows sys.getwindowsversion(major=6, minor=1, build=7601, platform=2, service_pack='Service Pack 1') BOOST_LIB_VERSION=1_49
2015-01-19T09:49:29.226-0600 I CONTROL  [initandlisten] allocator: system
2015-01-19T09:49:29.226-0600 I CONTROL  [initandlisten] options: { config: "C:\MongoDB\mongo28.yaml", net: { http: { enabled: true }, maxIncomingConnections: 4096, port: 27017 }, operationProfiling: { mode: "slowOp", slowOpThresholdMs: 50 }, replication: { oplogSizeMB: 8 }, security: { authorization: "disabled" }, service: true, storage: { dbPath: "C:\MongoDB\data\wiredTiger", directoryPerDB: true, engine: "wiredTiger", journal: { enabled: true }, wiredTiger: { collectionConfig: { blockCompressor: "snappy" }, engineConfig: { cacheSizeGB: 4, directoryForIndexes: true, journalCompressor: "snappy", statisticsLogDelaySecs: 600 }, indexConfig: { prefixCompression: true } } }, systemLog: { destination: "file", logAppend: false, path: "C:\MongoDB\log\mongodb2.log", verbosity: 0 } }
2015-01-19T09:49:29.227-0600 W -        [initandlisten] Detected unclean shutdown - C:\MongoDB\data\wiredTiger\mongod.lock is not empty.
2015-01-19T09:49:29.228-0600 W STORAGE  [initandlisten] Recovering data from the last clean checkpoint.
2015-01-19T09:49:29.228-0600 I STORAGE  [initandlisten] wiredtiger_open config: create,cache_size=4G,session_max=20000,eviction=(threads_max=4),statistics=(fast),log=(enabled=true,archive=true,path=journal,compressor=snappy),checkpoint=(wait=60,log_size=2GB),statistics_log=(wait=600),
2015-01-19T09:49:34.306-0600 I -        [initandlisten] Fatal assertion 28579 UnsupportedFormat Application metadata for table:SomeDatabase/index/3192--6589984641143232768 has unsupported format version 1
2015-01-19T09:49:34.306-0600 I -        [initandlisten] 
 
***aborting after fassert() failure
 
 
 

Shutdown Failure log:

2015-01-16T13:29:56.390-0600 I CONTROL  [serviceShutdown] got SERVICE_CONTROL_STOP request from Windows Service Control Manager, will terminate after current cmd ends
2015-01-16T13:29:56.395-0600 I COMMAND  [serviceShutdown] now exiting
2015-01-16T13:29:56.396-0600 I NETWORK  [serviceShutdown] shutdown: going to close listening sockets...
2015-01-16T13:29:56.396-0600 I NETWORK  [serviceShutdown] closing listening socket: 312
2015-01-16T13:29:56.396-0600 I NETWORK  [serviceShutdown] closing listening socket: 9120
2015-01-16T13:29:56.396-0600 I NETWORK  [serviceShutdown] shutdown: going to flush diaglog...
2015-01-16T13:29:56.396-0600 I NETWORK  [serviceShutdown] shutdown: going to close sockets...
2015-01-16T13:29:56.397-0600 I NETWORK  [conn24] end connection 127.0.0.1:1481 (7 connections now open)
2015-01-16T13:29:56.398-0600 I NETWORK  [conn33] end connection 127.0.0.1:1571 (7 connections now open)
2015-01-16T13:29:56.398-0600 I NETWORK  [conn32] end connection 127.0.0.1:1561 (7 connections now open)
2015-01-16T13:29:56.399-0600 I NETWORK  [conn36] end connection 127.0.0.1:1634 (7 connections now open)
2015-01-16T13:29:56.400-0600 I NETWORK  [conn37] end connection 127.0.0.1:1650 (7 connections now open)
2015-01-16T13:29:56.401-0600 I NETWORK  [conn35] end connection 127.0.0.1:1633 (7 connections now open)
2015-01-16T13:29:56.402-0600 I NETWORK  [conn34] end connection 127.0.0.1:1632 (7 connections now open)
2015-01-16T13:29:56.403-0600 I NETWORK  [conn31] end connection 127.0.0.1:1545 (7 connections now open)
2015-01-16T13:29:56.404-0600 I STORAGE  [serviceShutdown] WiredTigerKVEngine shutting down
2015-01-16T13:29:57.025-0600 I COMMAND  [serviceShutdown] dbexit:  rc: 49
2015-01-16T13:29:57.025-0600 I -        [serviceShutdown] Invariant failure _requests.empty() src\mongo\db\concurrency\lock_state.cpp 144
2015-01-16T13:30:06.427-0600 I CONTROL  [serviceShutdown] mongod.exe    ...\src\mongo\util\stacktrace_win.cpp(175)        mongo::printStackTrace+0x43
2015-01-16T13:30:06.427-0600 I CONTROL  [serviceShutdown] mongod.exe    ...\src\mongo\util\log.cpp(136)                   mongo::logContext+0x8f
2015-01-16T13:30:06.427-0600 I CONTROL  [serviceShutdown] mongod.exe    ...\src\mongo\util\assert_util.cpp(146)           mongo::invariantFailed+0xfb
2015-01-16T13:30:06.427-0600 I CONTROL  [serviceShutdown] mongod.exe    ...\src\mongo\db\concurrency\lock_state.cpp(144)  mongo::LockerImpl<0>::assertEmpty+0x79
2015-01-16T13:30:06.427-0600 I CONTROL  [serviceShutdown] mongod.exe    ...\src\mongo\db\concurrency\lock_state.cpp(225)  mongo::LockerImpl<0>::~LockerImpl<0>+0x2a
2015-01-16T13:30:06.427-0600 I CONTROL  [serviceShutdown] mongod.exe    ...\src\mongo\db\instance.cpp(1141)               mongo::exitCleanly+0x15a
2015-01-16T13:30:06.427-0600 I CONTROL  [serviceShutdown] mongod.exe    ...\src\mongo\util\ntservice.cpp(552)             mongo::ntservice::serviceShutdown+0xe6
2015-01-16T13:30:06.427-0600 I CONTROL  [serviceShutdown] sechost.dll                                                     CredProfileUnloaded+0xaa8
2015-01-16T13:30:06.428-0600 I CONTROL  [serviceShutdown] sechost.dll                                                     StartServiceCtrlDispatcherW+0x59
2015-01-16T13:30:06.428-0600 I CONTROL  [serviceShutdown] mongod.exe    ...\src\mongo\util\ntservice.cpp(575)             mongo::ntservice::startService+0xf0
2015-01-16T13:30:06.428-0600 I CONTROL  [serviceShutdown] mongod.exe    ...\src\mongo\db\db.cpp(864)                      mongoDbMain+0x1ed
2015-01-16T13:30:06.428-0600 I CONTROL  [serviceShutdown] mongod.exe    ...\src\mongo\db\db.cpp(669)                      wmain+0x35
2015-01-16T13:30:06.428-0600 I CONTROL  [serviceShutdown] mongod.exe    f:\dd\vctools\crt\crtw32\startup\crt0.c(255)      __tmainCRTStartup+0x144
2015-01-16T13:30:06.428-0600 I CONTROL  [serviceShutdown] KERNEL32.DLL                                                    BaseThreadInitThunk+0x22
2015-01-16T13:30:06.428-0600 I CONTROL  [serviceShutdown] 
2015-01-16T13:30:06.428-0600 I -        [serviceShutdown] 
 
***aborting after invariant() failure
 



 Comments   
Comment by Ramon Fernandez Marina [ 21/Jan/15 ]

Thanks for letting us know sallgeud, glad to hear the repair operation worked. Closing this ticket as a duplicate of SERVER-16632.

Comment by Chad Kreimendahl [ 21/Jan/15 ]

I know that I was running a pre-release version of rc5 (from a nightly build) for some other issues, and that the startup error in question is from rc5. The repair seems to have fixed the issue.

Comment by Kaloian Manassiev [ 21/Jan/15 ]

FYI - the shutdown assertion (second invariant above) has been fixed as part of SERVER-16600 and will be available in RC6.

Comment by Ramon Fernandez Marina [ 21/Jan/15 ]

sallgeud, are you sure this data was created with 2.8.0-rc5? Note that there was a change in index format from 2.8.0-rc4 and 2.8.0-rc5 (SERVER-16632), so users with indexes created in versions previous to 2.8.0-rc4 need to run:

mongod --storageEngine wiredTiger --repair

Can you please check (or upload) the full logs so we can verify whether this index format change was the source of the error you're seeing?

Thanks,
Ramón.

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