2022-12-11
壊れたデータベースとの向きあいかた
この記事は はてなエンジニア Advent Calendar 2022 の17日目です。
皆さんはデータベースが壊れたことがありますか? 僕はあります
一口に壊れると言っても壊れ方は色々ありますよね、データベースエンジンのバージョンアップで互換性がなくなったり、変なマイグレーションを走らせて状態がおかしくなったり…
という訳で今回は何故データベースが壊れてしまったのか、そしてどうやって直していったのかを皆さんにご紹介します。
登場人物
PostgreSQL 13
アップグレード前の DB
PostgreSQL 15
アップグレード後の DB、このあと壊れる
分散型ソーシャルネットワークアプリケーション、PostgreSQL を使っている。中身は Pleroma/Rokoucha
コンテナ管理ツール、PostgreSQL や Pleroma は全て Podman のコンテナとして動いている
わたし
オペミス常習犯、何も考えず VACUUM とかしがち
破壊その1
2022-11-27、わたしは重い腰をあげて遂に PostgreSQL 13 から PostgreSQL 15 への更新を実施した
というのも postgres_exporter がバージョン間で非互換な何かを使っていて pg_upgrade がこけていた
そのため、更新の戦略として必要なデータベースのみ pg_dump でバックアップを取り、新バージョンのコンテナを新しく立ててそこに pg_restore をすることにした
のだが、pg_restore をすると何かがおかしい
pg_restore: while PROCESSING TOC:pg_restore: from TOC entry 3507; 1259 95573 INDEX counter_cache_instance_index pleromapg_restore: error: could not execute query: ERROR: could not create unique index "counter_cache_instance_index"DETAIL: Key (instance)=(example.com) is duplicated.Command was: CREATE UNIQUE INDEX counter_cache_instance_index ON public.counter_cache USING btree (instance); なんとユニークな INDEX を張ろうとしたがキーが重複しているとエラーが出てしまった
2019年から3年間運用し続けていたので途中でマイグレーションで変更が入った結果異常な状態になっていた?
とりあえずデータを直接覗いてみて重複しているデータをマージして無事 INDEX が貼れるようになった
他にも重複で貼れない INDEX がちょこちょこあったので1件ずつデータをいじって貼っていった
最終的に INDEX を貼るのに10時間ぐらいかかったが無事更新を完了できた
破壊その2
2022-12-04 に VACUUM FULL をかけたが、途中で DB への接続が切れる事が続いた
VACUUM FULL は Pleroma のタスクから実行していた
前に /dev/shm の容量が小さすぎて VACUUM が落ちるということがあったので、コンテナへの割り当てを増量してみたがまだ動かない
コンテナの IPC をホストに接続してみたがそれでもまだ落ちる
ここで何かおかしいぞとやっと PostgreSQL のログを見るが時既に遅し
特定のテーブルに入った途端に worker が segfault している
LOG: server process (PID 123) was terminated by signal 11: Segmentation faultDETAIL: Failed process was running: COMMITLOG: terminating any other active server processesWARNING: terminating connection because of crash of another server processDETAIL: The postmaster has commanded this server process to roll back the current transaction and exit, because another server process exited abnormally and possibly corrupted shared memory.どうやら JSONB なカラムに JSONB ではない何かが入っているらしい
クラッシュするデータ範囲を日付で絞り込んで特定したデータを削除した
削除クエリはこけなくて本当に良かった
とりあえずこれで VACUUM は完走するようになった
破壊その3
しかし Pleroma のホームタイムラインが出ない!
どうやらクエリが重すぎてタイムアウトしている
次の日 2022-12-05 に REINDEX を走らせてみたがそれでも駄目
どうすれば…
2022-12-07 になっても有効な手は打てず
何回 VACUUM をしても ANALYZE をしてもクエリがタイムアウトする
試しに pg_dump を取って新しいデータベースに pg_restore をしてみることに…
>@rokoucha: 苦しいです♪
>
>@rokoucha: PostgreSQL が必死に INDEX 貼ってる所かれこれ8時間ぐらい眺めてる
>
しかし…
>@rokoucha: PostgreSQL でデータがぶっこわれてて INDEX 貼れない時にどうすればいいか分からなくて助けて!!!!!!!!!!!!!!!!
なんと REINDEX 中にデータの破損でエラーが!
pg_restore: creating INDEX "public.objects_fts"pg_restore: from TOC entry 3754; 1259 41869 INDEX objects_fts pleromapg_restore: error: could not execute query: ERROR: invalid byte sequence for encoding "UTF8": 0xe6 0xad 0x10 このあたりでこのデータベースが完全に壊れてしまっている事に気付き絶望
修復
時は 2022-12-11。2022-12-07 に今のデータベースが完全に壊れてしまっている事に気付き絶望したわたしは、遂に PostgreSQL のアップグレード前のデータに切り戻す事を決めた
>@rokoucha: VACUUM FULL すると何故かサイズがデカくなったり VACUUM ANALYZE が無限に終わらなくなったりするデータベースと向き合ってたら1週間消えてこれ
この時点でかなり疲弊している事が伺える
という訳でまた方針を決める
過去の経験から過去のデータベースはなるべく使いたくない
最新の Pleroma でデータベースを初期化して最新のスキーマを用意しておく
バックアップからはデータのみ復元する
合間合間にバックアップを取る
そして実行
途中 UNIQUE CONSTRAIT に引っかかるデータが何個かあったがマージしたり削除したりして対応
無事に復元完了!!!
復元完了後は VACUUM ANALYZE を実行
マジで遅い! 冗談抜きで10時間以上はかかってたはず
そのあとは VACUUM FULL も実行
こっちは比較的早かった
そして恐る恐るタイムラインを開くと…
見れた!
ついでに 20GB とかあった DB が 9GB ぐらいまで削減されて最高に
考察
データベースはどの時点で壊れたのか?
PostgreSQL でデータが破損するのは他で聞いたことがない
データ破損と言いながら INDEX がおかしくなっていて…みたいなのはよくある
ストレージやメモリは大丈夫そうなのでデータベースに対する何か操作が原因?
pg_dump がうまくいってなかった
普通にアップグレードの時に復元自体は出来たので違いそう
pg_restore がうまくいっていなかった
同じくアップグレードの時に復元自体は出来たので違いそう
VACUUM FULL が途中で落ちた時に壊れた
これな気がする
でも他に聞いたことがないので断言は出来ない、引き続き調べたい
どうするべきだったのか?
メンテナンスタスクの前にはバックアップを撮ろう!
ちゃんとログは見るべきだった
早めに見ていればここまで酷くは…
という訳で普通に生きてていたら体験出来ないようなありえない壊れ方(しかも3種類!)を体験する事ができました。
皆さんもデータベースを触る時はとにかく注意してバックアップは多すぎるぐらい取るようにしてください、僕のような被害者をこれ以上生まない為にもよろしくお願いします!
ちなみに Pleroma のタイムラインはまた見れなくなりました、VACUUM してもクエリがタイムアウトして本当に終わっています♪
たすけてください
追記 2022-12-24
Pleroma のバージョンを更新して ANALYZE したら無事にホームタイムラインが表示されるようになりました!!!!!!!!
