/note/tech

How Tailscale helped find the SQLite WAL-Reset bug

要約:

■ 1. 障害の経緯と謝罪

  • 昨年末からの不安定な稼働率:
    • ステータスページに現れた傾向がそのまま年明けまで継続
    • 多くの障害はSQLite深部に潜む単一のバグが原因
  • 数か月に及ぶ徹底的な調査:
    • 夏を迎えた現在、バグを発見し、理解し、修正したと確信している
  • 顧客への謝罪:
    • Tailscaleに信頼性を期待する顧客の期待に数か月応えられなかった
    • 何が起き、どう対応し、最終的にSQLite中核の長年のバグをどう発見したかを説明するために本記事を公開する

■ 2. 制御プレーンのアーキテクチャ

  • シャード構成の制御プレーン:
    • クライアントからはcontrolplane.tailscale.comという単一の公開エンドポイントに見える
    • 内部的には複数の協調サーバ(シャード)に分割されている
  • テイルネットとシャードの関係:
    • 各テイルネットは同時に1つの内部シャード上に存在し、シームレスに別シャードへ移行できる
    • シャードは内部実装の詳細であり、利用者が自分のシャードを知る必要はない
  • シャードごとのSQLiteデータベース:
    • 各シャードはそのシャード上のテイルネット情報をすべて保持するSQLiteデータベースを持つ
    • 単一のGoプロセスがそのデータベースを排他的に利用し、制御プレーンを提供する
    • この単一書き込み設計はSQLiteの本来意図された使い方そのもの
  • SQLite採用の理由:
    • 2022年から主データベースとして使用
    • よく知られ、信頼でき、広く使われている「退屈な技術」であることを良い意味で評価した
    • 他社もはるかに大規模な運用で問題なく使っており、同様に無風の運用を期待していた
  • バックアップの仕組み:
    • 数分ごとにデータベース全体のスナップショットを取得し、SQLiteファイル全体をS3バケットへアップロードする
    • この構成は2023年初頭から無事故で稼働していた

■ 3. データベース破損の発生

  • 最初の破損の検出:
    • 昨年8月、S3バックアップを読むデータパイプラインが1つのデータベースでエラーを報告
    • PRAGMA integrity_checkをバックアップに実行したところ、実際に破損していた
  • 破損の異常性:
    • SQLiteの破損は起こり得るが極めて稀であり、通常運用で遭遇すべきものではない
    • 該当データベースを修復し原因を調査したが成果は得られなかった
  • 破損の再発:
    • 大規模運用では稀な事象もある程度の頻度で起こるため、再発に驚くべきではなかった
    • 根本原因を解決するまでの6か月間で、合計19件の独立した破損が発生

■ 4. 破損がもたらした影響

  • データ消失の範囲:
    • 制御プレーンは設定データのみを扱い、テイルネットとデバイスのメタデータを保持する
    • 秘密鍵やネットワークトラフィックは一切含まれない
    • 初期のインシデントでは、新規追加デバイスや設定変更が数件永続化されず、少量のメタデータの再入力が必要になった
  • 修復中の停止:
    • 破損のたびに該当シャードの制御プレーンプロセスを停止して修復または復元する必要があった
    • そのシャード上のテイルネットは復旧中に制御プレーン全体が消失するため苦痛を強いられた
    • 初期は1時間超のダウンタイムだったが、インシデントを重ねるごとに復旧を高速化した
  • メッシュネットワークへの影響:
    • 各テイルネットはデバイス同士がピアツーピアのWireGuard接続を張るメッシュネットワーク
    • デバイスは参加時に制御プレーンから他デバイスの一覧を取得しないと新規接続を確立できない
    • SQLite停止中にオンラインになったデバイスは接続できなかった
  • 既存接続と管理機能:
    • 修復中も既にオンラインのデバイス同士の接続は維持された
    • ただしネットワークの変更を知ることはできなかった
    • 該当テイルネットは管理コンソールとTailscale APIへのアクセスも一時的に失った
  • 信頼への広範な影響:
    • 影響を受けるテイルネットが少数でもグローバルなインシデントとしてステータスページに掲載する
    • そのため自分に無関係なインシデント表示を多くの人が目にした
    • 実際には大多数のシャードとテイルネットは破損に一度も巻き込まれていない
    • それでも直接の影響の有無にかかわらず、繰り返すダウンタイムは信頼を損なう

■ 5. 難航した初期調査

  • 初期のあらゆる試みを退けたバグ:
    • 最初の破損時点から信頼性への深刻な脅威と認識し、多大なエンジニアリング時間を投入したが修正は容易でなかった
  • 変更履歴とコードの精査:
    • 最近の変更を調べたが関連しそうなものはなかった
    • SQLiteと接する低レベルコードは数年前に書かれ、それまで問題がなく、誰も触っていなかった
    • 該当コードを細部まで再レビューしたが、観測された破損を引き起こす欠陥は見つからなかった
  • 共通要因の不在:
    • 特定のシャード、顧客、テイルネット機能、時間帯、負荷水準のいずれとも結び付かなかった
    • 何が挙動を引き起こしているのか見当がつかなかった
  • 再現不能ゆえの受動的計測:
    • 信頼できるトリガ条件がないため合成的に再現できなかった
    • 本番環境に受動的なフォレンジック用テレメトリを仕込み、破損の現行犯を押さえるしかなかった
    • データベース障害の診断情報を本番で集めるのは最も避けたい手段だったが、選択肢がなかった
  • 不規則な発生間隔:
    • 数時間おきのこともあれば数週間空くこともあった
    • 次の診断ダンプがいつ得られるか読めず、進捗予測と作業計画が困難だった
    • 10月から12月にかけて6週間にわたり破損が止まり、その後クリスマスの歓迎せざる贈り物として再発した

■ 6. SQLite開発者との協業

  • プロフェッショナルサポート契約の締結:
    • 迅速で容易な修正にならないと判断し、SQLite開発者にサポート契約を申し入れた
    • 深い専門知識と経験に直接アクセスでき、アーキテクチャとインシデントについて詳細な技術的議論を重ねられた点で優れた判断だった
  • 複数の仮説の検証:
    • close()時のPOSIXロックの破損、SQLiteが所有するメモリの誤管理、スレッド安全性を無効化した状態での複数スレッドからの誤使用などの理論を洗い出した
    • インシデントのたびにデータを集め、診断を追加し、体系的に理論を排除していった
    • 真のバグへ徐々に収束していった

■ 7. 運用面の緊急対策

  • 復旧の自動化とダウンタイム最小化:
    • 根本原因の調査中も稼働中のプラットフォームを運用する必要があったため積極的な手を打った
  • 具体的な施策:
    • 破損検知時にシャードの制御プレーンを即座にハードストップさせる設定
    • バックアップに対しPRAGMA integrity_checkを継続実行する自動バックアップ監視の導入
    • ランブックとオンコール訓練の改善
  • 効果:
    • 対応時間を1時間未満に短縮した

■ 8. トランザクションログパイプラインと手がかり

  • 新たな復旧手段の必要性:
    • 直近の正常なバックアップへの巻き戻しは多くのデータを失う
    • 破損済みデータベースの修復は潜在的に危険
    • どちらにも依存しない復旧方法を求めた
  • トランザクションログの仕組み:
    • データベースを変更するすべてのSQL文を別のログファイルへストリーミングする方式を構築
    • SQLiteは単一書き込みで直列化可能トランザクションのため、トランザクション履歴は完全に線形かつ決定的になる
    • PostgresやMySQLのような複数書き込みデータベースでは成立しない性質
  • 復旧手順:
    • 直近の正常なバックアップに対しトランザクションを再生することで、破損を安全に回避しつつ最新状態へ復元できる
  • 予期せぬ手がかり:
    • 2件のインシデントでトランザクションログがきれいに再生できなかった
    • あるトランザクションが書き込んでコミットしたデータが、後続のトランザクションから不可解に見えなくなっていた
    • 書き込みがエラーも出さずに消失しており、本来あり得ない事象だった

■ 9. WALとチェックポイントの仕組み

  • ページ単位の構造:
    • SQLiteデータベースはページと呼ばれる情報の小さなブロックの連なりで構成される
    • 更新時には一部のページを新しい情報を持つページに置き換える必要がある
  • ライトアヘッドロギングの採用:
    • 性能と並行性を高めるためWrite-Ahead Loggingを有効にして運用している
    • 新しいページはデータベースファイルへ直接書かれず、WALファイルへ書かれる
  • チェックポイント処理:
    • WALファイルに無制限に書き続けることはできず、いずれ本体のデータベースファイルへ書き戻す必要がある
    • この処理をチェックポイントと呼ぶ
  • 手動制御という非標準運用:
    • 通常の構成ではSQLite自身がチェックポイント時期を決め、利用者にも開発者にも不可視
    • 制御プレーンでは高速で一貫性のあるバックアップのためチェックポイントを手動制御している
    • 原因候補を消していく過程で、この非標準的手法が疑わしく見えてきた
  • 統計値の異常:
    • 破損時のメトリクスで、SQLiteがWALファイル内の実在ページ数より多くのページをコピーしたと報告していた
    • WALに10ページしかないのに20ページがデータベースへコピーされるのは明らかな異常

■ 10. tmstmpvfs shimによる可視化

  • SQLiteの階層構造:
    • 最上層はパーサとコードジェネレータで、SQL文をSQLite内部のデータ構造へ変換する
    • 内部データ構造はページャへ渡され、ディスクへ書く個々のページに分割される
    • 実際のディスク書き込みはOSインターフェース、すなわち仮想ファイルシステムが担う
    • 現在の主流の仮想ファイルシステム実装はUnix向けとWindows向けの2つ
  • 層の差し替え可能性:
    • 各層を別実装に置き換えたり、既存層をラップして情報を得たりできる
  • 新しいデバッグツール:
    • チェックポイント処理にバグがあるとしばらく疑っていた
    • SQLite開発者は仮想ファイルシステムをラップし、追加のトレース情報とデータベース変更ログを出力するシムを作成した
    • このラッパーはtmstmpvfs shimと呼ばれ、ソースコードはSQLiteの公開リポジトリで入手できる
  • 本番投入:
    • シムを本番環境へ投入し、次の破損を待った
    • 幸か不幸か長く待つ必要はなかった

■ 11. WAL-Resetバグの正体

  • バグの特定:
    • 次の破損後、tmstmpvfs shimの追加ログによりSQLite開発者がバグを発見し修正した
    • 正体はチェックポイントと書き込みトランザクションの間で起きる稀なデータ競合
  • 発生メカニズム:
    • チェックポイント中の特定のタイミングで書き込みが発生するとチェックポイント処理が混乱する
    • 一部のページをWALからデータベース本体へコピー済みと誤認するが、実際にはコピーされていない
    • それらのページは永久にデータベースファイルへ書かれず、そのデータは失われる
    • 失われたページを参照するインデックスなどの他のページは書き込まれるため、ファイルが破損する
  • バグの命名と歴史:
    • SQLite開発者はこれをWAL-Resetバグと命名した
    • 少なくとも16年間SQLiteに存在していたと推定される
    • 極めて稀であるがゆえに長期間残存し、テスト環境では意図的に発生させるコードを追加する必要があるほどだった
    • 修正では、他スレッドによるWALのリセットを検知する追加チェックをチェックポイント関数に加えた
  • 観測事象との整合:
    • このバグがすべての不可解な挙動の原因だと確認された
    • 破損、きれいに適用できないトランザクションログ、一貫しないチェックポイント統計のすべてを説明した
  • 遭遇しやすかった理由:
    • チェックポイントを手動制御し、非常に積極的な頻度で実行していた
    • 稀な条件で起きるバグでもいずれ必ず踏むことになる状況だった
  • 転機としての意味:
    • 数か月の混乱と不確実性の末に、破損の妥当な理論と展開可能な修正を手にした瞬間

■ 12. 修正版の展開と二次的な問題

  • 3.52.0の段階的展開:
    • SQLite開発者は修正をSQLite 3.52.0としてリリースし、公開次第すぐ展開する準備を整えた
    • まず少数のカナリアシャードへ、順調な稼働を確認してから残りの制御プレーンへ展開した
  • 展開直後の警報:
    • バックアップ監視が即座に赤くなり、13のデータベースで破損を報告した
    • 極めて憂慮すべき事態だったが、復旧手順に従ってすべて修復し、問題なく収束した
    • これらは真の破損ではなく、当該SQLiteバージョンの第二の問題によるものだった
  • 陳腐化した式インデックスのバグ:
    • エラーをSQLite開発者と共有した結果、stale expression indexに関するバグが判明した
    • 計算値にインデックスを作成した後に計算内容が変わると、インデックスに不一致な値が残る
    • その不一致がPRAGMA integrity_checkで破損として報告される
  • 自社側の該当条件:
    • 高精度タイムスタンプをテキストとして保存し、VIRTUAL生成列で浮動小数点数へ変換していた
    • データ競合を修正した3.52.0は、テキストから浮動小数点数への変換の丸め挙動を微妙に変える最適化も含んでいた
    • カナリアシャードには変化した丸め挙動を引き起こすタイムスタンプが存在せず、段階的展開で検知できなかった
  • 双方の対処:
    • 誤検知を招くため、SQLite開発者は3.52.0を撤回し、WAL-Resetバグの修正のみを含む3.51.3を公開した
    • 自社側はタイムスタンプの精度を整数秒へ落とすことで対処した、テキストから整数への変換は曖昧さがない
    • SQLite開発者は3.53.0で自動的に自己修復するインデックス機能を作り、陳腐化した式インデックス問題を防いだ

■ 13. 修正の実証

  • 慎重な姿勢:
    • 制御プレーン全体へ修正を展開し勝利宣言をしたかったが、なお慎重であった
    • 破損が起きないことは修正の証明にならない、既に6週間の欺瞞的な平穏を経験している
  • 積極的な証明手段:
    • 本番環境でデータ競合が実際に起きている積極的な証拠を求めた
    • 書き込みトランザクションとWALリセットの衝突が原因と理解した上で、両操作が重なった際に警告を記録するようSQLiteドライバへパッチを当てた
    • 警告が出てもデータベースが破損しなければ、修正が破損を防いだと判明する
  • 待機と発火:
    • 警告を展開して待ち続けたが何週間も発火せず、警告の不具合や理論の誤り、真のバグの残存を疑い始めた
    • 2か月後、待ち望んだアラートがついに発火した
  • 結論:
    • このアラートはWAL-Resetバグの発生条件が本番環境で実際に起きることを証明した
    • 6か月に及ぶ不安定な稼働の原因がこのバグである可能性が高いと結論づけた
    • そのアラート以降、本稿執筆時点でさらに4か月間データベース障害なしで稼働している

■ 14. 教訓と成果

  • 全体の総括:
    • 6か月をSQLiteのバグ探しに費やすことなど誰も望んでいなかった
    • 顧客にとっても社員にとっても極めて苛立たしい経験であり、この不安定さを過去のものにできて安堵している
  • 非標準運用のリスク:
    • 退屈な技術を非標準的な方法で運用することはリスクである
    • 一般的な経路と標準構成は極めてよくテストされ信頼できる
    • 大多数の利用者は標準構成でSQLiteを使い、この種の問題に遭遇しない
  • 自社の位置づけ:
    • 実施していたことはすべて公開され文書化された、サポート対象の構成だった
    • それでもチェックポイントを手動制御し独自の積極的な頻度で走らせたことで、踏み固められた運用の道から外れていた
  • 関係者への謝意:
    • 解決はTailscaleのエンジニアリングとサポート、SQLiteのコアメンテナを含む数十人規模の横断的な取り組みだった
    • 影響がこれ以上悪化しなかったのは全員の功績
    • 繰り返すダウンタイムは影響人数にかかわらず信頼を損なうと理解しており、追跡中の顧客の忍耐と支援に感謝する
  • 得られた成果:
    • 苛立たしい期間ではあったが、以前より強い状態に立っている
    • SQLiteの長年のバグが修正された
    • 探索の過程で見つけた他の数十件の付随的な問題も修正した
    • 競合状態の切り分けを即座に助けたオープンソースのSQLite VFSシムに資金を提供し、将来の類似バグ追跡にも役立つ
    • データベースのバックアップと復旧の手順を洗練させ、十数回にわたり実地で検証した
  • 今後への構え:
    • 同種のデータベース障害が再び起きないことを願うが、起きたとしても備えはできている