ディスクの論理障害からの救助

 いやはや、ひどい目に遭いました。私は自分のサーバで外部向けの大きなサービスを提供しているわけではないので、障害対策に関しては「まぁいいか」的な姿勢で居たのですが、自力で解決しなければならないサーバ障害としては最大級の出来事となったかもしれません。


 金曜日の夕方に、サーバの一台にsshで接続できなくなり、まぁお遊び系サーバなので明日にでもゆっくり確認しようか、と夜に開催された勉強会と懇親会にも参加して、でもちょっと気になったので帰り際に事務所に寄ってみたら、結構オオゴトだと直感し、そのまま対応開始、結局「金曜日は、家に帰り着いたのが土曜のお昼過ぎでした」という不思議な状態となってしまいました。
 作業の記録もスットコドッコイな状態で、結構パニック起こしていたのだなぁと、今更ながらに気づきました(笑)。対応優先でほとんど一次情報にも当たっていないこともあり、信憑性とか因果関係とか怪しい部分もあると思いますが、記録として、以下、少し整理したメモとして残したいと思います。

発端

金曜19時過ぎ、sshで接続しようとしたら Too many file open (やや記憶曖昧)というエラーが出て接続できませんでした。正確に言うと、接続直後に bashがファイルを開けなくて切断してきたみたい。
夜の用事(勉強会とか懇親会とか)を済ませて、家に帰る前にちょっと様子を見てみようと、事務所に到着したのが土曜1時頃。

当該マシンで復旧トライ

 コンソールには なにかいっぱいメッセージが出ていた。メモを取っておらずその後色々あったので、すっかり忘れました。
psを見ると、/usr/sbin/sendmail -FCronDaemon -i -odi -oem -oi -t がたくさん。
一瞬、「spamメールの踏み台にされた!?」と動揺しました。
sudo になろうとすると、

sudo: Can't open /var/run/sudo/USERNAME/1: Read-only file system

初めて遭遇しました。こんなメッセージ。書かせてよ。


オオゴトである直感がしたので、大切なファイルが入っているフォルダ(主に私のホーム以下やetc等の設定ファイルがあるところ)を別サーバにコピー。

$ tar -cvfp - -C /home/USERNAME . | ssh 192.168.0.XXX 'tar -xfp - -C /home/USERNAME'


fsck をかけてみることにした。
まぁ出るわ出るわ。以下、適当にツマミグイで抜粋

Inode 5401841, i_blocks is 1400, should be 1376. Fix? yes
Inode 5401734 has illegal block(s). Clear? yes
Illegal block #63 (4294967256) in inode 5401734. CLEARED.
Too many illegal blocks in inode 5401734.
Clear inode? yes
Error while scanning inodes (27694656): A block group is missing an inode table
ye2fsck: aborted


 再起動したら、起動時から read-only filesystem になってしまい、そのせいか、ネットワーク系のサービスが立ち上がらす、完全にスタンドアロンマシンの状態に。。ここで諦めて、別のマシンへバトンタッチすることにしました。

別マシンへバトンタッチ

 空いている筐体があったので、速攻で CentOS を入れて、最低限の AMP 環境をセットアップ。問題のHDDを外して、IDEだったので、それ用のUSBで接続できるアダプタをくっつけて、新サーバに接続。
 やりたいことは、「mountして新HDDに必要なファイルをコピーする」こと。
(いくつかのファイルは↑でコピーしたけれども、すべてではないので)

dmesg コマンドにて、問題HDDは hda と認識されていることがわかった。
普通にmountしたら、/ と /lost+found とあともうひとつくらいしか、見えない。

# mkdir /mnt/wd32
# mount /dev/sdc /mnt/wd32/


ボリウムグループにしているから。ということで、ちょっと手のかかる作業を。
まず確認:

# vgscan
Reading all physical volumes. This may take a while...
Found volume group "VolGroup00" using metadata type lvm2
Found volume group "VolGroup00" using metadata type lvm2


 新しくセットアップしたマシンのHDDと問題HDDが同じボリウムグループ名になってしまっている。どちらかを変更する方向で。
 vgdisplay でUUIDを確認して、それを指定して名前を変える手順。

# vgdisplay
--- Volume group ---
VG Name VolGroup00
(略)
VG UUID 90oxuc-BXdk-8CD8-cR1c-QcCP-2JTJ-xWuCxl

--- Volume group ---
VG Name VolGroup00
(略)
VG UUID ZXx3q1-6A86-Xr2f-uAzI-cMmv-yKDk-UfK9RP


 ディスクのサイズが異なるので、それで今回は判別可能でした。上の90oxuc・・・というのが問題HDDのほう。こいつの名前を変えることにした。320GBディスクだったので、VolGroup0032に(安直)。

# vgrename 90oxuc-BXdk-8CD8-cR1c-QcCP-2JTJ-xWuCxl VolGroup0032
# vgscan
Reading all physical volumes. This may take a while...
Found volume group "VolGroup0032" using metadata type lvm2
Found volume group "VolGroup00" using metadata type lvm2

 ほら変わった。
で、mount。

# umount /dev/sdc
# mount /dev/VolGroup0032/LogVol00 /mnt/wd32


 一番大切なMySQLのデータファイル群をとにかくコピーしたかったので、cpコマンドで /var/lib/mysql/ 以下を全コピー。
・・・・の作業をしていたけれども、binlogが大量に溜まっていて時間がかかりすぎ。削除コマンドを発行するのも避けたかったので、結局はディレクトリやファイル指定でbinlogファイル以外のファイルをコピーしました。


 DBファイルのコピーを終えて、ちょっと操作していたら、mountが外れてしまいました。再マウントしようとしても、先ほどと状況が違う(先ほどはファイルシステムタイプを指定する必要はなかった)。

# mount /dev/VolGroup0032/LogVol00 /mnt/wd32
mount: you must specify the filesystem type

 しばらく見てみたけど、わからないし、どうしても救わなきゃいけないファイルは無事救出済みなので、諦めることにしました。

サーバ系

# /etc/init.d/mysql start

 で開始しようとして幾度とエラーが出た記録。エラーは、/var/log/mysqld.log に出力されます。



ちょっとごった煮だけど色々エラー:

110911 05:15:17 mysqld_safe Starting mysqld daemon with databases from /var/lib/mysql
/usr/sbin/mysqld: File '/var/lib/mysql/mysqld-bin.index' not found (Errcode: 13)110911 5:18:06 [ERROR] Can't open the mysql.plugin table. Please run mysql_upgrade to create it.
110911 5:18:06 [ERROR] Plugin 'InnoDB' init function returned error.
110911 5:18:06 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed.110911 5:28:26 [ERROR] Failed to open log (file '', errno 2)
110911 5:28:26 [ERROR] Could not open log file
110911 5:28:26 [ERROR] Can't init tc log

 カラのindexファイルを作ったり、
 ファイルコピーに失敗しているibdataファイルがあったので、コピー。(この日記での説明が前後しているが、このときにはまだmountされたファイル群が見えていた)
 また、ファイルコピーしたときにオーナーが変わってしまっていたので、変更:

# chown -R mysql:mysql ./*

110911 5:24:15 [ERROR] /usr/sbin/mysqld: unknown variable 'default_character_set=utf8'

 出ましたよ出ましたよ。今回バージョンが5.1から5.5に変わったので、サーバ文字セットは default_character_set ではなく、character_set_server に変わったのでした。my.cnf を修正。


今回感じたこと

 そんなわけで、楽しみにしていたPHPカンファレンスにも行けず、こんなことをしていました。すぐに相談できる相手もおらず(個別事象なので)、手探りでしたが、一番大切なデータとスクリプト群がほぼ無傷で救出できたのは、奇跡に近い気がします。
そんな今回思ったこと。
・バックアップ重要。当たり前だけど、いつも言うけれど、ほんとに。
・わけがわかんない。結局、何が起こったのかわからなかった。
・ちゃんと整理しておけば、サーバのハコを変えるのは、思っていたよりも手間がかからなかった
・まっさきにファイルコピーをした自分、GJ!
・ファイルの所有者やパーミッションで、結構ハマる。
PHPは、何のライブラリを入れておくか整理しないと、結構困る。今回の旧マシンは必要に応じて都度追加してきたので、今回新マシンでスクリプト動作確認をしている際に、ボロボロと不足ファイルが判明して、大変だった。



こんなわけでメモでした。