bauer's diary

凡人の凡人による凡人のための備忘録

きたるISUCON6向け武者修行その4 -kataribeでHTTPリクエストのパフォーマンスを可視化しよう-

ISUCON

kitakitabauer.hatenablog.com

前回はNginxのチューニングを行いました。
今回はISUCONの過去問でも登場してきたプロファイリング用のツールを予習しておきます。

kataribeとは？

"Nginx/Apache/Varnishncsa Log Profiler"と書かれている通り、
アクセスログに出力されたリクエスト時間を元に、時間がかかっているアクセスをランキング化してわかりやすくしてくれるツールです。
github.com

インストール

このサイトから実行元OSのものをダウンロードします。
Releases · matsuu/kataribe · GitHub

$ wget https://github.com/matsuu/kataribe/releases/download/v0.3.0/linux_386.zip ~

unzipがなかったので、yumインストールして展開します。

$ sudo yum install unzip

$ unzip ~/linux_386.zip
Archive:  /home/vagrant/linux_386.zip
  inflating: LICENSE
  inflating: README.md
  inflating: kataribe
  inflating: kataribe.toml


ログフォーマット確認、プロファイル用ログの準備

nginx.confに定義するログフォーマットは前回設定しましたが、kataribeのREADMEに記載された通りなので問題ありません。
上記フォーマットでログを出力するために、ベンチマーカーを一度動かしておきます。

$ ./benchmarker b


アクセスログをkataribeでプロファイル

終わったら、nginxのアクセスログをkataribeに噛ませます。

$ cat /var/log/nginx/access.log | ./kataribe

Top 20 Sort By Total
Count   Total       Mean     Stddev     Min   P50.0   P90.0   P95.0   P99.0     Max   2xx  3xx  4xx  5xx  Request
  587  46.784   0.079700   0.027365   0.004   0.092   0.102   0.109   0.134   0.182     0  587    0    0  POST /login HTTP/1.1
    1  23.642  23.642000   0.000000  23.642  23.642  23.642  23.642  23.642  23.642     1    0    0    0  GET /report HTTP/1.1
 3519  14.101   0.004007   0.001516   0.001   0.004   0.006   0.007   0.009   0.013  3519    0    0    0  stylesheets
 1173   4.765   0.004062   0.001323   0.001   0.004   0.006   0.006   0.008   0.014  1173    0    0    0  images
  113   3.293   0.029142   0.012153   0.002   0.033   0.037   0.039   0.047   0.054   113    0    0    0  GET /mypage HTTP/1.1
 1060   1.645   0.001552   0.000827   0.001   0.001   0.002   0.002   0.005   0.009  1060    0    0    0  GET / HTTP/1.1

単純なリクエスト数や中央値など色々な指標で出力されますが、上記のTotalが、最も時間がかかっているリクエストパスのランキングになります。
なので、ここでは/loginを改善すればパフォーマンスが出そう！ということが考察できます。

おまけ

リクエスト時間には関係ないですが、最も多いHTTPリクエストを昇順に表示するワンライナーです。
kataribeでも"Top 20 Sort By Count"で出力されますが、ワンライナーでさくっと表示したい場合はこちらで。

$ cat /var/log/nginx/access.log | awk '{print $7}' | sort | uniq -c | sort -n
      1 /report
    113 /mypage
    587 /login
   1060 /
   1173 /images/isucon-bank.png
   1173 /stylesheets/bootflat.min.css
   1173 /stylesheets/bootstrap.min.css
   1173 /stylesheets/isucon-bank.css