数日前の話、同僚からサポート issue の調査について相談を受けた。内容は「フォローリストが正しく表示されない(数人足りない)」というものだった。

最初にうちの会社の環境を紹介しておくと、メイン事業はモノリシックで巨大な rails で書かれている。最近は機能や開発を担当するチームごとに切り崩してマイクロサービス化される事例も増えてきた。今回調査したフォローシステムを提供するアプリケーションもメインの rails アプリケーションとは別に小さな rails として動いていた。

事前調査していた同僚から「DB 上のソーシャルグラフは正常だった事」と「名前のないユーザーはフォローリストに表示されない事」を教えてもらった。今回のサポート issue に挙がってきた事例もユーザー名が無いことが原因の様で、それはシステム上意図してない挙動だった。

調査の手始めにユーザー名の管理について調べた。DB はアプリケーション毎に別のものを参照していた。ユーザー名はメインの rails とフォローシステムの rails で二重管理されていて、メインの User モデルに変更があると内製の Pub/Sub システムを経由して変更内容が同期されるようになっていた。

Pub/Sub システムは Queue を持っていて、イベントが publish されると Queue にどんどん積んでいく。積まれたイベントは非同期にデキューされ、紐付けられた Docker イメージが立ち上がり事前に設定したスクリプトがその中で実行される。

デキュー後の処理はごく稀に失敗することを把握していたので今回もそこが原因だろうと考えた。

ところが影響範囲を調べてみると数十万人(直近数日でも数百人)の規模で起こっていることが判明して読みが外れていることに気づいた。デキュー後の処理が失敗するのは一日数件程度なので、もっと根本的なバグがありそうだった。

調査を再開して User モデル内の該当イベントが publish されている箇所を調べた。最近入った何らかの変更でイベントが飛ばなくなったみたいな話はいかにもありそうだ。そこで該当のイベント名で grep した見たところやはり見当たらなかった。

「おっエンバグの線で当たりかな..」と思ったがこれも間違いだった。User レコードが書き換わったときに該当イベントの publish をチェックするユニットテストが見つかった。 もしイベントが publish されなくなっていたらこのテストケースで気付くことができる。しかし master CI はずっと green のままだったし、当たり前だけれど手元でテストを実行してももちろん成功した。ここでエンバグによって publish イベントが消えたという線はなくなった。

やや脇道に逸れるけど一体どんな仕組みで該当イベントを publish しているのかどうしても気になったので該当モデルのコードをもう少し読んでみた。すると何かのイベントを publish している処理を見つけた。注意深くコードを追うとイベント名がメタプログラミングチックに組み立てられていることに気づいた。「なるほどだからさっきの grep では引っかからなかったのか」と納得が入った。一方で「なんて grep ビリティが低いコードなんだ。こんなに処理を汎化する意味はあるんだろうか...これだから ruby は..」と悪態をつきたくなった。(もちろんほとんど冗談の文脈。 ruby は別に悪くないし grep しさすさを重視するかは個人の好みに分かれそう)

イベントの publish までは正しく行われていることがわかった。次に疑うべきはイベントが流れる経路と subscribe 側の処理なのだけどここは疑う余地がほとんど無かった。他の Pub/Sub システムを利用したサービスは正常に動いていたし、さらに言えば内製の Pub/Sub システムはほとんど AWS のサービスのラッパーみたいなもので AWS 側で障害が起こったりしない限り原因になりえそうに無かったからだ。仮に障害が起こっていたら技術基盤かインフラチームの人がいち早く気づいて共有してくれると思うのでこのあたりを疑うのはすぐにやめた。

こうなってくると手詰まりで「申し訳ないけどちょっと原因がわからないな ちゃんと時間を確保して調べてみないとダメそうですね」という話をした。

他の作業も残っているので一旦調査をやめようかと思っていたのだけど、ふと昨年関わった仕事のことを思い出した。 そういえばユーザー登録基盤はメインの rails から引き剥がされてマイクロサービス化されていたのだ。

「ユーザー登録基盤の rails はメインの rails と DB を共有していて、ユーザー登録基盤の rails から DB を書き換えるとイベントが発火しないのでは」という仮説が偶然思いついた。結論だけ言うと大体合っていた。正確にはほとんどのテーブルは共有してなかったが users テーブルのみ直接参照/書き込みしていた。 (あまり詳しくないので間違っているかもしれない)

rails のチュートリアルに登場するフォローリストなら中間テーブルから一覧を引いてきて、ユーザー情報を列挙するだけのシンプルな実装で十分だけど、現実のフォローリストには無名のユーザーが表示されないロジックがあったり、ユーザー名は pub/sub で渡ってきて登録されていたり、とても複雑な構成になっていた。

たまたま思いついた雑な推測から原因が特定できて問題は解決したのだけど、現代のフォローリストは複雑なんだなーと思ったのが印象的でブログに調査ログを書いてみた。

今回の調査でアプリケーション間で DB の共有すると状況を把握するのが大変になるので、(しょうがないケースも多いけど) 出来るだけ避けたいですね。という学びがあった。アンチパターンなことは知ってはいたけれど、どういうケースで困るのか理解できていなかった。