1. はじめに
データセンター側のメンテナンスでVPSのインスタンスのお引越しを行う(行ってもらった)。IPやらなんやらは全く変わりませんとの事だったので油断していたら、案の定オレオレメールサーバに繋がらなくなる。
という訳で何か起きた時の為の切り分けの為の備忘録としてメモメモ。
因みに我が家の鯖はFreeBSDにPostfix + Dovecot + OpenLDAP + αみたいな構成デス。
2. メールを読む事が出来ない
PCからも携帯からもエラーになって繋がらない。エラーは認証エラー。つまり、問題はIMAP4側(dovecot)がアヤシイ。さらに認証エラーという事はOpenLDAPも怪しい。まずはこの観点でのチェックを行う。
2-1. SSHでサーバにつないでみる
良くやらかすドメインの更新系の話(更新忘れてて期限切れたり)は今回はサーバに繋がった後に認証エラーになる事から多分関係ない。という事で、まずはサーバその物が死んでるケース。確認のためにSSHでつないでみる。
問題無くつながる。クリア。
2-2. dovecotのデーモンが生きているか確認
% ps aux|grep dovecot
うん生きている。
こちらもクリア。
※後で考えてみると、ここでOpenLDAPの確認をしていればもう少し原因が早く分かったかも。
2-3. ログを見てみる
% tail /var/log/maillog
Apr 26 18:54:12 hoge postfix/cleanup[2872]: warning: dict_ldap_connect: Unable to bind to server ldap://ldap.example.com:389 with dn cn=Manager,dc=ldap,dc=example,dc=com: -1 (Can't contact LDAP server)
Apr 26 18:54:12 hoge postfix/cleanup[2872]: warning: ldap:/usr/local/etc/postfix/ldap/delivery.cf lookup error for "root@example.com"
Apr 26 18:54:12 hoge postfix/cleanup[2872]: warning: 8A9FE1900B: virtual_alias_maps map lookup problem for root@example.com -- message not accepted, try again later
お、ログを見るとLDAPサーバへのアクセスに失敗しているっぽい感じ。となるとOpenLDAPがアヤシイ。
2-4. OpenLDAPを確認
ここでOpenLDAPのデーモン名を思い出せず悶々とする。そう、slapdだった。どこにあるんだっけ・・・?
/usr/local/libexec/slapd
にある模様。設定ファイルは・・・
/usr/local/etc/openldap/
の下か。とりあえず
% sudo service slapd restart
・・・あれ、デーモン君動いていないみたい。
% sudo service slapd start
Starting slapd.
/usr/local/etc/rc.d/slapd: WARNING: failed to start slapd
なんの事やらわからん。こういう時は直接叩いてログを見るらしい。
% sudo /usr/local/libexec/slapd -Tt
59007378 bdb_db_open: warning - no DB_CONFIG file found in directory /var/db/openldap-data: (2).
Expect poor performance for suffix "dc=ldap,dc=example,dc=com".
59007378 bdb(dc=ldap,dc=example,dc=com): file id2entry.bdb has LSN 1/1314048, past end of log at 1/752606
59007378 bdb(dc=ldap,dc=example,dc=com): Commonly caused by moving a database from one database environment
59007378 bdb(dc=ldap,dc=example,dc=com): to another without clearing the database LSNs, or by removing all of
59007378 bdb(dc=ldap,dc=example,dc=com): the log files from a database environment
59007378 bdb(dc=ldap,dc=example,dc=com): /var/db/openldap-data/id2entry.bdb: unexpected file type or format
59007378 bdb_db_open: database "dc=ldap,dc=example,dc=com": db_open(/var/db/openldap-data/id2entry.bdb) failed: Invalid argument (22).
59007378 backend_startup_one (type=bdb, suffix="dc=ldap,dc=example,dc=com"): bi_db_open failed! (22)
slap_startup failed (test would succeed using the -u switch)
おやー・・・なんかDBファイル壊れてる??ちょっと血の気が引く。ググってみるとなにやら修復方法が書かれていた。試しにやってみよう。
参考
http://www.iredmail.org/forum/topic3694-iredmail-support-power-cut-ldap-dont-start.html
2-5. id2entry.bdbの修復
2-5-1. とりあえずバックアップをとって・・・
% sudo cp /var/db/openldap-data/id2entry.bdb .
% sudo chown myname id2entry.bdb
2-5-2. 中身をdumpします
% db41_dump id2entry.bdb > id2entry.bdb.dump
このdb41_dumpの41の部分は恐らくOpenLDAPのバックエンドに使っているBerkeley DBのバージョン依存なので適宜読み替えて下さい。
2-5-3. 元ファイルをリネームして、再構成
% mv id2entry.bdb id2entry.bdb.bak
% db41_load id2entry.bdb < id2entry.bdb.dump
2-5-4. 元の場所に戻す
一応パーミッション等を確認してから作業
% sudo ls -la /var/db/openldap-data/id2entry.bdb
-rw------- 1 ldap ldap 81920 Apr 26 10:07 /var/db/openldap-data/id2entry.bdb
% sudo rm /var/db/openldap-data/id2entry.bdb
% sudo cp id2entry.bdb /var/db/openldap-data
% sudo ls -la /var/db/openldap-data/id2entry.bdb
-rw-r--r-- 1 root ldap 81920 Apr 26 19:25 /var/db/openldap-data/id2entry.bdb
ふむ、パーミッションとオーナーが違いますね。
% sudo chown ldap /var/db/openldap-data/id2entry.bdb
% sudo chmod 600 /var/db/openldap-data/id2entry.bdb
% sudo ls -l /var/db/openldap-data/id2entry.bdb
-rw------- 1 ldap ldap 81920 Apr 26 19:25 /var/db/openldap-data/id2entry.bdb
これでOK
2-6. 再起動してみる
% sudo service slapd start
Starting slapd.
OK!
PCからも携帯からもちゃんと繋がる様になりましたとさ。
3. 最後に
今回の原因は、恐らくは意図しないタイミングでのシャットダウンが問題なのではないかと思うけど、詳細は不明。
というのも、VPSなので多分スナップショットとってバシっと止めた後に、引っ越し先のマシンで再開みたいな感じなので、仮想世界の中では何も起きなかった様に見えるのではないかと思う。従ってログにも当然何も残らない。
逆に、これで問題が起きるのは少々解せない部分ではある。まぁそうは言っても、接続中だったセッションとかは当然途中で切られてるだろうし、その辺で不整合が起きてもしょうがない。ただ、通信系の意図せぬ切断は普通に起きうる話なので、それでDBの中身がイカレてたりするのは少々怖いものがありますな。特にLDAPなので、基本参照専用のDBなんだし壊れちゃダメだよね・・・。
なにはともあれ復旧して良かった。