
App Runner環境で生じた障害調査とAWS WAFによる暫定対策を実施しました
この記事は公開されてから1年以上経過しています。情報が古い可能性がありますので、ご注意ください。
6/4 10:30 〜 11:50 (JST) App Runner 環境で発生した、遅延とエラー率が上昇する事象について、実施した対応について紹介させていただきます。
App Runner
App Runnerのダッシュボードを利用して、稼働状態の確認。
- 正常応答(HTTP 2xx)数が減少
- エラー応答(HTTP 4xx、5xx)と、レイテンシーが増加
の発生を確認しました。

App Runnerのアプリログを、エラー応答、レイテンシーが増加した時間帯を指定して確認。 タイムアウトに伴うエラーが記録されていました。

アプリケーションログ、 CloudWatch Logsの 「ログ異常検出」でも、タイムアウトに関連するログの急増が確認できました。

アクセスログ調査
準備
外部からの大量アクセス、DoS、DDoSの可能性を確認するため、App Runnerの前段の CloudFrontの標準アクセスログの調査を行いました。
対象の CloudFront、標準アクセスログはS3にそのまま出力する設定で利用中。
Athenaで不要なフルスキャンを避けるために、作業用のS3バケットを用意しました。
TEMP_S3='s3://athena-temp-ap-northeast-1-000000000000/'
aws s3 mb ${TEMP_S3}
s3 syncコマンドを利用して、調査対象となる時間帯を含むログを作業用S3バケットにコピーしました。
LOG_S3='s3://cloudfront-logs-ap-northeast-1-00000000/xxxx/'
aws s3 sync --dryrun --exclude '*' --include '*2024-06-04-0[0,1,2,3]*.gz' ${LOG_S3} ${TEMP_S3}
aws s3 sync --exclude '*' --include '*2024-06-04-0[0,1,2,3]*gz' ${LOG_S3} ${TEMP_S3}
Athenaのテーブルを AWSドキュメントに記載された、CloudFrontの標準ログ用のサンプルを踏襲、 作業用S3バケットのログが対象となる指定で作成しました。
CREATE EXTERNAL TABLE IF NOT EXISTS cloudfront_standard_logs ( `date` DATE, time STRING, x_edge_location STRING, sc_bytes BIGINT, c_ip STRING, cs_method STRING, cs_host STRING, cs_uri_stem STRING, sc_status INT, cs_referrer STRING, cs_user_agent STRING, cs_uri_query STRING, cs_cookie STRING, x_edge_result_type STRING, x_edge_request_id STRING, x_host_header STRING, cs_protocol STRING, cs_bytes BIGINT, time_taken FLOAT, x_forwarded_for STRING, ssl_protocol STRING, ssl_cipher STRING, x_edge_response_result_type STRING, cs_protocol_version STRING, fle_status STRING, fle_encrypted_fields INT, c_port INT, time_to_first_byte FLOAT, x_edge_detailed_result_type STRING, sc_content_type STRING, sc_content_len BIGINT, sc_range_start BIGINT, sc_range_end BIGINT ) ROW FORMAT DELIMITED FIELDS TERMINATED BY '\t' LOCATION 's3://athena-temp-ap-northeast-1-000000000000/' TBLPROPERTIES ( 'skip.header.line.count'='2' )
Athena解析
IPアドレス、UserAgent
過負荷の原因となったIPアドレス、UserAgentを求めました。
select
a.*,
a.required_time_sum / b.required_time_sum * 100
from
(
SELECT
c_ip,
substr(cs_user_agent, 1, 32) as cs_ua,
count(1) as request_count,
sum(time_taken) as required_time_sum
FROM
"default"."cloudfront_standard_logs"
group by
c_ip,
cs_user_agent
order by
sum(time_taken) desc
) a, (
SELECT
sum(time_taken) as required_time_sum
FROM
"default"."cloudfront_standard_logs"
) b
order by
a.required_time_sum desc
limit
10
負荷の10%相当が2つのIPである事。 UserAgent情報より、Pythonスクリプトと、kendraによるクローラーによる過負荷の可能性が確認されました。
| c_ip | cs_ua | request_count | required_time_sum | 所要時間比率(%) |
|---|---|---|---|---|
| 2600:1900:2000::::* | python-requests/2.32.3 | 18353 | 22470.455 | 6.7 |
| 13.114.. | amazon-kendra-customer-id-ca0d58 | 5160 | 16303.138 | 4.8 |
| 54.249.. | HatenaBlog-bot/0.02%20(+https:// | 1228 | 6086.256 | 1.8 |
| 54.249.. | HatenaBlog-bot/0.02%20(+https:// | 1141 | 5512.005 | 1.6 |
| 43.206.**.*** | curl/8.3.0 | 207 | 4162.735 | 1.2 |
| 107.178.. | Hatena-Favicon/2%20(https://www. | 989 | 2848.572 | 0.8 |
| 3.224.. | Mozilla/5.0%20(Macintosh;%20Inte | 602 | 1863.912 | 0.6 |
| 40.77.. | Mozilla/5.0%20AppleWebKit/537.36 | 351 | 1732.096 | 0.5 |
| 52.70.. | Mozilla/5.0%20(Macintosh;%20Inte | 539 | 1717.954 | 0.5 |
| 107.178.. | Hatena-Favicon/2%20(https://www. | 481 | 1573.606 | 0.5 |
10分毎の遷移
上位2つのIPアドレスに限定し、リクエスト数、所要時間の遷移を確認しました。
SELECT substr(time, 1, 4) || '0' as time_HHm0, count(1) as request_count, sum(time_taken) as required_time_sum FROM "default"."cloudfront_standard_logs" where c_ip = '2600:1900:2000:**::*:**' group by substr(time, 1, 4) || '0' order by time_HHm0
Python
| time_HHm0 | request_count | required_time_sum |
|---|---|---|
| 0:00 | 588 | 23.019001 |
| 0:10 | 1175 | 21.003 |
| 0:20 | 1357 | 102.297 |
| 0:30 | 261 | 4.396 |
| 0:40 | 908 | 40.65 |
| 0:50 | 461 | 15.831 |
| 1:00 | 641 | 20.357 |
| 1:10 | 1600 | 107.948 |
| 1:20 | 942 | 156.14 |
| 1:30 | 516 | 115.716 |
| 1:40 | 989 | 757.788 |
| 1:50 | 162 | 267.442 |
| 2:00 | 654 | 1783.432 |
| 2:10 | 1530 | 4276.497 |
| 2:20 | 905 | 1023.052 |
| 2:30 | 428 | 1915.644 |
| 2:40 | 738 | 4008.708 |
| 2:50 | 409 | 2037.077 |
| 3:00 | 697 | 1458.379 |
| 3:10 | 1375 | 1519.558 |
| 3:20 | 1045 | 2004.031 |
| 3:30 | 461 | 302.908 |
| 3:40 | 511 | 508.582 |
- 遅延やエラー応答の割合が顕著に増加した11時台、多数のリクエストと、長い応答時間が記録されていました。
kendra
| time_HHm0 | request_count | required_time_sum |
|---|---|---|
| 1:00 | 275 | 467.917 |
| 1:10 | 716 | 2171.106 |
| 1:20 | 349 | 2188.694 |
| 1:30 | 521 | 2165.101 |
| 1:40 | 354 | 2153.986 |
| 1:50 | 517 | 2113.016 |
| 2:00 | 309 | 1976.889 |
| 2:10 | 361 | 741.236 |
| 2:20 | 281 | 261.597 |
| 2:30 | 65 | 250.167 |
| 2:40 | 60 | 313.376 |
| 2:50 | 125 | 799.051 |
| 3:10 | 99 | 192.564 |
| 3:20 | 100 | 210.747 |
| 3:30 | 56 | 136.44 |
| 3:40 | 1 | 1.92 |
- 11時台、エラー率や遅延が増加した時間帯のリクエストは少なく、主原因ではないと判断しました。
対策
暫定対策 1
Pythonスクリプトの実行元IPアドレスを AWS WAFの IP Setsに登録。 WAF ACLsで遮断ルールの対象とする事で、暫定処置をとりました。

暫定対策 2
異なるIPアドレスからの再発に備え、過負荷対策としてレートルールの導入に向けた準備に取り掛かりました。
Bot Control ルールを有効化。Bot Categories情報の判定結果を評価中です。

検索エンジン(search_engine)、SNS(social_media)以外のBotを対象としたレートルール制限を導入する事で、 サーバ側の性能に対し、高性能すぎるクローラー対策とする予定です。
Bot Control ルールの精度や、レートルールとの組み合わせ利用については、追って紹介させて頂きたいと思います。







