Application Load Balancer の TargetResponseTime メトリクスの増加をトラブルシューティングするにはどうすればよいですか?

簡単な説明

TargetResponseTime は、リクエストがロードバランサーから送信されてからターゲットからの応答が受信されるまでの経過時間 (秒) です。これは、Application Load Balancer のアクセスログの target_processing_time フィールドに相当します。

TargetResponseTime の増加には、次のような原因が考えられます。

• ホストが異常。
• バックエンドインスタンスがあまりにも多くのリクエストを受け取っている。
• バックエンドインスタンスの CPU 使用率が高い。
• 1 つまたは複数のターゲットに障害がある。
• バックエンドインスタンスで実行されているウェブアプリケーションの依存関係に問題がある。

解決方法

ホストが異常

すべての Application Load Balancer のターゲットが正常であることを確認します。「Application Load Balancer をトラブルシューティングし、ヘルスチェックの失敗を修正するにはどうすればよいですか?」を参照してください。

バックエンドインスタンスがあまりにも多くのリクエストを受け取っている

Application Load Balancer の RequestCount および ActiveConnectionCount メトリクスの Sum (合計) 統計を確認します。TargetResponseTime の増加と一致する合計の増加は、バックエンドインスタンスがリクエストロードに圧倒されていることを示唆している可能性があります。

この問題を解決するには、バックエンドインスタンス用に Auto Scaling グループを設定します。「Tutorial: Set up a scaled and load-balanced application」(チュートリアル: スケーリングとロードバランシングを使用するアプリケーションのセットアップ) を参照してください。

バックエンドインスタンスの CPU 使用率が高い

バックエンドインスタンスの CloudWatch CPUUtilization メトリクスを確認します。CPU 使用率が高い場合、または使用率が急上昇している場合は、インスタンスをより大きなインスタンスタイプにアップグレードします。

1 つまたは複数のターゲットに障害がある

ターゲットに障害がある場合は、次のステップに従って問題を解決してください。

1.    ロードバランサーのアクセスログ記録を有効にします。

2.    TargetResponseTime が高い時間範囲のアクセスログをダウンロードします。例えば、AWS Command Line Interface (AWS CLI) を使用して 2022-02-01T03:00 から 2022-02-01T03:35 までのアクセスログをダウンロードするには、次のようにします。

aws s3 cp s3://bucket-name[/prefix]/AWSLogs/aws-account-id/elasticloadbalancing/region/2022/02/01/ ./alblogs --recursive --exclude "*" --include "*20220201T03[0123]*"

注: bucket-name は自分のバケット名に、aws-account-id は自分の AWS アカウントの ID に、region は自分のアカウントがある AWS リージョンに置き換えます。

3.    コマンドラインツールを使用してアクセスログを分析します。

Elastic Load Balancing (ELB) アクセスログは .gzip 形式で圧縮されます。

オプションのステップ: ログを抽出するには、次のコマンドを使用します。

$   gzip -dr ./alblogs

サンプルシナリオ

target_processing_time の最大レイテンシーを取得するには、次のコマンドを実行します。

圧縮ログファイル:

$zcat *.log.gz | awk '$7 != -1' | awk 'BEGIN{a=0}{if ($7>0+a) a=$7} END{print a}'

非圧縮ログファイル:

$cat *.log | awk '$7 != -1' | awk 'BEGIN{a=0}{if ($7>0+a) a=$7} END{print a}'

• または -

ターゲットごとに target_processing_time が「>=N」秒であるリクエストの数をカウントするには、N を要件を満たす秒数に変更します。

圧縮ログファイルのコマンド例:

$zcat *.log.gz | awk '{if($7 >= N){print $5}}' | sort | uniq -c

非圧縮ログファイルのコマンド例:

$cat *.log | awk '{if($7 >= N){print $5}}' | sort | uniq -c

出力例:

12 10.10.20.111:80 
12 10.10.60.163:80
254 10.10.70.7:80
6 10.10.80.109:80
20656 10.3.19.141:80

前の例では、IP アドレスが 10.3.19.141 のターゲットが TargetResponseTime の増加の大部分を占めています。この場合は、ターゲットのオペレーティングシステム (OS) とウェブアプリケーションを確認します。

バックエンドインスタンスで実行されているウェブアプリケーションの依存関係に問題がある

ターゲットでパケットキャプチャを実行して、ターゲット応答の遅延を特定します。Linux OS の場合は tcpdump を使用します。

ポート TCP/80 での HTTP リクエストと応答を含む、完全な送受信の POST HTTP 送信をキャプチャするには、次の手順を実行します。

tcpdump -i any -ns 0 -A 'tcp dst port 80 and tcp[((tcp[12:1] & 0xf0) >> 2):4] = 0x504F5354 or tcp[((tcp[12:1] & 0xf0) >> 2):4] = 0x48545450 or tcp[((tcp[12:1] & 0xf0) >> 2):4] = 0x3C21444F'

ポート TCP/80 での HTTP リクエストと応答を含む、完全な送受信の GET HTTP 送信をキャプチャするには、次の手順を実行します。

tcpdump -i any -ns 0 -A 'tcp dst port 80 and tcp[((tcp[12:1] & 0xf0) >> 2):4] = 0x47455420 or tcp[((tcp[12:1] & 0xf0) >> 2):4] = 0x48545450 or tcp[((tcp[12:1] & 0xf0) >> 2):4] = 0x3C21444F'

出力例:

14:04:12.186593 IP 10.10.30.219.13000 > 10.10.60.10.http: Flags [P.], seq 641705534:641705793, ack 1587610435, win 106, options [nop,nop,TS val 1165674323 ecr 263805247],
    length 259: HTTP: GET / HTTP/1.1 E..7."@...I. .. < 2..P&?.>^..C...j9...... Ez.S..Y?GET / HTTP/1.1 X-Forwarded-For: 54.66.76.204 X-Forwarded-Proto: http X-Forwarded-Port: 80 Host: labalbinternet-1236602672.ap-southeast-2.elb.amazonaws.com
    X-Amzn-Trace-Id: Root=1-6254355c-15db4904726649b66a1e47d7 User-Agent: curl/7.79.1 Accept: */* ................

14:04:21.187892 IP 10.10.60.10.http > 10.10.30.219.13000: Flags [P.], seq 1:592, ack 259, win 488, options [nop,nop,TS val 263814250
    ecr 1165674323], length 591: HTTP: HTTP/1.1 200 OK E...\.@.@.l. < ...P2.^..C&?.A....qn..... ..|jEz.SHTTP/1.1 200 OK Date: Mon, 11 Apr 2022 14:04:12 GMT Server: Apache/2.4.52 () OpenSSL/1.0.2k-fips X-Powered-By: PHP/7.2.34 Upgrade: h2,h2c
    Connection: Upgrade Transfer-Encoding: chunked Content-Type: text/html; charset=UTF-8 159 PHP file name: /index.php<br> ................

注: 上記の出力例では、GET HTTP は 14:04:12 に応答し、ターゲットは 14:04:21 に応答します。TargetResponseTime は約 9 秒です。X-Amzn-Trace-Id: Root を使用して、アクセスログ内のこのレコードをトレースできます。

圧縮ログファイルのコマンド例:

$zcat *.log.gz | awk '{if($20 ~ "1-6254355c-15db4904726649b66a1e47d7"){print $6,$7,$8 }}'

非圧縮ログファイルのコマンド例:

$cat *.log | awk '{if($20 ~ "1-6254355c-15db4904726649b66a1e47d7"){print $6,$7,$8 }}'

出力例:

0.008 9.002 0.000

---