追記
CPANにアップしました
http://search.cpan.org/dist/Log-Minimal/
/追記
アプリケーションサーバでエラーが起きていたり、レスポンスが遅かったりする場合に、Operation Engineer(インフラエンジニア)がまず見るのは、エラーログです。エラーログにでているメッセージを手がかりに原因を探ります。
サーバでエラーが起きている時には、データベースに接続ができなかったり、外部のAPIからレスポンスが得られない、またプログラムのBugが原因となっている場合もあるでしょう。またエラーにならなくても、複数台あるデータベースのスレーブサーバうち一台が落ちて接続をretryしていたり、APIのレスポンスが遅い際にはサーバ全体のパフォーマンスが低下します。
エラーログに障害の原因を探る情報があれば、Operation Engineerは素早く対応を開始できます。逆にエラーログに何も表示されていなければ、ソースコードを追ったり、tcpdumpやstrace、gdbでトレースしなければ原因の特定ができず、対応がどんどん遅れて行きます。ログはアプリケーションを実装するエンジニアとOperation Engineerを結ぶ媒体であり、コミュニケーション手段なのです。
コミュニケーションを円滑にするためはいくつかのプロトコル・制約を決めておくのが定石です。よく使われるのは、ログに残すメッセージに重要度によってレベルをつけることです。DEBUG、INFO、WARN、CRITICALなどのレベルはエンジニアならだれでも見たことがあるはずです。数多く出力されるログから運用ではWARNやCRTICALレベルのメッセージを中心に見れば良くなります。またメッセージがいつ発生したのかの日付情報、加えてどのソースコードで発生したのかの場所についての情報も付属していると障害の原因を追いやすく、またアプリケーションエンジニアとのコミュニケーションも「いつどこそこの何行目でほげほげというエラーがでてる」と具体的に場所を示すことができ、調査に向けての協力も円滑に行うことができます。
つまり何が言いたいかと言うと「アプリケーションからのログを出してください。仕事するのでお願いします」ということです。と、ここまでが前書きで、ログを書き出すための小さいモジュールを書いてみましたので、紹介します。
書いたのはLog::Minimalというモジュールです。まだgithubにしかありません。使い方は
use Log::Minimal;
critf("%s","foo"); # 2010-10-20T00:25:17 [CRITICAL] foo at example.pl line 12
warnf("%d %s", 1, "foo");
infof("foo");
debugf("foo"); # print if $ENV{LM_DEBUG} is true
こんな感じです。crit、warn、info、debugに「f」がくっついたメソッドがExportされます。各メソッドでは引数が複数あった場合、1個目をprintfのフォーマットとして扱います。引数が1つの場合はそのまま出力されます。デフォルトの出力方法は「warn」です
出力方法を変更するには、$Log::Minimal::PRINTで指定します
my $app = sub {
my $env = shift;
local $Log::Minimal::PRINT = sub {
my ( $time, $type, $message, $trace) = @_;
$env->{psgi.errors}->print("$time [$env->{SCRIPT_NAME}] $type $message $trace\n");
};
run_app(....);
};
上記の例では、PSGIのError Streamに対して、ログを出力しますが、その際にリクエストのあったファイル名もログに出力します。こうすることでさらに障害があった際のトレーサビリティを向上させることができます。Gearmanなどのworkerでも同じように実行しているjob名や引数が出力されると便利だと思われます。また、ここでsyslogでログを飛ばしたり、Log::Dispatchに渡したりする処理を入れてもいいでしょう
加えて、crit、warn、info、debugに「ff」という様に「f」を2つつけると、Stacktraceも出力されるようになります。
critff("%s","foo");
# 2010-10-20T00:25:17 [CRITICAL] foo at lib/Example.pm line 10, example.pl line 12
こんな感じに出力されます。
CPANにはLog系のモジュールはたくさんあるのだが、おなじぐらい簡単なジュールは既にあるのかなぁ。
