こんにちは。メディアサービス開発部Webアプリケーション開発課の奥川です。ニコニコ漫画のバックエンド開発を担当しています。

2021年初頭、ニコニコ漫画である作品の連載が開始されました。それに端を発する数カ月間のサーバ障害により、ユーザーの皆様には大変ご迷惑をおかけしました。

少し前の話にはなりますが、当時ニコニコ漫画のサーバでは何が起こっていたのか、どのような対応を行ったのかを振り返ってみたいと思います。

1号棟（事の起こり）

2021/01/08

問題の作品（以後、「作品I」*1と記述します）の第1話が投稿されます。その過激な内容からSNSなどでは一部で話題になりましたが、まだニコニコ漫画へのアクセスも穏やかなものでした。

2021/01/22

その2週間後、「第2話（前編）」の公開から事件が起こります。

ピークタイム最中の12:22頃から、まずmemcachedがCPU Utilization閾値を超過したとしてアラートを通知します。そこから間をおかずに各HTTPサーバに疎通できない警告が続々と届き、緊急で調査を開始しました。

アプリケーションのエラーログにはKVS（Key Value Store）からのデータ取得失敗が多く見られ、memcachedのCPU使用率と接続数が高い値で推移しています。ニコニコ漫画はmemcachedを酷使する仕組みのためアクセス増により性能上限に達してしまった可能性が頭をよぎります。しかし、すぐに対処できる改善策はなくアプリケーションのプロセスも連鎖的に飽和しているため、アプリケーションを一度問題のKVSから切り離して安定を図ります。

KVSの負荷が落ち着いたところで、今後はアプリケーションからデータベースに接続できないエラーが多発し始めました。データベース接続数は上がらないまま、処理中のプロセスも Error while reading greeting packet や mysql gone away といったメッセージを残して接続が安定しません。 RDSのPerformance Insightをみても目立った異常は見られず、スロークエリや（RDSの）エラーログにも特に出力はありませんでした。SHOW PROCESSLISTで重いクエリが負担になっている可能性も挙がりましたがこれも見つかりません。

問題発生の初日は特に有効な対処ができないままピークタイムが過ぎ、障害は自然に収束しました。

思い当たる原因としてはいくつか考えられましたが、どれも決め手となる情報もなく絞り込んで対処していくことが難しい状況でした。

アクセス数増加に伴う負荷上昇
直近のアプリケーション改修による負荷増加
KVS（memcached）の性能上限
何らかの原因によるデータベースの不安定化

2号棟（人妻たちとの戦い）

2021/01/25

この日は「作品I」の更新日ではありませんでしたが、前週と同様にKVSの負荷上昇と各HTTPサーバがプロセス数上限に達してサービス提供が困難な状況が発生していました。データベース接続数もかなり多くなっていますが、前週とは異なり接続エラーは確認できず状況の把握に苦心します。

比較的アクセスの多い曜日とはいえ急激に不安定になるということはまずアプリケーションに問題があると推測して直近の改修箇所から調査しました。この時期、ニコニコ漫画ではコインを利用することで無料公開よりも早く最新話が読める「先読み」機能を開発しており、この導入に向けた仕様変更が継続して行われていました。実装時点からパフォーマンス上の懸念は若干あったため、ここがアクセス集中時に負荷の一因になっていると考えチューニングを行います。この効果があったのか、その後しばらくは障害が再発することなくつかの間の平和が訪れます。

負荷増加に対してはスケーリングで解決する案もありましたが、アクセス数ではこれまでの傾向から極端に増えているようにもみえず、スケールアップが妥当な解決策になるという感触がありませんでした。既にそれなりのスペックで稼働しているKVSやデータベースにつて、費用インパクトの大きさに躊躇した面もあったかもしれません。

2021/02/05

ファン待望の「第2話（後編）」が公開されます。

前回の改善以降は安定稼働をみせていたニコニコ漫画でしたが、第1次ピークの11時台を平穏に乗り切り少し油断をしていたところで、やはり12:22頃からデータベース接続に失敗した旨のエラーが大量に出力されます。

この日のPerformance Insightでは更新処理による負荷がそれなりに高いことが確認されたため、上位のSQLを発行しているアプリ向けのセッション管理や閲覧数加算処理、しおり（既読情報）管理などを中心に負荷を減らす検討を始めました。SNSで話題になった影響でスマートフォン向けページにアクセスが増加したことから、特にゲストセッション周りで負荷が増えたのではないかという推測も立てます。

2021/02/12

障害の根本原因は未だ特定できないまま金曜日を迎えます。

負荷軽減の施策は少しずつ導入していますが、劇的な改善を見せるほどの効果はなく不安は払拭されません。「作品I」は更新されないため無事に過ぎることを祈っていましたが、この日はニコニコ漫画年間ランキングで2年連続1位を獲得した別の人気作品が更新されたことで、またも障害となってしまいます。

この日のデータベースでは津波のような謎の負荷傾向が確認されます。

これらの異常なグラフからもデータベースで何かが起こっていることは間違いありませんでしたが、特定のクエリが重いといった一般的な症状ではなく、負荷が高まった結果として接続障害や処理遅延などの問題が連鎖的に引き起こされているように思われました。また、この半年前にデータベースをオンプレミスからAmazon Auroraへと移行していたため、高負荷時の特性についてもまだ把握していないものがありました。

とはいえ、Writerインスタンスの負荷が高いことは従来からの課題でもあったため、当面は特に原因となりそうな箇所を中心に引き続き書き込み負荷を減らすチューニングを進めてデータベースの安定化を目指しました。

この時点での主な対処

アプリ向けセッション保持期間の調整

ニコニコ漫画ではニコニコOAuthのOpenID Connectを利用したログインの仕組みを持ち、ログイン中のセッション情報はKVSに保持します。

セッションキャッシュが揮発するとOAuthプロバイダ経由でユーザ情報を再取得して更新しますが、このときアクセストークンの有効期限が切れていた場合、トークンを更新して暗号化した上でデータベースに保存します。トークンの有効期限は短くピークタイム中のアクセスでも複数回更新される可能性があるため、キャッシュ保持期間を調整して更新頻度を下げる対応を行いました。

この対応によりニックネームなどのユーザ情報変更や、退会などによる認可解除の反映が遅延することが考えられましたが、漫画アプリ内でのユーザ情報表示の重要度や退会後のアプリ継続利用有無などを検討して、許容できる影響度であると判断しました。

閲覧数加算処理の切り替え

閲覧数の加算はアクセス毎にリアルタイムには行っておらず、一度バッファに蓄積してから一定間隔で更新されます。これには作品情報テーブルの更新頻度削減のほかに再生数工作などへの対処が含まれます。

この一時バッファがデータベースに記録されるため書き込み負荷としてはアクセス頻度と同等の高い傾向にありましたが、これをRedisを利用したバッファリングに切り替えることでデータベースへの書き込みを削減していきました。

ジョブキューのトランザクション管理

ジョブキューの処理は原則としてジョブ単位でトランザクション処理されますが、これを集約可能な箇所は状況に応じて複数ジョブをひとつのトランザクションとして扱うことでcommit回数を減らし、更新負荷が少しでも下がることを期待しました。

3号棟（反撃編）

2021/02/19

「第3話（前編）」の公開日です。

障害告知のお知らせをあらかじめ書いておくと障害が発生しないというオカルトが稀に発生するため、念のため用意しておきます。頼れるものは何でも使っていく姿勢でした。いくつかの書き込み負荷軽減施策が取り込まれたので今度こそはという気持ちで臨みましたが、12:18からアラートが届き始め敗北を喫します。

この日も津波のような負荷が観測されました。

特定のクエリで負荷上昇するわけでもないため、何か別の要因によってデータベースの異常負荷が引き起こされているようにも感じます。しかしRDSのログには全く有用な情報が出力されないままなので、ここに至って初めてAWS技術サポートに問い合わせることにします。

データベース接続数上限に達しているわけでもなく、低い推移のままクライアントが接続できない状況が続きます。

ピークタイムに接続数が10,000近くまで増えることも一般的なアプリケーションでは多くないと思われますが、この程度までは過去に問題なく運用できていた実績から原因からは除外していました。グラフ上は赤線が4,000付近に引かれておりこれが設定上の最大接続数のように思われますが、実際の設定値は16,000で稼働しています。

大量接続が負担になることは間違いがないため、ここでRDS Proxy本格導入の提案が出ました。PHPアプリケーションではプロセス毎にデータベース接続を持つため大量の接続を確立することになりますが、RDS Proxyはコネクションプーリングを提供するフルマネージド型のデータベースプロクシで、使用頻度の低い接続を使い回すことでデータベースへの接続数をへらすことができます。

RDS Proxyの導入検証

早速、RDS Proxyの検証を開始します。

RDS Proxyの導入にあたって留意するべき点の一つに、pinningと呼ばれるセッションの固定化現象があります。これはセッション共有されると不都合な変更が検知された場合、セッション完了まで接続を使い回さず固定化するRDS Proxy固有の動作で、pinningが発生すると接続の再利用性が下がるためプロクシ利用の有効性が充分に生かされません。

pinningの発生条件はドキュメントに記載されており、影響のあるSQLステートメントや変数利用では該当がありませんでしたが、プリペアドステートメントの使用でもpinningが発生するという点が気になりました。ニコニコ漫画ではデータベース接続にPDOを利用しており、PDO::prepareとPDOStatement::executeによりプレースホルダーを利用しています。これは内部的にmysql_stmt_prepareを呼んでいるためプリペアドステートメントとして扱われてpinningの原因になるのではと考えました。

この部分は確証が持てなかったため、開発環境のCloudWatchで DatabaseConnectionsCurrentlySessionPinned のメトリクスを監視することで実際に発生するかどうかを確認することにしました。（結果としてpinningの発生は起こってはおらず、この点については問題がないように思われました）

開発環境ではもう一点気になることとして接続数管理がありました。

RDS Proxyで接続数を管理する設定値には MaxConnectionsPercent と MaxIdleConnectionsPercent があります。前者は接続数の上限、後者はアイドル時の接続数をそれぞれ max_connections に対する割合で設定します。この値を上限95%、アイドル時50%で運用していたところ、数値上は接続数上限に達していないにも関わらず Too many connections でデータベース接続に失敗する事例が稀に発生しました。この現象については設定値を減らすことで再発はなくなりましたが原因については判明していません。

また、ピーク時の突入負荷を考慮するとアイドル時の数値もなるべく上限に近い値にしておくべきと考えましたが、その場合は常にピークタイムレベルの大量接続を保持することになります。これにより別の負荷問題に繋がるのではないかという不安もあり、適切な設定値を探る必要がありました。

いくつかの懸念事項から開発環境での検証を充分に行うべきだと判断して、この時点ではRDS Proxyの即時導入は一旦保留としました。

2021/02/26

細かな改善は続けているものの有用な手が打てていないため、絶望感とともに金曜を迎えます。

この日も鳴り止まないアラートに心を擦り減らしながら、システム安定化の手立てを探ります。

開発チームとしてはWriterインスタンスの書き込み負荷が最も可能性の高い原因として、リアルタイム更新が不要な情報のデータベース書き込みを非同期直列化する作業などを進めていました。並行して、AWS技術サポートとやり取りを重ねリソース状況や設定値などを確認しながら原因追求を進めます。インスタンスの性能上限や設定値の不備などはみつからず他に問題箇所がないか調査が続けられました。

2021/03/04

AWSの技術サポートより ConnectionAttempts の数値がピークタイムに急上昇している点を指摘されます。

ConnectionAttempts はMySQLのサーバ変数値としてはConnectionsに対応するメトリクスで、成功/失敗に問わずMySQLサーバへの接続試行数を示します。この値が秒間数千以上になると接続が不安定になる可能性があるとの情報をいただきました。

これを減らすには、コネクションプーリングを利用するか新規接続数自体を減らすことで対処します。

また、back_logの値をmax_connectionsと同数にすることで症状が緩和される可能性についても示されます。back_logは未処理接続リクエストのキューサイズでニコニコ漫画では最大接続数から算出される初期値900となっていました。

有用な情報が得られたため、早速新規接続数を減らすための検討を始めます。次の高負荷予定日は翌日だったため、半日で対応できる措置として以下の作業を行いました。

データ取得処理のキャッシュ参照箇所を追加してデータベース参照回数を削減
プッシュ通知用のトークン登録処理を非同期化してピーク時の突入負荷を緩和
back_logの値をmax_connectionsと同数に変更

2021/03/05

限られた時間で対策は行いましたが、この日は人気最上位の2作品が同時に更新されるというニコニコ漫画のサーバとしては最も苦しい状況であり、やはり障害となってしまいます。

負荷軽減の効果は多少出ておりスループットは上昇していましたが、その影響で裏側の別のバックエンドが高負荷となる問題も併発して結果としてはサーバダウンに繋がりました。Fランサーバの汚名は返上できません。

メトリクスをみると ConnectionAttempts の値は想定よりも下がっておらず、抜本的な改修が必要であることが分かりました。back_logについては今回の問題に対しては効果を得られなかったようにみえます。

さて、ニコニコ漫画は独自フレームワークのPHPアプリケーションで、データベース接続は各データ取得処理の内部でWriter/Readerのどちらを参照するか振り分けています。

これが実装の深い部分でハードコードされているため、Readerから参照可能なデータもWriterから読み出すような処理が各所で見受けられWriterに負荷が偏る原因ともなっていました。また、同じ理由で利用箇所ごとに柔軟に参照先を指定するようなことも難しい作りになっています。

そこで、フレームワーク自体に手を入れて「データベース接続先の自動切り替え」の仕組みを実装しました。

この機能がエンドポイント単位で有効にされた場合、（ハードコードされた指定を無視して）参照系クエリはReaderから読み込むような動作を強制し、更新系クエリが一度でも発行されたら以降は実装に従うという特殊な動作をします。データベース接続先の自動選択は一般的なフレームワークでも提供されるものがありますが、その簡易版と言えるでしょう。

この仕組みの導入によりWriterインスタンスへの接続数は大きく減少し、目に見えて効果が現れます。

2021/03/12

データベース接続先の自動切り替え機能を導入して迎えた次の金曜日。「作品I」の更新はありませんが、人気作品の更新が多くアクセス数は1週間で最も多い日です。

ピーク突入後の ConnectionAttempts は3〜4%程度の低下で若干の不安を感じましたが、その後の第2次ピーク突入でも増加傾向はこれまでよりも小さくなっており、前週まで平常時で120k、高負荷障害時に150k程度まで上がっていた数値が 100k 以下でピークアウトして障害発生のないまま乗り越えることができました。

また、接続先の切り替えによりこれまでWriter中心となっていた負荷傾向が、Writer/Readerでそこまで差のないレベルまで近づいてきました。更にWriter接続を減らすべく遅延の影響を受けにくい処理のReader参照化を進めます。

2021/03/19

そして迎えた「作品I」の更新日です。前日までの負荷傾向でかなりの改善が見られたので、久しぶりに余裕を持って待機しています。

この日の ConnectionAttempts は障害発生時を40%ほど下回る105k程度に留まり、エラーやアラートの発生もなくピークタイムが過ぎ去りました。念願の大勝利です！最初の障害発生から約2ヶ月間が経過していましたが、これ以降は高負荷の再発もなく平穏が取り戻されることになります。

グラフから見て取れるように、ニコニコ漫画ではピークタイムでのアクセス増加が極端で第1次ピークの11:00に一度直線的に跳ね上がり、一旦落ち着いた後で第2次ピークの12:30頃に更に倍程度まで増えるという傾きを描きます。このためオートスケーリングもメトリクス監視などのスケーリングでは需要に追いつかずscheduled scalingで対応しています。このアクセス傾向により、平時のサーバ状況からは予想できない負荷のかかり方やトラブルの発生があるため、常にピークタイムを見据えたシステム運用が求められています。

余談

その後も安定稼働を維持するために、不要なログイン判定のスキップや既読管理（しおり機能）のDynamoDB移行などを行ってデータベース負荷は大きく低減されました。Writer/Readerの負荷バランスも改善されたことからインスタンスサイズの縮小が可能になり、この障害の半年後にはスケールダウンによりデータベース費用の50%削減に成功しています。

当時を振り返って

2年近く前の出来事なので記憶はだいぶ曖昧でしたが、社内Slackや日次の作業記録があったのでそれなりに当時の様子を思い出すことができました。こうして振り返ってみると、効果的な対策が打てないまま障害に右往左往していた2ヶ月間だったようにも感じます。

先入観は怖い

最初の障害ではいくつかの複合要因はあったもの、最終にはデータベース負荷という部分で対策のターゲットは外してはいなかったことになります。ただ、接続数自体に関しては問題なく捌ける量であるという認識があったため重要度を下げてしまい、「新規接続の流速」というポイントに気が付くことができませんでした。結果として書き込み負荷を下げる対策ばかりを進めて障害改善が遅れることになり、先入観の怖さを思い知りました。（このときの負荷対策は後のインフラ費用削減には繋がりました）

チーム外からのアドバイスも大事

原因の分からない障害対策はチーム内だけで考えていても解決しないこともあり、詰まったら広く意見を求めることも大切でした。

今回解決の決め手となったConnectionAttempts についての諸情報もAWS技術サポートへの問い合わせから得られたものです。それまでは上限緩和申請程度にしか利用していなかった技術サポートですが、実際に利用してみるとAWSサービス固有の障害事例やノウハウを元に問題解決に導いてもらうことができます。この障害以降もトラブル発生時には何度かご協力いただき、サポートプランを契約している場合には非常に力強い味方だと思います。