ログイン障害(ハング)がおきているデータベースに無理やりログインする方法

nijimassさ〜ん。電話ですよ〜。


はいはーい。


「もしもし、お電話かわりました。nijimassです。」
「データベースにログインできないんですが・・・。」
「え?」


よくありますね。いやいや、よくはないか。たまにありますね。
優雅な午後の昼下がりを一瞬にして脂汗、男汁まみれにする悪魔な電話。
まぁ、ログイン障害なら、かわいいもんです。
たいていの場合は、インスタンスの再起動で解決!はい楽勝〜!
なんて思ってたら、お客様から、こんな突っ込みが入ります。


「今回起こったことは仕方ないけれど、今後、類似の障害を起こさないために、
原因究明をしっかりやる必要があります。で、原因は?」


はい。脂汗タイムアゲイン!


っつーことで、今日はデータベースがハングしてしまったときの情報収集について、
書いてみましょうか。


# この手順を実行したことによるいかなる損害も私のほうでは責任とれませんので、
# 自己責任でお願いしますね。
# また、下に書いてある情報を取得したからといって、必ず解析が成功するわけでは
# ありませんので、その点もご注意願います。




まずは、情報収集するにしてもなんにしても、ログインする必要があるわけですが、
ログイン障害が発生してるわけです。どないすんねんと。
そんなときには魔法のオプション。prelim。

[oracle@test1 ~]$ sqlplus -prelim / as sysdba

SQL*Plus: Release 10.2.0.3.0 - Production on420 20:28:33 2008

Copyright (c) 1982, 2006, Oracle.  All Rights Reserved.

SQL>


どうやら、このオプションをつけた場合、
ログイン時の様々なチェックやリソースの確保がバイパスされるようです。
ですので、ハング時でもログインできる可能性がグンとあがります。
ただし、これはサポートされている方法ではないと思いますので、何度も書きますが、
自己責任でお願いしますよ。


で、情報収集に入るわけですが、
基本的なとことしては、hanganalyze と systemstate あたりを取ればいいと思います。


まず、hanganalyze から。
これは、systemstate よりも ハングの解析によったダンプです。
下のようにして取りましょう。

[oracle@test1 ~]$ sqlplus -prelim / as sysdba

SQL*Plus: Release 10.2.0.3.0 - Production on420 20:28:33 2008

Copyright (c) 1982, 2006, Oracle.  All Rights Reserved.

SQL> oradebug setmypid
文が処理されました。
SQL> oradebug unlimit
文が処理されました。
SQL> oradebug hanganalyze 2
Hang Analysis in /opt/oracle/app/oracle/admin/orcl1/udump/orcl1_ora_5852.trc


RACの場合は、どこか1ノードで

oradebug setmypid
oradebug unlimit
oradebug setinst all
oradebug -g def hanganalyze 2


とすればよいでしょう。これで全ノード分の情報が取れます。


また、hanganalyze の後ろの数字はレベルの指定になっています。
数字が大きいほど細かい情報が取れますが、
取得時のサイズも負荷も大きくなります。
私はいっつも2で取ってますが、3で取るのも結構一般的みたいです。
他にどんなレベルがあるのかは調べてみてください。
ちなみに、こんな感じのファイルです。
私には解読できません。

[oracle@test1 udump]$ pwd
/opt/oracle/app/oracle/admin/orcl1/udump
[oracle@test1 udump]$ more orcl1_ora_5852.trc
/opt/oracle/app/oracle/admin/orcl1/udump/orcl1_ora_5852.trc
Oracle Database 10g Enterprise Edition Release 10.2.0.3.0 - Production
With the Partitioning and Data Mining options
ORACLE_HOME = /opt/oracle/app/oracle/product/10.2.0/db_1
System name:    Linux
Node name:      test1.xxxx.co.jp
Release:        2.6.9-67.0.0.0.1.EL
Version:        #1 Sun Nov 18 00:16:01 EST 2007
Machine:        i686
Instance name: orcl1
Redo thread mounted by this instance: 1
Oracle process number: 0
Unix process pid: 5852, image: oracle@test1.xxxx.co.jp

*** 2008-04-20 20:30:27.139
==============
HANG ANALYSIS:
==============
Open chains found:
Other chains found:
Chain 1 : <cnode/sid/sess_srno/proc_ptr/ospid/wait_event> :
    <0/147/1/0x32a1f820/5846/Streams AQ: waiting for time man>
Chain 2 : <cnode/sid/sess_srno/proc_ptr/ospid/wait_event> :
    <0/149/2/0x32a20390/5850/Streams AQ: qmn slave idle wait>
Chain 3 : <cnode/sid/sess_srno/proc_ptr/ospid/wait_event> :
    <0/154/1/0x32a1e140/5838/Streams AQ: qmn coordinator idle>
Chain 4 : <cnode/sid/sess_srno/proc_ptr/ospid/wait_event> :
    <0/158/19/0x32a1e6f8/5840/jobq slave wait>
Extra information that will be dumped at higher levels:
[level  5] :   4 node dumps -- [SINGLE_NODE] [SINGLE_NODE_NW] [IGN_DMP]
[level 10] :  11 node dumps -- [IGN]

State of nodes

...


続いて、systemstate を取得します。
hanganalyze を取得した続きで取れればいいんですが・・・、

SQL> oradebug dump systemstate 266
ORA-03113: 通信チャネルでend-of-fileが検出されました
ORA-24323: 値が許可されていません。


怒られます・・・。
たぶん、prelimで入っただけのプロセスでは、
いろいろな情報を取得する上で必要なリソースを確保していないとかがあるのでしょうね。
というわけで、pmonあたりにアタッチしてみて取得しましょうか。

[oracle@test1 ~]$ sqlplus -prelim / as sysdba

SQL*Plus: Release 10.2.0.3.0 - Production on420 20:38:33 2008

Copyright (c) 1982, 2006, Oracle.  All Rights Reserved.

SQL> !ps -ef | grep pmon
oracle    5814     1  0 20:23 ?        00:00:00 ora_pmon_orcl1
oracle    5880  5869  0 20:36 pts/1    00:00:00 /bin/bash -c ps -ef | grep pmon
SQL> oradebug setospid 5814
Oracle pid: 2, Unix process pid: 5814, image: oracle@test1.xxxx.co.jp (PMON)
SQL> oradebug unlimit
文が処理されました。
SQL> oradebug dump systemstate 266
文が処理されました。
SQL>


出力ファイルは user_dump_dest で指定したディレクトリに
こんな感じに出力されます。まぁ、これも読めませんがね。

[oracle@test1 udump]$ pwd
/opt/oracle/app/oracle/admin/orcl1/udump
[oracle@test1 udump]$ more orcl1_ora_5884.trc
/opt/oracle/app/oracle/admin/orcl1/udump/orcl1_ora_5884.trc
Oracle Database 10g Enterprise Edition Release 10.2.0.3.0 - Production
With the Partitioning and Data Mining options
ORACLE_HOME = /opt/oracle/app/oracle/product/10.2.0/db_1
System name:    Linux
Node name:      test1.xxxx.co.jp
Release:        2.6.9-67.0.0.0.1.EL
Version:        #1 Sun Nov 18 00:16:01 EST 2007
Machine:        i686
Instance name: orcl1
Redo thread mounted by this instance: 1
Oracle process number: 0
Unix process pid: 5884, image: oracle@test1.xxxx.co.jp

*** 2008-04-20 20:37:50.733
===================================================
SYSTEM STATE
------------
System global information:
     processes: base 0x32a0a928, size 150, cleanup 0x32a19ca0
     allocation: free sessions 0x32a56034, free calls (nil)
     control alloc errors: 0 (process), 0 (session), 0 (call)
     PMON latch cleanup depth: 0
     seconds since PMON's last scan for dead processes: 9
     system statistics:
37 logons cumulative
15 logons current
10218 opened cursors cumulative
33 opened cursors current
101 user commits
0 user rollbacks
102 user calls
164561 recursive calls


RACの場合には、全ノードでこれを繰り返してください。
めんどくさいけど。


あとは errorstack とかが取れればいいんですが・・・。
そんな時間は無いでしょう。時間がある場合はサポートに連絡して取り方を聞いてください。
基本的な流れは systemstate と同じですが、errorstack は、
プロセスのstackを取るというものになりますので、
ハングしているプロセスや問題となってそうなプロセス(できたら全部)に
oradebug setpid か setospid でアタッチして、errorstack を実行する必要があります。


あとは・・・、正常にログインできる状態なら、v$ 系の情報を取得するんですが、

SQL> select count(*) from v$session;
select count(*) from v$session
*
行1でエラーが発生しました。:
ORA-01012: not logged on


はい。prelim で入るとこうなってしまうので、取得できません。
だれか取る方法知ってたら教えてください。


っつーことで、ここまで取れたらサポートに連絡しましょう。

ただし!何度も言いますが、ここで書いた情報を取得したからといって、
必ず原因がわかるわけではありません。
一番良いのは、現象発生と同時にサポートに連絡し、
サポートの案内にしたがって必要な情報を取得することだと思います。
ここの情報は超奥の手として胸に秘めておくぐらいでお願いします。
あと、ほんとに何度も書きますが、この手順で余計トラブルがひどくなった!とか、
別の障害が起きた!とか、そういう事態に陥っても責任は取れませんので、
あくまでも自己責任でお願いします。


では。