2010年10月アーカイブ
追記
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系のモジュールはたくさんあるのだが、おなじぐらい簡単なジュールは既にあるのかなぁ。
自分の発表のことは前のエントリーに書いたので、全般的な感想を書いてみる。
今回のYAPC::Asiaで面白いなぁと思ったのは、運用系の発表が多くあったことだと思う。自分のCloudForecastの話の他にも、刺身さんの30days、myfinderさんのソーシャルアプリ向けの運用監視、盛り上がったnekokakさんの省サーバ運用などなどがありました。
インフラエンジニアはもっと前にでてもいいと言われるけど、既にhbstudyやqpstudyを通してインフラエンジニアが集まって喋る機会が生まれているし、そこから今回のYAPC::Asiaのような大きなイベントでも話すようになってきている。運用しているシステム・サービス、規模の大小に関わらずもっともっと多くの人が出て来て、刺激し合えると楽しいし、ノウハウを共有して仕事の質を高めて、楽ができるようになれば良いよね！
ところで、今回のYAPC::Asia 2日目は、土曜日ということもあり、息子と奥さんも一緒に会場の東工大に行ってみた。
天気がよかったので、講堂前や芝生で歩き回って遊べました。気が早いけど来年も休日ならまた連れて行きたいし、他に子供がいるエンジニアの方と芝生カンファレンスを開けたら良いんじゃないかと思いました！親ばかです！
最後に、JPAのスタッフの皆様、ボランティアの皆様、発表した皆様、参加してくれた皆様ありがとうござました！
YAPC::Asiaで CloudForecast のお話をさせて頂く機会を頂きました。JPA++ 941++でございます。Larry Wallのあとすぐということでちょっと緊張でした。
Yokohama.pm で話したこと+αで、監視についての話、CloudForecastの概要とインストール方法、拡張方法、また生成するグラフの見方、運用方法について紹介しました。
slideshare版の資料にはありませんが、発表で使った資料の最後はShibuya.pmの中継を見ていた息子です。去年の発表でも画像の縮小のサンプルにもつかってました^^
2010夏のmemcachedシリーズもいよいよ最後となりました。
1歳8ヶ月のうちの息子も見ていた Shibuya Perl Mongersテクニカルトーク#14「IPAとJPAは違う団体です」でmemcachedの運用について発表をさせていただきました。今回は監視scriptの書き方やcronlog、Nagiosの設定tipsなどの内容にしました。memcachedの監視というよりかは一般的なノウハウ寄りだったかなと
監視の狭間問題の対策としてmemcachedのuptimeを見るscriptを紹介していますが、この問題はmemcachedには限りません。自動的に再起動してくるようなサービスで勝手に再起動した=何か問題が起きたと想定できる、例えばMySQLや /proc/sys/kernel/panic が設定されているLinuxにも同じような監視が必要になるでしょう。
MySQLであれば次のようなscriptで監視ができます。
#!/usr/bin/perl
use strict;
use warnings;
use Getopt::Long;
use DBI;
GetOptions(
'H=s' => \my $HOST,
'p=s' => \my $PORT,
'c=i' => \my $CRIT
);
my $dbh=DBI->connect("dbi:mysql:;host=$HOST;port=$PORT");
if ( !$dbh ) {
print "Couldnt connect to $HOST:$PORT: $DBI::errstr\n";
exit(3); ##UNKNOWN
}
my $row=$dbh->selectrow_arrayref(q!show global status like "Uptime"!);
if ( !$row ) {
print "Couldnt get status: $dbh->errstr\n";
exit(3); ##UNKNOWN
}
if ( $row->[1] <= $CRIT ) {
print "Uptime is less than $CRIT / Uptime: $row->[1]\n";
exit(2); ##CRITICAL
}
exit(0); ##OK
MySQL 4.x とかだと役にたつことがあることもある
さて、2週間後にはいよいよ YAPC::Asia 2010 です。最近ライブドアだけじゃなく某社とか某社でも使われているらしい CloudForecast についてしゃべります。追加発売もしているのでぜひチケット買ってね！！
