アクセスログをスマート解析してくれる「request-log-analyzer」が超絶便利だった件
最近、Ruby率が高くなってきた@masudaKです。
ちょいとアクセスログを眺める機会があったのですが、ワンライナーも限界があるし、なんかいいプラグインでもあるんじゃないかと探したら、良さそうなのがあったので、紹介。
その名も「request-log-analyzer」。Ruby製のログ解析ツールでございます。 プロジェクトページを見ると、Railsのログだけではなく、Apacheのアクセスログや、S3のログ、MySQLのスロークエリログなんかにも対応してるとのこと。
とりあえず、combinedなログを解析したかったので、試しにやってみました。
49.212.129.187 - - [27/May/2013:05:48:01 +0900] "GET /top HTTP/1.1" 200 162 "-" "curl/7.19.7 (x86_64-redhat-linux-gnu) libcurl/7.19.7 NSS/3.13.6.0 zlib/1.2.3 libidn/1.18 libssh2/1.4.2" "-" 49.212.129.187 - - [27/May/2013:05:49:01 +0900] "GET /top HTTP/1.1" 200 162 "-" "curl/7.19.7 (x86_64-redhat-linux-gnu) libcurl/7.19.7 NSS/3.13.6.0 zlib/1.2.3 libidn/1.18 libssh2/1.4.2" "-"
こんなログとか、手元にあるログとか適当に用意してください。
んで、「request-log-analyzer」を入れる。
$ gem install request-log-analyzer --no-ri --no-rdoc
rbenvなりでRubyの環境は作っておいてください。
あとは、以下のように使うだけ。
$ request-log-analyzer default.access.log.sum
(request-log-analyzer --apache-format "%h %l %u %t \"%r\" %>s %b" access.logみたいな使い方もできるみたい)
すると、こんな感じで出力される。
$ time request-log-analyzer default.access.log.sum Request-log-analyzer, by Willem van Bergen and Bart ten Brinke - version 1.12.9 Website: http://railsdoctors.com default.access.log.sum: 100% [====================================================================================================================================] Time: 00:00:08 Request summary ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ Processsed File: /home/masudak/work/parse_accesslog/default.access.log.sum Parsed lines: 100204 Skipped lines: 0 Parsed requests: 100204 Skipped requests: 0 First request: 2013-05-27 05:48:05 Last request: 2013-05-27 23:31:11 Total time analyzed: 1 days Request distribution per hour ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 0:00 ┃ 0 hits/day ┃ 1:00 ┃ 0 hits/day ┃ 2:00 ┃ 0 hits/day ┃ 3:00 ┃ 0 hits/day ┃ 4:00 ┃ 0 hits/day ┃ 5:00 ┃ 1128 hits/day ┃ ░░ 6:00 ┃ 5640 hits/day ┃ ░░░░░░░░░ 7:00 ┃ 5640 hits/day ┃ ░░░░░░░░░ 8:00 ┃ 5734 hits/day ┃ ░░░░░░░░░ 9:00 ┃ 5640 hits/day ┃ ░░░░░░░░░ 10:00 ┃ 5640 hits/day ┃ ░░░░░░░░░ 11:00 ┃ 5640 hits/day ┃ ░░░░░░░░░ 12:00 ┃ 5640 hits/day ┃ ░░░░░░░░░ 13:00 ┃ 5640 hits/day ┃ ░░░░░░░░░ 14:00 ┃ 5640 hits/day ┃ ░░░░░░░░░ 15:00 ┃ 5640 hits/day ┃ ░░░░░░░░░ 16:00 ┃ 5640 hits/day ┃ ░░░░░░░░░ 17:00 ┃ 5640 hits/day ┃ ░░░░░░░░░ 18:00 ┃ 5640 hits/day ┃ ░░░░░░░░░ 19:00 ┃ 5640 hits/day ┃ ░░░░░░░░░ 20:00 ┃ 5640 hits/day ┃ ░░░░░░░░░ 21:00 ┃ 5640 hits/day ┃ ░░░░░░░░░ 22:00 ┃ 5640 hits/day ┃ ░░░░░░░░░ 23:00 ┃ 3102 hits/day ┃ ░░░░░ HTTP methods ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ GET ┃ 100110 hits ┃ 99.9% ┃ ░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░ HEAD ┃ 94 hits ┃ 0.1% ┃ HTTP statuses ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 200 ┃ 100110 hits ┃ 99.9% ┃ ░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░ 404 ┃ 94 hits ┃ 0.1% ┃ Most popular URIs ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ /tekitou ┃ 100016 hits ┃ 99.8% ┃ ░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░ http://hogehoge.net/test.php ┃ 94 hits ┃ 0.1% ┃ / ┃ 94 hits ┃ 0.1% ┃ User agents ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ curl/7.19.7 (x86_64-redhat-linux-gnu) libcurl/7.19.7 NSS/3.13.6.0 zlib/1.2.3 libidn/1.18 libssh2/1.4.2" "- ┃ 100016 hits ┃ 99.8% ┃ ░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░ Mozilla/5.0 (Windows; U; Windows NT 6.1; en-US; rv:1.9.2.28) Gecko/20120306 Firefox/3.6.28 (.NET CLR 3.5.30729)" "- ┃ 94 hits ┃ 0.1% ┃ -" "- ┃ 94 hits ┃ 0.1% ┃ Referers ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ None found. ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ Traffic - by sum ┃ Hits ┃ Sum ┃ Mean ┃ StdDev ┃ Min ┃ Max ┃ 95 %tile ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ /tekitou ┃ 100016 ┃ 16 MB ┃ 162 B ┃ 0 B ┃ 162 B ┃ 162 B ┃ 161 B-170 B http://hogehote.net/test.php ┃ 94 ┃ 15 kB ┃ 162 B ┃ 0 B ┃ 162 B ┃ 162 B ┃ 161 B-170 B / ┃ 94 ┃ 0 B ┃ 0 B ┃ 0 B ┃ 0 B ┃ 0 B ┃ 1 B-1 B ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ Traffic - by mean ┃ Hits ┃ Sum ┃ Mean ┃ StdDev ┃ Min ┃ Max ┃ 95 %tile ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ /tekitou ┃ 100016 ┃ 16 MB ┃ 162 B ┃ 0 B ┃ 162 B ┃ 162 B ┃ 161 B-170 B http://hogehoge.net/test.php ┃ 94 ┃ 15 kB ┃ 162 B ┃ 0 B ┃ 162 B ┃ 162 B ┃ 161 B-170 B / ┃ 94 ┃ 0 B ┃ 0 B ┃ 0 B ┃ 0 B ┃ 0 B ┃ 1 B-1 B Traffic - total: 16 MB Need an expert to analyze your application? Mail to contact@railsdoctors.com or visit us at http://railsdoctors.com. ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ Thanks for using request-log-analyzer! real 0m8.910s user 0m8.825s sys 0m0.036s
こんな感じで、トラフィックとか、ステータスコード、リファラーもろもろを綺麗に表示してくれる(このブログのCSSの横幅の限界がきてるので、ローカルで試してみてくださいm(__)m)。
対象のログサイズとか行数はこんな感じ。
$ du -sh default.access.log.sum 19M default.access.log.sum $ wc -l default.access.log.sum 100580 default.access.log.sum
標準出力すると、色もついて、今風な感じ。
perlワンライナーで出すのもいいんだけど、どうも限界がある。
$ perl -ne 'if(/(\d\d\:\d\d)/){$c{$1}++}END{for(sort keys %c){print "$_,$c{$_}\n"}}' /usr/local/tomcat/logs/access.log | sort -nr -t ',' -k 2,2 |head 16:34,1091 16:22,489 16:35,394 16:23,220 17:41,22 $ perl -MFile::Basename -lane 'print substr($F[3],1,14) if(((fileparse($F[6],qw(\.[^\.]+$) ))[2]) !~ /.gif|.js|.css/);' /usr/local/apache/logs/access_log | uniq -c 1022 17/May/2013:14 1235 17/May/2013:15 602 17/May/2013:16
ってのを考えると、こういうツールは悪くはないんじゃないかなぁと思ったり。
ちなみに、370MBほどあるアクセスログでやったら、10分かかりました。その上、メモリが少ないサーバでやると、途中でOOM killerに抹殺される可能性があるので、 大きめのログを解析するときは、少しスペックあげることおすすめします。 なので、的確に出したい項目決まってるならワンライナーでいいし、ざっくり概要把握したいなら、こういうのもいいでしょうという感じですな。
是非使ってみてください。