[SERVER-9550] Starting server during shutdown flush causes crash Created: 03/May/13  Updated: 24/Jan/15  Resolved: 23/Jan/15

Status: Closed
Project: Core Server
Component/s: Stability
Affects Version/s: 2.2.4, 2.4.3
Fix Version/s: None

Type: Bug Priority: Major - P3
Reporter: Pierre Dane Assignee: Victor Hooi
Resolution: Incomplete Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

Windows 2008 R2


Operating System: ALL
Participants:

 Description   

after shutting down mongod with db.shutdownServer(), if one tries to start up the server again before the flush has completed and the lock file removed, the shutdown does not complete cleanly, and the data is corrupted.



 Comments   
Comment by Ramon Fernandez Marina [ 27/Jun/14 ]

pierrearmageddon, we haven't heard back from you for a while. Are you still experiencing this issue? If the answer is yes, can you please provide the additional information requested by victor.hooi above so we can try to reproduce it on our end?

Thanks,
Ramón.

Comment by Victor Hooi [ 19/Mar/14 ]

pierrearmageddon My apologies that we haven't followed this up earlier.

I'm currently trying to reproduce this error and need some additional information.

Firstly, can I confirm if you have seen this error at all since the initial report? And if so, on what versions of MongoDB please?

Second, you mentioned database corruption - are you able to provide any more details on what sort of corruption was exhibited (e.g. missing documents, missing fields, log files, or was the database completely unreadable?)

Thanks,
Victor

Comment by Pierre Dane [ 16/May/13 ]

Nope - we aren't running with journal as we don't have a spare bay on this particular server for a separate journal disk, and using the same SSD caused massive performance impact.
Logs:

Thu May 16 10:21:39 dbexit: shutdown called
Thu May 16 10:21:39 [conn7818180] shutdown: going to close listening sockets...
Thu May 16 10:21:39 [conn7818180] closing listening socket: 560
Thu May 16 10:21:39 [conn7818180] closing listening socket: 596
Thu May 16 10:21:39 [conn7818180] shutdown: going to flush diaglog...
Thu May 16 10:21:39 [conn7818180] shutdown: going to close sockets...
Thu May 16 10:21:39 [conn7818180] shutdown: waiting for fs preallocator...
Thu May 16 10:21:39 [conn7818180] shutdown: closing all files...
Thu May 16 10:21:39 [conn9299340] got request after shutdown()
Thu May 16 10:21:39 [conn9299958] got request after shutdown()
Thu May 16 10:21:39 [conn9299474] got request after shutdown()
Thu May 16 10:21:39 [conn9299476] got request after shutdown()
Thu May 16 10:21:39 [conn9300023] got request after shutdown()
Thu May 16 10:21:39 [conn9299649] got request after shutdown()
Thu May 16 10:21:39 [conn9300077] got request after shutdown()
Thu May 16 10:21:39 [conn9300076] got request after shutdown()
Thu May 16 10:21:39 [conn9299965] got request after shutdown()
Thu May 16 10:21:39 [conn9299591] got request after shutdown()
Thu May 16 10:21:39 [conn9300021] got request after shutdown()
Thu May 16 10:21:39 [conn9299395] got request after shutdown()
Thu May 16 10:21:39 [conn9299652] got request after shutdown()
Thu May 16 10:21:39 [conn9299971] got request after shutdown()
Thu May 16 10:21:39 [conn9299903] got request after shutdown()
Thu May 16 10:21:39 [conn9299644] got request after shutdown()
Thu May 16 10:21:39 [conn9299202] got request after shutdown()
Thu May 16 10:21:39 [conn9299641] got request after shutdown()
Thu May 16 10:21:39 [conn9299964] got request after shutdown()
Thu May 16 10:21:40 [conn9299401] got request after shutdown()
Thu May 16 10:21:40 [conn9300083] got request after shutdown()
Thu May 16 10:21:40 [conn9299329] got request after shutdown()
Thu May 16 10:21:40 [conn9299459] got request after shutdown()
Thu May 16 10:21:40 [conn9299463] got request after shutdown()
Thu May 16 10:21:40 [conn9299466] got request after shutdown()
Thu May 16 10:21:40 [conn9299890] got request after shutdown()
Thu May 16 10:21:40 [conn9299301] got request after shutdown()
Thu May 16 10:21:40 [conn9299248] got request after shutdown()
Thu May 16 10:21:40 [conn9299904] got request after shutdown()
Thu May 16 10:21:40 [conn9299802] got request after shutdown()
Thu May 16 10:21:40 [conn9299305] got request after shutdown()
Thu May 16 10:21:40 [conn9299468] got request after shutdown()
Thu May 16 10:21:40 [conn9299472] got request after shutdown()
Thu May 16 10:21:41 [conn9299871] got request after shutdown()
Thu May 16 10:21:41 [conn7818180] 11/199 5%
Thu May 16 10:21:43 [conn7818180] 25/199 12%

          • SERVER RESTARTED *****

Thu May 16 10:21:57 [initandlisten] MongoDB starting : pid=5220 port=3006 dbpath=F:\data\attributestore 64-bit host=mongo80
Thu May 16 10:21:57 [initandlisten] db version v2.2.4, pdfile version 4.5
Thu May 16 10:21:57 [initandlisten] git version: a2880030d3cec10c850c6850efa7a51b628b8822
Thu May 16 10:21:57 [initandlisten] build info: windows sys.getwindowsversion(major=6, minor=1, build=7601, platform=2, service_pack='Service Pack 1') BOOST_LIB_VERSION=1_49
Thu May 16 10:21:57 [initandlisten] options:

{ dbpath: "F:\data\attributestore", logappend: true, logpath: "f:\logs\attributestore.txt", nojournal: true, oplogSize: 50000, port: 3006, quiet: true, replSet: "attributestore" }

Thu May 16 10:21:57 [initandlisten] exception in initAndListen: 13627 Unable to create/open lock file: F:\data\attributestore\mongod.lock The process cannot access the file because it is being used by another process.. Is a mongod instance already running?, terminating
Thu May 16 10:21:57 dbexit:
Thu May 16 10:21:57 [initandlisten] shutdown: going to close listening sockets...
Thu May 16 10:21:57 [initandlisten] shutdown: going to flush diaglog...
Thu May 16 10:21:57 [initandlisten] shutdown: going to close sockets...
Thu May 16 10:21:57 [initandlisten] shutdown: waiting for fs preallocator...
Thu May 16 10:21:57 [initandlisten] shutdown: closing all files...
Thu May 16 10:21:57 [initandlisten] closeAllFiles() finished
Thu May 16 10:21:57 dbexit: really exiting now
Thu May 16 10:22:09 [conn7818180] 26/199 13%

          • SERVER RESTARTED *****
Comment by Scott Hernandez (Inactive) [ 03/May/13 ]

Are you not running with journaling (which is on by default)?

Can you supply the full logs please?

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