mongodbが起動しない場合の対応（old lock file, terminating） - "Diary" インターネットさんへの恩返し

Mongodbへ接続が失敗する現象があったので解決方法をメモ。ハングなどでmongodbを強制終了した場合、mongod.lockファイルというものせいで、mongodbが起動できなくなる事象。mongodbは起動の際にmongod.lockファイルを作成し、停止する際にmongod.lockファイルを削除する仕組みだそうな。

なのでハングのため、mongod.lockが残った場合は、mongod.lockを直接消して、その後--repairオプションでmongodを実行し解消する。

[事象] node.jsでmongodbへの接続が失敗する

node xxx.jsでnode.jsを起動しようとすると「Error: failed to connect」となる。

vagrant@precise32:/vagrant/chat$ node app.js
server starting...
Error connected: mongodb://localhost/chat - Error: failed to connect to [localhost:27017]

直接mongodbを起動してみる。一見起動したように見える。

vagrant@precise32:/vagrant$ sudo service mongod start
mongod start/running, process 1168

しかし、mongoで接続しようとすると以下の様なメッセージが出る。「Error: couldn't connect to server」

vagrant@precise32:/vagrant$ mongo
MongoDB shell version: 2.6.0
connecting to: test
2014-04-18T02:35:46.646+0000 warning: Failed to connect to 127.0.0.1:27017, reason: errno:111 Connection refused
2014-04-18T02:35:46.647+0000 Error: couldn't connect to server 127.0.0.1:27017 (127.0.0.1), connection attempt failed at src/mongo/shell/mongo.js:146
exception: connect failed

mongodサービスが上がっているか確認。上がっていない。

vagrant@precise32:/vagrant$ ps -ef | grep mongod
vagrant   1178   988  0 02:36 pts/0    00:00:00 grep --color=auto mongod

ログ確認。「exception in initAndListen: 12596 old lock file, terminating」の表記が問題。

vagrant@precise32:/vagrant$ tail -n 20 /var/log/mongodb/mongod.log
2014-04-18T02:35:10.857+0000 [initandlisten]
2014-04-18T02:35:10.857+0000 [initandlisten] ** NOTE: This is a 32 bit MongoDB binary.
2014-04-18T02:35:10.857+0000 [initandlisten] **       32 bit builds are limited to less than 2GB of data (or less with --journal).
2014-04-18T02:35:10.857+0000 [initandlisten] **       Note that journaling defaults to off for 32 bit and is currently off.
2014-04-18T02:35:10.858+0000 [initandlisten] **       See http://dochub.mongodb.org/core/32bit
2014-04-18T02:35:10.858+0000 [initandlisten]
2014-04-18T02:35:10.858+0000 [initandlisten] db version v2.6.0
2014-04-18T02:35:10.858+0000 [initandlisten] git version: 1c1c76aeca21c5983dc178920f5052c298db616c
2014-04-18T02:35:10.858+0000 [initandlisten] build info: Linux ip-10-114-47-109 2.6.18-194.32.1.el5xen #1 SMP Mon Dec 20 11:08:09 EST 2010 i686 BOOST_LIB_VERSION=1_49
2014-04-18T02:35:10.858+0000 [initandlisten] allocator: system
2014-04-18T02:35:10.858+0000 [initandlisten] options: { config: "/etc/mongod.conf", net: { bindIp: "127.0.0.1" }, storage: { dbPath: "/var/lib/mongodb" }, systemLog: { destination: "file", logAppend: true, path: "/var/log/mongodb/mongod.log" } }
2014-04-18T02:35:10.858+0000 [initandlisten] exception in initAndListen: 12596 old lock file, terminating
2014-04-18T02:35:10.858+0000 [initandlisten] dbexit:
2014-04-18T02:35:10.858+0000 [initandlisten] shutdown: going to close listening sockets...
2014-04-18T02:35:10.858+0000 [initandlisten] shutdown: going to flush diaglog...
2014-04-18T02:35:10.858+0000 [initandlisten] shutdown: going to close sockets...
2014-04-18T02:35:10.858+0000 [initandlisten] shutdown: waiting for fs preallocator...
2014-04-18T02:35:10.858+0000 [initandlisten] shutdown: closing all files...
2014-04-18T02:35:10.858+0000 [initandlisten] closeAllFiles() finished
2014-04-18T02:35:10.858+0000 [initandlisten] dbexit: really exiting now

解決法

まず、mongod.lockファイルを削除。

vagrant@precise32:/var/lib/mongodb$ ls -atrl
total 327728
drwxr-xr-x 36 root    root        4096 Apr 15 02:18 ..
-rwxr-xr-x  1 mongodb nogroup        4 Apr 17 01:50 mongod.lock
-rw-------  1 mongodb nogroup 16777216 Apr 17 01:50 local.ns
-rw-------  1 mongodb nogroup 67108864 Apr 17 01:50 local.0
-rw-------  1 mongodb nogroup 16777216 Apr 17 03:14 user.ns
-rw-------  1 mongodb nogroup 67108864 Apr 17 03:14 user.0
drwxr-xr-x  2 mongodb nogroup     4096 Apr 17 03:21 _tmp
drwxr-xr-x  3 mongodb mongodb     4096 Apr 17 03:21 .
-rw-------  1 mongodb nogroup 16777216 Apr 17 10:16 chat.ns
-rw-------  1 mongodb nogroup 67108864 Apr 17 10:16 chat.0
-rw-------  1 mongodb nogroup 16777216 Apr 17 10:20 session.ns
-rw-------  1 mongodb nogroup 67108864 Apr 17 10:20 session.0
vagrant@precise32:/var/lib/mongodb$ ^C
vagrant@precise32:/var/lib/mongodb$ sudo rm -f mongod.lock
vagrant@precise32:/var/lib/mongodb$

「mongod --repair」コマンドを実行。

vagrant@precise32:/var/lib/mongodb$ sudo mongod --repair
2014-04-18T02:52:33.588+0000
2014-04-18T02:52:33.588+0000 warning: 32-bit servers don't have journaling enabled by default. Please use --journal if you want durability.
2014-04-18T02:52:33.589+0000
2014-04-18T02:52:33.592+0000 [initandlisten] MongoDB starting : pid=1193 port=27017 dbpath=/data/db 32-bit host=precise32
2014-04-18T02:52:33.593+0000 [initandlisten]
2014-04-18T02:52:33.593+0000 [initandlisten] ** NOTE: This is a 32 bit MongoDB binary.
2014-04-18T02:52:33.593+0000 [initandlisten] **       32 bit builds are limited to less than 2GB of data (or less with --journal).
2014-04-18T02:52:33.593+0000 [initandlisten] **       Note that journaling defaults to off for 32 bit and is currently off.
2014-04-18T02:52:33.594+0000 [initandlisten] **       See http://dochub.mongodb.org/core/32bit
2014-04-18T02:52:33.594+0000 [initandlisten]
2014-04-18T02:52:33.594+0000 [initandlisten] db version v2.6.0
2014-04-18T02:52:33.594+0000 [initandlisten] git version: 1c1c76aeca21c5983dc178920f5052c298db616c
2014-04-18T02:52:33.595+0000 [initandlisten] build info: Linux ip-10-114-47-109 2.6.18-194.32.1.el5xen #1 SMP Mon Dec 20 11:08:09 EST 2010 i686 BOOST_LIB_VERSION=1_49
2014-04-18T02:52:33.595+0000 [initandlisten] allocator: system
2014-04-18T02:52:33.595+0000 [initandlisten] options: { repair: true }
2014-04-18T02:52:33.605+0000 [initandlisten] repairDatabase local
2014-04-18T02:52:33.606+0000 [FileAllocator] allocating new datafile /data/db/_tmp_repairDatabase_0/local.ns, filling with zeroes...
2014-04-18T02:52:33.606+0000 [FileAllocator] creating directory /data/db/_tmp_repairDatabase_0/_tmp
2014-04-18T02:52:33.607+0000 [FileAllocator] done allocating datafile /data/db/_tmp_repairDatabase_0/local.ns, size: 16MB,  took 0 secs
2014-04-18T02:52:33.643+0000 [FileAllocator] allocating new datafile /data/db/_tmp_repairDatabase_0/local.0, filling with zeroes...
2014-04-18T02:52:33.644+0000 [FileAllocator] done allocating datafile /data/db/_tmp_repairDatabase_0/local.0, size: 64MB,  took 0 secs
2014-04-18T02:52:33.672+0000 [initandlisten] finished checking dbs
2014-04-18T02:52:33.673+0000 [initandlisten] dbexit:
2014-04-18T02:52:33.673+0000 [initandlisten] shutdown: going to close listening sockets...
2014-04-18T02:52:33.673+0000 [initandlisten] shutdown: going to flush diaglog...
2014-04-18T02:52:33.674+0000 [initandlisten] shutdown: going to close sockets...
2014-04-18T02:52:33.674+0000 [initandlisten] shutdown: waiting for fs preallocator...
2014-04-18T02:52:33.674+0000 [initandlisten] shutdown: closing all files...
2014-04-18T02:52:33.675+0000 [initandlisten] closeAllFiles() finished
2014-04-18T02:52:33.675+0000 [initandlisten] shutdown: removing fs lock...
2014-04-18T02:52:33.675+0000 [initandlisten] dbexit: really exiting now

mongodb起動確認。

vagrant@precise32:/var/lib/mongodb$ sudo service mongod start
mongod start/running, process 1206
vagrant@precise32:/var/lib/mongodb$ tail -n 30 /var/log/mongodb/mongod.log
2014-04-18T02:48:23.683+0000 [initandlisten] **       See http://dochub.mongodb.org/core/32bit
2014-04-18T02:48:23.683+0000 [initandlisten]
2014-04-18T02:48:23.683+0000 [initandlisten] db version v2.6.0
2014-04-18T02:48:23.683+0000 [initandlisten] git version: 1c1c76aeca21c5983dc178920f5052c298db616c
2014-04-18T02:48:23.683+0000 [initandlisten] build info: Linux ip-10-114-47-109 2.6.18-194.32.1.el5xen #1 SMP Mon Dec 20 11:08:09 EST 2010 i686 BOOST_LIB_VERSION=1_49
2014-04-18T02:48:23.683+0000 [initandlisten] allocator: system
2014-04-18T02:48:23.683+0000 [initandlisten] options: { config: "/etc/mongod.conf", net: { bindIp: "127.0.0.1" }, storage: { dbPath: "/var/lib/mongodb" }, systemLog: { destination: "file", logAppend: true, path: "/var/log/mongodb/mongod.log" } }
2014-04-18T02:48:23.683+0000 [initandlisten] exception in initAndListen: 12596 old lock file, terminating
2014-04-18T02:48:23.683+0000 [initandlisten] dbexit:
2014-04-18T02:48:23.683+0000 [initandlisten] shutdown: going to close listening sockets...
2014-04-18T02:48:23.683+0000 [initandlisten] shutdown: going to flush diaglog...
2014-04-18T02:48:23.683+0000 [initandlisten] shutdown: going to close sockets...
2014-04-18T02:48:23.683+0000 [initandlisten] shutdown: waiting for fs preallocator...
2014-04-18T02:48:23.683+0000 [initandlisten] shutdown: closing all files...
2014-04-18T02:48:23.683+0000 [initandlisten] closeAllFiles() finished
2014-04-18T02:48:23.683+0000 [initandlisten] dbexit: really exiting now
2014-04-18T02:52:55.232+0000 ***** SERVER RESTARTED *****
2014-04-18T02:52:55.237+0000 [initandlisten] MongoDB starting : pid=1206 port=27017 dbpath=/var/lib/mongodb 32-bit host=precise32
2014-04-18T02:52:55.237+0000 [initandlisten]
2014-04-18T02:52:55.237+0000 [initandlisten] ** NOTE: This is a 32 bit MongoDB binary.
2014-04-18T02:52:55.237+0000 [initandlisten] **       32 bit builds are limited to less than 2GB of data (or less with --journal).
2014-04-18T02:52:55.237+0000 [initandlisten] **       Note that journaling defaults to off for 32 bit and is currently off.
2014-04-18T02:52:55.237+0000 [initandlisten] **       See http://dochub.mongodb.org/core/32bit
2014-04-18T02:52:55.237+0000 [initandlisten]
2014-04-18T02:52:55.237+0000 [initandlisten] db version v2.6.0
2014-04-18T02:52:55.237+0000 [initandlisten] git version: 1c1c76aeca21c5983dc178920f5052c298db616c
2014-04-18T02:52:55.237+0000 [initandlisten] build info: Linux ip-10-114-47-109 2.6.18-194.32.1.el5xen #1 SMP Mon Dec 20 11:08:09 EST 2010 i686 BOOST_LIB_VERSION=1_49
2014-04-18T02:52:55.237+0000 [initandlisten] allocator: system
2014-04-18T02:52:55.237+0000 [initandlisten] options: { config: "/etc/mongod.conf", net: { bindIp: "127.0.0.1" }, storage: { dbPath: "/var/lib/mongodb" }, systemLog: { destination: "file", logAppend: true, path: "/var/log/mongodb/mongod.log" } }
2014-04-18T02:52:55.402+0000 [initandlisten] waiting for connections on port 27017
vagrant@precise32:/var/lib/mongodb$

接続確認。

vagrant@precise32:/var/lib/mongodb$ mongo
MongoDB shell version: 2.6.0
connecting to: test
Server has startup warnings:
2014-04-18T02:52:55.237+0000 [initandlisten]
2014-04-18T02:52:55.237+0000 [initandlisten] ** NOTE: This is a 32 bit MongoDB binary.
2014-04-18T02:52:55.237+0000 [initandlisten] **       32 bit builds are limited to less than 2GB of data (or less with --journal).
2014-04-18T02:52:55.237+0000 [initandlisten] **       Note that journaling defaults to off for 32 bit and is currently off.
2014-04-18T02:52:55.237+0000 [initandlisten] **       See http://dochub.mongodb.org/core/32bit
2014-04-18T02:52:55.237+0000 [initandlisten]
>

NOSQLの基礎知識 (ビッグデータを活かすデータベース技術)

作者: 本橋信也,河野達也,鶴見利章,太田洋
出版社/メーカー: リックテレコム
発売日: 2012/04/25
メディア: 単行本（ソフトカバー）
購入: 7人クリック: 81回
この商品を含むブログ (7件) を見る