Application Load Balancer で TargetResponseTime メトリクスが増加している場合のトラブルシューティング方法を教えてください。

解決策

TargetResponseTime は、Application Load Balancer のアクセスログでの target_processing_time フィールドにあたるものです。

次の問題が原因で、TargetResponseTime メトリクスが増加する可能性があります。

ホストが異常状態である

異常のある Application Load Balancer のターゲットを解決するには、「Application Load Balancer のヘルスチェックに失敗した場合のトラブルシューティング方法を教えてください」を参照してください。

リクエストが多すぎて、バックエンドインスタンスが処理しきれない

Application Load Balancer の Amazon CloudWatch メトリクス RequestCount と ActiveConnectionCountで Sum 統計を確認します。TargetResponseTime の増加に伴って合計が増加している場合、リクエストが多すぎることが原因で、バックエンドインスタンスに負荷がかかっている可能性があります。

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

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

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

ターゲットに障害がある

障害が発生したターゲットがある場合は、次の手順を実行してください。

1. ロードバランサーでアクセスログを有効にします。
2. TargetResponseTime が高い時間帯のアクセスログをダウンロードします。例えば、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 リージョンに置き換えてください。

アクセスログをダウンロードした後、次のコマンドを実行してログを分析します。

ELB のアクセスログ

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