Mirrativ Tech Blog

株式会社ミラティブの開発者(バックエンド,iOS,Android,Unity,機械学習,インフラ, etc.)によるブログです

インターン中、タスクに付随する予想外のエラーと戦った話

初めまして。9月から10月にかけて、インターンとしてミラティブのバックエンド基盤に関わっていた、logicaと申します。
今回は、期間中に扱っていたある1つのタスクにフォーカスしながら、インターンを振り返りたいと思います。

割り当てられたタスク

比較的簡単な1つ目のタスクを終え会社の雰囲気にも慣れてきた頃、出された次のタスクは「開発環境のみ一定確率でmemcachedの値を返さないようにする」というものでした。

背景

Mirrativのバックエンドは設計としてクリーンアーキテクチャを採用していますが、そのデータソースとして主に、永続化を担当するMySQL、キャッシュを担当するradisha・memcachedが動いています。
radishaについて↓ tech.mirrativ.stream

2023年6月頃、Mirrativはmemcachedのインスタンスの入れ替えに起因する障害が起き、結果的にユーザーが強制ログアウトされるという事態を生みました。
当時の調査の結果、Google連携済みユーザーのセッション情報はmemcachedへキャッシュされるのみで、MySQLへの永続化が漏れていたことが原因であることがわかりました。

この障害自体はMySQLへの永続化を適切に行うことで解決しましたが、このままでは今後、memcachedのみに依存したコードが同様に書かれた時に気づけない可能性があるため、再発防止策として開発環境のみ一定確率でmemcachdの値を返さない仕組みを導入することにしました。

すぐに終わる想定だった

文面で見ると少し難しそうに見えるかもしれませんが、実際そこまで難しいタスクではありませんでした。

Mirrativのサーバーサイドは、大部分でGo + Clean Architectureが採用されています。 tech.mirrativ.stream Infra層にはmemcachedのClientが実装されており、memcachedを利用するDataSource層は必ずmemcached Clientを使用してmemcachedにアクセスしています。
このおかげで、memcached ClientのGet系メソッドに、50%の確率で空データ(nil)を返すようにすればよく、数時間のうちに調査と実装が完了しました。

問題が起きたのは、「よし、だいぶ速くコード理解ができたな」などと嬉しそうに考えながら検証用環境でチェックを行っていた時でした。

検証用環境で問題発生!

本番リリース前に修正の影響範囲を確かめるべく、検証用環境に変更をデプロイして動作確認を進めていたところ、同じく動作確認を行っていた複数のエンジニアから不具合の報告が上がりました。

管理画面へのログインができない

上がってきた報告は以下のようなものでした。

  • 「検証用環境の管理画面へのログインが、謎のエラーでできなくなっている」
  • 「ログインボタンを連打するとログインできた」

連打するとログインできるということは、回数または確率が関係している可能性が高く、僕の変更が何らかの影響を及ぼしていると推測しました。
検証用環境から僕の変更をrevertしてみるとエラーが出なくなったので、これでmemcachedのデータが取得できないと管理画面へのログインができない、ということがわかりました。

タスクの続行

メンターからは、「このバグの調査はタスクの本質ではなく、予定以上に時間を食ったり退屈になってしまったりする可能性もあるため、この調査は他の人に任せて別タスクを取る手もあるよ」という提案をされました。
どうするか少し迷いましたが、今までの経験上「予想外に対処して目的の状態まできちんと持っていく力こそエンジニアの本質である」と考え、バグの調査に進むことを選択しました。

原因究明

他の人に修正影響が及ばないよう別の開発環境上に僕の変更をデプロイして再現性を確認した後、調査を開始しました。

403エラー

Chrome Devtoolsを使い、ログインができなかったのはログインに使われているAPIが403エラーを返していたからだと特定しました。
しかしこの403エラーは、Mirrativサーバーサイドの機構を考えると少し厄介なのです。

Mirrativサーバーは、ユースケース層でのエラーではステータスコードを400、500番台にせず、ステータスコード200とエラー文を返す機構になっています。
すなわち、ログインのコア機能でエラーが起こったら、ステータスコード200とエラー文を返すはずです。

にも関わらず403エラーが返っているということは、ハンドラの前後で行われる共通処理で問題が起こっているはずだと推察できますが、共通処理はエンドポイントの種類に関わらず適用される上、様々な処理が行われているので調査は難航しました。

CSRFトークン

共通処理の中で403のステータスコードを返している箇所を探した結果、CSRFトークンの照合に失敗した時のみ返されていることが分かり、ここに原因を絞りました。

そこからは、メンターと情報を共有し、ログインに至るまでのフローの理解を手助けしていただきました。
CSRFトークンがデータソースを出入りするのは、ログイン画面のHTMLレンダリング時にCSRFトークンを生成してセッションに保存するタイミングと、ログイン時にセッションからCSRFトークンを取り出すタイミングです。
セッションはAPIが呼ばれるたびにデータソースから取得します。 MySQLの負荷を下げるためにまずはmemcachedから取得し、無ければMySQLから取得します。
セッション保存時はmemcachedとMySQLに保存します。

これらのタイミングに焦点を絞りmemcached / MySQLのデータを閲覧しながらログインを行ったところ、HTMLレンダリングの際のセッション保存時にMySQLへの永続化がされていないことが根本原因であるということが明らかになりました。
セッションが永続化されていないので、memcachedが値を返さないとCSRFトークンが入っていない空のセッションが取得されるため、CSRFトークンの照合に失敗して403エラーが返っていました。

セッションの非永続性

セッション保存時の関数を読むと、memcachedとMySQLへの保存処理が書かれていましたが、MySQLへの保存処理はセッション情報にログイン済みを表すフラグが含まれている時のみ行われていました。
これに詳しい社内のエンジニアに聞いてみたところ、これはMySQLのレコード量が不必要に増えることを抑えるためにやっているとのことでした。

今回のCSRFトークンはログイン前のHTMLレンダリング時に保存されるため、どのように対応するのがベストか、メンターと1 on 1で意見を交換しました。

対処

そもそもCSRFトークンは永続化するべきか

最初にログインしていない時でもセッションにダミーフラグを追加して、HTMLレンダリング時のセッションを常に永続化するという案がまず上がりました。

ですが、ログインしていない時にセッションで保持するべきデータはCSRFトークンのみです。
CSRFトークンは、ログインフォームが表示されてからAPIが叩かれるまでの短い間保持すればよく、また揮発してもリロードすれば問題なくログインできます。
そのため、管理画面であることとMySQLのレコード増加の影響を考えると割に合わないという結論に至り、今回は採用しないこととしました。

セッション用Clientのみ、一定確率で値を返さなくする対応を止める

Mirrativでは、memcached Clientはセッション用とアプリケーション用で分かれており、データ属性に応じて適切なmemcachedインスタンスに接続できるようにしています。
ここが分かれていることを利用して、memcached Clientに一定確率で値を返さなくする機構を有効にするかどうかを制御するためのフラグを追加しました。
セッション用のmemcached Clientではこのフラグをfalseにすることで、一定確率で値を返さなくする対応を止めました。

セッション周りがmemcachedの永続性のみに依存してしまっても気づけないという点に関しても対策を施しました。
最初はLintによってログイン済みフラグの設定漏れを検出するという案もありましたが、Lintの自作については抜け漏れなく設定漏れを検出するのが難しく信頼性に欠けるため、実装コストに見合わないと判断しました。
最終的に、「今後セッション周りのコードを書く際は、既存のコードを基にするだろう」という考えのもと、既存のコードの中でセッション用memcached Clientを利用している全ての箇所に、フラグを設定しないとMySQLへの永続化が行われない旨をコメントで記載しました。

以上の対応によりCSRFトークンが消えてログインに失敗する問題は解決し、検証用環境でのテスト・本番環境でのデプロイを通して、インターン中にタスクを無事終えることができました。

今回のタスクを振り返って

インターンとしてはなかなかできない、貴重な体験ができたと思っています!
基本的にインターン生には簡単で引っ掛かりポイントのないタスクが優先的に振られると思うのですが、幸い今まで参加したインターンでこのように想定外の事象に出会ったことが無かったため、原因調査から対処するというのは初めての経験でした。

今回の経験で、想定外の事象に対する恐怖感も少し薄れ、エンジニアとして一回り逞しくなれたのではないかと思います!
メンターにタスクの続きを他の人に委譲するという選択肢を与えていただいたことで、心理的安全性が保たれていたのもありがたいポイントでした。

また、今回はメンターを初めバックエンド周りを担当している複数人のエンジニアの皆さんにご意見やご協力いただいたことで、僕の中では一番良い形に落とし込むことができたなと感じています。
この場を借りて御礼申し上げたいと思います。ありがとうございました。

終わりに

長くなってしまいましたが、お付き合いいただきありがとうございました。
この記事を通して、少しでもミラティブやミラティブのインターンに興味を持っていただけたら幸いです。

ミラティブでは現在インターンを募集中ですので、気になる学生の皆さんはぜひ応募してみてください!

hrmos.co