Postgresql障害対応／復旧メモ
今年はまだ一つもいい事ない
2月はいろいろと最悪な月だった。
半分は障害対応してた。
とりあえず備忘録として、何があってどのような対応をして解決したかをメモっておきます。
概要
うちのとあるサービスのDBサーバはPostgresql8.3.8。
8.3から追加されたウォームスタンバイ機能を使って非同期レプリケーションを行い、
マスタが落ちたら自動でスタンバイへフェールオーバーする仕組みになっています。
ウォームスタンバイ環境とかPITRは以下を参照にするとわかりやすいかも。微妙にうちと設定違うけど。
http://postgres.sios.com/modules/install/index.php?content_id=3
http://www-06.ibm.com/jp/domino01/mkt/cnpages7.nsf/page/default-000B5D90
そして、２月のとある平日にマスタ→スタンバイへフェールオーバーしたことが発覚。
まあここまではいい。
落ちたサーバの原因を解消して再度レプリケーション環境を作り直せばいいだけだし。*1
ちなみにインフラは協力会社さんにメンテをお願いしているので
そちらでサーバ自体は復旧してもらうことに。
ほんで数日後にサーバ復旧も完了したので
来週のどっかの深夜にレプリケーションの設定しましょう、
とスケジュール調整しました。
青天のなんとか
ほんでさらに数日後、協力会社さんから電話が来た。
「現在マスタになってるサーバのディスクやばいです。今日中に何とかしないとディスク100%いきます」
ええーなにそれ！*2
原因を調査してみると、どうやらWALログ*3が溢れかえっててディスクを圧迫してる様子。
postgersのログを確認すると、archive command*4 が失敗しているため
WALログが削除されずに残ってしまっているらしい。
WALログを削除していいか、を調査
チェックポイントは、一連のトランザクションにおいて、
28.4. WALの設定
それ以前に書き出された全ての情報でデータファイルが更新されていることが保証されている時点を指します。
チェックポイントでは、全てのダーティデータページがディスクに吐き出され、
特別なチェックポイントレコードがログファイルに書き込まれます。
クラッシュした時、クラッシュからの復旧処理は最後のチェックポイント記録を見つけ、
ログの中でどのレコード（これはredoレコードと呼ばれています）から復旧処理がREDOログ操作を開始すべきかを決定します。
このチェックポイント以前になされたデータの変更は、すでにディスク上にあることが分かっています。
従って、チェックポイントが行われた後、redo記録内のチェックポイント以前のログセグメントは不要となり、
再利用または削除することができます （WALアーカイブが行われる場合、
このログセグメントは削除もしくは再利用される前に保存されなければなりません）。
うん、予想通りチェックポイント以前のWALログは消しちゃってもいいようだ。
現在のチェックポイント位置の確認方法も探す
結構時間かかった。調べたところ、以下の３つの方法で確認できそう。
- global/pg_controlの更新日付
チェックポイントが実行され、ログが吐き出された後、チェックポイントの位置はpg_controlに保存されます。
28.5. WALの内部
したがって、リカバリを行う場合はサーバはまずpg_controlを読み、次にチェックポイントレコードを読みます。
そして、チェックポイントレコード内で示されたログの位置から前方をスキャンすることでREDO処理を行います。
データページの内容全体は、チェックポイント後の最初のページ変更時にログ内に保存されますので、
そのチェックポイント以降に変更された全てのページは一貫した状態に復旧されます。
WALログの更新日付がわかる。
- pgcontroldataコマンド
http://www.postgresql.jp/document/8.3/html/app-pgcontroldata.html:title=pg_controldata
上記pg_controlの更新日付と一緒？
- システム関数
select pg_xlogfile_name_offset(pg_current_xlog_location());
カレントWALログファイル名がこれで取得できるので、
確実にファイル名が欲しいならこれ一択かも。
というわけで、チェックポイント以前のWALログ削除して対応。
削除っていうか、別サーバにバックアップしたんだけどね。*5
デブサミで今回の障害について聞いてみる
atsさんありがとうございました！
ウォームスタンバイ環境復旧のリハーサル
次の週、ウォームスタンバイ環境の復旧。
スタンバイ環境を構築するところは
- pg_start_backupでラベル付ける
- 物理コピーでベースバックアップ作成
- pg_stop_backupで終了
- recovery.confでベースバックアップ＋アーカイブログでリカバリ完了
という流れなので基本的に問題ないはず。
ただし手動でWALログを消すとか、ゴミWALログが残っていたりとかで
マスタ側の整合性が合わなくなって変なエラー出たりしないか、というところが心配だったので
まずはec2にリハーサル環境作ってみて、そっちでテストした上で本番に望んだ。
リハーサル環境では
- 通常の手順でウォームスタンバイ環境構築
- チェックポイント以前のWALログを全て削除してウォームスタンバイ環境構築
- チェックポイント以前のWALログを歯抜けで削除してウォームスタンバイ環境構築
- すべてのWALログを削除してウォームスタンバイ環境構築
というテストケースでリハーサルしてみた。
１−３は予想通り、問題なく構築できた。
４は問題外。postgresの起動すらできなくなるｗｗｗｗ
ちなみにそんな時はログリセットという手もあるが…
http://www.postgresql.jp/document/8.3/html/app-pgresetxlog.html
マニュアルには怖いこと書いてるから、本当の最終手段で実行してね！
障害復旧へ
先週の深夜に作業。
緊張しながら作業したけど、特にこれと言ったハプニングも無く終了！よかったー
やっぱリハーサルしてると精神的に全然違う。
今回勉強したこと／できたこと
- ウォームスタンバイ／PITRがどのように実現されているか。
最初に環境を構築したのは協力会社さんなので深くは理解してなかったけど、
今回の障害で結構勉強した。
- WALログ→アーカイブログが物理的にどのように配置されているか、など。
pg_xlogの下にはarchive_statusというディレクトリがあって、
アーカイブされた（またはアーカイブしようとしている）WALログのステータスが確認出来る。
今回の障害中は、pg_xlog/archive_status以下に「*.ready」というファイルが沢山存在していた。
おそらくこれからアーカイブしようとしているWALログのステータスと思われる。
ちなみにアーカイブが終わると「*.done」に変わる。
ただ未だ腑に落ちない点としてはpg_xlog以下のWALログファイルの作られ方。
大抵連番になっているので、ファイル更新日付も連動するよなー？と思ってたら全然違った。
説明が難しいので例をとると、以下のような感じでWALログが作られていた
| WALログファイル名 | 更新日付 |
| 010 | 2010/2/1 11:58 |
| 011 | 2010/2/1 11:59 |
| 012 | 2010/2/1 12:00 |
| 013 | 2010/2/1 12:01 => ここがカレント |
| 014 | 2010/2/1 11:56 |
| 015 | 2010/2/1 11:57 |
つまり、先の連番で古い日付のファイルが出来ている。
おそらくだが、WALログのファイルがしきい値*6までくるとそれ以上ファイルは増えず、
古いWALログは削除ではなく「mv」でどんどん先の連番まで作っている？ということ？
単純に考えると、古いのを削除して新しいのを新規で作成するのが簡単だと思うけど、
そうしていないのは何か理由があってこんな風にしているんだろうな。パフォーマンスの問題かな？
