kataribe
kataribe はWebサーバーのアクセスログを解析してボトルネックを探すためのツール。
所定の形式で出力されたアクセスログを解析してレスポンスタイムを集計できる。
準備
kataribeのインストール
kataribeはGo言語で書かれているのでGo言語がインストールされている必要がある。
$ go install github.com/matsuu/kataribe@latest
$GOPATH/binにkataribeコマンドがインストールされる。
必要に応じて$GOPATH/binをPATHに追加しておくとよい。
kataribeの設定
kataribeの設定ファイルは以下のコマンドで生成できる。
$ kataribe -generate
カレントディレクトリにkataribe.tomlが生成される。
nginxのアクセスログの設定
nginxのアクセスログの設定は以下の通り。/etc/nginx/nginx.confなどの設定ファイルのhttpブロックに追加する。
log_format with_time '$remote_addr - $remote_user [$time_local] '
'"$request" $status $body_bytes_sent '
'"$http_referer" "$http_user_agent" $request_time';
access_log /var/log/nginx/access.log with_time;
参考: Apacheの場合
LogFormat "%h %l %u %t \"%r\" %>s %b \"%{Referer}i\" \"%{User-agent}i\" %D" with_time
CustomLog logs/access_log with_time
h2oなどその他Webサーバーについてはkataribe
のREADMEを参照。
kataribeでアクセスログを解析
kataribeでアクセスログを解析するには以下のコマンドを実行する。kataribe.tomlがあるディレクトリーで実行する。
$ sudo cat /var/log/nginx/access.log | kataribe
結果は標準出力に出力される。
Top 20 Sort By Count
Count Total Mean Stddev Min P50.0 P90.0 P95.0 P99.0 Max 2xx 3xx 4xx 5xx TotalBytes MinBytes MeanBytes MaxBytes Request
2665 506.536 0.1901 0.1346 0.001 0.167 0.379 0.449 0.522 0.566 2294 0 371 0 3502823 41 1314 3514 POST /login HTTP/1.1
457 90.984 0.1991 0.1356 0.013 0.198 0.395 0.451 0.523 0.551 440 0 17 0 3184402 0 6968 7305 POST /user HTTP/1.1
4 0.016 0.0040 0.0012 0.003 0.004 0.006 0.006 0.006 0.006 2 0 2 0 870 41 217 391 GET /user/1540414386/home HTTP/1.1
4 0.375 0.0938 0.0670 0.004 0.123 0.184 0.184 0.184 0.184 2 0 2 0 429 46 107 167 POST /admin/login HTTP/1.1
2 0.126 0.0630 0.0040 0.059 0.067 0.067 0.067 0.067 0.067 2 0 0 0 774 387 387 387 GET /user/5424374646/home HTTP/1.1
2 0.604 0.3020 0.1080 0.194 0.410 0.410 0.410 0.410 0.410 2 0 0 0 8828 2355 4414 6473 POST /user/100000070193/present/receive HTTP/1.1
2 0.366 0.1830 0.0750 0.108 0.258 0.258 0.258 0.258 0.258 2 0 0 0 7897 2095 3948 5802 GET /user/100000059776/present/index/1 HTTP/1.1
2 0.227 0.1135 0.0445 0.069 0.158 0.158 0.158 0.158 0.158 2 0 0 0 8828 2355 4414 6473 POST /user/100000029948/present/receive HTTP/1.1
2 0.569 0.2845 0.0505 0.234 0.335 0.335 0.335 0.335 0.335 2 0 0 0 7897 2095 3948 5802 GET /user/100000077380/present/index/1 HTTP/1.1
2 0.036 0.0180 0.0100 0.008 0.028 0.028 0.028 0.028 0.028 2 0 0 0 8597 2351 4298 6246 POST /user/100000005045/present/receive HTTP/1.1
2 0.296 0.1480 0.0280 0.120 0.176 0.176 0.176 0.176 0.176 2 0 0 0 7899 2097 3949 5802 GET /user/100000053758/present/index/1 HTTP/1.1
2 0.449 0.2245 0.0115 0.213 0.236 0.236 0.236 0.236 0.236 2 0 0 0 8826 2353 4413 6473 POST /user/100000073846/present/receive HTTP/1.1
2 0.027 0.0135 0.0055 0.008 0.019 0.019 0.019 0.019 0.019 2 0 0 0 8601 2355 4300 6246 POST /user/100000010915/present/receive HTTP/1.1
2 0.143 0.0715 0.0065 0.065 0.078 0.078 0.078 0.078 0.078 2 0 0 0 7900 2098 3950 5802 GET /user/100000029948/present/index/1 HTTP/1.1
2 0.408 0.2040 0.0640 0.140 0.268 0.268 0.268 0.268 0.268 2 0 0 0 7901 2099 3950 5802 GET /user/100000062067/present/index/1 HTTP/1.1
2 0.200 0.1000 0.0000 0.100 0.100 0.100 0.100 0.100 0.100 2 0 0 0 770 385 385 385 GET /user/908345872/home HTTP/1.1
2 0.243 0.1215 0.0625 0.059 0.184 0.184 0.184 0.184 0.184 2 0 0 0 7898 2096 3949 5802 GET /user/100000057300/present/index/1 HTTP/1.1
2 0.427 0.2135 0.0165 0.197 0.230 0.230 0.230 0.230 0.230 2 0 0 0 8827 2354 4413 6473 POST /user/100000062075/present/receive HTTP/1.1
2 0.281 0.1405 0.0095 0.131 0.150 0.150 0.150 0.150 0.150 2 0 0 0 7899 2097 3949 5802 GET /user/100000054781/present/index/1 HTTP/1.1
2 0.203 0.1015 0.0015 0.100 0.103 0.103 0.103 0.103 0.103 2 0 0 0 8827 2354 4413 6473 POST /user/100000033550/present/receive HTTP/1.1
Top 20 Sort By Total
Count Total Mean Stddev Min P50.0 P90.0 P95.0 P99.0 Max 2xx 3xx 4xx 5xx TotalBytes MinBytes MeanBytes MaxBytes Request
2665 506.536 0.1901 0.1346 0.001 0.167 0.379 0.449 0.522 0.566 2294 0 371 0 3502823 41 1314 3514 POST /login HTTP/1.1
457 90.984 0.1991 0.1356 0.013 0.198 0.395 0.451 0.523 0.551 440 0 17 0 3184402 0 6968 7305 POST /user HTTP/1.1
1 27.956 27.9560 0.0000 27.956 27.956 27.956 27.956 27.956 27.956 1 0 0 0 19 19 19 19 POST /initialize HTTP/1.1
2 0.894 0.4470 0.1070 0.340 0.554 0.554 0.554 0.554 0.554 2 0 0 0 8828 2355 4414 6473 POST /user/100000084001/present/receive HTTP/1.1
2 0.844 0.4220 0.1360 0.286 0.558 0.558 0.558 0.558 0.558 2 0 0 0 8828 2355 4414 6473 POST /user/100000083674/present/receive HTTP/1.1
2 0.840 0.4200 0.1230 0.297 0.543 0.543 0.543 0.543 0.543 2 0 0 0 8829 2356 4414 6473 POST /user/100000083447/present/receive HTTP/1.1
2 0.827 0.4135 0.1375 0.276 0.551 0.551 0.551 0.551 0.551 2 0 0 0 8827 2354 4413 6473 POST /user/100000084306/present/receive HTTP/1.1
2 0.826 0.4130 0.1280 0.285 0.541 0.541 0.541 0.541 0.541 2 0 0 0 8827 2354 4413 6473 POST /user/100000084717/present/receive HTTP/1.1
2 0.822 0.4110 0.1060 0.305 0.517 0.517 0.517 0.517 0.517 2 0 0 0 8828 2355 4414 6473 POST /user/100000083593/present/receive HTTP/1.1
2 0.820 0.4100 0.1150 0.295 0.525 0.525 0.525 0.525 0.525 2 0 0 0 8829 2356 4414 6473 POST /user/100000084802/present/receive HTTP/1.1
2 0.820 0.4100 0.1500 0.260 0.560 0.560 0.560 0.560 0.560 2 0 0 0 8826 2353 4413 6473 POST /user/100000084562/present/receive HTTP/1.1
2 0.818 0.4090 0.1400 0.269 0.549 0.549 0.549 0.549 0.549 2 0 0 0 8826 2353 4413 6473 POST /user/100000084750/present/receive HTTP/1.1
2 0.812 0.4060 0.1130 0.293 0.519 0.519 0.519 0.519 0.519 2 0 0 0 8826 2353 4413 6473 POST /user/100000084385/present/receive HTTP/1.1
2 0.760 0.3800 0.1070 0.273 0.487 0.487 0.487 0.487 0.487 2 0 0 0 8827 2354 4413 6473 POST /user/100000084988/present/receive HTTP/1.1
2 0.730 0.3650 0.1080 0.257 0.473 0.473 0.473 0.473 0.473 2 0 0 0 8828 2355 4414 6473 POST /user/100000083331/present/receive HTTP/1.1
2 0.718 0.3590 0.1050 0.254 0.464 0.464 0.464 0.464 0.464 2 0 0 0 7900 2098 3950 5802 GET /user/100000085515/present/index/1 HTTP/1.1
2 0.712 0.3560 0.0920 0.264 0.448 0.448 0.448 0.448 0.448 2 0 0 0 8825 2352 4412 6473 POST /user/100000083482/present/receive HTTP/1.1
2 0.695 0.3475 0.0335 0.314 0.381 0.381 0.381 0.381 0.381 2 0 0 0 8829 2356 4414 6473 POST /user/100000078964/present/receive HTTP/1.1
2 0.695 0.3475 0.0125 0.335 0.360 0.360 0.360 0.360 0.360 2 0 0 0 8827 2354 4413 6473 POST /user/100000078626/present/receive HTTP/1.1
2 0.680 0.3400 0.0320 0.308 0.372 0.372 0.372 0.372 0.372 2 0 0 0 8829 2356 4414 6473 POST /user/100000079109/present/receive HTTP/1.1
Top 20 Sort By Mean
Count Total Mean Stddev Min P50.0 P90.0 P95.0 P99.0 Max 2xx 3xx 4xx 5xx TotalBytes MinBytes MeanBytes MaxBytes Request
1 27.956 27.9560 0.0000 27.956 27.956 27.956 27.956 27.956 27.956 1 0 0 0 19 19 19 19 POST /initialize HTTP/1.1
1 0.509 0.5090 0.0000 0.509 0.509 0.509 0.509 0.509 0.509 1 0 0 0 1300 1300 1300 1300 GET /user/100000082003/item HTTP/1.1
1 0.506 0.5060 0.0000 0.506 0.506 0.506 0.506 0.506 0.506 1 0 0 0 1688 1688 1688 1688 GET /user/100000082730/item HTTP/1.1
1 0.504 0.5040 0.0000 0.504 0.504 0.504 0.504 0.504 0.504 1 0 0 0 387 387 387 387 GET /user/8618616429/home HTTP/1.1
1 0.503 0.5030 0.0000 0.503 0.503 0.503 0.503 0.503 0.503 1 0 0 0 388 388 388 388 GET /user/1743361944/home HTTP/1.1
1 0.500 0.5000 0.0000 0.500 0.500 0.500 0.500 0.500 0.500 1 0 0 0 386 386 386 386 GET /user/100000083447/home HTTP/1.1
1 0.500 0.5000 0.0000 0.500 0.500 0.500 0.500 0.500 0.500 1 0 0 0 1442 1442 1442 1442 GET /user/100000081987/item HTTP/1.1
1 0.498 0.4980 0.0000 0.498 0.498 0.498 0.498 0.498 0.498 1 0 0 0 1548 1548 1548 1548 GET /user/100000082926/item HTTP/1.1
1 0.498 0.4980 0.0000 0.498 0.498 0.498 0.498 0.498 0.498 1 0 0 0 2061 2061 2061 2061 POST /user/7019928330/gacha/draw/37/10 HTTP/1.1
1 0.496 0.4960 0.0000 0.496 0.496 0.496 0.496 0.496 0.496 1 0 0 0 389 389 389 389 GET /user/8629878440/home HTTP/1.1
1 0.496 0.4960 0.0000 0.496 0.496 0.496 0.496 0.496 0.496 1 0 0 0 1470 1470 1470 1470 GET /user/100000082473/item HTTP/1.1
1 0.494 0.4940 0.0000 0.494 0.494 0.494 0.494 0.494 0.494 1 0 0 0 388 388 388 388 GET /user/7303213429/home HTTP/1.1
1 0.493 0.4930 0.0000 0.493 0.493 0.493 0.493 0.493 0.493 1 0 0 0 388 388 388 388 GET /user/1009182962/home HTTP/1.1
1 0.493 0.4930 0.0000 0.493 0.493 0.493 0.493 0.493 0.493 1 0 0 0 1723 1723 1723 1723 GET /user/100000082447/item HTTP/1.1
1 0.493 0.4930 0.0000 0.493 0.493 0.493 0.493 0.493 0.493 1 0 0 0 386 386 386 386 GET /user/100000083285/home HTTP/1.1
1 0.492 0.4920 0.0000 0.492 0.492 0.492 0.492 0.492 0.492 1 0 0 0 1300 1300 1300 1300 GET /user/100000082704/item HTTP/1.1
1 0.491 0.4910 0.0000 0.491 0.491 0.491 0.491 0.491 0.491 1 0 0 0 1300 1300 1300 1300 GET /user/100000082786/item HTTP/1.1
1 0.491 0.4910 0.0000 0.491 0.491 0.491 0.491 0.491 0.491 1 0 0 0 1844 1844 1844 1844 GET /user/100000082324/item HTTP/1.1
1 0.490 0.4900 0.0000 0.490 0.490 0.490 0.490 0.490 0.490 1 0 0 0 386 386 386 386 GET /user/100000083593/home HTTP/1.1
1 0.487 0.4870 0.0000 0.487 0.487 0.487 0.487 0.487 0.487 1 0 0 0 2061 2061 2061 2061 POST /user/9041353175/gacha/draw/37/10 HTTP/1.1
Top 20 Sort By Standard Deviation
Count Total Mean Stddev Min P50.0 P90.0 P95.0 P99.0 Max 2xx 3xx 4xx 5xx TotalBytes MinBytes MeanBytes MaxBytes Request
2 0.605 0.3025 0.1595 0.143 0.462 0.462 0.462 0.462 0.462 2 0 0 0 8829 2356 4414 6473 POST /user/100000070255/present/receive HTTP/1.1
2 0.820 0.4100 0.1500 0.260 0.560 0.560 0.560 0.560 0.560 2 0 0 0 8826 2353 4413 6473 POST /user/100000084562/present/receive HTTP/1.1
2 0.818 0.4090 0.1400 0.269 0.549 0.549 0.549 0.549 0.549 2 0 0 0 8826 2353 4413 6473 POST /user/100000084750/present/receive HTTP/1.1
2 0.590 0.2950 0.1390 0.156 0.434 0.434 0.434 0.434 0.434 2 0 0 0 8828 2355 4414 6473 POST /user/100000070275/present/receive HTTP/1.1
2 0.827 0.4135 0.1375 0.276 0.551 0.551 0.551 0.551 0.551 2 0 0 0 8827 2354 4413 6473 POST /user/100000084306/present/receive HTTP/1.1
2 0.844 0.4220 0.1360 0.286 0.558 0.558 0.558 0.558 0.558 2 0 0 0 8828 2355 4414 6473 POST /user/100000083674/present/receive HTTP/1.1
457 90.984 0.1991 0.1356 0.013 0.198 0.395 0.451 0.523 0.551 440 0 17 0 3184402 0 6968 7305 POST /user HTTP/1.1
2665 506.536 0.1901 0.1346 0.001 0.167 0.379 0.449 0.522 0.566 2294 0 371 0 3502823 41 1314 3514 POST /login HTTP/1.1
2 0.586 0.2930 0.1330 0.160 0.426 0.426 0.426 0.426 0.426 2 0 0 0 8827 2354 4413 6473 POST /user/100000070211/present/receive HTTP/1.1
2 0.826 0.4130 0.1280 0.285 0.541 0.541 0.541 0.541 0.541 2 0 0 0 8827 2354 4413 6473 POST /user/100000084717/present/receive HTTP/1.1
2 0.628 0.3140 0.1240 0.190 0.438 0.438 0.438 0.438 0.438 2 0 0 0 8826 2353 4413 6473 POST /user/100000070205/present/receive HTTP/1.1
2 0.840 0.4200 0.1230 0.297 0.543 0.543 0.543 0.543 0.543 2 0 0 0 8829 2356 4414 6473 POST /user/100000083447/present/receive HTTP/1.1
2 0.615 0.3075 0.1205 0.187 0.428 0.428 0.428 0.428 0.428 2 0 0 0 8827 2354 4413 6473 POST /user/100000070552/present/receive HTTP/1.1
2 0.820 0.4100 0.1150 0.295 0.525 0.525 0.525 0.525 0.525 2 0 0 0 8829 2356 4414 6473 POST /user/100000084802/present/receive HTTP/1.1
2 0.812 0.4060 0.1130 0.293 0.519 0.519 0.519 0.519 0.519 2 0 0 0 8826 2353 4413 6473 POST /user/100000084385/present/receive HTTP/1.1
2 0.561 0.2805 0.1105 0.170 0.391 0.391 0.391 0.391 0.391 2 0 0 0 8825 2352 4412 6473 POST /user/100000070209/present/receive HTTP/1.1
2 0.604 0.3020 0.1080 0.194 0.410 0.410 0.410 0.410 0.410 2 0 0 0 8828 2355 4414 6473 POST /user/100000070193/present/receive HTTP/1.1
2 0.730 0.3650 0.1080 0.257 0.473 0.473 0.473 0.473 0.473 2 0 0 0 8828 2355 4414 6473 POST /user/100000083331/present/receive HTTP/1.1
2 0.894 0.4470 0.1070 0.340 0.554 0.554 0.554 0.554 0.554 2 0 0 0 8828 2355 4414 6473 POST /user/100000084001/present/receive HTTP/1.1
2 0.760 0.3800 0.1070 0.273 0.487 0.487 0.487 0.487 0.487 2 0 0 0 8827 2354 4413 6473 POST /user/100000084988/present/receive HTTP/1.1
Top 20 Sort By Maximum(100 Percentile)
Count Total Mean Stddev Min P50.0 P90.0 P95.0 P99.0 Max 2xx 3xx 4xx 5xx TotalBytes MinBytes MeanBytes MaxBytes Request
1 27.956 27.9560 0.0000 27.956 27.956 27.956 27.956 27.956 27.956 1 0 0 0 19 19 19 19 POST /initialize HTTP/1.1
2665 506.536 0.1901 0.1346 0.001 0.167 0.379 0.449 0.522 0.566 2294 0 371 0 3502823 41 1314 3514 POST /login HTTP/1.1
2 0.820 0.4100 0.1500 0.260 0.560 0.560 0.560 0.560 0.560 2 0 0 0 8826 2353 4413 6473 POST /user/100000084562/present/receive HTTP/1.1
2 0.844 0.4220 0.1360 0.286 0.558 0.558 0.558 0.558 0.558 2 0 0 0 8828 2355 4414 6473 POST /user/100000083674/present/receive HTTP/1.1
2 0.894 0.4470 0.1070 0.340 0.554 0.554 0.554 0.554 0.554 2 0 0 0 8828 2355 4414 6473 POST /user/100000084001/present/receive HTTP/1.1
2 0.827 0.4135 0.1375 0.276 0.551 0.551 0.551 0.551 0.551 2 0 0 0 8827 2354 4413 6473 POST /user/100000084306/present/receive HTTP/1.1
457 90.984 0.1991 0.1356 0.013 0.198 0.395 0.451 0.523 0.551 440 0 17 0 3184402 0 6968 7305 POST /user HTTP/1.1
2 0.818 0.4090 0.1400 0.269 0.549 0.549 0.549 0.549 0.549 2 0 0 0 8826 2353 4413 6473 POST /user/100000084750/present/receive HTTP/1.1
2 0.840 0.4200 0.1230 0.297 0.543 0.543 0.543 0.543 0.543 2 0 0 0 8829 2356 4414 6473 POST /user/100000083447/present/receive HTTP/1.1
2 0.826 0.4130 0.1280 0.285 0.541 0.541 0.541 0.541 0.541 2 0 0 0 8827 2354 4413 6473 POST /user/100000084717/present/receive HTTP/1.1
2 0.820 0.4100 0.1150 0.295 0.525 0.525 0.525 0.525 0.525 2 0 0 0 8829 2356 4414 6473 POST /user/100000084802/present/receive HTTP/1.1
2 0.812 0.4060 0.1130 0.293 0.519 0.519 0.519 0.519 0.519 2 0 0 0 8826 2353 4413 6473 POST /user/100000084385/present/receive HTTP/1.1
2 0.822 0.4110 0.1060 0.305 0.517 0.517 0.517 0.517 0.517 2 0 0 0 8828 2355 4414 6473 POST /user/100000083593/present/receive HTTP/1.1
1 0.509 0.5090 0.0000 0.509 0.509 0.509 0.509 0.509 0.509 1 0 0 0 1300 1300 1300 1300 GET /user/100000082003/item HTTP/1.1
1 0.506 0.5060 0.0000 0.506 0.506 0.506 0.506 0.506 0.506 1 0 0 0 1688 1688 1688 1688 GET /user/100000082730/item HTTP/1.1
1 0.504 0.5040 0.0000 0.504 0.504 0.504 0.504 0.504 0.504 1 0 0 0 387 387 387 387 GET /user/8618616429/home HTTP/1.1
1 0.503 0.5030 0.0000 0.503 0.503 0.503 0.503 0.503 0.503 1 0 0 0 388 388 388 388 GET /user/1743361944/home HTTP/1.1
1 0.500 0.5000 0.0000 0.500 0.500 0.500 0.500 0.500 0.500 1 0 0 0 1442 1442 1442 1442 GET /user/100000081987/item HTTP/1.1
1 0.500 0.5000 0.0000 0.500 0.500 0.500 0.500 0.500 0.500 1 0 0 0 386 386 386 386 GET /user/100000083447/home HTTP/1.1
1 0.498 0.4980 0.0000 0.498 0.498 0.498 0.498 0.498 0.498 1 0 0 0 1548 1548 1548 1548 GET /user/100000082926/item HTTP/1.1
TOP 37 Slow Requests
1 27.956 POST /initialize HTTP/1.1
2 0.566 POST /login HTTP/1.1
3 0.560 POST /user/100000084562/present/receive HTTP/1.1
4 0.558 POST /user/100000083674/present/receive HTTP/1.1
5 0.556 POST /login HTTP/1.1
6 0.554 POST /user/100000084001/present/receive HTTP/1.1
7 0.552 POST /login HTTP/1.1
8 0.552 POST /login HTTP/1.1
9 0.551 POST /user/100000084306/present/receive HTTP/1.1
10 0.551 POST /user HTTP/1.1
11 0.549 POST /user/100000084750/present/receive HTTP/1.1
12 0.543 POST /user HTTP/1.1
13 0.543 POST /user/100000083447/present/receive HTTP/1.1
14 0.543 POST /login HTTP/1.1
15 0.542 POST /login HTTP/1.1
16 0.541 POST /user/100000084717/present/receive HTTP/1.1
17 0.540 POST /login HTTP/1.1
18 0.539 POST /login HTTP/1.1
19 0.538 POST /login HTTP/1.1
20 0.536 POST /login HTTP/1.1
21 0.534 POST /login HTTP/1.1
22 0.534 POST /login HTTP/1.1
23 0.533 POST /login HTTP/1.1
24 0.532 POST /login HTTP/1.1
25 0.531 POST /login HTTP/1.1
26 0.531 POST /login HTTP/1.1
27 0.531 POST /login HTTP/1.1
28 0.530 POST /login HTTP/1.1
29 0.529 POST /login HTTP/1.1
30 0.529 POST /login HTTP/1.1
31 0.528 POST /user HTTP/1.1
32 0.528 POST /login HTTP/1.1
33 0.528 POST /login HTTP/1.1
34 0.525 POST /login HTTP/1.1
35 0.525 POST /user/100000084802/present/receive HTTP/1.1
36 0.524 POST /login HTTP/1.1
37 0.524 POST /login HTTP/1.1
設定ファイルの場所を指定して実行する
kataribe.tomlがおいてある場所と異なるディレクトリでkataribeを実行する場合はkataribeコマンドに--confオプションを指定する。
$ sudo cat /var/log/nginx/access.log | kataribe --conf /path/to/kataribe.toml
出力結果に含まれる情報
URLごとの集計の種類
集計の種類ごとに20件ずつ出力される。
集計の種類は以下の通り
- Top 20 Sort By Count: リクエスト回数の多い順
- Top 20 Sort By Total: リクエストの合計時間の多い順
- Top 20 Sort By Mean: リクエストの平均時間の多い順
- Top 20 Sort By Standard Deviation: リクエストの標準偏差の多い順
- Top 20 Sort By Maximum(100 Percentile): リクエストの最大値の多い順
集計の種類ごとの出力項目
それぞれの集計テーブルの項目は以下の通り。
- Count: リクエスト回数
- Total: リクエストの合計時間
- Mean: リクエストの平均時間
- Stddev: リクエストの標準偏差
- Min: リクエストの最小値
- P50.0: リクエストの50パーセンタイル
- P90.0: リクエストの90パーセンタイル
- P95.0: リクエストの95パーセンタイル
- P99.0: リクエストの99パーセンタイル
- Max: リクエストの最大値
- 2xx: 200番台のステータスコードでレスポンスしたリクエスト回数
- 3xx: 300番台のステータスコードでレスポンスしたリクエスト回数
- 4xx: 400番台のステータスコードでレスポンスしたリクエスト回数
- 5xx: 500番台のステータスコードでレスポンスしたリクエスト回数
- TotalBytes: リクエストの合計バイト数
- MinBytes: リクエストの最小バイト数
- MeanBytes: リクエストの平均バイト数
- MaxBytes: リクエストの最大バイト数
- Request: リクエストのHTTPメソッド、パス、HTTPバージョン
Slow Requests
出力結果の最後にSlow Requestとして時間がかかったリクエストの一覧が出力される。
パスパラメータの違いを無視してまとめる
集計結果を見ると以下のようにリクエストがパスパラメータのみ異なるものが多く存在する。
GET /user/100000059776/present/index/1 HTTP/1.1
GET /user/100000077380/present/index/1 HTTP/1.1
GET /user/100000053758/present/index/1 HTTP/1.1
GET /user/100000029948/present/index/1 HTTP/1.1
GET /user/100000062067/present/index/1 HTTP/1.1
GET /user/100000057300/present/index/1 HTTP/1.1
GET /user/100000054781/present/index/1 HTTP/1.1
POST /user/100000070193/present/receive HTTP/1.1
POST /user/100000029948/present/receive HTTP/1.1
POST /user/100000005045/present/receive HTTP/1.1
POST /user/100000073846/present/receive HTTP/1.1
POST /user/100000010915/present/receive HTTP/1.1
POST /user/100000062075/present/receive HTTP/1.1
POST /user/100000033550/present/receive HTTP/1.1
上記はそれぞれget '/user/:user_id/present/index/:n'や、post '/user/:user_id/present/receive'というルーティングで実装されたものであり、
同じ実装を修正すると一気に改善できる。
このような場合、パスパラメータの違いを無視してまとめたい。
上記のようなパスパラメータをまとめるにはkataribe.tomlに以下のように設定する。
[[replace]]
regexp = '/[0-9]+/'
replace = '/<ID>/'
[[replace]]
regexp = '/[0-9]+(\s)'
replace = '/<ID>$1'
上記設定は数字のみからなるパスパラメータを<ID>に置き換える。
上記設定で再度実行すると以下のようにパスパラメータをまとめた結果が出力される。
Top 20 Sort By Count
(...省略) Request
(...省略) GET /user/<ID>/present/index/<ID> HTTP/1.1
(...省略) GET /user/<ID>/home HTTP/1.1
(...省略) POST /login HTTP/1.1
(...省略) GET /user/<ID>/gacha/index HTTP/1.1
(...省略) POST /user/<ID>/gacha/draw/<ID>/<ID> HTTP/1.1
(...省略) POST /user/<ID>/present/receive HTTP/1.1
(...省略) POST /user/<ID>/reward HTTP/1.1
(...省略) POST /user HTTP/1.1
(...省略) GET /user/<ID>/item HTTP/1.1
(...省略) POST /user/<ID>/card/addexp/<ID> HTTP/1.1
(...省略) POST /user/<ID>/card HTTP/1.1
(...省略) POST /admin/login HTTP/1.1
(...省略) DELETE /admin/logout HTTP/1.1
(...省略) GET /admin/user/<ID> HTTP/1.1
(...省略) GET /admin/master HTTP/1.1
(...省略) GET /druid/index.html HTTP/1.1
(...省略) GET /.env HTTP/1.1
(...省略) POST /initialize HTTP/1.1
(...省略) POST /admin/user/<ID>/ban HTTP/1.1
(...省略) PUT /admin/master HTTP/1.1
・
・
・
解析結果でよく見る情報
Top 20 Sort By Total上位のリクエストのうち、Countが少ないものは1回のリクエストに時間がかかっているということであり、
処理の速度改善により向上が期待できる。
また、Top 20 Sort By Count上位のリクエストを確認すると、JavaScriptによる非同期呼び出しなどで不要に呼び出されているURLを発見できたりする。
TIPS: アクセスログを削除して負荷テストする
kataribeは渡されたアクセスログすべてを読み込んで処理するため、負荷テストを行なう際にはアクセスログを削除しておくとよい。
削除しないと、負荷テスト前のアクセスログも処理されるため、解析結果が正しく出力されない。
＼第一線のプログラマーの行動原理を学べる！／
