About
この記事は LITALICO Engineers Advent Calendar 2021 5日目の記事です。
株式会社LITALICOでSREグループのマネージャをしております、 tjinjinです。昨日は @nobuhide-saito の記事でした。キャラメルフラペチーノの食べたい。
さて、今回は原因不明のエラーを解決した話の流れを書きたいと思います。
前提
- 当該アプリはSPA + API（一部SSR)で構成されているマイクロサービスになります
- 社内ユーザと社外ユーザがそれぞれおります
問い合わせ
我々が運用しているアプリケーションで社内ユーザから突然エラー画面などが出てしまい、システムが利用できないことが頻発しているという連絡がありました。
サーバサイドではdatadogによるリソース監視及び、ログ監視をしていましたが、該当の問題を引き起こすような5XXエラーやリソースの逼迫は確認できておらず一旦は開発チーム側でクライアントサイドでのログを取るようにしました。
フロントエンドのログ
フロントエンドのログを確認したところ、いくつかエラーが出ていましたが概ね下記のようなエラーを検知しました
XHR error GET <社内のAPI>
フロントエンドでaxiosを使ってバックエンドのAPIをコールしており、そこで失敗しているようでした。エラーが起きているIPアドレスを確認するとほとんど社内ユーザのアクセスであり、社内で使っているツールやネットワークの問題かなと疑い始めました。エラーが起きているAPIは多種多様でした。
タスクフォース結成
開発・SREだけで解決する問題ではないものの、原因がはっきりしていなかったため小出しで社内のネットワークを管理しているチームと連携を取り始め、最終的にはCTO等を巻き込んでタスクフォースを結成しました。
最初の会合で現状起きている点を整理しました。
- エラーの頻度が低く、再現性が難しい点（当時時点で何人かのメンバーで再現確認を行ったが、再現性が0%だった）
- 各層においてログを確認する限り、完全な裏付けは難しいもののサーバサイドまで通信が到達していないように思われた（特にフロントエンドとサーバサイドのログの突き合わせはトレーシングするものが厳密にはなく状況証拠となってしまった）
ここで再現性を上げるため、よりエラーが出やすいユーザを調べ現地調査を行いました。
現地調査
特定のネットワークの問題なのか？切り分けるため社内インフラを司るチームと協力し、再現性テストを実施しました。
起きやすい時間帯にトライしても再現を試みるもなかなかエラーが出ず、諦めかけたタイミングでやっとエラーが出ました。ブラウザでログを確認すると、
net::ERR_SSL_PROTOCOL_ERROR
となっており、想定してなかったのでここから頭を抱え始めます。
エラー内容を拝見する限り、TCPでの3ウェイハンドシェイク後のSSLのハンドシェイク時何らかの問題が起きているように見えており、TCPレベルでは到達できている？という疑惑が出てきました。（当時確認してたのはこのエラーだけだったため、他のエラー内容があるかもとも考えておりました。）
上記エラー自体はググれば解決方法は出てきますが、問題は稀に出るということでした。まとめられている記事を引用しますと
- SSL状態をクリアする
- SSL証明書を確認する（DNS設定がまだ完全に浸透していない可能性があります）
- システムの時刻と日付を確認する
- ブラウザのキャッシュとCookieをクリアする
- ブラウザの拡張機能を無効にする
- ブラウザを最新バージョンに更新する
- オペレーティングシステムを更新する
- ウイルス対策とファイアウォールを一時的に無効にする（これらのソフトウェアが安全な接続を誤ってブロックする場合があります）
ERR_SSL_PROTOCOL_ERRORを解決する方法より引用
1,2,3,4,5,6,7,8 に関してはどれも原因を否定、もしくは可能性は低いと判断しました。
- APIコールを再度実行すると再現しない点。バージョン等の問題であれば、ずっとエラーが出続けるはず。
- エラーが出た際に、エラーが出る直前のリクエストまでは成功している点（同じドメインに対してAPIコールしている）。時刻ずれの可能性もSSL証明書の有効期限を考えると数秒のズレで大きく変わるとは考えづらい（OS時刻も別途確認済み）
ここから調査が難航します。
再現性を上げる/ユーザ調査及びリモート調査
一度起きたエラーの際にパケットキャプチャを取っていたので分析を行い、エラーが起きていない環境とのベースラインを比較し調査を行うなど、傾向分析をしていきました。
ただ大きな情報は得られず、再現性を上げる方向にシフトしていきました。
この時点でのフロントエンドのログとリクエスト数から推定される再現性は1%未満程度でした。
現時点の情報から社内から環境にアクセスするまでの間で何かが起きているのではないか？という仮説ができたので、いくつかのパターンを作ってユーザにも協力していただき切り分けを進めました。
同時にエラーが起きているネットワークにリモートから入れるようなマシンを手配していただき、調査をできるようにしました。
手がかり
私はパケットキャプチャを真面目にやったことがなかったので、この際本腰を入れようと 実践 パケット解析 第3版 を買って読みつつ、たまたま取れたエラーが起きた時間帯のパケットを細かく分析していきました。
TCPのやりとりやTLSのハンドシェイクなどを細かく見ていき、パケットの流れをみたいなとTCP Streamを見ていたところ、無線APでブロックをしてそうなログを見つけました。
これで後はベンダーに問い合わせすればすぐ解決するかなと思ったのですが、なかなかうまく話が進まずサポートとのやり取りを社内インフラチームで進めていただきました。
再現性1%の壁を超える
上記を進めていただく間、私はより詳細な情報を取るべくリモートPCを使った再現性の向上を狙いました。
数時間の格闘の末（心のなかで再現しろ！を唱えながらやりました。。。）、スーパーリロードするなどやることで再現性を5%くらいに上げられるようになりました（10分やって1回出るか程度）
ここで新たな発見もあり、SPAがAPIコールするときにエラーが出ると思ってましたが、fontファイルやGoogle Tag Managerでも同様のエラーが出ることも判明し、いよいよネットワーク層の問題という形になりました。
解決へ
社内インフラチームにAPの設定内容確認していただき、悪そうなfilterルールはないものの昔の名残で入れていた設定があったため、そこを試しに外していただくと9割型解決しました。
まだごくまれにでていますが、1/100程度までエラーを減らすことが出来ました（引き続き調査中です）。
まとめ
今回様々なチームを跨いだ総力戦になりました。開発者やSREグループのメンバーを始め、相談に乗ってくださった有識者の方々、現地調査やネットワークの調査などを進めてくださった社内インフラチーム、調査協力していただいた社内ユーザ、PC手配などを進めて頂いたサポートチーム、問い合わせ窓口となってくださった調整を引き受けていただいたPdMのメンバー、皆様ありがとうございました。また、問い合わせを上げてくださった社内のユーザの皆様ありがとうございました！
結果的に社内のユーザにご迷惑をおかけしており、その点はきちんと反省・及び問題の検知精度を上げるべき課題だと重く受け止めております。また、チームを巻き込む初動もスムーズだったか？と言われるとより良い進め方はあったと思っております。
ただ、ユーザに価値を届けるためにそれぞれが何をすべきか？という観点で多くの方々と一つの問題に対して動けたのは個人的に良い経験でした。引き続きユーザに価値を届けるため、自分には何が出来何をすべきか？をしっかり考えていきたいと思います。
明日は @_miki_ によるセキュリティエンジニアの考え方のお話です！乞うご期待下さい！