デプロイ後のAWS ALBエラー数高騰に対処した話

はじめに

こんにちは、はじめまして。イタンジ株式会社のtakumi1129と申します。

私事ではありますが、最近体重計に乗ったら体重が3桁になっておりました。
流石に冗談かと思って乗り直してみたものの冗談ではありませんでした。
正月太りって恐ろしいですね！
弟も3桁、父も3桁、3人合わせて300キロオーバー親子で御座います。
300キロ制限のエレベーターには3人で乗れません！
せめて2桁にしたいと思いリングフィットアドベンチャーを買いましたが、絶賛塩漬け中で御座います。

今回はデプロイしたらELB（ALB）でHTTPCode_ELB_5XX_Countが高騰した話をします。

最初に結論

  • デプロイによりECSタスクが作り直され、そのタイミングでELB - バックエンド間の通信が不安定になり5XXを返すようになった
  • ELBを作り直したら復旧した
  • 原因はロードバランサーノードの不具合

経緯

弊社のあるサービスはAWS ECS（Fargate）を利用しており、デプロイはCircleCI + Terraformという構成を取っております。
プルリクをマージしたらTerraformによりECSタスクが作り直され、新しいコンテナイメージが適用されるという構成です。

そのあるサービスで本番ECSに対してデプロイを行った直後、突然ELB_5XXが高騰しました。
そのサービスでは毎分1万アクセスほどあるんですが、大体20%ほど5XXが返っている状況です！
また、同じタイミングでターゲット接続エラーも出ているようです！！

f:id:takumi1129:20200127174336p:plainf:id:takumi1129:20200127174333p:plain

まず真っ先にECSタスクを再起動したものの、復旧しませんでした。

調査と対応

調査時に実施したこと

発生したのがデプロイの直後ということもあり最初はデプロイが原因かと思いましたが、
とにかくまずはCloudWatch上で異常が無いかどうかを確認しました。

その結果、サービスが利用しているELBのアベイラビリティゾーンのうち、
ap-northeast-1d （以下1d）からのアクセスのみELB 5XXを返している（ように見える）事がわかりました。

f:id:takumi1129:20200124191528p:plainf:id:takumi1129:20200124190800p:plain

ELBが5XXを返す原因として考えられるのは、バックエンドに何らかの問題が生じている場合のようです。
参考 : Application Load Balancer のトラブルシューティング https://docs.aws.amazon.com/ja_jp/elasticloadbalancing/latest/application/load-balancer-troubleshooting.html#load-balancer-http-error-codes

しかし！アベイラビリティゾーンが3つもあるのに、1dだけが5XX返すという状況は意図的にそういう状況を作らない限り成り得ないと考え、
ネットワーク周りの設定（SubnetのACL、ECSのSecurityGroup等）や、CloudTrailを確認してみましたが問題等は見つかりませんでした。
そのため、AWS側のネットワークに何らかの問題が発生したと推定し、1dを切り離すことにしました。

1dに原因があると推定しての対応

  1. ELBのサブネット切り替え
    まずサービスへの影響が無い部分からやろうと思い、ELBのサブネットを切り替えてみることにしました。
    これにより、ELBを名前解決した際に引けるIPが変わるため、
    IPが変わったことにより、事象が改善するのではないかと考えたためです。
    画面的には以下から1dを同じ1dの違うサブネットに変更しました。
    f:id:takumi1129:20200127173713p:plain digコマンドを利用し、ELBを名前解決した際に引けるIPが変わったことを確認しましたが、事象の解決には至りませんでした。
  2. ECSタスクを1dから1a,1cに散らす
    次にやったのは1dにあるECSタスクを1aと1cに散らす対応をしました。
    ECSタスクは全部で15個あり、そのうち1dでは6個動いていたので、 ECSサービスの設定変更を行い、この6個を他のAZに散らしてみましたが、 事象の解決には至りませんでした。
  3. ELBから1dのサブネット削除 1dで動いているECSタスクが無くなったので、ELBから1dのサブネットを削除してみることにしました。
    画面的には以下から1dのサブネットのチェックを外しました。 f:id:takumi1129:20200127173713p:plain しかし！これでも復旧しない！
    これはもうデプロイに原因があるに違いない！と考え、 ECSタスクをデプロイ前に戻すことにしました。

デプロイに原因があると推定しての対応

デプロイ前に戻す対応を行う前に、デプロイが原因でECSタスクが重くなり、
ELB - バックエンド間でタイムアウトを起こしている可能性もあると考え、
ELBでアイドルタイムアウトの設定変更を行いました。
しかし！！復旧せず！

満身創痍でECSタスクをデプロイ前に戻したものの・・
復旧せず！！！

さあどうしよう

このタイミングで大体午前3時
朝一には使えるようにしたかったので、必死に考えを巡らせました。

デプロイ直後に発生したのにデプロイ前に戻したのに復旧せず、
ELBサブネット変更も行ったのに復旧しない、
これはもうELBを作り直すぐらいしか方法は無いと考え、ELBを作り直すことにしました。

ELBが原因だと推定しての対応

ELBに原因がありそうとはいえ、DNSレコードをいきなり新側に向けたら設定漏れ等の問題があった場合に影響があるので、
DNSラウンドロビンを使い、新側に徐々にトラフィックを流すことにしました。
実施した内容としては、

  1. 新ELBの作成
    VPC、サブネット、バックエンド、SecurityGroupが全く同一の新ELBを作成しました。

  2. ECSサービスの設定変更
    1つのECSサービスに対して複数のELBを紐付けることが出来るので、そのように変更しました。
    参考 : Amazon ECS サービスで複数のロードバランサーターゲットグループのサポートを開始 https://aws.amazon.com/jp/about-aws/whats-new/2019/07/amazon-ecs-services-now-support-multiple-load-balancer-target-groups/

  3. DNSラウンドロビンの準備
    サービスで利用しているホストゾーンで、旧側ELBを向いているレコードと全く同一のレコードをもう1個作成し、向き先を新側ELBにしました。
    このままだとトラフィックが新側、旧側に1:1で流れてしまうため、まずは1/10だけ流れるように重み付けの設定を行いました。

  4. 効果測定
    なんと新側でELB_5XXが全く計測されず！！
    この時点で午前4時にも関わらず、テンションがここ1週間で最高潮に！
    心なしか体重も2桁に戻ったようです！
    f:id:takumi1129:20200127174730p:plain
  5. 重み付けの設定変更 旧ELBに問題があるということが確定したので、重み付けの設定を
    新側10 旧側0
    に変更しました。
    旧側の削除は行わず、AWSサポートに調査依頼を行うことにしました。

教訓

  • ネットワーク的にありえないグラフが表示されたらAWS側も疑ってみる

サポートからの回答

その後AWSサポートより回答があり、デプロイしたタイミングでロードバランサーノードに不具合が発生していたようで、それにより今回の事象が発生していたようです。
参考 : アベイラビリティーゾーンとロードバランサーノード https://docs.aws.amazon.com/ja_jp/elasticloadbalancing/latest/userguide/how-elastic-load-balancing-works.html#availability-zones