ログ欠損という失敗からの学びと問題解決を振り返る

この記事は NewsPicks Advent Calendar 2024 の14日目の記事です。

こんにちは!ソーシャル経済メディア「NewsPicks」の堀です。
主に法人顧客向けのサービスや機能の開発に携わっております。
今回はNewsPicksにおける「ログ」に関する失敗と、その問題解決に向けた取り組みについて紹介したいと思います。

ログは大事

まず、この記事で言及するログとは、OSのシステムログやアプリケーションのエラーログ等ではなく、NewsPicksのユーザーがどんな操作を行なったかを記録している「行動ログ」と呼ばれているものです。
NewsPicksでは、記事のタップ、スクロール、コメント投稿など、ユーザーのあらゆる操作を行動ログとして記録しています。
この行動ログは、複数段階の集計処理を経てユーザー分析などに活用されておりますが、法人事業や広告事業においては、PV、DAU、WAU、MAUといった数値をレポートとして顧客に提供しております。
ログが送信されてから顧客がレポートを参照するまでの流れを簡易的に表すとこのような感じになります。

送信されたログが集計されてレポートとして参照されるまでの流れ

簡易的な図ではありますが、行動ログが送信されてから最終的に数値レポートとして参照されるまでには、複数のサーバーやプロセス、DBを経ていることはお分かりいただけるかと思います。
また、最初の時点で行動ログが正しく保存されないと、顧客に間違った数値を提供するというビジネスリスクがあるということもお分かりいただけるかと思います。
ゆえにNewsPicksにおいてはログは大事なのです。

起きてしまった障害

しかし今年、特定の行動ログがWebブラウザから正常に送信、記録されず、顧客に提供している数値がずれてしまうという障害が発生しました。
さらに悪いことに、障害発生から問題の発覚および原因の特定までの間に数ヶ月経過してしまったこともありました。 一部の顧客には多大なご迷惑をおかけすることとなり、ログのリカバリー作業および数値の再集計、顧客への説明、謝罪対応などに追われました。 NewsPicksではこの問題を重く受け止め、二度と同じ失敗を起こさないために「ログ欠損再発防止タスクフォース」を組成し、その名の通りログ欠損を防ぐための取り組みを行ってきました。

なぜ障害が起きてしまったのか

そもそもなぜ障害が発生してしまったのでしょうか。
直接的な原因としては、

  • 機能改修で特定の画面での行動ログの送信条件が意図せず変更されてしまい、送信内容に一部欠損が生じてしまった。

  • インフラの設定変更で行動ログとして記録される内容に一部欠損が生じてしてしまった。

といった開発によるデグレードです。
しかし、なぜリリース前に問題に気づけなかったのでしょうか。
端的にはテスト不足ですが、もう少し掘り下げると

  • 開発者が修正の影響範囲を把握しきれておらず、テスト内容が不十分だった

  • テストケースは存在しているが、テストの実施判断を見誤った

といった問題がありました。
この問題の根本には、行動ログ送信周りの複雑な仕様や、記録された行動ログがどう活用されているのかをエンジニアが把握していなかったということがあったと思います。

また、障害発生から異常検出までに長期間を要してしまった点については、

  • ログ送信から数値レポート化までのプロセスが多く、問題箇所の検出が難しかった

  • 異常検出するための仕組みがなかった

といったものが原因として挙げられます。
こちらも障害の早期発見・対応という観点では無視できない問題です。

いろいろ挙げましたが、「ログは大事」であるにも関わらず、その重要度に対して品質保証の体制が整っていなかったということになります。

自動テスト化

とにかくこれ以上顧客の信頼を損なわないためにも、火急的速やかに再発防止策を講じる必要がありました。
そこで最初に短期的な再発防止策として取り組んだことは、重要ログの自動テスト化でした。
NewsPicksには膨大な種類の行動ログがあるので、まずはその中から「重要なログ = 欠損すると顧客へのインパクトが大きいログ」を精査しました。
例えば、前述のPV、DAU、WAU、DAUといった数値は顧客企業がNewsPicksのアクティブユーザーなどを把握するための重要指標です。
こういった重要な数値に影響を及ぼすログの精査から始めました。
重要ログを精査後には、ログを送信している画面、パラメータのパターンを再度洗い出してテストケースとして整備し直しました。
最後にテストケースを元に自動テストを作成しましたが、その仕組みに関してはNewsPicksの下記ブログに紹介されておりますので是非読んでみてください。

tech.uzabase.com

また、モバイルアプリから送信されるログのテストについては先んじて仕組み化されており、下記ブログにて紹介されております。
こちらも是非ご一読ください。

tech.uzabase.com

再発時の早期検知も大事

整備した自動テストは既に運用されており、バックエンド、フロントエンド問わずリリース時におけるデグレード防止の仕組みは整ったと言えます。
しかし、万が一ログ欠損が起きてしまった際に迅速に発見できるようにする策も必要です。
前述の通り、発生してから発覚するまでかなり時間が経過してしまったケースもありました。
こうした事態も防ぐために、一部のログについてはカウントや割合を定期監視し、異常を検知した場合にアラート通知する仕組みも整備しました。

今後の長期的な問題解決

「なぜ障害が起きてしまったのか」でも少し触れましたが、NewsPicksのログ送信の仕組みは複雑ゆえシニアエンジニアでも把握していない部分がありました。
さらに行動ログの仕様書はスプレッドシートで管理されておりますがメンテナンスがしやすいとは言えません。
同じ行動ログでも画面や記事の種別によって送信されるパラメータも異なるケースがあるため、これらをスプレッドシートで管理するには限界があります。 こうした問題の解決策として、ログ仕様書のコード化(TypeScript化)およびテストケースの自動生成を計画しております。
スプレッドシートから脱却し、エンジニアがメンテしやすいフォーマットで仕様書を定義できるようにし、さらにその仕様書からテストを生成、実行する仕組みを作ることで、ヒューマンエラーを防げるようにしていく予定です。

終わりに

NewsPicksはこれまでに様々な失敗を経験してきましたが、その都度反省し、問題解決を繰り返すことでプロダクトや組織を強化してきました。
今回の記事で紹介したログ欠損の障害は、今年1年を振り返った中でもかなりインパクトの大きな障害であり、お客様に多大なるご迷惑をおかけすることとなりました。
しかし、この失敗を重く受け止め、再発防止に向けて取り組んだ問題解決は、プロダクトをより強固にしていくと思います。
今後も問題解決は続きますが、より良いプロダクトを提供できるように努めてまいりたいと思います。

Page top