RAC Member Kill Escalation

RAC Member Kill Escalation

Rate This
  • Comments 1

Managing a healthy cluster belongs to the most important goals of every cluster stack, and Oracle Clusterware is not an exception to this rule. To ensure cluster and data integrity unhealthy nodes should be forcefully evicted from a cluster. A node eviction will be initiated if:

- cluster member cannot communicate via network heartbeat (default timeout 30 seconds)
- cluster member cannot communicate via disk heartbeat using the majority of voting files (long I/O timeout - 200 sec.; short I/O timeout - 27 sec.)
- server hung, CPU starvation
- problems with core Oracle Clusterware processes (e.g.: OCSSD).

For more information about Clusterware node fencing see an Trivadis article "Oracle Clusterware Node Fencing – A Killing Glance Beyond The Surface" available in the download area at http://www.trivadis.com.

But what happens if the Oracle Clusterware itself is working perfectly and at the same time one of the RAC instances is hanging ? Whould the cluster evict the node ? The answer is no. The database LMON process will request a member kill escalation and ask the CSS process to remove the hanging  database instance from the cluster. The following example will demonstrate it in a cluster consisting of two nodes:

SQL> select instance_name, host_name from gv$instance;

INSTANCE_NAME     HOST_NAME
---------------- ------------------------------
RAC1         white.example.com
RAC2         black.example.com

1. On black server we stop the execution of all rdbms processes (by sending the STOP signal)

oracle@black:~/ [+ASM2] ps -ef | grep ora_ | grep RAC2 | awk '{print $2}' | while read PID
> do
> kill -STOP $PID
> done
oracle@black:~/ [+ASM2]

The process status:

oracle@black:~/ [+ASM2] ps -efl | grep ora_ | grep RAC2
0 T oracle    5123     1  0  80   0 - 191387 signal 13:03 ?       00:00:00 ora_pmon_RAC2
0 T oracle    5125     1  0  80   0 - 190748 signal 13:03 ?       00:00:00 ora_psp0_RAC2
0 T oracle    5127     1  1  58   - - 190748 signal 13:03 ?       00:00:04 ora_vktm_RAC2
0 T oracle    5131     1  0  80   0 - 192260 signal 13:03 ?       00:00:00 ora_gen0_RAC2
0 T oracle    5133     1  0  80   0 - 192290 signal 13:03 ?       00:00:00 ora_diag_RAC2
0 T oracle    5135     1  0  80   0 - 191139 signal 13:03 ?       00:00:00 ora_dbrm_RAC2
0 T oracle    5137     1  0  80   0 - 190748 signal 13:03 ?       00:00:00 ora_ping_RAC2
0 T oracle    5139     1  0  80   0 - 190748 signal 13:03 ?       00:00:00 ora_acms_RAC2
0 T oracle    5141     1  0  80   0 - 193330 signal 13:03 ?       00:00:01 ora_dia0_RAC2
0 T oracle    5143     1  0  80   0 - 193883 signal 13:03 ?       00:00:01 ora_lmon_RAC2
...

2. From the client point of view the Real Application Cluster database is hanging on both nodes. No queries or DMLs are possible.

SQL> select instance_name, host_name from gv$instance;

-- no output, query hangs ...

3. Due to RDBMS inactivity (no heartbeats) on the server black the ASM instance will kill the RDBMS database client process. From the ASM alert log file:

Sat Oct 15 13:03:07 2011
NOTE: client RAC2:RAC_SITE1 registered, osid 5179, mbr 0x1
...
Sat Oct 15 13:12:18 2011
WARNING: client [RAC2:RAC_SITE1] not responsive for 236s; state=0x1. killing pid 5179
Sat Oct 15 13:13:18 2011
WARNING: client [RAC2:RAC_SITE1] cleanup delayed; waited 297s, pid 5179 mbr 0x1
...

4. Due to missing heartbeats the healthy RAC instance on node white will remove the hanging RAC instance by requesting a member kill escalation. From the database alert log file on the white server:

Sat Oct 15 13:12:49 2011
LMS0 (ospid: 5065) has detected no messaging activity from instance 2
LMS0 (ospid: 5065) issues an IMR to resolve the situation
Please check LMS0 trace file for more detail.
...
Evicting instance 2 from cluster
Waiting for instances to leave: 2
Sat Oct 15 13:13:51 2011
IPC Send timeout detected. Sender: ospid 5069 [oracle@white.example.com (LMS1)]
Receiver: inst 2 binc 429419788 ospid 5151
Sat Oct 15 13:13:51 2011
IPC Send timeout detected. Sender: ospid 5065 [oracle@white.example.com (LMS0)]
Receiver: inst 2 binc 429419784 ospid 5147
IPC Send timeout to 2.1 inc 4 for msg type 44 from opid 13
IPC Send timeout to 2.2 inc 4 for msg type 44 from opid 14
Sat Oct 15 13:14:03 2011
Restarting dead background process MMON
Sat Oct 15 13:14:03 2011
MMON started with pid=25, OS id=6428
Sat Oct 15 13:14:07 2011
Remote instance kill is issued with system inc 6
Remote instance kill map (size 1) : 2
LMON received an instance eviction notification from instance 1
The instance eviction reason is 0x20000000
The instance eviction map is 2
Reconfiguration started (old inc 4, new inc 8)
List of instances:
 1 (myinst: 1)
 Global Resource Directory frozen
 * dead instance detected - domain 0 invalid = TRUE
 Communication channels reestablished
 Master broadcasted resource hash value bitmaps
 Non-local Process blocks cleaned out
Sat Oct 15 13:14:08 2011
 LMS 0: 0 GCS shadows cancelled, 0 closed, 0 Xw survived
Sat Oct 15 13:14:08 2011
 LMS 1: 0 GCS shadows cancelled, 0 closed, 0 Xw survived
 Set master node info
 Submitted all remote-enqueue requests
 Dwn-cvts replayed, VALBLKs dubious
 All grantable enqueues granted
 Post SMON to start 1st pass IR
Sat Oct 15 13:14:08 2011
Instance recovery: looking for dead threads
 Submitted all GCS remote-cache requests
 Post SMON to start 1st pass IR
 Fix write in gcs resources
Reconfiguration complete
...

5. In the cluster alert log file on the white server you will find the following entry about member kill escalation requested by the database LMON process:

2011-10-15 13:14:07.524
[cssd(4389)]CRS-1663:Member kill issued by PID 5061 for 1 members, group DBRAC_SITE1. Details at (:CSSGM00044:) in /u00/app/grid/11.2.0.3/log/white/cssd/ocssd.log.

SQL> select pname from v$process where spid=5061;

PNAME
-----
LMON

SQL>


In the cluster alert log file on the server black we will find the following entry:

2011-10-15 13:14:07.382
[cssd(4243)]CRS-1662:Member kill requested by node white for member number 1, group DBRAC_SITE1

6. In the OCSSD log file on the server white:

2011-10-15 13:14:07.523: [    CSSD][1107581248]clssgmExecuteClientRequest: Member kill request from client (0x7fca8c243290)
2011-10-15 13:14:07.523: [    CSSD][1107581248](:CSSGM00044:)clssgmReqMemberKill: Kill requested map 0x00000002 flags 0x2 escalate 0xffffffff
2011-10-15 13:14:07.524: [    CSSD][1121773888]clssgmMbrKillThread: Kill requested map 0x00000002 id 1 Group name DBRAC_SITE1 flags 0x00000001 start time 0xfffe5a42 end time 0xfffed166 time out 30500 req node 1
...
2011-10-15 13:14:07.681: [    CSSD][1121773888]clssgmMbrKillDoneChk: Work item results. Success map 0x00000002 Fail map 0x00000000 Req node 1 Responding node 0 Num left 0 Kill count 1 Number of answers 1
2011-10-15 13:14:07.681: [    CSSD][1117043008]clssgmQueueGrockEvent: groupName(DBRAC_SITE1) count(1) master(0) event(1), incarn 4, mbrc 1, to member 0, events 0x68, state 0x0
2011-10-15 13:14:07.681: [    CSSD][1121773888]clssgmMbrKillThread: Member kill request complete.
...

On the server black:

2011-10-15 13:14:07.381: [    CSSD][1113635136]clssgmpProcessRequestMsg: Member kill request from remote node
2011-10-15 13:14:07.382: [    CSSD][1121519936]clssgmmkLocalKillThread: Local kill requested: id 1 mbr map 0x00000002 Group name DBRAC_SITE1 flags 0x00000000 st time -109066 end time -78566 time out 30500 req node 1
2011-10-15 13:14:07.382: [    CSSD][1121519936]clssgmmkLocalKillThread: Kill requested for member 1 group (0x7fdad86d7a70/DBRAC_SITE1)
2011-10-15 13:14:07.382: [    CSSD][1121519936]GM Diagnostics started for mbrnum/grockname: 1/DBRAC_SITE1
...
2011-10-15 13:14:07.537: [    CSSD][1113635136]clssgmRemoveMember: Member 1 is the target of a mbr kill
2011-10-15 13:14:07.537: [    CSSD][1113635136]clssgmKillMbrGone: Posting mbrgone event Req node 1 id 1 member 1 grock name DBRAC_SITE1
2011-10-15 13:14:07.537: [    CSSD][1113635136]clssgmRPCDone: rpc 0x7fdaddfce608 (RPC#131) state 6, flags 0x100
2011-10-15 13:14:07.538: [    CSSD][1113635136]clssgmDelMemCmpl: rpc 0x7fdaddfce608, ret 0, client (nil) member 0x7fdad860f0c0
2011-10-15 13:14:07.538: [    CSSD][1113635136]clssgmFreeRPCIndex: freeing rpc 131
2011-10-15 13:14:07.538: [    CSSD][1113635136]clssgmHandleGrockRcfgUpdate: grock(DBRAC_SITE1), updateseq(4), status(0), sendresp(1)
2011-10-15 13:14:07.538: [    CSSD][1121519936]clssgmmkLocalKillDoneChk: Work item results. Success map 0x00000002 Fail map 0x00000000 Req node 1 Responding node 0 Num left 0 Kill count 1 Number of answers 1
2011-10-15 13:14:07.538: [    CSSD][1121519936]clssgmmkLocalKillResults: Replying to kill request from remote node 1 kill id 1 Success map 0x00000002 Fail map 0x00000000
...

7. Now the query executed at point 2. has returned with an error; the database service on node white is available again:

SQL> select instance_name, host_name from gv$instance
select instance_name, host_name from gv$instance
*
ERROR at line 1:
ORA-12805: parallel query server died unexpectedly

Elapsed: 00:06:17.02

8. After sendig the CONT signal to the database instance processes on the node black the instance will be bounced automatically:

oracle@black:~/ [+ASM2] ps -ef | grep ora_ | grep RAC2 | awk '{print $2}' | while read PID
> do
> kill -CONT $PID
> done
oracle@black:~/ [+ASM2]


From the database alert log file on the black server:

Sat Oct 15 15:09:53 2011
Time drift detected. Please check VKTM trace file for more details.
Sat Oct 15 15:09:53 2011
PMON (ospid: 8903): terminating the instance due to error 481
Sat Oct 15 15:09:54 2011
ORA-1092 : opitsk aborting process
Sat Oct 15 15:09:54 2011
License high water mark = 4
Instance terminated by PMON, pid = 8903
USER (ospid: 9297): terminating the instance
Instance terminated by USER, pid = 9297
Sat Oct 15 15:10:00 2011
Adjusting the default value of parameter parallel_max_servers
from 160 to 135 due to the value of parameter processes (150)
Starting ORACLE instance (normal)
LICENSE_MAX_SESSION = 0
LICENSE_SESSIONS_WARNING = 0
...

Your comment has been posted.   Close
Thank you, your comment requires moderation so it may take a while to appear.   Close
Leave a Comment
  • Post
  • Hi Robert,

    really cool blog entry.

    Thanx

Page 1 of 1 (1 items)