ここ数日間、頭を悩ませていたRaq550サーバーの cce の障害がやっと解決した。
直接的な原因は、 /usr/sausalito/schemas/base/am/am.schema ファイルが壊れていたことだった。なぜ壊れたのかは分からないけど、このファイル1つが壊れただけで、ネットワークもHTTPサーバーも正常動作しなくなってしまったことは事実である。
原因が分かったので、ファイルを修復して再起動したら、何事もなかったかのようにサーバーが順調に稼動を始めた。
諦めてOSをリストアしてしまえばそれで解決するけれども、それでは何のノウハウも得られないし、経験値も稼げない。今回の障害は、管理画面が開けないことを除けば他のサービスに実害はないので、できるところまで頑張ってみるだけの価値はある。
経験豊富でスキルの高いシステム管理者ならばおそらく、この障害はすぐに解決できるレベルのものだと思う。私の場合、原因分析にかなり遠回りをしたあげくに、偶然のひらめきで解決できたという状況だったので、単にラッキーなだけだった。
このまま終わってしまえば、再発した時にも同じように頭を悩ますことになるはずなので、どうやって解決したのか、少し分析してみようと思う。
「今日こそは絶対に解決するぞ!」と決心したのが昨日の夜だった。
まずは定石どおり、システムログ("/var/log/messages")を分析して、最初に出たエラーを分析してみることにした。
------------------------------------------------------------------------------------------- Sep 2 00:44:23 www cced[278]: Cobalt Configuration Engine (CCE) version 0.80.2 Sep 2 00:44:23 www cced[278]: Copyright (c) 1999,2000 Cobalt Networks, Inc. Sep 2 00:44:23 www cced[278]: starting up (pid 278) Sep 2 00:44:23 www logger: cce_construct started Sep 2 00:44:23 www CONSTRUCTOR: ----- constructing ----- Sep 2 00:44:23 www CONSTRUCTOR: /usr/sausalito/constructor/base/system/10_addSystem.pl Sep 2 00:44:23 www logger: ***** cce_construct: /usr/sausalito/constructor/base/system/10_addSystem.pl Sep 2 00:44:26 www cced(smd)[278]: Invalid type "amstate" for "ActiveMonitor.ECC.currentState" Sep 2 00:44:26 www cced(smd)[278]: Removing class "ActiveMonitor", namespace "ECC" Sep 2 00:44:27 www CONSTRUCTOR: Use of uninitialized value in scalar assignment at /usr/sausalito/perl/I18n.pm line 120. Sep 2 00:44:27 www CONSTRUCTOR: /usr/sausalito/constructor/base/alpine/11_configureSystem.pl Sep 2 00:44:27 www logger: ***** cce_construct: /usr/sausalito/constructor/base/alpine/11_configureSystem.pl -------------------------------------------------------------------------------------------
この中で最初にエラーらしきメッセージが出ているのは、次の8行目である。
Sep 2 00:44:26 www cced(smd)[278]: Invalid type "amstate" for "ActiveMonitor.ECC.currentState"
この行に含まれるキーワードを Yahoo と Google を使って検索してみたら、満足な答えは見つからなかった。特に、"amstate"って何だ? という問題が気になって、これを調べるのに無駄なエネルギーを使った。これが分かればすべて解決すると思ったので、ここにエネルギーを割くのは間違いではないと思ったからである。辞書を引いても出てこないので、何かの略語だろうか? アメリカンステートの略か? アムステルダムの関係か? 等を推測したが、どれも関係なさそうだ。
結局分からず、「ActiveMonitor」「ECC」「currentState」のキーワードで、インターネット上を探してみたら、やはり Cobalt のソフトウェアである、いくつかの Perl モジュールでエラーを吐いているらしいということは推測できた。最悪の場合、Perl モジュールを順番に追う覚悟でいたけれども、とりあえずこの3つのキーワードを含むモジュールだけを調べれば良いと考えて、解決に一歩近づいたような気がした。
その時に突然ひらめいたのが、amstate は、「ActiveMonitorのcurrentState」の略ではないか?というものだった。だから、 am という名前がつくディレクトリだけに的を絞れば解決できそうだと考えた。
さっそく am の名が付くモジュールを開いて中身を見てみたが、プログラムを見たところでますます分からなくなるだけである。プログラムが突然壊れることは考えにくいので、設定ファイルか状態ファイルが壊れたのだろうと思って、Perlモジュールの中に書かれているファイルの パス名とファイル名 をピックアップして見るようにした。でも順番に解析していくと時間がかかりそうで疲れてくるので、途中でやめた。
とりあえず、am の名を含むディレクトリを探して、その中から拡張子が .pl 以外のファイルを調べてみることにした。すると、次のようなディレクトリが該当した。
/usr/sausalito/perl/AM
/usr/sausalito/conf/base/am/
/usr/sausalito/confconstructor/base/am
/usr/sausalito/handlers/base/am/
/usr/sausalito/schemas/base/am/
最初に見たのは、/usr/sausalito/conf/base/am/am.conf ファイルである。この中身を見ると、「ActiveMonitor.ECC.」というキーワードが見つかったけど、特におかしな様子はなかった。
次の3つのディレクトリ内は .pl のファイルしか入っていなかった。
そして /usr/sausalito/schemas/base/am/ のディレクトリを見たら、 .pl 以外のファイルがいくつかあったので、ここを徹底して調べてみることにした。
できれば全部印刷してみて、正常に動作している Raq550サーバーと比べてみたいので、FTPを使ってこのディレクトリをローカルPCのハードディスクにダウンロードを始めた。
ところが、最初の am.schema というファイルのダウンロードに異常に時間がかかることに気が付いた。ダウンロードのサイズが100MBを超えてもまだ終わりそうにない。さすがにおかしいと思ってダウンロードを中止し、SSHで 「ls -l」コマンドを入力してみたところ、次のように表示された。
------------------------------------------------------------------------------- [root am]# ls -l 合計 24 -rw-r--r-- 1 root root 2892176555428481344 2月 19 1953 am.schema -rw-r--r-- 1 root root 2359 4月 12 2002 am_base.schema -rw-r--r-- 1 root root 1371 4月 12 2002 ecc-am.schema -rw-r--r-- 1 root root 1633 4月 12 2002 fans-am.schema -rw-r--r-- 1 root root 1863 4月 12 2002 temperature-am.schema [root am]# -------------------------------------------------------------------------------
何だ、このファイルサイズは!? と思って、正常な Raq550サーバーの方を見てみると、やはり異常な状況になっていることが明らかに分かった。この瞬間に、この問題は解決したと確信できた。
さっそくこのファイルを削除して、正常な Raq550サーバーからFTPでダウンロードしたら、ファイルサイズは次のように正常に戻った。
-rw-r--r-- 1 root root 2359 Apr 12 2002 am_base.schema
さっそく 「/etc/rc.d/init.d/cced.init start」 コマンドで cced を起動したら、こんどはシステムログにエラーを吐かなくなった。「/etc/rc.d/init.d/cced.init status」コマンドで状態を確認すると、
cced (pid 278) is running...
と表示されたので、サーバーを再起動してみた。
そうしてすべて元に戻ったことが確認できた。
今回はFTPによって異常ファイルサイズを発見できたけど、実はもっと前に発見できたはずである。この障害が発生した当初、 /usr/sausalito/ ディレクトリ内を全部ローカルPCにダウンロードするために tar コマンドでアーカイブしようとしたら異常に時間がかかって中断したことがある。思えばこの時に気づいてもよかったのである。
今後は、予期しないことが起こったら、まずはすべてのディレクトリ一覧の詳細をテキストファイルに落として、正常動作のRaq550サーバーと比較してみることを試すようにしたいと思う。
スターダスト
お疲れ様でした。 有難うございました。
…やはりひらめきって大切ですね。
お願いがございます。
http://www.adamski.jp/wwwboard/newcheck.cgi
最新メッセージ一覧ですが、bbs本体と同期がとれていませんです。なにとぞよろしくお願い申し上げます。