SREチームの市原(@ichi_taro3) です。
モノタロウでは、www.monotaro.com という大規模なECサイトを自社で開発、運用しています。
Webアプリケーションの運用ではトラブルはつきものです。今回は、とあるトラブルシュート事例を軸に、どのように運用を改善しているのかについて紹介します。
どんなことが起こったのか?
あるとき、モノタロウのWebサービス全体でレイテンシ悪化やバックエンドAPIへのタイムアウトの増加が頻発したことがありました。
当然これらは歓迎される状況ではなく、すぐに開発者やSRE、インフラチームの担当者が集まり調査を開始しました。現象はトラフィックがかなり大きい時間帯に発生しており、なんらかのリソース不足だろうことは想像できました。
レイテンシ悪化自体はサービスの運用上経験することのあるもので、ある程度トラブルシュートのやり方は整理されていました。そのため、当初は原因がすぐに発見されて、問題は解決するだろうと思われました。
ところが、問題は即座に解決せず、鳴り止まないアラートに悩まされる事になったのです。
モノタロウのサイトの監視について
トラブルシュートの詳細に立ち入る前に、前提知識として、モノタロウのECサイトではどのような監視をしていたのかを簡単に紹介します。
Googleの書籍『Site Reliability Engineering』には監視(Monitoring)の基本となる The Four Golden Signals というものが紹介されています。
- レイテンシ(Latency)
- トラフィック (Traffic)
- エラー (Error)
- リソース (Saturation/サチュレーション)
モノタロウのサイトの監視の仕組みも概ねこのいずれかのSignalに分類することができます。
レイテンシ監視
提供しているサービスが、ある一定の速度で結果を返却できているかを監視します。Webアプリケーションにおいては、ブラウザがリクエストを送信してからレスポンスが返ってくるまでの時間や、描画速度、ロード時間などが問題になります。
モノタロウにとってもレイテンシは重要な指標です。サイトのレイテンシが悪化すると顧客体験が悪化し、お客様に商品をご購入頂く前にサイトから離脱してしまう可能性が高くなるからです。
そのため、ロードバランサーレベル、WebサーバーやAPIサーバーなどの個別のアプリケーションレベルなど、様々なレイヤでそれぞれでレイテンシの情報を取得しており、サイト全体の動作に関わる主要な指標については、Datadogのダッシュボードを利用して一覧できるようにしている他、ある閾値を超えた場合にはアラート通知を送信できるようにしています。また、BigQueryに集約している各リクエストのログを元に、それぞれのレイヤで処理にどの程度かかるのか統計を出せるようになっています。
今回の事例では、サイト全体のレイテンシを示すロードバランサーレベルでの指標と、Webサーバー・バックエンドのAPIサーバーの指標それぞれで遅延発生の通知が飛ぶことになりました。
トラフィック監視
Webアプリケーション運用においては、アクセス傾向を把握して、サイトが落ちないように十分な処理能力を確保しておくことが重要な仕事です。そのためには、過去から現在までにどのようなアクセスがあるのかを把握する必要があります。
モノタロウにおいては、CDNやロードバランサーレベルでのトラフィック情報をダッシュボードにのせて全体の傾向を見ています。
サイトの一時的な性能悪化はトラフィックの瞬間的な増大によりスケールが追いつかないパターンも多いため、トラブル発生時に現在のトラフィック状況を確認するのに利用しています。
また、各バックエンドのサービスごと、例えばホスト一台ごとの秒間リクエスト数(rps)がどの程度であるかを把握することで、サーバーのスペックやスケーリングの計画に役立てています。
余談ですが、モノタロウのサイトのアクセス傾向には特徴的な動きがあります。www.monotaro.com を利用いただいているお客様の大部分は法人や個人事業主の方であり、基本的にはB2Bが主体のサービスです。そのため、平日日中のトラフィックが最も大きくなり、昼休みを挟んで業務時間の終わりまでピークが続きます。B2Cがメインのサービスとは異なり、夜間や休日アクセス数は少ないのが現在の傾向です。お盆やお正月などもトラフィックが小さくなります。
エラー監視
ユーザーが期待した通りの正常なレスポンスをWebアプリケーションが正常に返却できているかは、サイトの信頼性を考える上で重要な指標です。エラー発生時にはその発生状況を適切に把握して、必要な手をうつ必要があります。
モノタロウでは、2つのアプローチでこの課題に対応しています。
まず、正常なレスポンスの割合を計測することで、サイトがどの程度の正常なレスポンスを返却できているかを判定しています。正常率は以下の計算式で考えます。
この数値が悪化している場合は、サイトを構成する要素のどこかで、何らかの問題が発生していることになります。正常率を計測することで、運用しているサービスが信頼できる状態であるかを客観的に示すことができます。
もう一つのアプローチが、アプリケーションのエラーそのものの通知です。
アプリケーションがクラッシュするような問題が発生した場合には、エラー報告が通知され、開発者はその通知を元にバグ修正の計画を行うことができます。エラー報告にはトレースの情報や環境情報も含まれていて、調査のヒントとなるように構成されています。
リソース監視
リソースの利用状況が逼迫していないかを監視します。
あるシステムがリソースを使っていることそのものは問題ではありませんが、許容限度以上にリソースが消費されてしまった場合、処理能力の低下や予期しないエラーの発生につながるため、監視をする必要があります。
例えば物理サーバーやVMでは、CPU使用率、メモリ使用率、ディスク使用率、ネットワークトラフィックなどが監視対象になりえます。
マネージドサービスでは、上記の観点は考慮しなくてよいことは多いですが、サービス特有のクオータの消費状況などは監視が必要な場合があるかもしれません。
モノタロウにおいては、ロードアベレージ、CPU使用率、メモリ使用率、ディスク使用率などの主要な指標はダッシュボードで一覧できるようになっており、トラブル発生時の調査に利用しています。ダッシュボードに載せていない指標も当然ありますが、Datadogなどのツールで必要に応じて過去のログを含めて参照できるようになっています。
ログ
ここまでの監視とはやや異なりますが、トラブルシュートの点でログも重要な構成要素です。
モノタロウでは、ほぼ全てのアプリケーションログやWebサーバーのログがBigQueryに集約されています。
サイトへの各アクセスにはユニークなIDが付与されていて、このIDを元に特定のリクエストのログをフロントからバックエンドまで横串に検索することができるようになっています。
また、サーバーごとのレスポンスタイムやステータスコードの統計を調査したり、アクセス傾向の分析などにも利用しています。
トラブルシュートの進め方
冒頭の事例に戻ります。
モノタロウのサービスで、レイテンシの悪化やタイムアウトエラーの通知が頻発する事態が起こっていました。
発生検知
サービスに問題が起こっていることを検知するために、モノタロウでは、単位時間あたりのサイトのエラー増加が閾値を超えた場合や、サイトのレイテンシが悪化した場合に担当者に通知が飛ぶように設定されています。
今回のトラブル事例では、ある短時間にエラーが増加しているというアラートと、レイテンシが悪化しているというアラートの両方の通知が飛ぶことになりました。サービスにアクセスしづらくなっていたり、利用しようとしてもクラッシュしてしまっている可能性があるため、原因を突き止めて解決する必要がありました。
発生箇所の特定
サイトを構成する要素のどこで問題が発生したかを明らかにする必要があります。
モノタロウでは、これまでの運用経験から、問題箇所を把握するための「いつもの」やり方というものがありました。
例えば、この事例のようなレイテンシの悪化の場合は次のような手順で問題を調査することが多いです。
担当者はまず、サイトについての代表的な指標を掲載したダッシュボードを参照します。トラフィック状況を確認して、サイト全体の傾向を知ります。トラフィックが上昇したことでサイトを構成する何らかの処理能力が不足してしまっている可能性を切り分けるためです。
トラフィックが上昇している場合、サーバーの処理能力不足という仮説を念頭において、各コンポーネントのロードアベレージ、CPU使用率、メモリ使用率などリソースの使用状況を調べます。これらの指標を比較することで、どこかで処理性能が不足してリソースの使用率が上昇していないかを探るのです。
また、タイムアウトが発生している場合は、発生箇所のログ情報やエラートレースからも推測の手がかりを得ることができます。
最も簡単なトラブルシュートの場合は、ここで処理能力が足りていないサーバーを特定して、スケールアウトすれば完了します。
この対応で問題が解決すれば、サーバー処理能力不足という仮説は妥当だったと判断できるためです。
今回の事例においても、はじめはスケールアウトして作業終了だと考えられていました。タイムアウトエラーの発生箇所の情報と、ダッシュボードに表示されたCPU、メモリなどのリソース使用量が増加していたことから、これまでに何度か経験したことがあるバックエンドAPIサーバーのリソースの逼迫だと判断されました。実際、対象のサービスをスケールアウトすることで、エラーは収束しました。このAPIサーバーの処理能力は増強したまま維持されたため、問題は解消されたかにみえました。
ところが、翌週になって再び同様の事象が発生しだしました。サイトのレイテンシ悪化やバックエンドAPIへのタイムアウトの頻発です。エラートレースの情報からは、前回と同様APIサーバーになんらかの問題があるように見受けられました。
「いつも」のダッシュボードで調査すると、ターゲットのAPIサーバーのリソース使用状況は、それほど悪化していませんでした。ここでスケールアウトを行っても、改善する可能性は低いと判断されました。最初の仮説だった「APIサーバー処理能力の不足」説は棄却されたのです。
これは後で判明したことですが、前週のスケールアウトで能力が向上したことによって、それまでAPIサーバーで詰まっていたリクエストがスムーズにバックエンドに流れるようになり、より後ろ側のコンポーネントに負荷が集中して新たなボトルネックが発生していたのです。スケールアウトをしたことで障害点が移動するという「落とし穴」にはまっていたのでした。
根本原因の調査
--
※ (2021/05/20 10:40) 「packets per second(pps)のクォータの超過(pps_allowance_exceeded)」を「接続カウント許容量のクォータの超過(conntrack_allowance_exceeded)」に修正
--
このように定形のやり方で調査しても原因が見つからないことは当然ありますが、無駄な作業ではありません。
問題がどのあたりで発生していそうかという絞り込みと、エラー発生箇所の処理能力不足ではないという情報を得ることができたためです。ここで得た情報を元に新たな仮説を立てて、本当の原因を探っていくことができます。
定常のダッシュボードで調査が不十分である場合は、より詳細な情報を収集する必要があります。
エラーの発生箇所はこれまでの切り分けにより当たりがついているので、仮説・検証のサイクルを繰り返しながら真因を探ります。検証には、ダッシュボードには掲載していないシステム指標やアプリケーションログなどの情報も駆使していきます。
次の仮説として疑われたのは、バックエンドの検索エンジンでした。問題が発生しているURLから、検索に関連する一連の処理のどこかで詰まっていることは明らかでした。APIサーバーから検索エンジンへの問い合わせを行う部分で、一定割合で処理の遅延が起こっていたことがログから判明していました。システムメトリクスのログからは、逼迫しているとまではいえないものの相対的にCPU使用率が上昇していることが分かりました。
チーム内では技術上の根本原因への確信はなかったものの、状況証拠から一旦検索エンジンを増強してみることにしました。
しかし、この仮説はハズレでした。検索エンジンのスケールアウト後も、レイテンシ悪化は定期的に発生したのです。
再度、発生箇所の特定が始まりました。
- 各サーバー個別のリクエストログを調べ直す
- エラー監視のトレースからタイムアウトエラーの詳細を整理する
- ネットワーク関係の統計を見直す
- Datadogで関係ありそうな指標を探索する
チームではまず、タイムアウトするようなレスポンスタイムの非常に遅いリクエストに何が起こっているのかを調べることにしました。すると、APIサーバーで非常に時間がかかっているはずの処理が、リバースプロキシと検索エンジンのログでは短時間で終わっていたのです。正常応答を返していたため、サーバーがクラッシュしたわけではないように思われました。
APIサーバーで時間がかかっていて、リバースプロキシで時間がかかっていないということは、APIサーバーからリバースプロキシに到達するまでの経路のどこかで処理に時間がかかっている可能性が高いといえます。
また、タイムアウトエラーのエラートレースからライブラリコードを詳細に調べると、TCPレベルでの接続確立時のタイムアウトが発生していることが分かってきました。
ここで、リバースプロキシにおけるTCP通信になんらかの問題が発生しているのではないか?という仮説が浮上したのです。
リバースプロキシは、CPU使用率やメモリ、ネットワーク帯域などスカスカといっていいほど余裕があったために、それまで原因の候補から外されていたのですが、改めてより詳細に調べられていきました。
すると、netstatの出力から、タイムアウト時にはカーネルレベルでSYNパケットがあふれたことを示す指標が増加していたことが判明しました。更に、EC2インスタンスのENIにおいて、接続カウント許容量のクォータの超過(conntrack_allowance_exceeded)も発生していたことが分かりました。Datadogのネットワーク系の指標を探索すると、タイムアウトが頻発するときにはtcp セグメントの再送(system.net.tcp.retrans_segs)が頻発していたことがわかり、これも傍証となりました。
ここまでの調査から、仮説を裏付ける証拠が多く見つかりました。APIサーバー-リバースプロキシ間でのTCP接続およびパケットが溢れてしまったというのが、真の発生箇所であり根本原因であったということが判明したのです。
原因の推測がつけば、対処は可能です。tcp接続数溢れの対策としてはリバースプロキシのスケールアウトよって処理可能な接続数を増やすことで解決することができました。また、同時に行ったスケールアップも効果を発揮しました。ENIの接続カウント許容量クオータはインスタンスタイプによって決定されるためです。実際、作業実施後に、サイトのレイテンシ悪化は発生しなくなり、一連のトラブルは解消しました。
強化
サービスが拡大していくと、考慮されていなかった層での課題が顕在化することがあります。今回の事例であれば、カーネルがネットワーク接続を扱う部分について、明示的に監視する必要が明らかになりました。
モノタロウ社内での事後の対応としては、監視項目がアップデートされることになりました。
それまでのCPUやメモリなどのリソースに加えて、ネットワーク接続に問題が発生した場合を検知できるようなメトリクスをいくつかダッシュボードに追加しました。これにより、次に同様の課題が発生した場合にも切り分けができるようにしたのです。
より詳細な情報を簡単に取得できるようにするため、監視設定の見直しも行い、同じ問題がおこってもすぐに分かるように対応しました。
変化し続けるサービスに対応して、監視も常にアップデートしていくことが重要なのです。
課題
ここまで、モノタロウのWebサービス運用における監視と運用について説明してきましたが、まだまだ沢山の課題があります。
理想的なシステム運用を考えれば、問題発生が自動的に検知されて、可能であれば自動で修復される、必要な場合だけ担当者に通知されるという状態が望ましいでしょう。
しかし、現在のモノタロウの運用・監視は、手動で行っている部分や人間の都度判断が必要な部分もまだ多くあります。
監視の定義そのものについても手動で設定されているものが多く、コード化によるレビューや自動適用などもこれから検討して導入したい、という段階です。
サイトの安定性を定義する最適な指標は何か、どうすればサイトが安定していると宣言できるのかについても、検討をすすめています。
SREのプラクティスにあるようなSLOベースでのサイト運用もチャレンジ中です。お客様にとって信頼できるサイトがどのようなものであるのかを定義した上で、適切なサービスレベルを設定し、維持運用したいと考えております。
おわりに
モノタロウでは、運用の高度化に一緒に挑戦しSREの取り組みを進めていくメンバーを募集しています。年間20%もの成長を続ける巨大ECサイトの開発・運用はチャレンジが多く刺激的です。
興味がある方は是非下のバナーをクリックしてみてください!