Mongod起動不可

2023.04.22

ansibleで組んでいた自動構成スクリプトでサーバを新規構築したところ、Laravel からマイグレーションしようとしたらコケました。

vagrant@SERVER-NG:~$ ./artisan migrate:fresh --seed
(snip)
   MongoDB\Driver\Exception\ConnectionTimeoutException

  No suitable servers found (`serverSelectionTryOnce` set): [connection refused calling hello on '127.0.0.1:27017']

環境

  • 母艦：Windows11 22H2 + VirtualBox 7.0.8 + Vagrant 2.3.4
  • 仮想マシン：AlmaLinux release 8.7

このサーバではDBストレージとして MariaDB 以外に MongoDB も動かしています。コケているのは MongoDB にコレクションを作ろうとしている箇所です。

vagrant@SERVER-NG:~$ systemctl status mongod
● mongod.service - MongoDB Database Server
   Loaded: loaded (/usr/lib/systemd/system/mongod.service; enabled; vendor preset: disabled)
   Active: failed (Result: exit-code) since Sat 2023-04-22 07:15:46 JST; 29min ago
     Docs: https://docs.mongodb.org/manual
  Process: 4781 ExecStart=/usr/bin/mongod $OPTIONS (code=exited, status=1/FAILURE)
 Main PID: 4781 (code=exited, status=1/FAILURE)

サービス起動に失敗しています。これまではちゃんと動いていたのに…。

過去に動いていたサーバと、バージョンを比べてみます。当該記事では、問題がある方のホスト名を SERVER-NG, 動く方を SERVER-OK で記述しています。

動いている方）

vagrant@SERVER-OK:~$ rpm -qa | grep mongo | sort
libmongocrypt-1.6.2-1.el8.x86_64
mongo-c-driver-libs-1.23.1-1.el8.x86_64
mongodb-database-tools-100.6.1-1.x86_64
mongodb-org-4.4.18-1.el8.x86_64
mongodb-org-database-tools-extra-4.4.18-1.el8.x86_64
mongodb-org-mongos-4.4.18-1.el8.x86_64
mongodb-org-server-4.4.18-1.el8.x86_64
mongodb-org-shell-4.4.18-1.el8.x86_64
mongodb-org-tools-4.4.18-1.el8.x86_64
php-pecl-mongodb-1.15.1-1.el8.remi.7.4.x86_64
python3-pymongo-3.7.0-1.module_el8.5.0+2569+5c5719bc.x86_64

動かない方）

vagrant@SERVER-NG:~$ rpm -qa | grep mongo | sort
libmongocrypt-1.6.2-1.el8.x86_64
mongo-c-driver-libs-1.23.3-1.el8.x86_64
mongodb-database-tools-100.7.0-1.x86_64
mongodb-org-4.4.20-1.el8.x86_64
mongodb-org-database-tools-extra-4.4.20-1.el8.x86_64
mongodb-org-mongos-4.4.20-1.el8.x86_64
mongodb-org-server-4.4.20-1.el8.x86_64
mongodb-org-shell-4.4.20-1.el8.x86_64
mongodb-org-tools-4.4.20-1.el8.x86_64
php-pecl-mongodb-1.15.1-1.el8.remi.7.4.x86_64
python3-pymongo-3.7.0-1.module_el8.5.0+2569+5c5719bc.x86_64

若干バージョン（パッチレベル）が上がったものの、大差ないように見えます。

コケている直接の原因を調査します。

vagrant@SERVER-NG:~$ sudo tail -1 /var/log/mongodb/mongod.log
{"t":{"$date":"2023-04-22T07:15:46.265+09:00"},"s":"I",  "c":"CONTROL",  "id":23330,   "ctx":"main","msg":"ERROR: Cannot write pid file to {path_string}: {errAndStr_second}","attr":{"path_string":"/var/run/mongodb/mongod.pid","errAndStr_second":"No such file or directory"}}

/var/run/mongodb/mongod.pid を作れないと言っています。

vagrant@SERVER-NG:~$ ls -l /var/run/mongodb/mongod.pid
ls: cannot access '/var/run/mongodb/mongod.pid': そのようなファイルやディレクトリはありません
vagrant@SERVER-NG:~$ ls -ld /var/run/mongodb/
ls: cannot access '/var/run/mongodb/': そのようなファイルやディレクトリはありません

あれ？ディレクトリ自体作られていない？

vagrant@SERVER-NG:~$ ls -ld /var/run
lrwxrwxrwx. 1 root root 6  3月 29 11:45 /var/run -> ../run

RedHat 系の AlmaLinux では、/var/run は /run へのシンボリックリンクとなっているようです。

動いている方で、このファイルの作成者（パッケージ名）を調べてみます。

vagrant@SERVER-OK:~$ rpm -qf /var/run/mongodb/mongod.pid
file /var/run/mongodb/mongod.pid is not owned by any package
vagrant@SERVER-OK:~$ rpm -qf /var/run/mongodb
mongodb-org-server-4.4.18-1.el8.x86_64
vagrant@SERVER-OK:~$ rpm -ql mongodb-org-server | grep run
/run/mongodb

mongodb-org-server を入れれば自動的に作られるようです。一方、動かない方はというと？

vagrant@SERVER-NG:~$ rpm -ql mongodb-org-server | grep run
/run/mongodb

パッケージ構成としては変わっていないように見えます。

まずは再現テスト。パッケージを手作業で再インストールしてみます。

vagrant@SERVER-NG:~$ sudo dnf reinstall -y mongodb-org-server
(snip)
Reinstalled:
  mongodb-org-server-4.4.20-1.el8.x86_64

Complete!
vagrant@SERVER-NG:~$  ls -l /run/mongodb
total 4
-rw-r--r-- 1 mongod mongod 5  4月 22 07:59 mongod.pid

あら？できてる？

vagrant@SERVER-NG:~$  sudo systemctl start mongod
vagrant@SERVER-NG:~$  sudo systemctl status mongod
● mongod.service - MongoDB Database Server
   Loaded: loaded (/usr/lib/systemd/system/mongod.service; enabled; vendor pres>
   Active: active (running) since Sat 2023-04-22 07:59:25 JST; 1min 37s ago

当然動きますね。困った。。。インストール後に誰かが消しているのかしら？

以下、蛇足

（今回は動けばいいというものではなく、インストール用の ansible playbook のメンテナンスの一環なので、手作業なしで一発で動いてくれなくては困るのです。）

これでは不安なので、ansible を流し直す前に撮っていた vagrant のスナップショットに戻して再現テストをします。

PS C:\Users\hotta\vm\brms> vagrant snapshot list SERVER-NG
==> SERVER-NG:
base
PS C:\Users\hotta\vm\brms> vagrant snapshot restore SERVER-NG base

（この後、紆余曲折あり）

Command: ["hostonlyif", "ipconfig", "VirtualBox Host-Only Ethernet Adapter #24", "--ip", "192.168.56.1", "--netmask", "255.255.255.0"]

Stderr: VBoxManage.exe: error: The host network interface named 'VirtualBox Host-Only Ethernet Adapter #24' could not be found
VBoxManage.exe: error: Details: code E_INVALIDARG (0x80070057), component HostWrap, interface IHost, callee IUnknown
VBoxManage.exe: error: Context: "FindHostNetworkInterfaceByName(Bstr(pszName).raw(), hif.asOutParam())" at line 242 of file VBoxManageHostonly.cpp

このような謎エラーの深みにハマって、やむなく仮想マシンを消して作り直すことになってしまいました。その後、同一の手順で環境を作ったところ、/run/mongod も正しく作られていました。

今回は、途中で vagrant 側で “Read Only File System” 的なエラーが出ていたので、下位レイヤーに起因する障害であり、アプリケーションやミドルウェア的には問題なかったのであろうということにしました。

なお、この記事を書くために途中で VirtualBox-7.0.8 に上げたところ、Windows 側に数十個あったはずの Host-Only NetWork アダプターが全部消えてしまって、再度作られなくなったというトラブルにも見舞われました。これは結局 Windows 母艦をリブートしたら、何事もなく動きました。今までは VirtualBox のアップデート時はリブートはいらなかった気がしたので盲点でした。

結論：レイヤーが深くなると、トラブルシュートが難しくなりますね。

タイトルとURLをコピーしました