_ [システム運用][Perl] Apache Combined Log を効率的にパースする正規表現メモ

ググるとよく見つかるのははてな - Apache形式のログを解析する正規表現を教えてください (Geekなぺーじ : アクセスログの読み方（apache combined logの場合）) の

($host, $ident, $user, $time, $request, $status, $bytes, $referer, $agent)
= ($line =~ /^(.*) (.*) (.*) \[(.*)\] "(.*)" (.*) (.*) "(.*)" "(.*)"/);

だが、最長一致の .* が多数登場するためか、マッチ処理がとても遅い。たった10万行パースするのに Core2 使って23.7秒ってあり得なくね?

できるだけ最短一致でマッチさせるように

($host, $ident, $user, $time, $request, $status, $bytes, $referer, $agent)
= ($line =~ /^([^ ]*) ([^ ]*) ([^ ]*) \[([^]]*)\] "(.*?)" ([^ ]*) ([^ ]*) "(.*?)" "(.*?)"/);

という感じにすると、同環境にて約21倍速くなった。(1.12秒)

実際には Request String をさらに分割取得したいことが多いので

($host, $ident, $user, $time, $method, $resource, $proto, $status, $bytes, $referer, $agent)
= ($line =~ /^([^ ]*) ([^ ]*) ([^ ]*) \[([^]]*)\] "([^ ]*)(?: *([^ ]*) *([^ ]*))?" ([^ ]*) ([^ ]*) "(.*?)" "(.*?)"/);

という感じで使うと良さ毛だ。

_ [システム運用][Perl] Apache Combined Log 解析正規表現ベンチマークの補足 (2007/10/05)

(高速に) Apache の log を解析する正規表現として My RSS 管理人ブログで取り上げられたようなので、これに絡んで補足。

"([^"]*)" ではなく "(.*?)" を使うべき

最初にそこで例示された

m!^([^\s]*) [^\s]* [^\s]* \[([^]]*)\] "([^"]*)" ([^\s]*) [^\s]* "([^"]*)" "([^"]*)"!

だが、HTTP Request には稀に " が含まれていることがあるため、その場合 "([^"]*)" の部分でマッチミスを起こす。

このため、最初に自分が取り上げた上記正規表現では敢えて "(.*?)" としていたわけである。

…というコメントを寄せたところ補足を加えていただけたようだが、それでも Referer と User-Agent の部分を (.*) に戻されただけなので、Request に " が含まれていた場合に対応できていない。また、以下に示す通り、(.*) を (.*?) に変えるだけでも劇的な効果を得られるので、(.*) は (.*?) にした方が良い。

"(.*?)" と "((\\"|[^"])*)" はどちらが高速なのか

また、最初に送信したコメントでも触れたが、Request 中に " が含まれる場合は \" とエスケープされてログに記録されるので、"(.*?)" の部分は "((\\"|[^"])*)" とすると解析パフォーマンスを向上させられる可能性があると考え、ベンチマークを取ってみた。(以下全てのベンチマーク環境は Pentium III 1GHz マシンの Debian GNU/Linux 3.1 - Perl 5.8.4)

rx_optim_pmakino1 が /^([^ ]*) [^ ]* [^ ]* \[([^]]*)\] "(.*?)" ([^ ]*) [^ ]* "(.*?)" "(.*?)"/ で、rx_optim_pmakino2 が "(.*?)" の部分を "((?:\\"|[^"])*)" で置き換えたものである。

rx_optim_pmakino2 10204/s    --
rx_optim_pmakino1 46691/s  458%

…予想に反してかえって大幅に遅くなってしまった。

ではひょっとして、わざわざ [^ ]* や [^"]* 等を使わずに単純に最短一致の .*? にした方が速くなるのか? と試してみたところ、(rx_optim_pmakino3 → /^(.*?) .*? .*? \[(.*?)\] "(.*?)" (.*?) .*? "(.*?)" "(.*?)"/)

rx_optim_pmakino1 46691/s    --
rx_optim_pmakino3 51633/s  111%

はい、速くなりました。[^ ]* なんか使うより .*? 使った方が速いのね。

[^\s] と \S と [^ ] はどれが速いのか

※[^\s] は \S でも OK です。

[(高速に)Apache の log を解析する正規表現 : a++ My RSS 管理人ブログより引用]

というコメントで、[^\s] と \S と [^ ] はどれが最速なのか気になったのでそれも比較。(rx_optim_myrss3 が [^\s]、rx_optim_myrss4 が \S、rx_optim_myrss5 が [^ ])

rx_optim_myrss3 44522/s    --
rx_optim_myrss5 47010/s  106%
rx_optim_myrss4 48470/s  109%

\S > [^ ] >> [^\s]、ということらしい。

[.+?] と [.*?] はどちらが速いのか

上記の最速パターン、最初は必ず何かしらの文字列が入ることが確定している部分については当初 .*? ではなく .+? でマッチさせていた。が、実は .*? の方が微妙に速いっぽいような結果が見え隠れしていたのでそれも比較。(rx_optim_pmakino1 が .*?、rx_optim_pmakino4 が .*?)

rx_optim_pmakino4 45366/s   --
rx_optim_pmakino1 46837/s  103%

僅かだが .*? の方が速いらしい。

結局最速なのは

色々小細工するよりも、実は最初の最も遅い例の .* を片っ端から .*? に置き換えた

/^(.*?) .*? .*? \[(.*?)\] "(.*?)" (.*?) .*? "(.*?)" "(.*?)"/

が最速だったと。

Request String をさらにメソッドとリソースとプロトコルに分割するなら

/^(.*?) .*? .*? \[(.*?)\] "(\S+?)(?: +(.*?) +(\S*?))?" (.*?) .*? "(.*?)" "(.*?)"/

で。

(もっとも、LogFormat をいじれるのであればそもそもログ自体を TSV にしてしまうのが一番効率が良いのだが)

(諸々のテストコード)

(ちなみに正規表現は事前にコンパイルしておくことができるそうなのでそれも試してみたが、速度に全く変化が見られなかった。)

(2009/02/28追記)

スペース区切りのApacheデフォルトログ書式(Combined Log Format)を解析する正規表現の解説 - アルバイト論というエントリが出来ているのに気づいた。

速度的な面での探求ではないけど、どんなおかしなログが来ても正しく解析できるような正規表現とは何なのかを調査されていて一見の価値ありだと思った。

(2014/05/05追記)

たった6個のsedを通せば、Apacheログは驚くほど扱いやすくなる - Qiita にていくつか検証・コメントさせていただいた。

_ [システム運用][Perl] Apache Combied Log を解析する CPAN モジュール

これらを使った場合のベンチマークも取ってみたい