URL パスごとにレイテンシーやアクセス数を分析する (ALB + Athena)

# ALB のログで URL パスごとに分析したい

Web アプリケーションのパフォーマンス問題に遭遇することがあります。その際に、闇雲にパフォーマンスチューニング行うのは、あまり良い方法とは言えないです。お金でリソースを購入するスケールアウト/アップの対応は考えられますが、エンジニアとしてはお金以外の解決策も持っておきたいです。通常、まずはボトルネックを特定したうえで、その後の対策を行います。

ざっくりどこの URL パスにボトルネックがありそうかを把握したくなります。そこで、ALB のアクセスログを基に Athena を利用して検索することで、URL パスごとのレイテンシーやアクセス回数などを把握する方法を紹介します。



# S3 バケットポリシー

ALB のアクセスログは、S3 に出力する機能があります。これを利用するため、S3 バケットポリシーを編集します。

![image-20250104103815383.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/1002774/b0afe27b-f2ec-8621-4e13-5af956986b07.png)



東京リージョンの場合は、次のようなポリシーを入れます。[ALB を動かしているリージョンごとに許可する Account ID が異なるので、こちらのドキュメントを基に指定します。](https://docs.aws.amazon.com/ja_jp/elasticloadbalancing/latest/application/enable-access-logging.html)

```
{
  "Version": "2012-10-17",
  "Statement": [
    {
      "Effect": "Allow",
      "Principal": {
        "AWS": "arn:aws:iam::582318560864:root"
      },
      "Action": "s3:PutObject",
      "Resource": "arn:aws:s3:::alb-cognito-nginx01-logs/*"
    }
  ]
}
```



![image-20250104103848833.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/1002774/9c7f4d14-7f97-d98b-cb7b-384404211e1e.png)



# ALB でログ設定

ALB 側でログを S3 に出力する設定をします。Attributes タブから Edit を押します。

![image-20250104103336346.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/1002774/97547c57-ac18-487f-dc78-86edad80b5e2.png)



Monitoring の欄で、出力先の S3 バケットを指定します。

![image-20250104103545144.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/1002774/443e0421-0007-5803-7da6-aecb1c279b11.png)

# S3 ログ確認

その後、ALB にアクセスすると、実際にログが出力されている様子が確認できます。

![image-20250104104042022.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/1002774/82582b5c-aaad-bea7-04de-df490dda130b.png)



こんな感じで、リージョンや日付ごとにディレクトリが切られて、5 分ごと、ALB の Node ごとに gz ファイルが出力されています。

![image-20250104104132583.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/1002774/86b96348-00b4-4979-2d94-d6c9ecb4723c.png)



# Athena のテーブル作成

Athena の操作方法は省略しますが、[ALB のログ出力の形式に合わせた Table の Create 文が公式で提供されています。](https://docs.aws.amazon.com/ja_jp/athena/latest/ug/create-alb-access-logs-table.html) これの Create 文を利用して、Athena 上で SQL クエリーを発行できるように準備を進めます。

Tips : 公式の Create 文ではパーティションが定義されておらず、大規模になってくると料金やパフォーマンス面で気になってきます。また、ALB は 5 分ごとに gz ファイルを出力するため、細かいファイルが多く出来上がります。大規模な環境では、パーティショニングや定期的に Parquet 形式にまとめる方法を検討してもいいかもしれません。 

```
CREATE EXTERNAL TABLE IF NOT EXISTS alb_access_logs (
            type string,
            time string,
            elb string,
            client_ip string,
            client_port int,
            target_ip string,
            target_port int,
            request_processing_time double,
            target_processing_time double,
            response_processing_time double,
            elb_status_code int,
            target_status_code string,
            received_bytes bigint,
            sent_bytes bigint,
            request_verb string,
            request_url string,
            request_proto string,
            user_agent string,
            ssl_cipher string,
            ssl_protocol string,
            target_group_arn string,
            trace_id string,
            domain_name string,
            chosen_cert_arn string,
            matched_rule_priority string,
            request_creation_time string,
            actions_executed string,
            redirect_url string,
            lambda_error_reason string,
            target_port_list string,
            target_status_code_list string,
            classification string,
            classification_reason string,
            conn_trace_id string
            )
            ROW FORMAT SERDE 'org.apache.hadoop.hive.serde2.RegexSerDe'
            WITH SERDEPROPERTIES (
            'serialization.format' = '1',
            'input.regex' = 
        '([^ ]*) ([^ ]*) ([^ ]*) ([^ ]*):([0-9]*) ([^ ]*)[:-]([0-9]*) ([-.0-9]*) ([-.0-9]*) ([-.0-9]*) (|[-0-9]*) (-|[-0-9]*) ([-0-9]*) ([-0-9]*) \"([^ ]*) (.*) (- |[^ ]*)\" \"([^\"]*)\" ([A-Z0-9-_]+) ([A-Za-z0-9.-]*) ([^ ]*) \"([^\"]*)\" \"([^\"]*)\" \"([^\"]*)\" ([-.0-9]*) ([^ ]*) \"([^\"]*)\" \"([^\"]*)\" \"([^ ]*)\" \"([^\\s]+?)\" \"([^\\s]+)\" \"([^ ]*)\" \"([^ ]*)\" ?([^ ]*)?'
            )
            LOCATION 's3://alb-cognito-nginx01-logs/accesslogs/'
```



# ALB のログフォーマット

ALB が出力するログのフォーマットが、[こちらの Document で整理されています。](https://docs.aws.amazon.com/ja_jp/elasticloadbalancing/latest/application/load-balancer-access-logs.html)



重要な列をピックアップします。

- target_processing_time : ロードバランサーがターゲットにリクエストを送信した時点から、そのターゲットが応答ヘッダーの送信を開始した時点までの合計経過時間。つまり、EC2 などの Web アプリケーション側の処理にかかるレイテンシー。
- request : URI パスを含めたアクセス先の表示



上記の 2 列のデータをコアに分析することで、どの Path にどれくらいの時間がかかっていそうなのか、パフォーマンス概要を把握できます。特に遅い Path や、アクセス回数が多い Path を発見できたら、そこでより深くボトルネックを確認する動きに活かせます。



# Athena でクエリーを行う

いくつか Athena で分析してみましょう。



- 直近 1 週間以内
- 最も Web アプリ側の処理時間 (target_processing_time) が長い URL Path を Top 10 まで表示

```
SELECT 
    time,
    request_url,
    request_processing_time,
    target_processing_time,
    response_processing_time,
    elb_status_code,
    client_ip
FROM alb_access_logs
WHERE target_processing_time > 0
    AND time >= date_format(current_timestamp - interval '7' day, '%Y-%m-%dT%H:%i:%s.000Z')
ORDER BY target_processing_time DESC
LIMIT 10;
```



実行例

![image-20250104162825460.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/1002774/6f751352-b65b-56d5-cd90-b610caa72b35.png)



- 直近 1 週間以内
- url_extract_path を利用して、URL パラメーターが付与されているものでも同じ Path をまとめる。以下のように同じ Path で異なる Parameter である場合でも、同じ Path として Group By を行い集計する。
  - /sample?testkey1=testvalue1
  - /sample?testkey2=testvalue2
  - /sample?testkey3=testvalue3
- 最も Web アプリ側の処理時間 (target_processing_time) が長い順に Path を表示
- アクセス数を表示

- アクセス数と平均レイテンシーを掛け算を行い、処理に費やしている時間の合計を

```
SELECT 
    domain_name,
    url_extract_path(request_url) as path,
    COUNT(*) as access_count,
    ROUND(AVG(target_processing_time), 3) as avg_target_processing_time,
    MAX(target_processing_time) as max_target_processing_time,
    MIN(target_processing_time) as min_target_processing_time,
    ROUND(COUNT(*) * AVG(target_processing_time), 3) as total_processing_time
FROM alb_access_logs
WHERE target_processing_time > 0
    AND time >= date_format(current_timestamp - interval '7' day, '%Y-%m-%dT%H:%i:%s.000Z')
    AND domain_name = 'cognito-nginx01.sugiaws.tokyo'
GROUP BY 
    domain_name,
    url_extract_path(request_url)
ORDER BY avg_target_processing_time DESC;
```



実行例

![image-20250104163622465.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/1002774/035e5095-dd9c-7522-bf09-0ac4219d77f2.png)



- アクセス元 IP の多い順

```
SELECT distinct client_ip, count() as count 
FROM alb_access_logs 
GROUP BY client_ip 
ORDER BY count() DESC
```





# その他 Tips 

- S3 に格納される日付は、UTC 時間で格納がされているので、日本時間でフィルターをしたい場合は時差に気を付ける。





# 参考 URL

https://docs.aws.amazon.com/elasticloadbalancing/latest/application/load-balancer-access-logs.html

[初心者向け]Application Load Balancerのアクセスログを、Amazon Athenaで色々なクエリを実行し分析してみた
https://dev.classmethod.jp/articles/application-load-balancer-athena-202306/