こんばんは。
早速ISUCONに向けてプロファイリングツールを試して行きたいと思います。
# alpの導入
github.com
alp is Access Log Profile
alpとはAccess Log Profileの略なんですね。
とりあえず導入していきます。
// alpをダウンロード
$ wget https://github.com/tkuchiki/alp/releases/download/v0.0.4/alp_linux_amd64.zip
// zipを解凍するためにunzipをインストール
$ sudo apt install unzip
$ unzip alp_linux_amd64.zip
$ sudo mv alp /usr/local/bin/alp
$ sudo chown root:root /usr/local/bin/alp
これでalpの準備は万端です。
次にnginxの設定を修正指定いきます。
/etc/nginx/conf.d/log_format.confを新規に作り、下記を入力します。
下記では、access.logをalpが読み込めるフォーマットに整える設定です。
log_format ltsv "time:$time_local"
"\thost:$remote_addr"
"\tforwardedfor:$http_x_forwarded_for"
"\treq:$request"
"\tstatus:$status"
"\tmethod:$request_method"
"\turi:$request_uri"
"\tsize:$body_bytes_sent"
"\treferer:$http_referer"
"\tua:$http_user_agent"
"\treqtime:$request_time"
"\tcache:$upstream_http_x_cache"
"\truntime:$upstream_http_x_runtime"
"\tapptime:$upstream_response_time"
"\tvhost:$host";
access_log /var/log/nginx/access.log ltsv;
次に、これを読み込むためにnginx.confを修正します。
httpタグの中にincludeすることにより、log_format.confを展開してくれます。
http {
...
include /etc/nginx/conf.d/*.conf;
...
}
nginxを再起動します。
$ sudo nginx -s reload
これでnginxの設定も完了しました。
alpを実行してみます。
$ sudo alp -f /var/log/nginx/access.log
こんな感じで出力されます。
# alpの使い方
これでalpを使ったログの解析ができましたが、これらのデータをどうみていけば良いか考えて行きましょう。
alpではアクセスされたエントリポイントごとに集計を行います。
したがって、列で表されているデータはエントリポイントごとの値となります。
| 名前 |
概要 |
備考 |
| max |
最長レスポンスの時間 |
|
| min |
最短レスポンスの時間 |
|
| avg |
全レスポンス時間の平均 |
|
| sum |
全レスポンス時間の合計 |
|
| cnt |
アクセス数 |
|
| uri |
URI |
|
| method |
メソッド |
|
| max-body |
最大のボディサイズ |
|
| min-body |
最少のボディサイズ |
|
| avg-body |
平均のボディサイズ |
|
| sum-body |
合計ボディサイズ |
|
| p1 |
1パーセンタイルのレスポンス時間 |
小さい方から1%目の時間 |
| p50 |
50パーセンタイルのレスポンス時間 |
中央値 |
| p99 |
99パーセンタイルのレスポンス時間 |
小さい方から99%目の時間 |
| stddev |
レスポンス時間の標準偏差 |
|
となっています。
例として、max,sum,cntあたりを見てチューニングの当たりをつけてみましょう。
max
sum
count
maxを見るに、/が最大7秒の時間がかかっており、/keyword/xxxといったアクセスに関しても4秒程度の時間がかかっていることがわかる。
sumを見ても、/が700秒と断トツにアクセスが来ているため、/を最適化すると効きそうな気がします。
ついで、POSTのエントリポイントである/login,/keyword,/starsが上位に並んでおり、これらも改善の余地があると思われます。
最後にcntを見ると、/starsが940回も来ているのがわかります。ただ、1アクセスあたりの時間がそこまでかかっていないので、改善してもあまり効果がないかもしれません。
これらを見る限り、とりあえずは/を最適化し、ついで/login, /keyword, /starsのPOST, /keyword/xxxのGETを最適化すれば良いかと思われます。
大会の時には、何回もベンチマークを回すため、ベンチマークを回す前にログをローテート、解析結果をslackに連携などできると良さそうです。
# 参考
papix.hatenablog.com
