Perl6のGrammarでサーバログをパースする
何がしたいか
某編集部で運用中のマインクラフトサーバのログを解析して、プレイ時間の一番長い廃人を算出したい。折角なのでPerl6でやりましょうという企画です。lldecadeでPerl6の話が少し出たようなので、それに乗っかろうという感じですね。
はじめに
Grammarとは何ぞや？という話があると思いますが、これについては去年のPerl6 AdCで書かれた@Yoshimura/_yuuくんの記事を参考にして下さい。おそらく日本語でGrammarを解説した記事の中では、彼のが一番まとまっていると思います。
今回のテーマについて
GrammarとActionsはとても強力です。強力なんですが、あまりに複雑なのと制約が多いので使い道があまりまりません。対象となる文字列をパースする際にメモリ上に構文木が展開されてしまうため、あまり大きなファイル（例えばプログラムのソースコード）などをパースするのに向いているかと言われると微妙な気がします。また、普通の正規表現に比べて格段に処理速度が遅いのも残念なところです。
なので今回は、メモリと速度という制約を受けない、サーバログのパースをしてみようと思います。ログの解析なら行指向なので一回のパース量は少なくて住みますし、リアルタイム性も必要ありませんからね。
ログのフォーマット
今回は、サーバログの中から「ログイン」と「ログアウト」を探し出し、プレイ時間の集計を撮りたいと思います。それぞれのログはこんなふうになっています。
- ログイン
2011-09-09 21:29:42 [INFO] VienosNotes [/192.168.xxx.xxx:xxxxx] logged in with entity id xxx at (X, Y, Z)
- ログアウト
2011-09-09 21:56:37 [INFO] VienosNotes lost connection: disconnect.quitting
当然細かい部分は場合に応じて変わるのですが、だいたいこんな感じです。
ルールを書く
ではこの2つについて、どういう場合にマッチするのかのルール(rules)を実際に書いて行きましょう。個人的な好みですが、Grammarを書いていく時は、トップダウンでrulesを書いていくと楽な気がします。細かい部分は名前をつけて切り分け、後回しにすると見通しの良いGrammarが書けるようになるからです。ただ、rulesの複雑さは処理速度に直結しますので、そのへんの兼ね合いを考える必要があるかもしれません。
まずは"TOP"です。これはあらゆるGrammarに必要な、特殊なルールです。Grammarを用いたマッチングは、先頭から部分正規表現について深さ優先探索でマッチングを試みていくのですが、その根の部分に当たるのが"TOP"になります。今回の場合はこんな感じでしょうか。
rule TOP {
<log_login> | <log_logout>
}
要は、このGrammarでは"log_login"もしくは"log_logout"という名前の正規表現にマッチさせるよ、というのがTOPにあたります。
次は"log_login"を書きましょう。タイムスタンプやIPアドレスなどを記述すると煩雑になるため、これも名前付きで下に切り分けます。また、名前をつけることでフックするActionを書けるようになるので、パースした結果として使いたい部分には名前をつけるのが良いでしょう。
rule log_login {
<timestamp> <.ws> '[INFO]' <.ws> <username> <.ws> '[/' <ipaddress> ']' <.ws> 'logged in with' .*
}
rule log_logout {
<timestamp> <.ws> '[INFO]' <.ws> [<username>|'/' <ipaddress>] <.ws> ['[/' <ipaddress> ']']? <.ws> 'lost connection:' .*
}
}
ログアウトは、たまにユーザ名でなくIPアドレスになることがあるので（原因はよくわからん）、少し手を入れてます。
タイムスタンプは、あとで年や月、日を使うので名前で切り分けましょう。
rule timestamp {
$<year>=(\d ** 4) '-' $<month>=(\d ** 2) '-' $<day>=(\d ** 2) <.ws> $<hour>=(\d ** 2) ':' $<minute>=(\d ** 2) ':' $<second>=(\d ** 2)
}
ユーザ名はマインクラフトの細かい仕様を知らないので適当です。
rule username {
<[0..9a..zA..Z_]>+
}
IPアドレスのバリデーションとかは必要ないでしょう。手抜きですがこんな感じ。
rule ipaddress {
\d ** 1..3 \. \d ** 1..3 \. \d ** 1..3 \. \d ** 1..3 [':' \d ** 1..5]?
}
これで、ログイン/ログアウトの行だけを抜き出して、マッチオブジェクトを生成することができるようになりました。まとめると、次のようなGrammarになります。
grammar Minecraft::ServerLog::Format {
rule timestamp {
$<year>=(\d ** 4) '-' $<month>=(\d ** 2) '-' $<day>=(\d ** 2) <.ws> $<hour>=(\d ** 2) ':' $<minute>=(\d ** 2) ':' $<second>=(\d ** 2)
}
rule ipaddress {
\d ** 1..3 \. \d ** 1..3 \. \d ** 1..3 \. \d ** 1..3 [':' \d ** 1..5]?
}
rule username {
<[0..9a..zA..Z_]>+
}
rule TOP {
<log_login> | <log_logout>
}
rule log_login {
<timestamp> <.ws> '[INFO]' <.ws> <username> <.ws> '[/' <ipaddress> ']' <.ws> 'logged in with' .*
}
rule log_logout {
<timestamp> <.ws> '[INFO]' <.ws> [<username>|'/' <ipaddress>] <.ws> ['[/' <ipaddress> ']']? <.ws> 'lost connection:' .*
}
}
Actionsを書く
parseメソッドのactionsにクラスまたはインスタンスを指定することで、各部分マッチ成功時にフックするメソッドを設定することができます。ステートレスな処理ではクラスを指定すればいいですが、今回はログを解析しながらプレイ時間の集計を取るので、インスタンスを指定しましょう。
(正直なところ、私はActionsを使った場合の綺麗なクラス設計がよくわかりません。ステートフルな処理を行いたいとい、私が設計するとselfを渡すかグローバルな変数を使うかのどちらかになってしまいます。なんか上手いアイデアがあったら教えて下さい。)
10/25追記
とりあえずMinecraft::ServerLogクラスを作ります。また、各ユーザごとの情報を保持するためにUserクラスも作りましょう。
class Minecraft::ServerLog {
has $.logfile;
has %.users is rw;
method new (Str $filename where { $_.IO.f }) {
return self.bless(*, logfile => $filename);
}
}
class User {
has Int $.count is rw;
has Int $.time is rw;
has DateTime $.lastlogin is rw;
method new () {
return self.bless(*, count => 1, time => 0);
}
}
また、ActionsとしてMinecraft::ServerLog自身を使うのですが、ここでは見通しを良くするためにroleに分離します。今回フックしたいのはlog_loginとlog_logoutだけなので、これらのメソッドを定義しましょう。ぶっちゃけこれくらいだとActionsを使うメリットは薄いのですが、ログから引っ張りたい行の種類(エラー、警告、etc...)が増えた場合に、どの種類がマッチしたのかを判定する部分を記述する必要がなくなります。
role Minecraft::ServerLog::Actions {
method log_login ($/) {
my $name = $<username>.Str.chomp;
if self.users{$name} -> $user {
$user.count++;
} else {
self.users{$name} = User.new;
}
my $time = $<timestamp>;
my $dt = DateTime.new(year => $time<year>.Int, month => $time<month>.Int, day => $time<day>.Int,
hour => $time<hour>.Int, minute => $time<minute>.Int, second => $time<second>.Int);
self.users{$name}.lastlogin = $dt;
}
method log_logout ($/) {
my $name = $<username>.Str.chomp;
if self.users.exists($name) && self.users{$name}.lastlogin.defined {
my $time = $<timestamp>;
my $dt = DateTime.new(year => $time<year>.Int, month => $time<month>.Int, day => $time<day>.Int,
hour => $time<hour>.Int, minute => $time<minute>.Int, second => $time<second>.Int);
self.users{$name}.time += ($dt.Instant.Int - self.users{$name}.lastlogin.Instant.Int);
}
self.users{$name}.lastlogin = DateTime;
}
}
内容としては、ログイン時にはタイムスタンプから時刻を取得してlastloginに記録する、ログアウト時には時刻をlastloginと比較してtimeに記録するという単純なものです。
これを先ほどのMinecraft::ServerLogクラスにmixinしましょう。後は一行ずつログファイルを読み込んでGrammarに食わせるだけです。
class Minecraft::ServerLog {
also does Minecraft::ServerLog::Actions;
...
method get_user_list {
my Int $now;
for $!logfile.IO.lines -> $line {
print "\rproccessing line " ~ $now++;
Minecraft::ServerLog::Format.parse($line, actions => self);
}
say "\nAnalyze completed...\n";
}
}
あとは、集計が終わったユーザごとのログイン時間を表示するだけですね。今までのコードをまとめると、以下のようになります。
