ISUCONへの道~プロファイリングツール編~
こんばんは。
早速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