久々にRMANの仕事だ。障害時のリストア＆リカバリなどなかなかお目にかかれないので
しっかりとメモしておこう。
背景：Oracle10gデータベースがORA-600でOpenできなくなった。
・既知の不具合情報なし。
・隠しパラメータを使った強制Openも効かなかった。
・調査に時間を費やすことも出来ないため
バックアップファイルからのリストアを敢行。
・バックアップはRMAN+Networkerで取得
（但し、最新のバックアップファイルは一ヶ月前のファイル）
・アーカイブは、多分揃っている。
・リストアするファイルはLTOに入っている
・LTOはLTOライブラリに入っている
※後になって考えると、クラスタソフトの挙動がおかしかった
(Active-Activeになっていた)との事。
ORA-600の内容から考えると、クラスタソフトが両ノードから
インスタンスを上げたのではないだろうか。
こんな背景なのできっとOracle社にトレースを提供しても原因追及できないだろう。
用意されていたリストアコマンドファイル
************************************************************
set dbid=xxxxxxxxxx;
connect target sys/sys
startup force nomount;
run {
allocate channel c1 type 'SBT_TAPE';
send 'NSR_ENV=(NSR_SERVER=xxxxxxxx,
NSR_DATA_VOLUME_POOL=TEST)';
restore controlfile from autobackup;
alter database mount;
restore database;
restore archivelog all;
release channel c1;
}
************************************************************
全てのデータファイル、REDO、制御ファイルを退避させ
上記スクリプト実行！
すると
restore controlfile from autobackup;
の箇所にて下記エラー発生。
==================================================================
restoreが開始されました(開始場所: 05-09-13)
チャネルORA_DISK_1の使用
チャネルORA_DISK_1: 曜日の自動バックアップを探しています: 20050913
チャネルORA_DISK_1: 曜日の自動バックアップを探しています: 20050912
チャネルORA_DISK_1: 曜日の自動バックアップを探しています: 20050911
チャネルORA_DISK_1: 曜日の自動バックアップを探しています: 20050910
チャネルORA_DISK_1: 曜日の自動バックアップを探しています: 20050909
チャネルORA_DISK_1: 曜日の自動バックアップを探しています: 20050908
チャネルORA_DISK_1: 曜日の自動バックアップを探しています: 20050907
チャネルORA_DISK_1: 7曜日の自動バックアップが見つかりません
RMAN-00571: ===========================================================
RMAN-00569: =============== ERROR MESSAGE STACK FOLLOWS ===============
RMAN-00571: ===========================================================
RMAN-03002: failure of restore command at 09/13/2005 20:35:50
RMAN-06172: no autobackup found or specified handle is not a valid copy or piece
==================================================================
どうやら、デフォルトでは7日前までの制御ファイルしか探しに行かない。
これからは、スクリプトファイルに頼らず、
ちょびちょびと実行していくことにした。
■restore controlfile from autobackup maxdays=365;
とコマンドに手を加え実行
==================================================================
チャネルc1: 曜日の自動バックアップを探しています: 20050816
チャネルc1: 自動バックアップが見つかりました: c-295683763-20050816-04
==================================================================
と、無事リストアすべき制御ファイルが見つかった。
ところが、待てど暮らせど次のメッセージ(リストア完了のMSG)が出ない。。
Networkerのログを見てみると、LTOがセットされるのを待っているようだ。
LTOを一度取り出し、再度挿入するが無反応。
「nwadmin」コマンドをROOTで実行しGUIを立ち上げて
メディアをマウントさせることが必要だった。
マウント後、待っていたRMAN処理は流れ、無事制御ファイルをリストアできた。
==================================================================
チャネルc1: 自動バックアップからの制御ファイルのリストアが完了しました
出力ファイル名=/storage/oracle/oradata/cosmo/control01.ctl
出力ファイル名=/storage/oracle/oradata/cosmo/control02.ctl
出力ファイル名=/storage/oracle/oradata/cosmo/control03.ctl
restoreが完了しました(完了場所: 05-09-13)
==================================================================
■alter database mount;
これは全く問題なし
■restore database;
==================================================================
データ・ファイルXXXを/xxx/xxx.dbfへリストア
チャネルc1: バックアップ・ピース1がリストアされました
ピース・ハンドル=df_3kgs8123_1_1.bak タグ=TAG20050816T153115
チャネルc1: リストアが完了しました
restoreが完了しました(完了場所: 05-09-13)
チャネル: c1がリリースされました
==================================================================
これも無事完了。
■restore archivelog all;
一部エラーは出るもののとりあえず完了。
ここで、アーカイブログの状況を確認してみる。
==================================================================
bash-2.05$ ls -lst|tail
（下記出力結果は一部加工しています）
oracle oinstall 10087936 8月 17日 17:00 1_9_566498800.dbf
oracle oinstall 10087936 8月 17日 17:00 1_8_566498800.dbf
oracle oinstall 10087936 8月 17日 17:00 1_7_566498800.dbf
oracle oinstall 10087936 8月 17日 17:00 1_6_566498800.dbf
oracle oinstall 10085376 8月 17日 16:42 1_5_566498800.dbf
oracle oinstall 10087936 8月 17日 11:00 1_4_566498800.dbf
oracle oinstall 10220032 8月 17日 03:20 1_3_566498800.dbf
oracle oinstall 10087936 8月 16日 22:44 1_2_566498800.dbf
oracle oinstall 10087936 8月 16日 22:00 1_1_566498800.dbf
oracle oinstall 212992 8月 16日 16:03 1_4_566492238.dbf
oracle oinstall 6144 8月 16日 15:xx 1_3_566492238.dbf
oracle oinstall 28160 8月 16日 15:xx 1_2_566492238.dbf
oracle oinstall 1790976 8月 16日 15:xx 1_1_566492238.dbf
==================================================================
ん？いやな予感が。8/16の22時以降はインカネーションが変わっているように見える。
しかし、この状況はどうにもできないのでとりあえず作業を進める。
■select controlfile_time from v$database;
リストア直後のDB日時を見てみる。
2005/08/16 15:32:46
だそうだ。
■recover database using backup controlfie;
バックアップした制御ファイルからのリカバリなので
「using backup controlfile」が必要。
AUTOリカバリは怖いのでログ指定でリカバリを進めた。
==================================================================
SQL> recover database using backup controlfile;
ORA-00279: 変更1861408(08/16/2005 15:31:15で生成)にはスレッド1が必要です
ORA-00289: 検討すべきログ・ファイル:/storage/oracle/archive/cosmo/1_2_566492238.dbf
ORA-00280: 変更1861408(スレッド1)は順序番号2に存在します。
ログの指定: {<RET>=suggested | filename | AUTO | CANCEL}
/storage/oracle/archive/cosmo/1_2_566492238.dbf
ORA-00279: 変更1861447(08/16/2005 15:32:40で生成)にはスレッド1が必要です
ORA-00289: 検討すべきログ・ファイル:/storage/oracle/archive/cosmo/1_3_566492238.dbf
ORA-00280: 変更1861447(スレッド1)は順序番号3に存在します。
ORA-00278: ログ・ファイル'/storage/oracle/archive/cosmo/1_2_566492238.dbf'はこのリカバリでは必要なくなりました
ログの指定: {<RET>=suggested | filename | AUTO | CANCEL}
/storage/oracle/archive/cosmo/1_3_566492238.dbf
ORA-00279: 変更1861458(08/16/2005 15:32:42で生成)にはスレッド1が必要です
ORA-00289: 検討すべきログ・ファイル:/storage/oracle/archive/cosmo/1_4_566492238.dbf
ORA-00280: 変更1861458(スレッド1)は順序番号4に存在します。
ORA-00278: ログ・ファイル'/storage/oracle/archive/cosmo/1_3_566492238.dbf'はこのリカバリでは必要なくなりました
ログの指定: {<RET>=suggested | filename | AUTO | CANCEL}
/storage/oracle/archive/cosmo/1_4_566492238.dbf
ログが適用されました。
メディア・リカバリが完了しました。
==================================================================
・・・。やはり終わってしまった。
■悪あがき
==================================================================
SQL> alter database open;
alter database open
*
行1でエラーが発生しました。:
ORA-01589: データベースをオープンするにはRESETLOGSまたはNORESETLOGSを使用する必要があります
[感想]ですよねー。
SQL> recover database using backup controlfile;
ORA-00279: 変更1861726(08/16/2005 15:33:53で生成)にはスレッド1が必要です
ORA-00289: 検討すべきログ・ファイル:/storage/oracle/archive/cosmo/1_4_566492238.dbf
ORA-00280: 変更1861726(スレッド1)は順序番号4に存在します。
ログの指定: {<RET>=suggested | filename | AUTO | CANCEL}
/storage/oracle/archive/cosmo/1_4_566492238.dbf
ORA-00328: アーカイブ・ログは変更1861725で終了します。さらに新しい変更1861726が必要です
ORA-00334: アーカイブ・ログ: '/storage/oracle/archive/cosmo/1_4_566492238.dbf'
[感想]さっき適用したのに何してるんだ、俺？
SQL> recover database using backup controlfile;
ORA-00279: 変更1861726(08/16/2005 15:33:53で生成)にはスレッド1が必要です
ORA-00289: 検討すべきログ・ファイル:/storage/oracle/archive/cosmo/1_4_566492238.dbf
ORA-00280: 変更1861726(スレッド1)は順序番号4に存在します。
ログの指定: {<RET>=suggested | filename | AUTO | CANCEL}
/storage/oracle/archive/cosmo/1_1_566498800.dbf
ORA-00342: アーカイブ・ログに予期したリセットログSCN 1859559がありません
ORA-00334: アーカイブ・ログ: '/storage/oracle/archive/cosmo/1_1_566498800.dbf'
[感想]やっぱインカネーション違うんですよね。。
==================================================================
■諦めてopen resetlogs
==================================================================
SQL> alter database open resetlogs;
データベースが変更されました。
==================================================================
あーあ、Openしてしまった。
アーカイブは今日の分まであるのに。。
■総括
データベースは
2005/08/16 15:33:53
の時点に復旧できました。めでたしめでたし。。
