WEBサーバのログから簡単にレスポンスタイムの90%ile値を取得する

負荷テストでレスポンスタイムの合否判定をするとき、平均やMAXのレスポンスタイムではなく90%ile値や95%ile値を用いる。
異常に時間がかかっているリクエストが全体から見ると極少数でもあると、平均値に影響を及ぼすことがあるし、極少数のレスポンス遅延をもってして負荷テスト不合格とすることは通常しないため、上位90%のレスポンスタイム値を見る。

JMeterのような負荷テストツールを使っているとpercentile値を表示してくれる機能がついているのだが、percentile値の表示機能がない負荷テストツール（自作の負荷テストツールだったり、有名どころでもLocustは現在未対応のはず）を使用している場合に、WEBサーバのログから簡単にpercentile値を確認する方法も知っておきたい。

前提として、今回の例ではNginxのログにrequest_time:秒数と出力されるようにログのformatを設定しているとする。

Pythonのnumpyにpercentileという名前そのままなメソッドがある。簡単に確認したいので、ターミナル上ですぐに実行できるように書いてみる。

$ awk 'match($0, /request_time:([0-9\.]+)/, a){print a[1]}' /var/log/nginx/access.log |
python -c '
import numpy as np
import sys
a = np.loadtxt(sys.stdin)
print "90%ile:", np.percentile(a,90)
print "max:", np.amax(a)
print "total:", len(a)
'

標準出力にレスポンスタイムだけを出力し、それをPythonで受け取っている。numpy.loadtxtというメソッドがあり、ファイルや標準入力を読み込んでarrayにしてくれる。

arrayを作るときに、レスポンスタイムを全部スクリプトに書き込んで、それを実行する方法でもいい。

$ result=$(awk 'match($0, /request_time:([0-9\.]+)/, a){print a[1]}' /var/log/nginx/access.log | sed "s/$/,/")
$ cat <<EOF | python
import numpy as np
a = np.array([$result])
print "90%ile:", np.percentile(a,90)
print "max:", np.amax(a)
print "total:", len(a)
EOF

今回は全URLまとめてpercentile値を取得したが、負荷テストをするのであれば、本当はURLごとにpercentile値、max値、リクエスト数を出したほうがいい。はじめにレスポンスタイムの一覧をawkで取得するところを、URLごとに取得するように工夫すれば対応できるだろう。