今回はノードのCSSD障害が発生した場合のクラスタの動きの検証結果を書こうと思います。
CSSD(ocssd.bin)障害とCSSD(ocssd.bin)および関連プロセス(cssagent、cssdmonitor)障害の2パターンを検証してみました。
■検証環境
OS：Oracle Linux 6.5
GI:Oracle Grid Infrastructure 12c Release 1 (12.1.0.2.0) Enterprise Edition
DB:Oracle Database 12c Release 1 (12.1.0.2.0) Enterprise Edition
※3ノードRAC(管理者管理型DB)
■前提
・SCANを使用しています
・DNSサーバはdnsmasqを使用しています
・ASMの冗長構成は標準冗長性(2多重)
■設定情報
[root@node1 ~]# /u01/app/12.1.0/grid/bin/crsctl stat res -t
--------------------------------------------------------------------------------
Name Target State Server State details
--------------------------------------------------------------------------------
Local Resources
--------------------------------------------------------------------------------
ora.CRS.dg
ONLINE ONLINE node1 STABLE
ONLINE ONLINE node2 STABLE
ONLINE ONLINE node3 STABLE
ora.DATA.dg
ONLINE ONLINE node1 STABLE
ONLINE ONLINE node2 STABLE
ONLINE ONLINE node3 STABLE
ora.FRA.dg
ONLINE ONLINE node1 STABLE
ONLINE ONLINE node2 STABLE
ONLINE ONLINE node3 STABLE
ora.LISTENER.lsnr
ONLINE ONLINE node1 STABLE
ONLINE ONLINE node2 STABLE
ONLINE ONLINE node3 STABLE
ora.asm
ONLINE ONLINE node1 Started,STABLE
ONLINE ONLINE node2 Started,STABLE
ONLINE ONLINE node3 Started,STABLE
ora.net1.network
ONLINE ONLINE node1 STABLE
ONLINE ONLINE node2 STABLE
ONLINE ONLINE node3 STABLE
ora.ons
ONLINE ONLINE node1 STABLE
ONLINE ONLINE node2 STABLE
ONLINE ONLINE node3 STABLE
--------------------------------------------------------------------------------
Cluster Resources
--------------------------------------------------------------------------------
ora.LISTENER_SCAN1.lsnr
1 ONLINE ONLINE node2 STABLE
ora.LISTENER_SCAN2.lsnr
1 ONLINE ONLINE node3 STABLE
ora.LISTENER_SCAN3.lsnr
1 ONLINE ONLINE node1 STABLE
ora.MGMTLSNR
1 ONLINE ONLINE node1 169.254.243.236 192.
168.100.101,STABLE
ora.cvu
1 ONLINE ONLINE node1 STABLE
ora.mgmtdb
1 ONLINE ONLINE node1 Open,STABLE
ora.node1.vip
1 ONLINE ONLINE node1 STABLE
ora.node2.vip
1 ONLINE ONLINE node2 STABLE
ora.node3.vip
1 ONLINE ONLINE node3 STABLE
ora.oc4j
1 ONLINE ONLINE node1 STABLE
ora.orcl.db
1 ONLINE ONLINE node1 Open,STABLE
2 ONLINE ONLINE node2 Open,STABLE
3 ONLINE ONLINE node3 Open,STABLE
ora.scan1.vip
1 ONLINE ONLINE node2 STABLE
ora.scan2.vip
1 ONLINE ONLINE node3 STABLE
ora.scan3.vip
1 ONLINE ONLINE node1 STABLE
--------------------------------------------------------------------------------
投票ディスク状態確認
[root@node1 ~]# /u01/app/12.1.0/grid/bin/crsctl query css votedisk
## STATE File Universal Id File Name Disk group
-- ----- ----------------- --------- ---------
1. ONLINE c65a4dc1e8824ff7bfb08ce7e31cf578 (/dev/sdb1) [CRS]
2. ONLINE cdc840af67ef4fcfbf5a77edeedc41bc (/dev/sdc1) [CRS]
3. ONLINE aafc9cb42c8d4fbebf1108e1d519d0c9 (/dev/sdd1) [CRS]
Located 3 voting disk(s).
CSSのMISSCOUNT値
[root@node1 ~]# /u01/app/12.1.0/grid/bin/crsctl get css misscount
CRS-4678: Successful get misscount 30 for Cluster Synchronization Services.
CSSのDISKTIMEOUT値
[root@node1 ~]# /u01/app/12.1.0/grid/bin/crsctl get css disktimeout
CRS-4678: Successful get disktimeout 200 for Cluster Synchronization Services.
CSSのREBOOTTIME値
[root@node1 ~]# /u01/app/12.1.0/grid/bin/crsctl get css reboottime
CRS-4678: Successful get reboottime 3 for Cluster Synchronization Services.
■検証パターン
①ノード1のCSS障害(ocssd.binプロセス停止)
②ノード1のCSS障害(cssdagent,ocssd.bin,cssdmonitorプロセス停止)
■検証
①ノード1のCSS障害(ocssd.binプロセス停止)
ノード1でCSS障害(ocssd.binプロセス停止)が発生した場合のクラスタの動きやDBからアプリデータをSELECTできるか検証します
今回はノード1のocssd.binプロセスをkillして疑似的にCSS障害を発生させます
【検証手順】
1. ノード1のocssd.binプロセスをkill
2. プロセスkill直後の各ノードのクラスタリソースと投票ディスクの状態を確認
3. プロセスkillの30秒後(MISSCOUNT値)の各ノードのクラスタリソースと投票ディスクの状態を確認
4. プロセスkillの200秒後(DISKTIMEOUT値)の各ノードのクラスタリソースと投票ディスクの状態を確認
5. ノード1でDBからアプリデータをSELECT
【想定】
ノード1が自動的に再起動され、ノード1でDBからアプリデータをSELECTできるはず
【検証結果】
ノード1が自動的に再起動され、ノード1でDBからアプリデータをSELECTできた(インスタンスが起動するまではDB接続できない)
※AIXはocssd.binをkillした後、ノード再起動しないバグがあります(Doc ID 2276152.1)
ただし、バグは12.2.0.2で修正済みとなっています
【作業ログ】
[root@node1 ~]# ps -ef | grep d.bin | grep -v grep
root 3428 1 1 20:20 ? 00:00:09 /u01/app/12.1.0/grid/bin/ohasd.bin reboot
grid 3793 1 0 20:20 ? 00:00:03 /u01/app/12.1.0/grid/bin/oraagent.bin
grid 3804 1 0 20:20 ? 00:00:02 /u01/app/12.1.0/grid/bin/mdnsd.bin
grid 3808 1 0 20:20 ? 00:00:06 /u01/app/12.1.0/grid/bin/evmd.bin
grid 3824 1 0 20:20 ? 00:00:02 /u01/app/12.1.0/grid/bin/gpnpd.bin
grid 3836 3808 0 20:20 ? 00:00:02 /u01/app/12.1.0/grid/bin/evmlogger.bin -o /u01/app/12.1.0/grid/log/[HOSTNAME]/evmd/evmlogger.info -l /u01/app/12.1.0/grid/log/[HOSTNAME]/evmd/evmlogger.log
grid 3842 1 1 20:20 ? 00:00:14 /u01/app/12.1.0/grid/bin/gipcd.bin
root 3851 1 0 20:20 ? 00:00:03 /u01/app/12.1.0/grid/bin/orarootagent.bin
root 4040 1 0 20:20 ? 00:00:02 /u01/app/12.1.0/grid/bin/cssdmonitor
root 4066 1 0 20:20 ? 00:00:02 /u01/app/12.1.0/grid/bin/cssdagent
grid 4077 1 1 20:20 ? 00:00:11 /u01/app/12.1.0/grid/bin/ocssd.bin
root 4279 1 0 20:21 ? 00:00:04 /u01/app/12.1.0/grid/bin/octssd.bin reboot
root 4508 1 0 20:21 ? 00:00:05 /u01/app/12.1.0/grid/bin/osysmond.bin
root 4532 1 1 20:21 ? 00:00:12 /u01/app/12.1.0/grid/bin/crsd.bin reboot
grid 4671 1 0 20:21 ? 00:00:04 /u01/app/12.1.0/grid/bin/oraagent.bin
root 4687 1 0 20:21 ? 00:00:05 /u01/app/12.1.0/grid/bin/orarootagent.bin
grid 4782 1 0 20:21 ? 00:00:01 /u01/app/12.1.0/grid/bin/scriptagent.bin
grid 4785 1 0 20:21 ? 00:00:00 /u01/app/12.1.0/grid/bin/tnslsnr MGMTLSNR -no_crs_notify -inherit
grid 5023 1 0 20:21 ? 00:00:00 /u01/app/12.1.0/grid/bin/tnslsnr LISTENER -no_crs_notify -inherit
grid 5030 1 0 20:21 ? 00:00:00 /u01/app/12.1.0/grid/bin/tnslsnr LISTENER_SCAN3 -no_crs_notify -inherit
oracle 5092 1 0 20:22 ? 00:00:03 /u01/app/12.1.0/grid/bin/oraagent.bin
[root@node1 ~]# kill -9 4077
★セッション断発生(ノード1再起動発生)
[root@node1 ~]# Last login: Sun Sep 18 20:32:35 2022 from 192.168.56.1
★ノード1へ再ログイン後
2. プロセスkill直後の各ノードのクラスタリソースと投票ディスクの状態を確認
# ノード1
★ノード再起動中のため、クラスタリソースと投票ディスクの状態は確認できなかった
# ノード2 ※ノード3も同様
クラスタリソース確認
[root@node2 ~]# /u01/app/12.1.0/grid/bin/crsctl stat res -t
--------------------------------------------------------------------------------
Name Target State Server State details
--------------------------------------------------------------------------------
Local Resources
--------------------------------------------------------------------------------
ora.CRS.dg
ONLINE ONLINE node2 STABLE
ONLINE ONLINE node3 STABLE
ora.DATA.dg
ONLINE ONLINE node2 STABLE
ONLINE ONLINE node3 STABLE
ora.FRA.dg
ONLINE ONLINE node2 STABLE
ONLINE ONLINE node3 STABLE
ora.LISTENER.lsnr
ONLINE ONLINE node2 STABLE
ONLINE ONLINE node3 STABLE
ora.asm
ONLINE ONLINE node2 Started,STABLE
ONLINE ONLINE node3 Started,STABLE
ora.net1.network
ONLINE ONLINE node2 STABLE
ONLINE ONLINE node3 STABLE
ora.ons
ONLINE ONLINE node2 STABLE
ONLINE ONLINE node3 STABLE
--------------------------------------------------------------------------------
Cluster Resources
--------------------------------------------------------------------------------
ora.LISTENER_SCAN1.lsnr
1 ONLINE ONLINE node2 STABLE
ora.LISTENER_SCAN2.lsnr
1 ONLINE ONLINE node3 STABLE
ora.LISTENER_SCAN3.lsnr
1 ONLINE OFFLINE STABLE
ora.MGMTLSNR
1 ONLINE OFFLINE node3 STARTING
ora.cvu
1 OFFLINE OFFLINE STABLE
ora.mgmtdb
1 ONLINE OFFLINE STABLE
ora.node1.vip
1 ONLINE OFFLINE node3 STARTING
ora.node2.vip
1 ONLINE ONLINE node2 STABLE
ora.node3.vip
1 ONLINE ONLINE node3 STABLE
ora.oc4j
1 ONLINE OFFLINE node2 STARTING
ora.orcl.db
1 ONLINE OFFLINE STABLE
2 ONLINE ONLINE node2 Open,STABLE
3 ONLINE ONLINE node3 Open,STABLE
ora.scan1.vip
1 ONLINE ONLINE node2 STABLE
ora.scan2.vip
1 ONLINE ONLINE node3 STABLE
ora.scan3.vip
1 ONLINE OFFLINE node2 STARTING
--------------------------------------------------------------------------------
★ノード1のノードVIPがノード3へフェイルオーバーし起動中ですが、インスタンス1は停止しました
クラスタリソースがノード2とノード3で稼働するよう再構成されました
投票ディスク状態確認
[root@node2 ~]# /u01/app/12.1.0/grid/bin/crsctl query css votedisk
## STATE File Universal Id File Name Disk group
-- ----- ----------------- --------- ---------
1. ONLINE c65a4dc1e8824ff7bfb08ce7e31cf578 (/dev/sdb1) [CRS]
2. ONLINE cdc840af67ef4fcfbf5a77edeedc41bc (/dev/sdc1) [CRS]
3. ONLINE aafc9cb42c8d4fbebf1108e1d519d0c9 (/dev/sdd1) [CRS]
Located 3 voting disk(s).
3. プロセスkillの30秒後(MISSCOUNT値)の各ノードのクラスタリソースと投票ディスクの状態を確認
# ノード1
クラスタリソース確認
[root@node1 ~]# /u01/app/12.1.0/grid/bin/crsctl stat res -t
CRS-4535: Cannot communicate with Cluster Ready Services
CRS-4000: Command Status failed, or completed with errors.
投票ディスク状態確認
[root@node1 ~]# /u01/app/12.1.0/grid/bin/crsctl query css votedisk
## STATE File Universal Id File Name Disk group
-- ----- ----------------- --------- ---------
1. ONLINE c65a4dc1e8824ff7bfb08ce7e31cf578 (/dev/sdb1) [CRS]
2. ONLINE cdc840af67ef4fcfbf5a77edeedc41bc (/dev/sdc1) [CRS]
3. ONLINE aafc9cb42c8d4fbebf1108e1d519d0c9 (/dev/sdd1) [CRS]
Located 3 voting disk(s).
[root@node1 ~]# su - oracle -c "sqlplus / as sysdba"
アイドル・インスタンスに接続しました。
★ノード1再起動直後はインスタンス1へ接続できなかった
# ノード2 ※ノード3も同様
クラスタリソース確認
[root@node2 ~]# /u01/app/12.1.0/grid/bin/crsctl stat res -t
--------------------------------------------------------------------------------
Name Target State Server State details
--------------------------------------------------------------------------------
Local Resources
--------------------------------------------------------------------------------
ora.CRS.dg
ONLINE ONLINE node2 STABLE
ONLINE ONLINE node3 STABLE
ora.DATA.dg
ONLINE ONLINE node2 STABLE
ONLINE ONLINE node3 STABLE
ora.FRA.dg
ONLINE ONLINE node2 STABLE
ONLINE ONLINE node3 STABLE
ora.LISTENER.lsnr
ONLINE ONLINE node2 STABLE
ONLINE ONLINE node3 STABLE
ora.asm
ONLINE ONLINE node2 Started,STABLE
ONLINE ONLINE node3 Started,STABLE
ora.net1.network
ONLINE ONLINE node2 STABLE
ONLINE ONLINE node3 STABLE
ora.ons
ONLINE ONLINE node2 STABLE
ONLINE ONLINE node3 STABLE
--------------------------------------------------------------------------------
Cluster Resources
--------------------------------------------------------------------------------
ora.LISTENER_SCAN1.lsnr
1 ONLINE ONLINE node2 STABLE
ora.LISTENER_SCAN2.lsnr
1 ONLINE ONLINE node3 STABLE
ora.LISTENER_SCAN3.lsnr
1 ONLINE ONLINE node2 STABLE
ora.MGMTLSNR
1 ONLINE ONLINE node3 169.254.57.30 192.16
8.100.103,STABLE
ora.cvu
1 OFFLINE OFFLINE STABLE
ora.mgmtdb
1 ONLINE OFFLINE node3 STARTING
ora.node1.vip
1 ONLINE INTERMEDIATE node3 FAILED OVER,STABLE
ora.node2.vip
1 ONLINE ONLINE node2 STABLE
ora.node3.vip
1 ONLINE ONLINE node3 STABLE
ora.oc4j
1 ONLINE OFFLINE node2 STARTING
ora.orcl.db
1 ONLINE OFFLINE STABLE
2 ONLINE ONLINE node2 Open,STABLE
3 ONLINE ONLINE node3 Open,STABLE
ora.scan1.vip
1 ONLINE ONLINE node2 STABLE
ora.scan2.vip
1 ONLINE ONLINE node3 STABLE
ora.scan3.vip
1 ONLINE ONLINE node2 STABLE
--------------------------------------------------------------------------------
★ノード1のノードVIPがノード3へフェイルオーバーしました
投票ディスク状態確認
[root@node2 ~]# /u01/app/12.1.0/grid/bin/crsctl query css votedisk
## STATE File Universal Id File Name Disk group
-- ----- ----------------- --------- ---------
1. ONLINE c65a4dc1e8824ff7bfb08ce7e31cf578 (/dev/sdb1) [CRS]
2. ONLINE cdc840af67ef4fcfbf5a77edeedc41bc (/dev/sdc1) [CRS]
3. ONLINE aafc9cb42c8d4fbebf1108e1d519d0c9 (/dev/sdd1) [CRS]
Located 3 voting disk(s).
4. プロセスkillの200秒後(DISKTIMEOUT値)の各ノードのクラスタリソースと投票ディスクの状態を確認
# ノード1 ※ノード2・3も同様
クラスタリソース確認
[root@node1 ~]# /u01/app/12.1.0/grid/bin/crsctl stat res -t
--------------------------------------------------------------------------------
Name Target State Server State details
--------------------------------------------------------------------------------
Local Resources
--------------------------------------------------------------------------------
ora.CRS.dg
ONLINE ONLINE node1 STABLE
ONLINE ONLINE node2 STABLE
ONLINE ONLINE node3 STABLE
ora.DATA.dg
ONLINE ONLINE node1 STABLE
ONLINE ONLINE node2 STABLE
ONLINE ONLINE node3 STABLE
ora.FRA.dg
ONLINE ONLINE node1 STABLE
ONLINE ONLINE node2 STABLE
ONLINE ONLINE node3 STABLE
ora.LISTENER.lsnr
ONLINE ONLINE node1 STABLE
ONLINE ONLINE node2 STABLE
ONLINE ONLINE node3 STABLE
ora.asm
ONLINE ONLINE node1 Started,STABLE
ONLINE ONLINE node2 Started,STABLE
ONLINE ONLINE node3 Started,STABLE
ora.net1.network
ONLINE ONLINE node1 STABLE
ONLINE ONLINE node2 STABLE
ONLINE ONLINE node3 STABLE
ora.ons
ONLINE ONLINE node1 STABLE
ONLINE ONLINE node2 STABLE
ONLINE ONLINE node3 STABLE
--------------------------------------------------------------------------------
Cluster Resources
--------------------------------------------------------------------------------
ora.LISTENER_SCAN1.lsnr
1 ONLINE ONLINE node1 STABLE
ora.LISTENER_SCAN2.lsnr
1 ONLINE ONLINE node3 STABLE
ora.LISTENER_SCAN3.lsnr
1 ONLINE ONLINE node2 STABLE
ora.MGMTLSNR
1 ONLINE ONLINE node3 169.254.57.30 192.16
8.100.103,STABLE
ora.cvu
1 OFFLINE OFFLINE STABLE
ora.mgmtdb
1 ONLINE ONLINE node3 Open,STABLE
ora.node1.vip
1 ONLINE ONLINE node1 STABLE
ora.node2.vip
1 ONLINE ONLINE node2 STABLE
ora.node3.vip
1 ONLINE ONLINE node3 STABLE
ora.oc4j
1 ONLINE ONLINE node2 STABLE
ora.orcl.db
1 ONLINE ONLINE node1 Open,STABLE
2 ONLINE ONLINE node2 Open,STABLE
3 ONLINE ONLINE node3 Open,STABLE
ora.scan1.vip
1 ONLINE ONLINE node1 STABLE
ora.scan2.vip
1 ONLINE ONLINE node3 STABLE
ora.scan3.vip
1 ONLINE ONLINE node2 STABLE
--------------------------------------------------------------------------------
★ノード3へフェイルオーバーしたノード1のノードVIPがノード1へフェイルバックしています
インスタンス1も起動しました
クラスタリソースもノード1・2・3で稼働するよう再構成されました
投票ディスク状態確認
[root@node1 ~]# /u01/app/12.1.0/grid/bin/crsctl query css votedisk
## STATE File Universal Id File Name Disk group
-- ----- ----------------- --------- ---------
1. ONLINE c65a4dc1e8824ff7bfb08ce7e31cf578 (/dev/sdb1) [CRS]
2. ONLINE cdc840af67ef4fcfbf5a77edeedc41bc (/dev/sdc1) [CRS]
3. ONLINE aafc9cb42c8d4fbebf1108e1d519d0c9 (/dev/sdd1) [CRS]
Located 3 voting disk(s).
5. ノード1でDBからアプリデータをSELECT
[root@node1 ~]# su - oracle -c "sqlplus / as sysdba"
SQL> select * from scott.emp;
EMPNO ENAME JOB MGR HIREDATE SAL COMM DEPTNO
---------- ------------------------------ --------------------------- ---------- -------- ---------- ---------- ----------
7369 SMITH CLERK 7902 80-12-17 800 20
7499 ALLEN SALESMAN 7698 81-02-20 1600 300 30
7521 WARD SALESMAN 7698 81-02-22 1250 500 30
7566 JONES MANAGER 7839 81-04-02 2975 20
7654 MARTIN SALESMAN 7698 81-09-28 1250 1400 30
7698 BLAKE MANAGER 7839 81-05-01 2850 30
7782 CLARK MANAGER 7839 81-06-09 2450 10
7839 KING PRESIDENT 81-11-17 5000 10
7844 TURNER SALESMAN 7698 81-09-08 1500 0 30
7900 JAMES CLERK 7698 81-12-03 950 30
7902 FORD ANALYST 7566 81-12-03 3000 20
7934 MILLER CLERK 7782 82-01-23 1300 10
12行が選択されました。
★ノード1でDBからアプリデータをSELECTできた
●各ノードのクラスタアラートログ
# ノード1
2022-09-18 20:40:30.707 [OHASD(3475)]CRS-8500: Oracle Clusterware OHASDプロセスをオペレーティング・システム・プロセスID 3475で開始しています
2022-09-18 20:40:30.715 [OHASD(3475)]CRS-0714: Oracle Clusterwareリリース12.1.0.2.0。
2022-09-18 20:40:30.727 [OHASD(3475)]CRS-2112: OLRサービスがノードnode1で起動されました。
2022-09-18 20:40:30.751 [OHASD(3475)]CRS-1301: Oracle高可用性サービスがノードnode1で起動されました。
2022-09-18 20:40:30.752 [OHASD(3475)]CRS-8011: ホストからの再起動アドバイザ・メッセージ: node1、コンポーネント: cssmonit、タイム・スタンプ: L-2022-09-16-12:20:59.691
2022-09-18 20:40:30.752 [OHASD(3475)]CRS-8013: 再起動アドバイザ・メッセージ・テキスト: Rebooting HUB node after limit 28290 exceeded; disk timeout 28290, network timeout 0, last heartbeat from CSSD at epoch seconds 1663298431.354, 28340 milliseconds ago based on invariant clock value of 5431824
2022-09-18 20:40:30.753 [OHASD(3475)]CRS-8017: 場所: /etc/oracle/lastgaspに2件の再起動アドバイザ・ログ・ファイルがあります(1が通知され、0件のエラーが発生しました)
2022-09-18 20:40:30.989 [CSSDAGENT(3769)]CRS-8500: Oracle Clusterware CSSDAGENTプロセスをオペレーティング・システム・プロセスID 3769で開始しています
2022-09-18 20:40:30.989 [CSSDMONITOR(3771)]CRS-8500: Oracle Clusterware CSSDMONITORプロセスをオペレーティング・システム・プロセスID 3771で開始しています
2022-09-18 20:40:31.017 [ORAROOTAGENT(3762)]CRS-8500: Oracle Clusterware ORAROOTAGENTプロセスをオペレーティング・システム・プロセスID 3762で開始しています
2022-09-18 20:40:31.019 [ORAAGENT(3766)]CRS-8500: Oracle Clusterware ORAAGENTプロセスをオペレーティング・システム・プロセスID 3766で開始しています
2022-09-18 20:40:31.127 [ORAAGENT(3766)]CRS-5011: リソース"ora.asm"のチェックが失敗しました: 詳細は"(:CLSN00006:)"("/u01/app/grid/diag/crs/node1/crs/trace/ohasd_oraagent_grid.trc")を参照してください
2022-09-18 20:40:31.374 [ORAAGENT(3826)]CRS-8500: Oracle Clusterware ORAAGENTプロセスをオペレーティング・システム・プロセスID 3826で開始しています
2022-09-18 20:40:31.421 [MDNSD(3839)]CRS-8500: Oracle Clusterware MDNSDプロセスをオペレーティング・システム・プロセスID 3839で開始しています
2022-09-18 20:40:31.430 [EVMD(3841)]CRS-8500: Oracle Clusterware EVMDプロセスをオペレーティング・システム・プロセスID 3841で開始しています
2022-09-18 20:40:32.462 [GPNPD(3856)]CRS-8500: Oracle Clusterware GPNPDプロセスをオペレーティング・システム・プロセスID 3856で開始しています
2022-09-18 20:40:33.492 [GIPCD(3875)]CRS-8500: Oracle Clusterware GIPCDプロセスをオペレーティング・システム・プロセスID 3875で開始しています
2022-09-18 20:40:33.504 [GPNPD(3856)]CRS-2328: GPNPDがノードnode1で起動されました。
2022-09-18 20:40:34.539 [ORAROOTAGENT(3896)]CRS-8500: Oracle Clusterware ORAROOTAGENTプロセスをオペレーティング・システム・プロセスID 3896で開始しています
2022-09-18 20:40:34.662 [CLSECHO(3919)]CRS-10001: 18-Sep-22 20:40 ACFS-9391: 既存のADVM/ACFSインストールをチェックしています。
2022-09-18 20:40:34.796 [CLSECHO(3924)]CRS-10001: 18-Sep-22 20:40 ACFS-9392: オペレーティング・システム用のADVM/ACFSインストール・ファイルを検証しています。
2022-09-18 20:40:34.809 [CLSECHO(3926)]CRS-10001: 18-Sep-22 20:40 ACFS-9393: ASM管理者の設定を確認しています。
2022-09-18 20:40:34.841 [CLSECHO(3931)]CRS-10001: 18-Sep-22 20:40 ACFS-9308: インストールしたADVM/ACFSドライバをロードしています。
2022-09-18 20:40:34.856 [CLSECHO(3934)]CRS-10001: 18-Sep-22 20:40 ACFS-9154: 'oracleoks.ko'ドライバをロードしています。
2022-09-18 20:40:34.934 [CLSECHO(3949)]CRS-10001: 18-Sep-22 20:40 ACFS-9154: 'oracleadvm.ko'ドライバをロードしています。
2022-09-18 20:40:35.008 [CLSECHO(3972)]CRS-10001: 18-Sep-22 20:40 ACFS-9154: 'oracleacfs.ko'ドライバをロードしています。
2022-09-18 20:40:35.107 [CLSECHO(4047)]CRS-10001: 18-Sep-22 20:40 ACFS-9327: ADVM/ACFSデバイスを検証しています。
2022-09-18 20:40:35.119 [CLSECHO(4049)]CRS-10001: 18-Sep-22 20:40 ACFS-9156: コントロール・デバイス'/dev/asm/.asm_ctl_spec'を検出しています。
2022-09-18 20:40:35.133 [CLSECHO(4053)]CRS-10001: 18-Sep-22 20:40 ACFS-9156: コントロール・デバイス'/dev/ofsctl'を検出しています。
2022-09-18 20:40:35.159 [CLSECHO(4058)]CRS-10001: 18-Sep-22 20:40 ACFS-9322: 完了
2022-09-18 20:40:42.988 [CSSDMONITOR(4081)]CRS-8500: Oracle Clusterware CSSDMONITORプロセスをオペレーティング・システム・プロセスID 4081で開始しています
2022-09-18 20:40:43.131 [CSSDAGENT(4097)]CRS-8500: Oracle Clusterware CSSDAGENTプロセスをオペレーティング・システム・プロセスID 4097で開始しています
2022-09-18 20:40:43.277 [OCSSD(4108)]CRS-8500: Oracle Clusterware OCSSDプロセスをオペレーティング・システム・プロセスID 4108で開始しています
2022-09-18 20:40:44.333 [OCSSD(4108)]CRS-1713: CSSDデーモンがhubモードで起動しています
2022-09-18 20:41:00.119 [OCSSD(4108)]CRS-1707: ノードnode1、番号1のリース取得が完了しました
2022-09-18 20:41:01.192 [OCSSD(4108)]CRS-1605: CSSD投票ファイルがオンラインです: /dev/sdd1。詳細は/u01/app/grid/diag/crs/node1/crs/trace/ocssd.trcを参照してください。
2022-09-18 20:41:01.195 [OCSSD(4108)]CRS-1605: CSSD投票ファイルがオンラインです: /dev/sdc1。詳細は/u01/app/grid/diag/crs/node1/crs/trace/ocssd.trcを参照してください。
2022-09-18 20:41:01.198 [OCSSD(4108)]CRS-1605: CSSD投票ファイルがオンラインです: /dev/sdb1。詳細は/u01/app/grid/diag/crs/node1/crs/trace/ocssd.trcを参照してください。
2022-09-18 20:41:02.331 [OCSSD(4108)]CRS-1601: CSSDの再構成が完了しました。アクティブ・ノードはnode1 node2 node3 です。
2022-09-18 20:41:04.328 [OCTSSD(4338)]CRS-8500: Oracle Clusterware OCTSSDプロセスをオペレーティング・システム・プロセスID 4338で開始しています
2022-09-18 20:41:05.438 [OCTSSD(4338)]CRS-2407: 新しいクラスタ時刻同期化サービスの参照ノードはホストnode2です。
2022-09-18 20:41:05.438 [OCTSSD(4338)]CRS-2401: クラスタ時刻同期化サービスがホストnode1で起動されました。
2022-09-18 20:41:06.055 [OCTSSD(4338)]CRS-2408: ホストnode1の時計は、平均クラスタ時刻と同期化するために、クラスタ時刻同期化サービスによって更新されました。
2022-09-18 20:41:14.422 [ORAAGENT(3826)]CRS-5011: リソース"ora.asm"のチェックが失敗しました: 詳細は"(:CLSN00006:)"("/u01/app/grid/diag/crs/node1/crs/trace/ohasd_oraagent_grid.trc")を参照してください
2022-09-18 20:41:15.641 [ORAAGENT(3826)]CRS-5011: リソース"ora.asm"のチェックが失敗しました: 詳細は"(:CLSN00006:)"("/u01/app/grid/diag/crs/node1/crs/trace/ohasd_oraagent_grid.trc")を参照してください
2022-09-18 20:41:15.658 [ORAAGENT(3826)]CRS-5011: リソース"ora.asm"のチェックが失敗しました: 詳細は"(:CLSN00006:)"("/u01/app/grid/diag/crs/node1/crs/trace/ohasd_oraagent_grid.trc")を参照してください
2022-09-18 20:41:30.225 [OSYSMOND(4568)]CRS-8500: Oracle Clusterware OSYSMONDプロセスをオペレーティング・システム・プロセスID 4568で開始しています
2022-09-18 20:41:31.302 [CRSD(4575)]CRS-8500: Oracle Clusterware CRSDプロセスをオペレーティング・システム・プロセスID 4575で開始しています
2022-09-18 20:41:32.595 [CRSD(4575)]CRS-1012: OCRサービスがノードnode1で起動されました。
2022-09-18 20:41:32.694 [CRSD(4575)]CRS-1201: CRSDがノードnode1で起動されました。
2022-09-18 20:41:32.933 [ORAAGENT(4708)]CRS-8500: Oracle Clusterware ORAAGENTプロセスをオペレーティング・システム・プロセスID 4708で開始しています
2022-09-18 20:41:32.974 [ORAAGENT(4713)]CRS-8500: Oracle Clusterware ORAAGENTプロセスをオペレーティング・システム・プロセスID 4713で開始しています
2022-09-18 20:41:32.981 [ORAROOTAGENT(4724)]CRS-8500: Oracle Clusterware ORAROOTAGENTプロセスをオペレーティング・システム・プロセスID 4724で開始しています
2022-09-18 20:41:33.052 [ORAAGENT(4713)]CRS-5011: リソース"orcl"のチェックが失敗しました: 詳細は"(:CLSN00007:)"("/u01/app/grid/diag/crs/node1/crs/trace/crsd_oraagent_oracle.trc")を参照してください
2022-09-18 20:41:46.829 [ORAAGENT(4882)]CRS-8500: Oracle Clusterware ORAAGENTプロセスをオペレーティング・システム・プロセスID 4882で開始しています
2022-09-18 20:41:47.926 [ORAAGENT(4898)]CRS-8500: Oracle Clusterware ORAAGENTプロセスをオペレーティング・システム・プロセスID 4898で開始しています
2022-09-18 20:41:48.017 [ORAAGENT(4898)]CRS-5011: リソース"orcl"のチェックが失敗しました: 詳細は"(:CLSN00007:)"("/u01/app/grid/diag/crs/node1/crs/trace/crsd_oraagent_oracle.trc")を参照してください
# ノード2
2022-09-18 20:40:17.632 [OCSSD(4027)]CRS-1612: タイムアウト間隔の50%で、ノードnode1(1)のネットワーク通信がありません。クラスタからこのノードを14.250秒内に削除します
2022-09-18 20:40:24.640 [OCSSD(4027)]CRS-1611: タイムアウト間隔の75%で、ノードnode1(1)のネットワーク通信がありません。クラスタからこのノードを7.240秒内に削除します
2022-09-18 20:40:29.647 [OCSSD(4027)]CRS-1610: タイムアウト間隔の90%で、ノードnode1(1)のネットワーク通信がありません。クラスタからこのノードを2.230秒内に削除します
2022-09-18 20:40:31.884 [OCSSD(4027)]CRS-1632: ノードnode1がクラスタ・インカーネーション558998463のクラスタから削除されています
2022-09-18 20:40:32.359 [OCSSD(4027)]CRS-1601: CSSDの再構成が完了しました。アクティブ・ノードはnode2 node3 です。
2022-09-18 20:40:32.381 [OCTSSD(4244)]CRS-2407: 新しいクラスタ時刻同期化サービスの参照ノードはホストnode2です。
2022-09-18 20:40:34.646 [CRSD(4510)]CRS-5504: ノード'node1'について、ノード・ダウン・イベントが報告されました。
2022-09-18 20:40:34.998 [CRSCTL(13462)]CRS-4743: ファイル/u01/app/12.1.0/grid/oc4j/j2ee/home/OC4J_DBWLM_config/system-jazn-data.xmlはOCR(サイズ: 13365(新)、13378(旧)バイト)から更新されました
2022-09-18 20:40:56.953 [CRSD(4510)]CRS-2773: サーバー'node1'はプール'Generic'から削除されました。
2022-09-18 20:40:56.954 [CRSD(4510)]CRS-2773: サーバー'node1'はプール'ora.orcl'から削除されました。
2022-09-18 20:41:02.934 [OCSSD(4027)]CRS-1601: CSSDの再構成が完了しました。アクティブ・ノードはnode1 node2 node3 です。
2022-09-18 20:41:34.817 [CRSD(4510)]CRS-2772: サーバー'node1'はプール'Generic'に割り当てられています。
2022-09-18 20:41:34.817 [CRSD(4510)]CRS-2772: サーバー'node1'はプール'ora.orcl'に割り当てられています。
# ノード3
2022-09-18 20:40:17.329 [OCSSD(3851)]CRS-1612: タイムアウト間隔の50%で、ノードnode1(1)のネットワーク通信がありません。クラスタからこのノードを14.550秒内に削除します
2022-09-18 20:40:25.335 [OCSSD(3851)]CRS-1611: タイムアウト間隔の75%で、ノードnode1(1)のネットワーク通信がありません。クラスタからこのノードを6.550秒内に削除します
2022-09-18 20:40:29.337 [OCSSD(3851)]CRS-1610: タイムアウト間隔の90%で、ノードnode1(1)のネットワーク通信がありません。クラスタからこのノードを2.550秒内に削除します
2022-09-18 20:40:32.360 [OCSSD(3851)]CRS-1601: CSSDの再構成が完了しました。アクティブ・ノードはnode2 node3 です。
2022-09-18 20:40:32.379 [OCTSSD(4066)]CRS-2407: 新しいクラスタ時刻同期化サービスの参照ノードはホストnode2です。
2022-09-18 20:41:02.926 [OCSSD(3851)]CRS-1601: CSSDの再構成が完了しました。アクティブ・ノードはnode1 node2 node3 です。
●各ノードのASMアラートログ
# ノード1
Sun Sep 18 20:41:25 2022
MEMORY_TARGET defaulting to 1128267776.
* instance_number obtained from CSS = 1, checking for the existence of node 0...
* node 0 does not exist. instance_number = 1
Starting ORACLE instance (normal) (OS id: 4382)
Sun Sep 18 20:41:25 2022
CLI notifier numLatches:7 maxDescs:620
Sun Sep 18 20:41:25 2022
**********************************************************************
Sun Sep 18 20:41:25 2022
(中略)
Sun Sep 18 20:41:32 2022
NOTE: Standard client +ASM1:+ASM:node-cluster registered, osid 4659, mbr 0x0, asmb 4657 (reg:3294390061)
Sun Sep 18 20:41:32 2022
NOTE: ASMB connected to ASM instance +ASM1 osid: 4659 (Flex mode; client id 0xffffffffffffffff)
Sun Sep 18 20:41:51 2022
NOTE: Standard client orcl1:orcl:node-cluster registered, osid 5009, mbr 0x1, asmb 5003 (reg:1996464035)
NOTE: client orcl1:orcl:node-cluster mounted group 3 (FRA)
NOTE: client orcl1:orcl:node-cluster mounted group 2 (DATA)
Sun Sep 18 20:44:33 2022
ALTER SYSTEM SET local_listener=' (ADDRESS=(PROTOCOL=TCP)(HOST=192.168.56.111)(PORT=1521))' SCOPE=MEMORY SID='+ASM1';
# ノード2
Sun Sep 18 20:40:33 2022
Reconfiguration started (old inc 6, new inc 8)
List of instances (total 2) :
2 3
Dead instances (total 1) :
1
My inst 2
Global Resource Directory frozen
* dead instance detected - domain 1 invalid = TRUE
* dead instance detected - domain 2 invalid = TRUE
(中略)
End lmon rcfg omni enqueue reconfig stage5
All grantable enqueues granted
Begin lmon rcfg omni enqueue reconfig stage6
End lmon rcfg omni enqueue reconfig stage6
Submitted all GCS remote-cache requests
Begin lmon rcfg omni enqueue reconfig stage7
End lmon rcfg omni enqueue reconfig stage7
Fix write in gcs resources
Sun Sep 18 20:41:27 2022
Reconfiguration complete (total time 0.3 secs)
# ノード3
Sun Sep 18 20:40:33 2022
Reconfiguration started (old inc 6, new inc 8)
List of instances (total 2) :
2 3
Dead instances (total 1) :
1
My inst 3
Global Resource Directory frozen
* dead instance detected - domain 1 invalid = TRUE
* dead instance detected - domain 2 invalid = TRUE
(中略)
End lmon rcfg omni enqueue reconfig stage5
All grantable enqueues granted
Begin lmon rcfg omni enqueue reconfig stage6
End lmon rcfg omni enqueue reconfig stage6
Submitted all GCS remote-cache requests
Begin lmon rcfg omni enqueue reconfig stage7
End lmon rcfg omni enqueue reconfig stage7
Fix write in gcs resources
Sun Sep 18 20:41:27 2022
Reconfiguration complete (total time 0.3 secs)
●各ノードのDBアラートログ
# ノード1
Sun Sep 18 20:40:02 2022
Error 29701: unexpected return code 6 from the Cluster Synchronization Service.
Sun Sep 18 20:40:02 2022
Restarting dead background process LMHB
Starting background process LMHB
Sun Sep 18 20:41:49 2022
Starting ORACLE instance (normal) (OS id: 4916)
Sun Sep 18 20:41:49 2022
CLI notifier numLatches:7 maxDescs:519
Sun Sep 18 20:41:49 2022
(中略)
Sun Sep 18 20:42:14 2022
Shared IO Pool defaulting to 48MB. Trying to get it from Buffer Cache for process 5212.
Sun Sep 18 20:42:16 2022
===========================================================
Dumping current patch information
===========================================================
No patches have been applied
===========================================================
Sun Sep 18 20:42:16 2022
Network Resource Management enabled for Process LG01 (pid 4993) for Exadata I/O
# ノード2
Sun Sep 18 20:37:22 2022
Network Resource Management enabled for Process LG01 (pid 5041) for Exadata I/O
Sun Sep 18 20:40:32 2022
Reconfiguration started (old inc 6, new inc 8)
List of instances (total 2) :
2 3
Dead instances (total 1) :
1
My inst 2
publish big name space - dead or down/up instance detected, invalidate domain 0
(中略)
Dwn-cvts replayed, VALBLKs dubious
All grantable enqueues granted
Submitted all GCS remote-cache requests
Fix write in gcs resources
Sun Sep 18 20:41:52 2022
Reconfiguration complete (total time 0.2 secs)
Sun Sep 18 20:41:54 2022
minact-scn: Master returning as live inst:1 has inc# mismatch instinc:0 cur:10 errcnt:0
Sun Sep 18 20:42:05 2022
Setting Resource Manager plan DEFAULT_MAINTENANCE_PLAN via parameter
# ノード3
Sun Sep 18 20:37:22 2022
Network Resource Management enabled for Process LG01 (pid 4806) for Exadata I/O
Sun Sep 18 20:40:32 2022
Reconfiguration started (old inc 6, new inc 8)
List of instances (total 2) :
2 3
Dead instances (total 1) :
1
My inst 3
publish big name space - dead or down/up instance detected, invalidate domain 0
(中略)
Set master node info
Submitted all remote-enqueue requests
Dwn-cvts replayed, VALBLKs dubious
All grantable enqueues granted
Submitted all GCS remote-cache requests
Fix write in gcs resources
Sun Sep 18 20:41:52 2022
Reconfiguration complete (total time 0.2 secs)
Sun Sep 18 20:42:05 2022
Setting Resource Manager plan DEFAULT_MAINTENANCE_PLAN via parameter
■おわりに
CSS障害(ocssd.binプロセス停止)が発生した場合、ノードが自動的に再起動され、DBからアプリデータをSELECTできることを確認できました。
ボリュームが多すぎてCSS障害(cssdagent,ocssd.bin,cssdmonitorプロセス停止)の検証結果まで書けなかったため、次回はCSS障害(cssdagent,ocssd.bin,cssdmonitorプロセス停止)の検証結果について書こうと思います。
