[SERVER-3162] old lock file error even when using journaling Created: 27/May/11  Updated: 04/Jun/13  Resolved: 19/Aug/11

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

Type: Bug Priority: Major - P3
Reporter: pablo platt Assignee: Mathias Stearn
Resolution: Done Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

ubuntu 11.04 64bit running as a vbox guest


Operating System: Linux
Participants:

 Description   

Mongodb can't start and I'm getting the old lock file error in the log although journaling is enabled
and the log says it cleaned the journal files when it receive the machine shut down signal.

journaling is enabled by adding the following to /etc/mongodb.conf:
journal = true

This is the log file:

Fri May 27 09:49:13 got kill or ctrl c or hup signal 15 (Terminated), will terminate after current cmd ends
Fri May 27 09:49:13 [interruptThread] now exiting
Fri May 27 09:49:13 dbexit:
Fri May 27 09:49:13 [interruptThread] shutdown: going to close listening sockets...
Fri May 27 09:49:13 [interruptThread] closing listening socket: 6
Fri May 27 09:49:13 [interruptThread] closing listening socket: 7
Fri May 27 09:49:13 [interruptThread] closing listening socket: 8
Fri May 27 09:49:13 [interruptThread] closing listening socket: 9
Fri May 27 09:49:13 [interruptThread] removing socket file: /tmp/mongodb-27017.sock
Fri May 27 09:49:13 [interruptThread] removing socket file: /tmp/mongodb-28017.sock
Fri May 27 09:49:13 [interruptThread] shutdown: going to flush diaglog...
Fri May 27 09:49:13 [interruptThread] shutdown: going to close sockets...
Fri May 27 09:49:14 [interruptThread] shutdown: waiting for fs preallocator...
Fri May 27 09:49:14 [interruptThread] shutdown: lock for final commit...
Fri May 27 09:49:14 [interruptThread] shutdown: final commit...
Fri May 27 09:49:14 [interruptThread] shutdown: closing all files...
Fri May 27 09:49:14 closeAllFiles() finished
Fri May 27 09:49:14 [interruptThread] shutdown: journalCleanup...
Fri May 27 09:49:14 [interruptThread] removeJournalFiles
Fri May 27 11:03:26 [initandlisten] MongoDB starting : pid=668 port=27017 dbpath=/var/lib/mongodb 64-bit
Fri May 27 11:03:26 [initandlisten] db version v1.8.1, pdfile version 4.5
Fri May 27 11:03:26 [initandlisten] git version: a429cd4f535b2499cc4130b06ff7c26f41c00f04
Fri May 27 11:03:26 [initandlisten] build sys info: Linux bs-linux64.10gen.cc 2.6.21.7-2.ec2.v1.2.fc8xen #1 SMP Fri Nov 20 17:48:28 EST 2009 x86_64 BOOST_LIB_VERSION=1_41
**************
old lock file: /var/lib/mongodb/mongod.lock. probably means unclean shutdown,
but there are no journal files to recover.
this is likely human error or filesystem corruption.
found 4 dbs.
see: http://dochub.mongodb.org/core/repair for more information
*************
Fri May 27 11:03:26 [initandlisten] exception in initAndListen std::exception: old lock file, terminating
Fri May 27 11:03:26 dbexit:
Fri May 27 11:03:26 [initandlisten] shutdown: going to close listening sockets...
Fri May 27 11:03:26 [initandlisten] shutdown: going to flush diaglog...
Fri May 27 11:03:26 [initandlisten] shutdown: going to close sockets...
Fri May 27 11:03:26 [initandlisten] shutdown: waiting for fs preallocator...
Fri May 27 11:03:26 [initandlisten] shutdown: lock for final commit...
Fri May 27 11:03:26 [initandlisten] shutdown: final commit...
Fri May 27 11:03:26 [initandlisten] shutdown: closing all files...
Fri May 27 11:03:26 closeAllFiles() finished
Fri May 27 11:03:26 [initandlisten] shutdown: journalCleanup...
Fri May 27 11:03:26 dbexit: really exiting now



 Comments   
Comment by Paul Joey Clark [ 04/Jun/13 ]

FWIW I am getting this with mongodb-server 1:2.0.6-1ubuntu4 on Ubuntu 12.10 running on a 32bit laptop.

I had run 'halt' to shutdown the machine, but a few minutes later I saw shutdown had still not completed. Then I had to leave, and when I returned the machine had died due to loss of power.

Tue Jun 4 18:33:36 [interruptThread] shutdown: final commit...
Tue Jun 4 18:33:37 [interruptThread] shutdown: closing all files...
Tue Jun 4 18:33:37 [interruptThread] closeAllFiles() finished
Tue Jun 4 18:33:37 [interruptThread] journalCleanup...
Tue Jun 4 18:33:37 [interruptThread] removeJournalFiles

          • SERVER RESTARTED *****
            Tue Jun 4 22:29:23 [initandlisten] MongoDB starting : pid=1206 port=27017 dbpath=/var/lib/mongodb 32-bit host=porridge
            Tue Jun 4 22:29:23 [initandlisten]$
            Tue Jun 4 22:29:23 [initandlisten] ** NOTE: when using MongoDB 32 bit, you are limited to about 2 gigabytes of data
            Tue Jun 4 22:29:23 [initandlisten] ** see http://blog.mongodb.org/post/137788967/32-bit-limitations
            Tue Jun 4 22:29:23 [initandlisten] ** with --journal, the limit is lower
            Tue Jun 4 22:29:23 [initandlisten]$
            Tue Jun 4 22:29:23 [initandlisten] db version v2.0.6, pdfile version 4.5

I have:
journal=true
in my mongodb.conf

Not too concerned about this happening on my dev machine, but I really want to make sure it doesn't happen on live!

Comment by Mathias Stearn [ 19/Aug/11 ]

The solution is to use the new --shutdown flag in init scripts for 2.0.

I don't think we will be backporting to 1.8.x

Comment by Mathias Stearn [ 21/Jun/11 ]

I'm actually working on that now: https://jira.mongodb.org/browse/SERVER-3307. There should be a fix for this in master today.

Comment by pablo platt [ 21/Jun/11 ]

"For a long term fix, I'd suggest modifying your init scripts to block on shutdown until the mongod successfully exits."
I'm just using your ubuntu package.
What about a server power failure?

I'm not the only one seeing this problem:
http://groups.google.com/group/fameisfame/browse_thread/thread/304c44ad2b6f9a95/857805ebe960b265?lnk=raot&pli=1

That's a serious issue. If there is a power failure mongodb might not start.
I don't understand how you and Scott dismiss this issue instead of giving it high priority.

Comment by Mathias Stearn [ 21/Jun/11 ]

typically the last two lines in the log file after "removeJournalFiles" look like this:

Tue Jun 21 11:16:35 [interruptThread] shutdown: removing fs lock...
Tue Jun 21 11:16:35 dbexit: really exiting now

The fact that you don't have those implies that the mongod was killed before it got a chance to remove the lock file. It looks like you rebooted the server and mongod got the TERM signal, but your shutdown process didn't wait for it to finish before sending the KILL signal. Judging by where it failed it should be safe to just remove the lock file and continue (if you haven't already). For a long term fix, I'd suggest modifying your init scripts to block on shutdown until the mongod successfully exits.

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