alpの使い方

63 min読了の目安(約57500字TECH技術記事

主にISUCONで使われているアクセスログ集計ツール alp の使い方を、ISUCON10オンライン予選問題のアクセスログを例に紹介します。

https://github.com/tkuchiki/alp

執筆時現在の最新バージョンはv1.0.3です。

インストール方法

https://github.com/tkuchiki/alp/releases 上のバイナリをダウンロードして利用することができます。
また、以下の方法でインストールすることもできます。

macOS

$ brew install alp

asdf

$ asdf plugin-add alp https://github.com/asdf-community/asdf-alp.git
$ asdf install alp <バージョン>
$ asdf global alp <バージョン>

サポートしているログフォーマット

alpは以下のログフォーマットをサポートしています。

また、解析するログフォーマットを正規表現で記述する機能もあるため、テキストフォーマットであればどのようなフォーマットのログでも解析することができます。

設定

alpでアクセスログを集計する前に、集計できるログフォーマットに変更する必要があります。
ドキュメントにログフォーマットごとのApache, Nginx, H2Oの設定例を記載していますのでそちらを参照してください。

使い方

alpはltsv, json, regexpの3つのサブコマンドで構成されています。

$ alp --help
usage: alp [<flags>] <command> [<args> ...]

alp is the access log profiler for LTSV, JSON, and others.

Flags:
      --help               Show context-sensitive help (also try --help-long and --help-man).
  -c, --config=CONFIG      The configuration file
      --file=FILE          The access log file
  -d, --dump=DUMP          Dump profiled data as YAML
  -l, --load=LOAD          Load the profiled YAML data
      --sort=count         Output the results in sorted order
  -r, --reverse            Sort results in reverse order
  -q, --query-string       Include the URI query string.
      --format=table       The output format (table, markdown, tsv and csv)
      --noheaders          Output no header line at all (only --format=tsv, csv)
      --show-footers       Output footer line at all (only --format=table, markdown)
      --limit=5000         The maximum number of results to display.
      --location=Local     Location name for the timezone
  -o, --output=all         Specifies the results to display, separated by commas
  -m, --matching-groups=PATTERN,...
                           Specifies URI matching groups separated by commas
  -f, --filters=FILTERS    Only the logs are profiled that match the conditions
      --pos=POSITION_FILE  The position file
      --nosave-pos         Do not save position file
      --version            Show application version.

Commands:
  help [<command>...]
    Show help.

  ltsv [<flags>]
    Profile the logs for LTSV

  json [<flags>]
    Profile the logs for JSON

  regexp [<flags>]
    Profile the logs that match a regular expression

ISUCON10オンライン予選問題のアクセスログ(JSON)を例に使い方を説明します。

まずは、何もオプションを指定しないで実行します。

$ cat /path/to/access.log | alp json
+-------+-----+-----+-----+-----+-----+--------+------------------------------+-------+-------+-------+-------+-------+-------+-------+--------+-----------+-----------+------------+-----------+
| COUNT | 1XX | 2XX | 3XX | 4XX | 5XX | METHOD |             URI              |  MIN  |  MAX  |  SUM  |  AVG  |  P1   |  P50  |  P99  | STDDEV | MIN(BODY) | MAX(BODY) | SUM(BODY)  | AVG(BODY) |
+-------+-----+-----+-----+-----+-----+--------+------------------------------+-------+-------+-------+-------+-------+-------+-------+--------+-----------+-----------+------------+-----------+
|     1 |   0 |   1 |   0 |   0 |   0 | GET    | /api/recommended_estate/24   | 1.140 | 1.140 | 1.140 | 1.140 | 1.140 | 1.140 | 1.140 |  0.000 | 13253.000 | 13253.000 |  13253.000 | 13253.000 |
|     1 |   0 |   1 |   0 |   0 |   0 | GET    | /api/estate/8654             | 0.004 | 0.004 | 0.004 | 0.004 | 0.004 | 0.004 | 0.004 |  0.000 |   667.000 |   667.000 |    667.000 |   667.000 |
|     1 |   0 |   1 |   0 |   0 |   0 | GET    | /api/estate/15302            | 0.004 | 0.004 | 0.004 | 0.004 | 0.004 | 0.004 | 0.004 |  0.000 |   542.000 |   542.000 |    542.000 |   542.000 |
|     1 |   0 |   1 |   0 |   0 |   0 | GET    | /api/chair/53                | 0.008 | 0.008 | 0.008 | 0.008 | 0.008 | 0.008 | 0.008 |  0.000 |   584.000 |   584.000 |    584.000 |   584.000 |
|     1 |   0 |   1 |   0 |   0 |   0 | GET    | /api/estate/51               | 0.012 | 0.012 | 0.012 | 0.012 | 0.012 | 0.012 | 0.012 |  0.000 |   615.000 |   615.000 |    615.000 |   615.000 |
|     1 |   0 |   1 |   0 |   0 |   0 | GET    | /api/chair/11534             | 0.004 | 0.004 | 0.004 | 0.004 | 0.004 | 0.004 | 0.004 |  0.000 |   512.000 |   512.000 |    512.000 |   512.000 |
|     1 |   0 |   1 |   0 |   0 |   0 | GET    | /api/chair/21                | 0.016 | 0.016 | 0.016 | 0.016 | 0.016 | 0.016 | 0.016 |  0.000 |   544.000 |   544.000 |    544.000 |   544.000 |
|     1 |   0 |   1 |   0 |   0 |   0 | GET    | /api/chair/85                | 0.016 | 0.016 | 0.016 | 0.016 | 0.016 | 0.016 | 0.016 |  0.000 |   535.000 |   535.000 |    535.000 |   535.000 |
|     1 |   0 |   1 |   0 |   0 |   0 | GET    | /api/chair/50                | 0.016 | 0.016 | 0.016 | 0.016 | 0.016 | 0.016 | 0.016 |  0.000 |   527.000 |   527.000 |    527.000 |   527.000 |
|     1 |   0 |   1 |   0 |   0 |   0 | POST   | /api/chair/buy/29501         | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 |  0.000 |     0.000 |     0.000 |      0.000 |     0.000 |
|     1 |   0 |   1 |   0 |   0 |   0 | GET    | /api/chair/65                | 0.020 | 0.020 | 0.020 | 0.020 | 0.020 | 0.020 | 0.020 |  0.000 |   486.000 |   486.000 |    486.000 |   486.000 |
|     1 |   0 |   1 |   0 |   0 |   0 | GET    | /api/estate/26               | 0.020 | 0.020 | 0.020 | 0.020 | 0.020 | 0.020 | 0.020 |  0.000 |   651.000 |   651.000 |    651.000 |   651.000 |
|     1 |   0 |   1 |   0 |   0 |   0 | GET    | /api/estate/76               | 0.020 | 0.020 | 0.020 | 0.020 | 0.020 | 0.020 | 0.020 |  0.000 |   634.000 |   634.000 |    634.000 |   634.000 |
|     1 |   0 |   1 |   0 |   0 |   0 | GET    | /api/estate/64               | 0.020 | 0.020 | 0.020 | 0.020 | 0.020 | 0.020 | 0.020 |  0.000 |   638.000 |   638.000 |    638.000 |   638.000 |
|     1 |   0 |   1 |   0 |   0 |   0 | GET    | /api/estate/35               | 0.024 | 0.024 | 0.024 | 0.024 | 0.024 | 0.024 | 0.024 |  0.000 |   634.000 |   634.000 |    634.000 |   634.000 |
|     1 |   0 |   1 |   0 |   0 |   0 | POST   | /initialize                  | 7.524 | 7.524 | 7.524 | 7.524 | 7.524 | 7.524 | 7.524 |  0.000 |    23.000 |    23.000 |     23.000 |    23.000 |
|     1 |   0 |   1 |   0 |   0 |   0 | POST   | /api/chair                   | 0.032 | 0.032 | 0.032 | 0.032 | 0.032 | 0.032 | 0.032 |  0.000 |     0.000 |     0.000 |      0.000 |     0.000 |
|     1 |   0 |   1 |   0 |   0 |   0 | POST   | /api/estate                  | 0.020 | 0.020 | 0.020 | 0.020 | 0.020 | 0.020 | 0.020 |  0.000 |     0.000 |     0.000 |      0.000 |     0.000 |
|     1 |   0 |   1 |   0 |   0 |   0 | GET    | /api/recommended_estate/17   | 1.284 | 1.284 | 1.284 | 1.284 | 1.284 | 1.284 | 1.284 |  0.000 | 13430.000 | 13430.000 |  13430.000 | 13430.000 |
|     1 |   0 |   1 |   0 |   0 |   0 | GET    | /api/recommended_estate/42   | 1.000 | 1.000 | 1.000 | 1.000 | 1.000 | 1.000 | 1.000 |  0.000 | 13690.000 | 13690.000 |  13690.000 | 13690.000 |
|     1 |   0 |   1 |   0 |   0 |   0 | POST   | /api/estate/req_doc/8654     | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 |  0.000 |     0.000 |     0.000 |      0.000 |     0.000 |
|     2 |   0 |   2 |   0 |   0 |   0 | GET    | /api/recommended_estate/61   | 0.956 | 0.972 | 1.928 | 0.964 | 0.956 | 0.956 | 0.956 |  0.008 | 13682.000 | 13682.000 |  27364.000 | 13682.000 |
|     2 |   0 |   1 |   0 |   1 |   0 | GET    | /api/estate/29501            | 0.004 | 0.004 | 0.004 | 0.002 | 0.000 | 0.000 | 0.000 |  0.002 |   616.000 |   616.000 |    616.000 |   308.000 |
|     4 |   0 |   2 |   0 |   2 |   0 | GET    | /api/chair/29501             | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 |  0.000 |     0.000 |   542.000 |   1084.000 |   271.000 |
|     4 |   0 |   4 |   0 |   0 |   0 | GET    | /api/chair/search/condition  | 0.000 | 0.004 | 0.008 | 0.002 | 0.004 | 0.004 | 0.000 |  0.002 |  3392.000 |  3392.000 |  13568.000 |  3392.000 |
|     4 |   0 |   4 |   0 |   0 |   0 | GET    | /api/estate/search/condition | 0.000 | 0.004 | 0.004 | 0.001 | 0.004 | 0.000 | 0.000 |  0.002 |  2563.000 |  2563.000 |  10252.000 |  2563.000 |
|     5 |   0 |   5 |   0 |   0 |   0 | POST   | /api/estate/nazotte          | 0.024 | 0.404 | 1.056 | 0.211 | 0.024 | 0.044 | 0.328 |  0.152 |    34.000 | 33925.000 |  67433.000 | 13486.600 |
|     8 |   0 |   8 |   0 |   0 |   0 | GET    | /api/chair/low_priced        | 0.000 | 0.020 | 0.020 | 0.003 | 0.020 | 0.000 | 0.000 |  0.007 | 12153.000 | 12153.000 |  97224.000 | 12153.000 |
|     8 |   0 |   8 |   0 |   0 |   0 | GET    | /api/estate/low_priced       | 0.000 | 0.016 | 0.036 | 0.005 | 0.016 | 0.004 | 0.000 |  0.005 | 13397.000 | 13397.000 | 107176.000 | 13397.000 |
|    21 |   0 |  21 |   0 |   0 |   0 | GET    | /api/chair/search            | 0.028 | 0.232 | 2.364 | 0.113 | 0.120 | 0.128 | 0.044 |  0.061 |    33.000 | 20139.000 | 280994.000 | 13380.667 |
|    21 |   0 |  21 |   0 |   0 |   0 | GET    | /api/estate/search           | 0.040 | 0.708 | 4.880 | 0.232 | 0.612 | 0.092 | 0.116 |  0.230 |   728.000 | 27368.000 | 354375.000 | 16875.000 |
+-------+-----+-----+-----+-----+-----+--------+------------------------------+-------+-------+-------+-------+-------+-------+-------+--------+-----------+-----------+------------+-----------+

デフォルトでは、COUNTの昇順でソートし、URIはQuery Stringを省略した状態で集計、テーブル形式で出力します。

アクセスログの集計結果を眺めると、/api/estate/8654/api/estate/15302など、同じようなURIが多いことに気がつきます。これらは、同じhandlerで処理されるので一つのURIとして集計したほうが良いことが多いでしょう。そのようなケースで役立つのが-mです。

$ cat /path/to/access.log | alp json -m '/api/estate/[0-9]+'
+-------+-----+-----+-----+-----+-----+--------+------------------------------+-------+-------+-------+-------+-------+-------+-------+--------+-----------+-----------+------------+-----------+
| COUNT | 1XX | 2XX | 3XX | 4XX | 5XX | METHOD |             URI              |  MIN  |  MAX  |  SUM  |  AVG  |  P1   |  P50  |  P99  | STDDEV | MIN(BODY) | MAX(BODY) | SUM(BODY)  | AVG(BODY) |
+-------+-----+-----+-----+-----+-----+--------+------------------------------+-------+-------+-------+-------+-------+-------+-------+--------+-----------+-----------+------------+-----------+
|     1 |   0 |   1 |   0 |   0 |   0 | GET    | /api/recommended_estate/42   | 1.000 | 1.000 | 1.000 | 1.000 | 1.000 | 1.000 | 1.000 |  0.000 | 13690.000 | 13690.000 |  13690.000 | 13690.000 |
|     1 |   0 |   1 |   0 |   0 |   0 | GET    | /api/chair/11534             | 0.004 | 0.004 | 0.004 | 0.004 | 0.004 | 0.004 | 0.004 |  0.000 |   512.000 |   512.000 |    512.000 |   512.000 |
|     1 |   0 |   1 |   0 |   0 |   0 | POST   | /api/chair/buy/29501         | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 |  0.000 |     0.000 |     0.000 |      0.000 |     0.000 |
|     1 |   0 |   1 |   0 |   0 |   0 | GET    | /api/chair/53                | 0.008 | 0.008 | 0.008 | 0.008 | 0.008 | 0.008 | 0.008 |  0.000 |   584.000 |   584.000 |    584.000 |   584.000 |
|     1 |   0 |   1 |   0 |   0 |   0 | POST   | /api/chair                   | 0.032 | 0.032 | 0.032 | 0.032 | 0.032 | 0.032 | 0.032 |  0.000 |     0.000 |     0.000 |      0.000 |     0.000 |
|     1 |   0 |   1 |   0 |   0 |   0 | POST   | /api/estate                  | 0.020 | 0.020 | 0.020 | 0.020 | 0.020 | 0.020 | 0.020 |  0.000 |     0.000 |     0.000 |      0.000 |     0.000 |
|     1 |   0 |   1 |   0 |   0 |   0 | GET    | /api/chair/21                | 0.016 | 0.016 | 0.016 | 0.016 | 0.016 | 0.016 | 0.016 |  0.000 |   544.000 |   544.000 |    544.000 |   544.000 |
|     1 |   0 |   1 |   0 |   0 |   0 | GET    | /api/chair/85                | 0.016 | 0.016 | 0.016 | 0.016 | 0.016 | 0.016 | 0.016 |  0.000 |   535.000 |   535.000 |    535.000 |   535.000 |
|     1 |   0 |   1 |   0 |   0 |   0 | GET    | /api/chair/50                | 0.016 | 0.016 | 0.016 | 0.016 | 0.016 | 0.016 | 0.016 |  0.000 |   527.000 |   527.000 |    527.000 |   527.000 |
|     1 |   0 |   1 |   0 |   0 |   0 | GET    | /api/recommended_estate/17   | 1.284 | 1.284 | 1.284 | 1.284 | 1.284 | 1.284 | 1.284 |  0.000 | 13430.000 | 13430.000 |  13430.000 | 13430.000 |
|     1 |   0 |   1 |   0 |   0 |   0 | GET    | /api/chair/65                | 0.020 | 0.020 | 0.020 | 0.020 | 0.020 | 0.020 | 0.020 |  0.000 |   486.000 |   486.000 |    486.000 |   486.000 |
|     1 |   0 |   1 |   0 |   0 |   0 | GET    | /api/recommended_estate/24   | 1.140 | 1.140 | 1.140 | 1.140 | 1.140 | 1.140 | 1.140 |  0.000 | 13253.000 | 13253.000 |  13253.000 | 13253.000 |
|     1 |   0 |   1 |   0 |   0 |   0 | POST   | /initialize                  | 7.524 | 7.524 | 7.524 | 7.524 | 7.524 | 7.524 | 7.524 |  0.000 |    23.000 |    23.000 |     23.000 |    23.000 |
|     1 |   0 |   1 |   0 |   0 |   0 | POST   | /api/estate/req_doc/8654     | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 |  0.000 |     0.000 |     0.000 |      0.000 |     0.000 |
|     2 |   0 |   2 |   0 |   0 |   0 | GET    | /api/recommended_estate/61   | 0.956 | 0.972 | 1.928 | 0.964 | 0.956 | 0.956 | 0.956 |  0.008 | 13682.000 | 13682.000 |  27364.000 | 13682.000 |
|     4 |   0 |   4 |   0 |   0 |   0 | GET    | /api/chair/search/condition  | 0.000 | 0.004 | 0.008 | 0.002 | 0.004 | 0.004 | 0.000 |  0.002 |  3392.000 |  3392.000 |  13568.000 |  3392.000 |
|     4 |   0 |   4 |   0 |   0 |   0 | GET    | /api/estate/search/condition | 0.000 | 0.004 | 0.004 | 0.001 | 0.004 | 0.000 | 0.000 |  0.002 |  2563.000 |  2563.000 |  10252.000 |  2563.000 |
|     4 |   0 |   2 |   0 |   2 |   0 | GET    | /api/chair/29501             | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 |  0.000 |     0.000 |   542.000 |   1084.000 |   271.000 |
|     5 |   0 |   5 |   0 |   0 |   0 | POST   | /api/estate/nazotte          | 0.024 | 0.404 | 1.056 | 0.211 | 0.024 | 0.044 | 0.328 |  0.152 |    34.000 | 33925.000 |  67433.000 | 13486.600 |
|     8 |   0 |   8 |   0 |   0 |   0 | GET    | /api/chair/low_priced        | 0.000 | 0.020 | 0.020 | 0.003 | 0.020 | 0.000 | 0.000 |  0.007 | 12153.000 | 12153.000 |  97224.000 | 12153.000 |
|     8 |   0 |   8 |   0 |   0 |   0 | GET    | /api/estate/low_priced       | 0.000 | 0.016 | 0.036 | 0.005 | 0.016 | 0.004 | 0.000 |  0.005 | 13397.000 | 13397.000 | 107176.000 | 13397.000 |
|     9 |   0 |   8 |   0 |   1 |   0 | GET    | /api/estate/[0-9]+           | 0.004 | 0.024 | 0.108 | 0.012 | 0.012 | 0.020 | 0.004 |  0.009 |   542.000 |   667.000 |   4997.000 |   555.222 |
|    21 |   0 |  21 |   0 |   0 |   0 | GET    | /api/estate/search           | 0.040 | 0.708 | 4.880 | 0.232 | 0.612 | 0.092 | 0.116 |  0.230 |   728.000 | 27368.000 | 354375.000 | 16875.000 |
|    21 |   0 |  21 |   0 |   0 |   0 | GET    | /api/chair/search            | 0.028 | 0.232 | 2.364 | 0.113 | 0.120 | 0.128 | 0.044 |  0.061 |    33.000 | 20139.000 | 280994.000 | 13380.667 |
+-------+-----+-----+-----+-----+-----+--------+------------------------------+-------+-------+-------+-------+-------+-------+-------+--------+-----------+-----------+------------+-----------+

/api/estate/8654/api/estate/15302などが/api/estate/[0-9]+にまとめられています。このように-mは正規表現にマッチしたURIをひとつのURIとして集計する機能です。カンマ区切りで複数指定することも可能です。

$ cat /path/to/access.log | alp json -m '/api/estate/[0-9]+,/api/chair/[0-9]+,/api/recommended_estate/[0-9]+'
+-------+-----+-----+-----+-----+-----+--------+--------------------------------+-------+-------+-------+-------+-------+-------+-------+--------+-----------+-----------+------------+-----------+
| COUNT | 1XX | 2XX | 3XX | 4XX | 5XX | METHOD |              URI               |  MIN  |  MAX  |  SUM  |  AVG  |  P1   |  P50  |  P99  | STDDEV | MIN(BODY) | MAX(BODY) | SUM(BODY)  | AVG(BODY) |
+-------+-----+-----+-----+-----+-----+--------+--------------------------------+-------+-------+-------+-------+-------+-------+-------+--------+-----------+-----------+------------+-----------+
|     1 |   0 |   1 |   0 |   0 |   0 | POST   | /initialize                    | 7.524 | 7.524 | 7.524 | 7.524 | 7.524 | 7.524 | 7.524 |  0.000 |    23.000 |    23.000 |     23.000 |    23.000 |
|     1 |   0 |   1 |   0 |   0 |   0 | POST   | /api/chair/buy/29501           | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 |  0.000 |     0.000 |     0.000 |      0.000 |     0.000 |
|     1 |   0 |   1 |   0 |   0 |   0 | POST   | /api/chair                     | 0.032 | 0.032 | 0.032 | 0.032 | 0.032 | 0.032 | 0.032 |  0.000 |     0.000 |     0.000 |      0.000 |     0.000 |
|     1 |   0 |   1 |   0 |   0 |   0 | POST   | /api/estate                    | 0.020 | 0.020 | 0.020 | 0.020 | 0.020 | 0.020 | 0.020 |  0.000 |     0.000 |     0.000 |      0.000 |     0.000 |
|     1 |   0 |   1 |   0 |   0 |   0 | POST   | /api/estate/req_doc/8654       | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 |  0.000 |     0.000 |     0.000 |      0.000 |     0.000 |
|     4 |   0 |   4 |   0 |   0 |   0 | GET    | /api/chair/search/condition    | 0.000 | 0.004 | 0.008 | 0.002 | 0.004 | 0.004 | 0.000 |  0.002 |  3392.000 |  3392.000 |  13568.000 |  3392.000 |
|     4 |   0 |   4 |   0 |   0 |   0 | GET    | /api/estate/search/condition   | 0.000 | 0.004 | 0.004 | 0.001 | 0.004 | 0.000 | 0.000 |  0.002 |  2563.000 |  2563.000 |  10252.000 |  2563.000 |
|     5 |   0 |   5 |   0 |   0 |   0 | POST   | /api/estate/nazotte            | 0.024 | 0.404 | 1.056 | 0.211 | 0.024 | 0.044 | 0.328 |  0.152 |    34.000 | 33925.000 |  67433.000 | 13486.600 |
|     5 |   0 |   5 |   0 |   0 |   0 | GET    | /api/recommended_estate/[0-9]+ | 0.956 | 1.284 | 5.352 | 1.070 | 0.956 | 0.972 | 1.140 |  0.125 | 13253.000 | 13690.000 |  67737.000 | 13547.400 |
|     8 |   0 |   8 |   0 |   0 |   0 | GET    | /api/estate/low_priced         | 0.000 | 0.016 | 0.036 | 0.005 | 0.016 | 0.004 | 0.000 |  0.005 | 13397.000 | 13397.000 | 107176.000 | 13397.000 |
|     8 |   0 |   8 |   0 |   0 |   0 | GET    | /api/chair/low_priced          | 0.000 | 0.020 | 0.020 | 0.003 | 0.020 | 0.000 | 0.000 |  0.007 | 12153.000 | 12153.000 |  97224.000 | 12153.000 |
|     9 |   0 |   8 |   0 |   1 |   0 | GET    | /api/estate/[0-9]+             | 0.004 | 0.024 | 0.108 | 0.012 | 0.012 | 0.020 | 0.004 |  0.009 |   542.000 |   667.000 |   4997.000 |   555.222 |
|    10 |   0 |   8 |   0 |   2 |   0 | GET    | /api/chair/[0-9]+              | 0.004 | 0.020 | 0.080 | 0.008 | 0.008 | 0.020 | 0.000 |  0.008 |   512.000 |   584.000 |   4272.000 |   427.200 |
|    21 |   0 |  21 |   0 |   0 |   0 | GET    | /api/estate/search             | 0.040 | 0.708 | 4.880 | 0.232 | 0.612 | 0.092 | 0.116 |  0.230 |   728.000 | 27368.000 | 354375.000 | 16875.000 |
|    21 |   0 |  21 |   0 |   0 |   0 | GET    | /api/chair/search              | 0.028 | 0.232 | 2.364 | 0.113 | 0.120 | 0.128 | 0.044 |  0.061 |    33.000 | 20139.000 | 280994.000 | 13380.667 |
+-------+-----+-----+-----+-----+-----+--------+--------------------------------+-------+-------+-------+-------+-------+-------+-------+--------+-----------+-----------+------------+-----------+

集計結果をAverageごと、さらに降順でソートしたいときは--sort avg-rを使います。

$ cat /path/to/access.log | alp json -m '/api/estate/[0-9]+,/api/chair/[0-9]+,/api/recommended_estate/[0-9]+' --sort avg -r
+-------+-----+-----+-----+-----+-----+--------+--------------------------------+-------+-------+-------+-------+-------+-------+-------+--------+-----------+-----------+------------+-----------+
| COUNT | 1XX | 2XX | 3XX | 4XX | 5XX | METHOD |              URI               |  MIN  |  MAX  |  SUM  |  AVG  |  P1   |  P50  |  P99  | STDDEV | MIN(BODY) | MAX(BODY) | SUM(BODY)  | AVG(BODY) |
+-------+-----+-----+-----+-----+-----+--------+--------------------------------+-------+-------+-------+-------+-------+-------+-------+--------+-----------+-----------+------------+-----------+
|     1 |   0 |   1 |   0 |   0 |   0 | POST   | /initialize                    | 7.524 | 7.524 | 7.524 | 7.524 | 7.524 | 7.524 | 7.524 |  0.000 |    23.000 |    23.000 |     23.000 |    23.000 |
|     5 |   0 |   5 |   0 |   0 |   0 | GET    | /api/recommended_estate/[0-9]+ | 0.956 | 1.284 | 5.352 | 1.070 | 0.956 | 0.972 | 1.140 |  0.125 | 13253.000 | 13690.000 |  67737.000 | 13547.400 |
|    21 |   0 |  21 |   0 |   0 |   0 | GET    | /api/estate/search             | 0.040 | 0.708 | 4.880 | 0.232 | 0.612 | 0.092 | 0.116 |  0.230 |   728.000 | 27368.000 | 354375.000 | 16875.000 |
|     5 |   0 |   5 |   0 |   0 |   0 | POST   | /api/estate/nazotte            | 0.024 | 0.404 | 1.056 | 0.211 | 0.024 | 0.044 | 0.328 |  0.152 |    34.000 | 33925.000 |  67433.000 | 13486.600 |
|    21 |   0 |  21 |   0 |   0 |   0 | GET    | /api/chair/search              | 0.028 | 0.232 | 2.364 | 0.113 | 0.120 | 0.128 | 0.044 |  0.061 |    33.000 | 20139.000 | 280994.000 | 13380.667 |
|     1 |   0 |   1 |   0 |   0 |   0 | POST   | /api/chair                     | 0.032 | 0.032 | 0.032 | 0.032 | 0.032 | 0.032 | 0.032 |  0.000 |     0.000 |     0.000 |      0.000 |     0.000 |
|     1 |   0 |   1 |   0 |   0 |   0 | POST   | /api/estate                    | 0.020 | 0.020 | 0.020 | 0.020 | 0.020 | 0.020 | 0.020 |  0.000 |     0.000 |     0.000 |      0.000 |     0.000 |
|     9 |   0 |   8 |   0 |   1 |   0 | GET    | /api/estate/[0-9]+             | 0.004 | 0.024 | 0.108 | 0.012 | 0.012 | 0.020 | 0.004 |  0.009 |   542.000 |   667.000 |   4997.000 |   555.222 |
|    10 |   0 |   8 |   0 |   2 |   0 | GET    | /api/chair/[0-9]+              | 0.004 | 0.020 | 0.080 | 0.008 | 0.008 | 0.020 | 0.000 |  0.008 |   512.000 |   584.000 |   4272.000 |   427.200 |
|     8 |   0 |   8 |   0 |   0 |   0 | GET    | /api/estate/low_priced         | 0.000 | 0.016 | 0.036 | 0.005 | 0.016 | 0.004 | 0.000 |  0.005 | 13397.000 | 13397.000 | 107176.000 | 13397.000 |
|     8 |   0 |   8 |   0 |   0 |   0 | GET    | /api/chair/low_priced          | 0.000 | 0.020 | 0.020 | 0.003 | 0.020 | 0.000 | 0.000 |  0.007 | 12153.000 | 12153.000 |  97224.000 | 12153.000 |
|     4 |   0 |   4 |   0 |   0 |   0 | GET    | /api/chair/search/condition    | 0.000 | 0.004 | 0.008 | 0.002 | 0.004 | 0.004 | 0.000 |  0.002 |  3392.000 |  3392.000 |  13568.000 |  3392.000 |
|     4 |   0 |   4 |   0 |   0 |   0 | GET    | /api/estate/search/condition   | 0.000 | 0.004 | 0.004 | 0.001 | 0.004 | 0.000 | 0.000 |  0.002 |  2563.000 |  2563.000 |  10252.000 |  2563.000 |
|     1 |   0 |   1 |   0 |   0 |   0 | POST   | /api/chair/buy/29501           | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 |  0.000 |     0.000 |     0.000 |      0.000 |     0.000 |
|     1 |   0 |   1 |   0 |   0 |   0 | POST   | /api/estate/req_doc/8654       | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 |  0.000 |     0.000 |     0.000 |      0.000 |     0.000 |
+-------+-----+-----+-----+-----+-----+--------+--------------------------------+-------+-------+-------+-------+-------+-------+-------+--------+-----------+-----------+------------+-----------+

--sortにはcountavg以外にも様々な値を指定できます。詳細はドキュメントを参照してください。

これまでの集計結果のURIに/api/chair/searchがありますが、アクセスログを見るとQuery Stringが含まれています。Query Stringまで含めて集計対象とする場合は-qを使います。

$ cat /path/to/access.log | alp json -m '/api/estate/[0-9]+,/api/chair/[0-9]+,/api/recommended_estate/[0-9]+' --sort avg -r -q
+-------+-----+-----+-----+-----+-----+--------+-------------------------------------------------------------------------------------------+-------+-------+-------+-------+-------+-------+-------+--------+-----------+-----------+------------+-----------+
| COUNT | 1XX | 2XX | 3XX | 4XX | 5XX | METHOD |                                            URI                                            |  MIN  |  MAX  |  SUM  |  AVG  |  P1   |  P50  |  P99  | STDDEV | MIN(BODY) | MAX(BODY) | SUM(BODY)  | AVG(BODY) |
+-------+-----+-----+-----+-----+-----+--------+-------------------------------------------------------------------------------------------+-------+-------+-------+-------+-------+-------+-------+--------+-----------+-----------+------------+-----------+
|     1 |   0 |   1 |   0 |   0 |   0 | POST   | /initialize                                                                               | 7.524 | 7.524 | 7.524 | 7.524 | 7.524 | 7.524 | 7.524 |  0.000 |    23.000 |    23.000 |     23.000 |    23.000 |
|     5 |   0 |   5 |   0 |   0 |   0 | GET    | /api/recommended_estate/[0-9]+                                                            | 0.956 | 1.284 | 5.352 | 1.070 | 0.956 | 0.972 | 1.140 |  0.125 | 13253.000 | 13690.000 |  67737.000 | 13547.400 |
|     3 |   0 |   3 |   0 |   0 |   0 | GET    | /api/estate/search?features=xxx&page=xxx&perPage=xxx                                      | 0.616 | 0.708 | 1.956 | 0.652 | 0.616 | 0.616 | 0.632 |  0.040 |   728.000 | 18569.000 |  34222.000 | 11407.333 |
|     1 |   0 |   1 |   0 |   0 |   0 | GET    | /api/estate/search?features=xxx&page=xxx&perPage=xxx&rentRangeId=xxx                      | 0.624 | 0.624 | 0.624 | 0.624 | 0.624 | 0.624 | 0.624 |  0.000 | 27368.000 | 27368.000 |  27368.000 | 27368.000 |
|     1 |   0 |   1 |   0 |   0 |   0 | GET    | /api/estate/search?doorWidthRangeId=xxx&features=xxx&page=xxx&perPage=xxx&rentRangeId=xxx | 0.612 | 0.612 | 0.612 | 0.612 | 0.612 | 0.612 | 0.612 |  0.000 | 25478.000 | 25478.000 |  25478.000 | 25478.000 |
|     1 |   0 |   1 |   0 |   0 |   0 | GET    | /api/chair/search?features=xxx&page=xxx&perPage=xxx                                       | 0.232 | 0.232 | 0.232 | 0.232 | 0.232 | 0.232 | 0.232 |  0.000 |  5482.000 |  5482.000 |   5482.000 |  5482.000 |
|     1 |   0 |   1 |   0 |   0 |   0 | GET    | /api/chair/search?depthRangeId=xxx&features=xxx&page=xxx&perPage=xxx&widthRangeId=xxx     | 0.224 | 0.224 | 0.224 | 0.224 | 0.224 | 0.224 | 0.224 |  0.000 | 20139.000 | 20139.000 |  20139.000 | 20139.000 |
|     5 |   0 |   5 |   0 |   0 |   0 | POST   | /api/estate/nazotte                                                                       | 0.024 | 0.404 | 1.056 | 0.211 | 0.024 | 0.044 | 0.328 |  0.152 |    34.000 | 33925.000 |  67433.000 | 13486.600 |
|     1 |   0 |   1 |   0 |   0 |   0 | GET    | /api/chair/search?features=xxx&page=xxx&perPage=xxx&priceRangeId=xxx                      | 0.192 | 0.192 | 0.192 | 0.192 | 0.192 | 0.192 | 0.192 |  0.000 |    33.000 |    33.000 |     33.000 |    33.000 |
|     1 |   0 |   1 |   0 |   0 |   0 | GET    | /api/chair/search?features=xxx&kind=xxx&page=xxx&perPage=xxx                              | 0.184 | 0.184 | 0.184 | 0.184 | 0.184 | 0.184 | 0.184 |  0.000 | 15221.000 | 15221.000 |  15221.000 | 15221.000 |
|     1 |   0 |   1 |   0 |   0 |   0 | GET    | /api/chair/search?color=xxx&features=xxx&page=xxx&perPage=xxx                             | 0.120 | 0.120 | 0.120 | 0.120 | 0.120 | 0.120 | 0.120 |  0.000 |    33.000 |    33.000 |     33.000 |    33.000 |
|     5 |   0 |   5 |   0 |   0 |   0 | GET    | /api/estate/search?doorHeightRangeId=xxx&page=xxx&perPage=xxx                             | 0.092 | 0.168 | 0.568 | 0.114 | 0.092 | 0.092 | 0.168 |  0.030 | 16349.000 | 16894.000 |  83523.000 | 16704.600 |
|     9 |   0 |   9 |   0 |   0 |   0 | GET    | /api/chair/search?heightRangeId=xxx&page=xxx&perPage=xxx                                  | 0.028 | 0.180 | 0.968 | 0.108 | 0.028 | 0.128 | 0.180 |  0.049 | 14741.000 | 15173.000 | 134783.000 | 14975.889 |
|    11 |   0 |  11 |   0 |   0 |   0 | GET    | /api/estate/search?page=xxx&perPage=xxx&rentRangeId=xxx                                   | 0.040 | 0.176 | 1.120 | 0.102 | 0.040 | 0.084 | 0.116 |  0.035 | 16456.000 | 17241.000 | 183784.000 | 16707.636 |
|     5 |   0 |   5 |   0 |   0 |   0 | GET    | /api/chair/search?kind=xxx&page=xxx&perPage=xxx                                           | 0.056 | 0.084 | 0.356 | 0.071 | 0.084 | 0.080 | 0.056 |  0.012 | 14624.000 | 15241.000 |  74753.000 | 14950.600 |
|     2 |   0 |   2 |   0 |   0 |   0 | GET    | /api/chair/search?page=xxx&perPage=xxx&priceRangeId=xxx                                   | 0.044 | 0.044 | 0.088 | 0.044 | 0.044 | 0.044 | 0.044 |  0.000 | 15275.000 | 15275.000 |  30550.000 | 15275.000 |
|     1 |   0 |   1 |   0 |   0 |   0 | POST   | /api/chair                                                                                | 0.032 | 0.032 | 0.032 | 0.032 | 0.032 | 0.032 | 0.032 |  0.000 |     0.000 |     0.000 |      0.000 |     0.000 |
|     1 |   0 |   1 |   0 |   0 |   0 | POST   | /api/estate                                                                               | 0.020 | 0.020 | 0.020 | 0.020 | 0.020 | 0.020 | 0.020 |  0.000 |     0.000 |     0.000 |      0.000 |     0.000 |
|     9 |   0 |   8 |   0 |   1 |   0 | GET    | /api/estate/[0-9]+                                                                        | 0.004 | 0.024 | 0.108 | 0.012 | 0.012 | 0.020 | 0.004 |  0.009 |   542.000 |   667.000 |   4997.000 |   555.222 |
|    10 |   0 |   8 |   0 |   2 |   0 | GET    | /api/chair/[0-9]+                                                                         | 0.004 | 0.020 | 0.080 | 0.008 | 0.008 | 0.020 | 0.000 |  0.008 |   512.000 |   584.000 |   4272.000 |   427.200 |
|     8 |   0 |   8 |   0 |   0 |   0 | GET    | /api/estate/low_priced                                                                    | 0.000 | 0.016 | 0.036 | 0.005 | 0.016 | 0.004 | 0.000 |  0.005 | 13397.000 | 13397.000 | 107176.000 | 13397.000 |
|     8 |   0 |   8 |   0 |   0 |   0 | GET    | /api/chair/low_priced                                                                     | 0.000 | 0.020 | 0.020 | 0.003 | 0.020 | 0.000 | 0.000 |  0.007 | 12153.000 | 12153.000 |  97224.000 | 12153.000 |
|     4 |   0 |   4 |   0 |   0 |   0 | GET    | /api/chair/search/condition                                                               | 0.000 | 0.004 | 0.008 | 0.002 | 0.004 | 0.004 | 0.000 |  0.002 |  3392.000 |  3392.000 |  13568.000 |  3392.000 |
|     4 |   0 |   4 |   0 |   0 |   0 | GET    | /api/estate/search/condition                                                              | 0.000 | 0.004 | 0.004 | 0.001 | 0.004 | 0.000 | 0.000 |  0.002 |  2563.000 |  2563.000 |  10252.000 |  2563.000 |
|     1 |   0 |   1 |   0 |   0 |   0 | POST   | /api/chair/buy/29501                                                                      | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 |  0.000 |     0.000 |     0.000 |      0.000 |     0.000 |
|     1 |   0 |   1 |   0 |   0 |   0 | POST   | /api/estate/req_doc/8654                                                                  | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 |  0.000 |     0.000 |     0.000 |      0.000 |     0.000 |
+-------+-----+-----+-----+-----+-----+--------+-------------------------------------------------------------------------------------------+-------+-------+-------+-------+-------+-------+-------+--------+-----------+-----------+------------+-----------+

URIに/api/estate/search?features=xxx&page=xxx&perPage=xxx/api/estate/search?features=xxx&page=xxx&perPage=xxx&rentRangeId=xxxなどが出力されるようになりました。features=xxxとなっているのはQuery Stringのキーだけを見て、全てのキーが一致していたら値に関係なく同一URIとして集計しているためです(現状、Query Stringの値まで含めて一つのURIとして集計する機能はないです)。

アクセスは全てでどれくらいで、HTTPステータスコードごとだとどれくらいかを知りたいときは--show-footersを使うと出力できます。

$ cat /path/to/access.log | alp json -m '/api/estate/[0-9]+,/api/chair/[0-9]+,/api/recommended_estate/[0-9]+' --sort avg -r -q --show-footers
+-------+-----+-----+-----+-----+-----+--------+-------------------------------------------------------------------------------------------+-------+-------+-------+-------+-------+-------+-------+--------+-----------+-----------+------------+-----------+
| COUNT | 1XX | 2XX | 3XX | 4XX | 5XX | METHOD |                                            URI                                            |  MIN  |  MAX  |  SUM  |  AVG  |  P1   |  P50  |  P99  | STDDEV | MIN(BODY) | MAX(BODY) | SUM(BODY)  | AVG(BODY) |
+-------+-----+-----+-----+-----+-----+--------+-------------------------------------------------------------------------------------------+-------+-------+-------+-------+-------+-------+-------+--------+-----------+-----------+------------+-----------+
|     1 |   0 |   1 |   0 |   0 |   0 | POST   | /initialize                                                                               | 7.524 | 7.524 | 7.524 | 7.524 | 7.524 | 7.524 | 7.524 |  0.000 |    23.000 |    23.000 |     23.000 |    23.000 |
|     5 |   0 |   5 |   0 |   0 |   0 | GET    | /api/recommended_estate/[0-9]+                                                            | 0.956 | 1.284 | 5.352 | 1.070 | 0.956 | 0.972 | 1.140 |  0.125 | 13253.000 | 13690.000 |  67737.000 | 13547.400 |
|     3 |   0 |   3 |   0 |   0 |   0 | GET    | /api/estate/search?features=xxx&page=xxx&perPage=xxx                                      | 0.616 | 0.708 | 1.956 | 0.652 | 0.616 | 0.616 | 0.632 |  0.040 |   728.000 | 18569.000 |  34222.000 | 11407.333 |
|     1 |   0 |   1 |   0 |   0 |   0 | GET    | /api/estate/search?features=xxx&page=xxx&perPage=xxx&rentRangeId=xxx                      | 0.624 | 0.624 | 0.624 | 0.624 | 0.624 | 0.624 | 0.624 |  0.000 | 27368.000 | 27368.000 |  27368.000 | 27368.000 |
|     1 |   0 |   1 |   0 |   0 |   0 | GET    | /api/estate/search?doorWidthRangeId=xxx&features=xxx&page=xxx&perPage=xxx&rentRangeId=xxx | 0.612 | 0.612 | 0.612 | 0.612 | 0.612 | 0.612 | 0.612 |  0.000 | 25478.000 | 25478.000 |  25478.000 | 25478.000 |
|     1 |   0 |   1 |   0 |   0 |   0 | GET    | /api/chair/search?features=xxx&page=xxx&perPage=xxx                                       | 0.232 | 0.232 | 0.232 | 0.232 | 0.232 | 0.232 | 0.232 |  0.000 |  5482.000 |  5482.000 |   5482.000 |  5482.000 |
|     1 |   0 |   1 |   0 |   0 |   0 | GET    | /api/chair/search?depthRangeId=xxx&features=xxx&page=xxx&perPage=xxx&widthRangeId=xxx     | 0.224 | 0.224 | 0.224 | 0.224 | 0.224 | 0.224 | 0.224 |  0.000 | 20139.000 | 20139.000 |  20139.000 | 20139.000 |
|     5 |   0 |   5 |   0 |   0 |   0 | POST   | /api/estate/nazotte                                                                       | 0.024 | 0.404 | 1.056 | 0.211 | 0.024 | 0.044 | 0.328 |  0.152 |    34.000 | 33925.000 |  67433.000 | 13486.600 |
|     1 |   0 |   1 |   0 |   0 |   0 | GET    | /api/chair/search?features=xxx&page=xxx&perPage=xxx&priceRangeId=xxx                      | 0.192 | 0.192 | 0.192 | 0.192 | 0.192 | 0.192 | 0.192 |  0.000 |    33.000 |    33.000 |     33.000 |    33.000 |
|     1 |   0 |   1 |   0 |   0 |   0 | GET    | /api/chair/search?features=xxx&kind=xxx&page=xxx&perPage=xxx                              | 0.184 | 0.184 | 0.184 | 0.184 | 0.184 | 0.184 | 0.184 |  0.000 | 15221.000 | 15221.000 |  15221.000 | 15221.000 |
|     1 |   0 |   1 |   0 |   0 |   0 | GET    | /api/chair/search?color=xxx&features=xxx&page=xxx&perPage=xxx                             | 0.120 | 0.120 | 0.120 | 0.120 | 0.120 | 0.120 | 0.120 |  0.000 |    33.000 |    33.000 |     33.000 |    33.000 |
|     5 |   0 |   5 |   0 |   0 |   0 | GET    | /api/estate/search?doorHeightRangeId=xxx&page=xxx&perPage=xxx                             | 0.092 | 0.168 | 0.568 | 0.114 | 0.092 | 0.092 | 0.168 |  0.030 | 16349.000 | 16894.000 |  83523.000 | 16704.600 |
|     9 |   0 |   9 |   0 |   0 |   0 | GET    | /api/chair/search?heightRangeId=xxx&page=xxx&perPage=xxx                                  | 0.028 | 0.180 | 0.968 | 0.108 | 0.028 | 0.128 | 0.180 |  0.049 | 14741.000 | 15173.000 | 134783.000 | 14975.889 |
|    11 |   0 |  11 |   0 |   0 |   0 | GET    | /api/estate/search?page=xxx&perPage=xxx&rentRangeId=xxx                                   | 0.040 | 0.176 | 1.120 | 0.102 | 0.040 | 0.084 | 0.116 |  0.035 | 16456.000 | 17241.000 | 183784.000 | 16707.636 |
|     5 |   0 |   5 |   0 |   0 |   0 | GET    | /api/chair/search?kind=xxx&page=xxx&perPage=xxx                                           | 0.056 | 0.084 | 0.356 | 0.071 | 0.084 | 0.080 | 0.056 |  0.012 | 14624.000 | 15241.000 |  74753.000 | 14950.600 |
|     2 |   0 |   2 |   0 |   0 |   0 | GET    | /api/chair/search?page=xxx&perPage=xxx&priceRangeId=xxx                                   | 0.044 | 0.044 | 0.088 | 0.044 | 0.044 | 0.044 | 0.044 |  0.000 | 15275.000 | 15275.000 |  30550.000 | 15275.000 |
|     1 |   0 |   1 |   0 |   0 |   0 | POST   | /api/chair                                                                                | 0.032 | 0.032 | 0.032 | 0.032 | 0.032 | 0.032 | 0.032 |  0.000 |     0.000 |     0.000 |      0.000 |     0.000 |
|     1 |   0 |   1 |   0 |   0 |   0 | POST   | /api/estate                                                                               | 0.020 | 0.020 | 0.020 | 0.020 | 0.020 | 0.020 | 0.020 |  0.000 |     0.000 |     0.000 |      0.000 |     0.000 |
|     9 |   0 |   8 |   0 |   1 |   0 | GET    | /api/estate/[0-9]+                                                                        | 0.004 | 0.024 | 0.108 | 0.012 | 0.012 | 0.020 | 0.004 |  0.009 |   542.000 |   667.000 |   4997.000 |   555.222 |
|    10 |   0 |   8 |   0 |   2 |   0 | GET    | /api/chair/[0-9]+                                                                         | 0.004 | 0.020 | 0.080 | 0.008 | 0.008 | 0.020 | 0.000 |  0.008 |   512.000 |   584.000 |   4272.000 |   427.200 |
|     8 |   0 |   8 |   0 |   0 |   0 | GET    | /api/estate/low_priced                                                                    | 0.000 | 0.016 | 0.036 | 0.005 | 0.016 | 0.004 | 0.000 |  0.005 | 13397.000 | 13397.000 | 107176.000 | 13397.000 |
|     8 |   0 |   8 |   0 |   0 |   0 | GET    | /api/chair/low_priced                                                                     | 0.000 | 0.020 | 0.020 | 0.003 | 0.020 | 0.000 | 0.000 |  0.007 | 12153.000 | 12153.000 |  97224.000 | 12153.000 |
|     4 |   0 |   4 |   0 |   0 |   0 | GET    | /api/chair/search/condition                                                               | 0.000 | 0.004 | 0.008 | 0.002 | 0.004 | 0.004 | 0.000 |  0.002 |  3392.000 |  3392.000 |  13568.000 |  3392.000 |
|     4 |   0 |   4 |   0 |   0 |   0 | GET    | /api/estate/search/condition                                                              | 0.000 | 0.004 | 0.004 | 0.001 | 0.004 | 0.000 | 0.000 |  0.002 |  2563.000 |  2563.000 |  10252.000 |  2563.000 |
|     1 |   0 |   1 |   0 |   0 |   0 | POST   | /api/chair/buy/29501                                                                      | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 |  0.000 |     0.000 |     0.000 |      0.000 |     0.000 |
|     1 |   0 |   1 |   0 |   0 |   0 | POST   | /api/estate/req_doc/8654                                                                  | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 |  0.000 |     0.000 |     0.000 |      0.000 |     0.000 |
+-------+-----+-----+-----+-----+-----+--------+-------------------------------------------------------------------------------------------+-------+-------+-------+-------+-------+-------+-------+--------+-----------+-----------+------------+-----------+
|   100 |   0 |  97 |   0 |   3 |   0 |                                                                                                                                                                                                                       
+-------+-----+-----+-----+-----+-----+--------+-------------------------------------------------------------------------------------------+-------+-------+-------+-------+-------+-------+-------+--------+-----------+-----------+------------+-----------+

横に広すぎて見にくいので情報量を減らしたいというときは-oが使えます。

$ cat /path/to/access.log | alp json -m '/api/estate/[0-9]+,/api/chair/[0-9]+,/api/recommended_estate/[0-9]+' --sort avg -r -q --show-footers -o count,1xx,2xx,3xx,4xx,5xx,min,max,avg,sum,p99
+-------+-----+-----+-----+-----+-----+-------+-------+-------+-------+-------+
| COUNT | 1XX | 2XX | 3XX | 4XX | 5XX |  MIN  |  MAX  |  AVG  |  SUM  |  P99  |
+-------+-----+-----+-----+-----+-----+-------+-------+-------+-------+-------+
|     1 |   0 |   1 |   0 |   0 |   0 | 7.524 | 7.524 | 7.524 | 7.524 | 7.524 |
|     5 |   0 |   5 |   0 |   0 |   0 | 0.956 | 1.284 | 1.070 | 5.352 | 1.140 |
|     3 |   0 |   3 |   0 |   0 |   0 | 0.616 | 0.708 | 0.652 | 1.956 | 0.632 |
|     1 |   0 |   1 |   0 |   0 |   0 | 0.624 | 0.624 | 0.624 | 0.624 | 0.624 |
|     1 |   0 |   1 |   0 |   0 |   0 | 0.612 | 0.612 | 0.612 | 0.612 | 0.612 |
|     1 |   0 |   1 |   0 |   0 |   0 | 0.232 | 0.232 | 0.232 | 0.232 | 0.232 |
|     1 |   0 |   1 |   0 |   0 |   0 | 0.224 | 0.224 | 0.224 | 0.224 | 0.224 |
|     5 |   0 |   5 |   0 |   0 |   0 | 0.024 | 0.404 | 0.211 | 1.056 | 0.328 |
|     1 |   0 |   1 |   0 |   0 |   0 | 0.192 | 0.192 | 0.192 | 0.192 | 0.192 |
|     1 |   0 |   1 |   0 |   0 |   0 | 0.184 | 0.184 | 0.184 | 0.184 | 0.184 |
|     1 |   0 |   1 |   0 |   0 |   0 | 0.120 | 0.120 | 0.120 | 0.120 | 0.120 |
|     5 |   0 |   5 |   0 |   0 |   0 | 0.092 | 0.168 | 0.114 | 0.568 | 0.168 |
|     9 |   0 |   9 |   0 |   0 |   0 | 0.028 | 0.180 | 0.108 | 0.968 | 0.180 |
|    11 |   0 |  11 |   0 |   0 |   0 | 0.040 | 0.176 | 0.102 | 1.120 | 0.116 |
|     5 |   0 |   5 |   0 |   0 |   0 | 0.056 | 0.084 | 0.071 | 0.356 | 0.056 |
|     2 |   0 |   2 |   0 |   0 |   0 | 0.044 | 0.044 | 0.044 | 0.088 | 0.044 |
|     1 |   0 |   1 |   0 |   0 |   0 | 0.032 | 0.032 | 0.032 | 0.032 | 0.032 |
|     1 |   0 |   1 |   0 |   0 |   0 | 0.020 | 0.020 | 0.020 | 0.020 | 0.020 |
|     9 |   0 |   8 |   0 |   1 |   0 | 0.004 | 0.024 | 0.012 | 0.108 | 0.004 |
|    10 |   0 |   8 |   0 |   2 |   0 | 0.004 | 0.020 | 0.008 | 0.080 | 0.000 |
|     8 |   0 |   8 |   0 |   0 |   0 | 0.000 | 0.016 | 0.005 | 0.036 | 0.000 |
|     8 |   0 |   8 |   0 |   0 |   0 | 0.000 | 0.020 | 0.003 | 0.020 | 0.000 |
|     4 |   0 |   4 |   0 |   0 |   0 | 0.000 | 0.004 | 0.002 | 0.008 | 0.000 |
|     4 |   0 |   4 |   0 |   0 |   0 | 0.000 | 0.004 | 0.001 | 0.004 | 0.000 |
|     1 |   0 |   1 |   0 |   0 |   0 | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 |
|     1 |   0 |   1 |   0 |   0 |   0 | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 |
+-------+-----+-----+-----+-----+-----+-------+-------+-------+-------+-------+
|   100 |   0 |  97 |   0 |   3 |   0 |
+-------+-----+-----+-----+-----+-----+-------+-------+-------+-------+-------+

このようにカンマ区切りで指定できます。指定できる値はドキュメントを参照してください。

以上が基本的な使い方です。

基本的ではなく、あまり使われていなさそうな機能もせっかくなので紹介します。

alpには--sort-r-oで出力結果を変えることができます。その際に毎回アクセスログを集計していると、ログのサイズによっては時間がかかります。そのようなケースで使うのが--dump--loadです。

$ cat /path/to/access.log | alp json -m '/api/estate/[0-9]+,/api/chair/[0-9]+,/api/recommended_estate/[0-9]+' --sort avg -r -q --show-footers -o count,1xx,2xx,3xx,4xx,5xx,min,max,avg,sum,p99 --dump /tmp/dump.log
+-------+-----+-----+-----+-----+-----+-------+-------+-------+-------+-------+
| COUNT | 1XX | 2XX | 3XX | 4XX | 5XX |  MIN  |  MAX  |  AVG  |  SUM  |  P99  |
+-------+-----+-----+-----+-----+-----+-------+-------+-------+-------+-------+
|     1 |   0 |   1 |   0 |   0 |   0 | 7.524 | 7.524 | 7.524 | 7.524 | 7.524 |
|     5 |   0 |   5 |   0 |   0 |   0 | 0.956 | 1.284 | 1.070 | 5.352 | 1.140 |
|     3 |   0 |   3 |   0 |   0 |   0 | 0.616 | 0.708 | 0.652 | 1.956 | 0.632 |
|     1 |   0 |   1 |   0 |   0 |   0 | 0.624 | 0.624 | 0.624 | 0.624 | 0.624 |
|     1 |   0 |   1 |   0 |   0 |   0 | 0.612 | 0.612 | 0.612 | 0.612 | 0.612 |
|     1 |   0 |   1 |   0 |   0 |   0 | 0.232 | 0.232 | 0.232 | 0.232 | 0.232 |
|     1 |   0 |   1 |   0 |   0 |   0 | 0.224 | 0.224 | 0.224 | 0.224 | 0.224 |
|     5 |   0 |   5 |   0 |   0 |   0 | 0.024 | 0.404 | 0.211 | 1.056 | 0.328 |
|     1 |   0 |   1 |   0 |   0 |   0 | 0.192 | 0.192 | 0.192 | 0.192 | 0.192 |
|     1 |   0 |   1 |   0 |   0 |   0 | 0.184 | 0.184 | 0.184 | 0.184 | 0.184 |
|     1 |   0 |   1 |   0 |   0 |   0 | 0.120 | 0.120 | 0.120 | 0.120 | 0.120 |
|     5 |   0 |   5 |   0 |   0 |   0 | 0.092 | 0.168 | 0.114 | 0.568 | 0.168 |
|     9 |   0 |   9 |   0 |   0 |   0 | 0.028 | 0.180 | 0.108 | 0.968 | 0.180 |
|    11 |   0 |  11 |   0 |   0 |   0 | 0.040 | 0.176 | 0.102 | 1.120 | 0.116 |
|     5 |   0 |   5 |   0 |   0 |   0 | 0.056 | 0.084 | 0.071 | 0.356 | 0.056 |
|     2 |   0 |   2 |   0 |   0 |   0 | 0.044 | 0.044 | 0.044 | 0.088 | 0.044 |
|     1 |   0 |   1 |   0 |   0 |   0 | 0.032 | 0.032 | 0.032 | 0.032 | 0.032 |
|     1 |   0 |   1 |   0 |   0 |   0 | 0.020 | 0.020 | 0.020 | 0.020 | 0.020 |
|     9 |   0 |   8 |   0 |   1 |   0 | 0.004 | 0.024 | 0.012 | 0.108 | 0.004 |
|    10 |   0 |   8 |   0 |   2 |   0 | 0.004 | 0.020 | 0.008 | 0.080 | 0.000 |
|     8 |   0 |   8 |   0 |   0 |   0 | 0.000 | 0.016 | 0.005 | 0.036 | 0.000 |
|     8 |   0 |   8 |   0 |   0 |   0 | 0.000 | 0.020 | 0.003 | 0.020 | 0.000 |
|     4 |   0 |   4 |   0 |   0 |   0 | 0.000 | 0.004 | 0.002 | 0.008 | 0.000 |
|     4 |   0 |   4 |   0 |   0 |   0 | 0.000 | 0.004 | 0.001 | 0.004 | 0.000 |
|     1 |   0 |   1 |   0 |   0 |   0 | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 |
|     1 |   0 |   1 |   0 |   0 |   0 | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 |
+-------+-----+-----+-----+-----+-----+-------+-------+-------+-------+-------+
|   100 |   0 |  97 |   0 |   3 |   0 |
+-------+-----+-----+-----+-----+-----+-------+-------+-------+-------+-------+

集計結果を出力されるのは今までどおりですが、/tmp/dump.logというファイルが出力されています。このファイルには集計結果が記録されているので、--loadに指定するとログを集計せず結果を出力することができます。出力結果を変えるために-rを削除してみます。

$ alp json -m '/api/estate/[0-9]+,/api/chair/[0-9]+,/api/recommended_estate/[0-9]+' --sort avg -q --show-footers -o count,1xx,2xx,3xx,4xx,5xx,min,max,avg,sum,p99 --load /tmp/dump.log
+-------+-----+-----+-----+-----+-----+-------+-------+-------+-------+-------+
| COUNT | 1XX | 2XX | 3XX | 4XX | 5XX |  MIN  |  MAX  |  AVG  |  SUM  |  P99  |
+-------+-----+-----+-----+-----+-----+-------+-------+-------+-------+-------+
|     1 |   0 |   1 |   0 |   0 |   0 | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 |
|     1 |   0 |   1 |   0 |   0 |   0 | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 |
|     4 |   0 |   4 |   0 |   0 |   0 | 0.000 | 0.004 | 0.001 | 0.004 | 0.000 |
|     4 |   0 |   4 |   0 |   0 |   0 | 0.000 | 0.004 | 0.002 | 0.008 | 0.000 |
|     8 |   0 |   8 |   0 |   0 |   0 | 0.000 | 0.020 | 0.003 | 0.020 | 0.000 |
|     8 |   0 |   8 |   0 |   0 |   0 | 0.000 | 0.016 | 0.005 | 0.036 | 0.000 |
|    10 |   0 |   8 |   0 |   2 |   0 | 0.004 | 0.020 | 0.008 | 0.080 | 0.000 |
|     9 |   0 |   8 |   0 |   1 |   0 | 0.004 | 0.024 | 0.012 | 0.108 | 0.004 |
|     1 |   0 |   1 |   0 |   0 |   0 | 0.020 | 0.020 | 0.020 | 0.020 | 0.020 |
|     1 |   0 |   1 |   0 |   0 |   0 | 0.032 | 0.032 | 0.032 | 0.032 | 0.032 |
|     2 |   0 |   2 |   0 |   0 |   0 | 0.044 | 0.044 | 0.044 | 0.088 | 0.044 |
|     5 |   0 |   5 |   0 |   0 |   0 | 0.056 | 0.084 | 0.071 | 0.356 | 0.056 |
|    11 |   0 |  11 |   0 |   0 |   0 | 0.040 | 0.176 | 0.102 | 1.120 | 0.116 |
|     9 |   0 |   9 |   0 |   0 |   0 | 0.028 | 0.180 | 0.108 | 0.968 | 0.180 |
|     5 |   0 |   5 |   0 |   0 |   0 | 0.092 | 0.168 | 0.114 | 0.568 | 0.168 |
|     1 |   0 |   1 |   0 |   0 |   0 | 0.120 | 0.120 | 0.120 | 0.120 | 0.120 |
|     1 |   0 |   1 |   0 |   0 |   0 | 0.184 | 0.184 | 0.184 | 0.184 | 0.184 |
|     1 |   0 |   1 |   0 |   0 |   0 | 0.192 | 0.192 | 0.192 | 0.192 | 0.192 |
|     5 |   0 |   5 |   0 |   0 |   0 | 0.024 | 0.404 | 0.211 | 1.056 | 0.328 |
|     1 |   0 |   1 |   0 |   0 |   0 | 0.224 | 0.224 | 0.224 | 0.224 | 0.224 |
|     1 |   0 |   1 |   0 |   0 |   0 | 0.232 | 0.232 | 0.232 | 0.232 | 0.232 |
|     1 |   0 |   1 |   0 |   0 |   0 | 0.612 | 0.612 | 0.612 | 0.612 | 0.612 |
|     1 |   0 |   1 |   0 |   0 |   0 | 0.624 | 0.624 | 0.624 | 0.624 | 0.624 |
|     3 |   0 |   3 |   0 |   0 |   0 | 0.616 | 0.708 | 0.652 | 1.956 | 0.632 |
|     5 |   0 |   5 |   0 |   0 |   0 | 0.956 | 1.284 | 1.070 | 5.352 | 1.140 |
|     1 |   0 |   1 |   0 |   0 |   0 | 7.524 | 7.524 | 7.524 | 7.524 | 7.524 |
+-------+-----+-----+-----+-----+-----+-------+-------+-------+-------+-------+
|   100 |   0 |  97 |   0 |   3 |   0 |
+-------+-----+-----+-----+-----+-----+-------+-------+-------+-------+-------+

結果が変わりました。今回例として使用しているアクセスログファイルは100行しかないので効果はほとんど感じられませんが、ログサイズが大きくなるほど効果を発揮するはずです。

alpのオプションを色々紹介しましたが、オプションが多くなると複数人で作業しているときにオプションを共有するのが面倒なこともあると思います。そのようなケースでは--configが役立ちます。指定できるオプションが多いので説明は割愛しますが、詳細は設定ファイルの例を参照してください。

また、ISUCONでの利用に特化した機能として--posがあります。このオプションはfluentdのpos_fileを真似した機能で、アクセスログファイルを集計する際にどこまで読み込んだか記憶し、以降は続きから集計することができます。この機能を活用すると、ベンチマークを実行するごとにファイルをtruncateする必要がなくなりますし、ファイルの増分だけを集計対象にできるので高速に動作します。

$ cat /path/to/access.log | alp json -m '/api/estate/[0-9]+,/api/chair/[0-9]+,/api/recommended_estate/[0-9]+' --sort avg -r -q --show-footers -o count,1xx,2xx,3xx,4xx,5xx,min,max,avg,sum,p99 --pos /tmp/alp.pos
+-------+-----+-----+-----+-----+-----+-------+-------+-------+-------+-------+
| COUNT | 1XX | 2XX | 3XX | 4XX | 5XX |  MIN  |  MAX  |  AVG  |  SUM  |  P99  |
+-------+-----+-----+-----+-----+-----+-------+-------+-------+-------+-------+
|     1 |   0 |   1 |   0 |   0 |   0 | 7.524 | 7.524 | 7.524 | 7.524 | 7.524 |
|     5 |   0 |   5 |   0 |   0 |   0 | 0.956 | 1.284 | 1.070 | 5.352 | 1.140 |
|     3 |   0 |   3 |   0 |   0 |   0 | 0.616 | 0.708 | 0.652 | 1.956 | 0.632 |
|     1 |   0 |   1 |   0 |   0 |   0 | 0.624 | 0.624 | 0.624 | 0.624 | 0.624 |
|     1 |   0 |   1 |   0 |   0 |   0 | 0.612 | 0.612 | 0.612 | 0.612 | 0.612 |
|     1 |   0 |   1 |   0 |   0 |   0 | 0.232 | 0.232 | 0.232 | 0.232 | 0.232 |
|     1 |   0 |   1 |   0 |   0 |   0 | 0.224 | 0.224 | 0.224 | 0.224 | 0.224 |
|     5 |   0 |   5 |   0 |   0 |   0 | 0.024 | 0.404 | 0.211 | 1.056 | 0.328 |
|     1 |   0 |   1 |   0 |   0 |   0 | 0.192 | 0.192 | 0.192 | 0.192 | 0.192 |
|     1 |   0 |   1 |   0 |   0 |   0 | 0.184 | 0.184 | 0.184 | 0.184 | 0.184 |
|     1 |   0 |   1 |   0 |   0 |   0 | 0.120 | 0.120 | 0.120 | 0.120 | 0.120 |
|     5 |   0 |   5 |   0 |   0 |   0 | 0.092 | 0.168 | 0.114 | 0.568 | 0.168 |
|     9 |   0 |   9 |   0 |   0 |   0 | 0.028 | 0.180 | 0.108 | 0.968 | 0.180 |
|    11 |   0 |  11 |   0 |   0 |   0 | 0.040 | 0.176 | 0.102 | 1.120 | 0.116 |
|     5 |   0 |   5 |   0 |   0 |   0 | 0.056 | 0.084 | 0.071 | 0.356 | 0.056 |
|     2 |   0 |   2 |   0 |   0 |   0 | 0.044 | 0.044 | 0.044 | 0.088 | 0.044 |
|     1 |   0 |   1 |   0 |   0 |   0 | 0.032 | 0.032 | 0.032 | 0.032 | 0.032 |
|     1 |   0 |   1 |   0 |   0 |   0 | 0.020 | 0.020 | 0.020 | 0.020 | 0.020 |
|     9 |   0 |   8 |   0 |   1 |   0 | 0.004 | 0.024 | 0.012 | 0.108 | 0.004 |
|    10 |   0 |   8 |   0 |   2 |   0 | 0.004 | 0.020 | 0.008 | 0.080 | 0.000 |
|     8 |   0 |   8 |   0 |   0 |   0 | 0.000 | 0.016 | 0.005 | 0.036 | 0.000 |
|     8 |   0 |   8 |   0 |   0 |   0 | 0.000 | 0.020 | 0.003 | 0.020 | 0.000 |
|     4 |   0 |   4 |   0 |   0 |   0 | 0.000 | 0.004 | 0.002 | 0.008 | 0.000 |
|     4 |   0 |   4 |   0 |   0 |   0 | 0.000 | 0.004 | 0.001 | 0.004 | 0.000 |
|     1 |   0 |   1 |   0 |   0 |   0 | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 |
|     1 |   0 |   1 |   0 |   0 |   0 | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 |
+-------+-----+-----+-----+-----+-----+-------+-------+-------+-------+-------+
|   100 |   0 |  97 |   0 |   3 |   0 |
+-------+-----+-----+-----+-----+-----+-------+-------+-------+-------+-------+

$ cat /tmp/alp.pos
40149

$ cat >> /path/to/access.log
{"time":"12/Sep/2020:11:55:34 +0000","host":"10.162.66.104","forwardedfor":"","req":"GET /api/chair/low_priced HTTP/1.1","status":"200","method":"GET","uri":"/api/chair/low_priced","body_bytes":12153,"referer":"","ua":"ISUCON Edge-aea5877d-df92-4065-a69a-2e7d154fbc41","request_time":0.004,"cache":"","runtime":"","response_time":"0.000","vhost":"10.162.66.103"}
^C

$ cat /path/to/access.log | alp json -m '/api/estate/[0-9]+,/api/chair/[0-9]+,/api/recommended_estate/[0-9]+' --sort avg -r -q --show-footers -o count,1xx,2xx,3xx,4xx,5xx,min,max,avg,sum,p99 --pos /tmp/alp.pos
+-------+-----+-----+-----+-----+-----+-------+-------+-------+-------+-------+
| COUNT | 1XX | 2XX | 3XX | 4XX | 5XX |  MIN  |  MAX  |  AVG  |  SUM  |  P99  |
+-------+-----+-----+-----+-----+-----+-------+-------+-------+-------+-------+
|     1 |   0 |   1 |   0 |   0 |   0 | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 |
+-------+-----+-----+-----+-----+-----+-------+-------+-------+-------+-------+
|     1 |   0 |   1 |   0 |   0 |   0 |
+-------+-----+-----+-----+-----+-----+-------+-------+-------+-------+-------+

$ cat /tmp/alp.pos
40512

/tmp/alp.posにどこまで読み込んだかバイト数が記録されており、1行ログを追加したあとに再度実行すると増分だけが集計されていることがわかります。また、/tmp/alp.posに記録されているバイト数が更新されています。
このように、毎回--posをつけていると読み込んだバイト数はどんどん更新されていきますが、更新したくない場合は--posと一緒に--nosave-posを使えば抑制できます。

フィルタ

alpにはフィルタ機能があり、マッチしたアクセスログだけを集計することができます。詳しくに説明すると長くなりすぎるので詳細はドキュメントを参照いただければと思いますが、簡単な例としてHTTPメソッドをGETだけ集計する例を示します。

$ cat /path/to/access.log | alp json -m '/api/estate/[0-9]+,/api/chair/[0-9]+,/api/recommended_estate/[0-9]+' --sort avg -r -q --show-footers -o count,1xx,2xx,3xx,4xx,5xx,min,max,avg,sum,p99 --filters 'Method == "GET"'
+-------+-----+-----+-----+-----+-----+-------+-------+-------+-------+-------+
| COUNT | 1XX | 2XX | 3XX | 4XX | 5XX |  MIN  |  MAX  |  AVG  |  SUM  |  P99  |
+-------+-----+-----+-----+-----+-----+-------+-------+-------+-------+-------+
|     5 |   0 |   5 |   0 |   0 |   0 | 0.956 | 1.284 | 1.070 | 5.352 | 1.140 |
|     3 |   0 |   3 |   0 |   0 |   0 | 0.616 | 0.708 | 0.652 | 1.956 | 0.632 |
|     1 |   0 |   1 |   0 |   0 |   0 | 0.624 | 0.624 | 0.624 | 0.624 | 0.624 |
|     1 |   0 |   1 |   0 |   0 |   0 | 0.612 | 0.612 | 0.612 | 0.612 | 0.612 |
|     1 |   0 |   1 |   0 |   0 |   0 | 0.232 | 0.232 | 0.232 | 0.232 | 0.232 |
|     1 |   0 |   1 |   0 |   0 |   0 | 0.224 | 0.224 | 0.224 | 0.224 | 0.224 |
|     1 |   0 |   1 |   0 |   0 |   0 | 0.192 | 0.192 | 0.192 | 0.192 | 0.192 |
|     1 |   0 |   1 |   0 |   0 |   0 | 0.184 | 0.184 | 0.184 | 0.184 | 0.184 |
|     1 |   0 |   1 |   0 |   0 |   0 | 0.120 | 0.120 | 0.120 | 0.120 | 0.120 |
|     5 |   0 |   5 |   0 |   0 |   0 | 0.092 | 0.168 | 0.114 | 0.568 | 0.168 |
|     9 |   0 |   9 |   0 |   0 |   0 | 0.028 | 0.180 | 0.108 | 0.968 | 0.180 |
|    11 |   0 |  11 |   0 |   0 |   0 | 0.040 | 0.176 | 0.102 | 1.120 | 0.116 |
|     5 |   0 |   5 |   0 |   0 |   0 | 0.056 | 0.084 | 0.071 | 0.356 | 0.056 |
|     2 |   0 |   2 |   0 |   0 |   0 | 0.044 | 0.044 | 0.044 | 0.088 | 0.044 |
|     9 |   0 |   8 |   0 |   1 |   0 | 0.004 | 0.024 | 0.012 | 0.108 | 0.004 |
|    10 |   0 |   8 |   0 |   2 |   0 | 0.004 | 0.020 | 0.008 | 0.080 | 0.000 |
|     8 |   0 |   8 |   0 |   0 |   0 | 0.000 | 0.016 | 0.005 | 0.036 | 0.000 |
|     8 |   0 |   8 |   0 |   0 |   0 | 0.000 | 0.020 | 0.003 | 0.020 | 0.000 |
|     4 |   0 |   4 |   0 |   0 |   0 | 0.000 | 0.004 | 0.002 | 0.008 | 0.000 |
|     4 |   0 |   4 |   0 |   0 |   0 | 0.000 | 0.004 | 0.001 | 0.004 | 0.000 |
+-------+-----+-----+-----+-----+-----+-------+-------+-------+-------+-------+
|    90 |   0 |  87 |   0 |   3 |   0 |
+-------+-----+-----+-----+-----+-----+-------+-------+-------+-------+-------+

まとめ

ISUCON10オンライン予選問題のアクセスログを例にalpの使い方を紹介しました。
ISUCONに参加する方もそうでない方にも役立てば幸いです。

要望があればGitHub Issueか本記事にコメントお願いします。また、PullRequestも歓迎しています!

おまけ

ISUCON用にアクセスログやスロークエリログを自動で集計するツールも作成しているのでそちらも紹介します。

https://github.com/tkuchiki/watchcat

watchcatは、ファイルサイズ・更新日時を監視して、ファイルがしばらく更新されなくなり、かつ指定したバイト数以上増加したときに増分を任意のコマンドにpipeで渡すことができます。

alpを例に使い方を説明します。以下のようなshellscriptを用意しておき(ファイルはcommand.shとします)、

#!/bin/bash

cat - | alp json

以下のように実行します。

$ watchcat --interval 5s --no-changes=10 --filesize=1024 --file /path/to/access.log --command command.sh

このとき、watchcatは以下のように動作します。

  • 5秒ごとに/path/to/access.logのファイルサイズと更新日時をチェック
  • 最終更新日時から10秒以上経過
  • かつ、1024バイト以上ファイルが増加していたら
  • ファイルの増分をcommand.shにpipeで渡す
  • コマンドを実行したあとは、ファイルをどこまで読み込んだか記憶

--filesizeを適切に設定すると、ベンチマークを実行する前に少しアプリを触ってみたときのログなどを集計対象から除外できる想定で、--no-changesで指定した時間(秒)以上ファイルが更新されておらず、--filesizeで指定したバイト数未満しか更新されていないと、ファイルをどこまで読み込んだかの情報を更新して、次回の集計の対象外にします。

これを使うと、ベンチマーク実行中は常にログファイルが更新されているのでalpで集計されず、ベンチマークが完了してログファイルが更新されなくなったらalpで集計する、けれどアプリを少し触ったときのログは集計対象から除外する、ということができます(アプリを触って即ベンチマークを実行した場合はその限りではありません)。
上記の例ではcommand.shでalpを実行するだけなので意味はないですが、その結果をSlackやGitHub Issueにpostすると便利です。alpは--output mdを指定することで出力をテーブル形式からmarkdownのテーブル形式に変更することができますので、私はGitHub Issueにpostするときにこのオプションを使っています。

アクセスログやスロークエリログを自動集計するようにしたいけれど、まだその仕組を持っていない方は是非使ってみていただけると幸いです。