Internal Only: Advanced Troubleshooting of CSS Heartbeat Failures (Network) (Doc ID 457772.1)
9365 ワード
Applies to:
Oracle Server - Enterprise Edition - Version: 10.2.0.1 to 10.2.0.1Information in this document applies to any platform.
Purpose
Internal Note to Explain How to Troubleshoot CSS Heartbeat Failures (Network).Scope and Application
For Oracle Support and DevelopmentInternal Only: Advanced Troubleshooting of CSS Heartbeat Failures (Network)
The tell tale sign of a CSS network heartbeat related issue is the following type of message in the CSS log:
[ CSSD]2007-09-06 18:38:45.861 [18] >WARNING: clssnmPollingThread: node scadfrai11 (2) at 50% heartbeat fatal, eviction in 14.275 seconds The first thing to do is find out if the missed checkins ARE the problem or are a result of the node going down due to other reasons. Check the messages file to see what exact time the node went down and compare it to the time of the missed checkins.
- If the messages file reboot time < missed checkin time then the node eviction was likely not due to these missed checkins. <<<<時間によってrebootがmiss checkinsによって引き起こされたか否かを判断する.-If the messages file reboot time > missed checkin time then the node eviction was likely a result of the missed checkins.
If you determine that CSS actually did reboot the node due to missed checkins, then we need to find out why. There are 3 threads in CSS that deal with CSS heartbeats:
<<<<ノードごとにcss heartbeat,受信,送信,採決を処理する3つのtheadsがある.診断時には,これらが送信されたかどうか,すべて受信されたかどうか,miss checkinが存在するかどうかを見る必要がある.clssnmSendingThread - This thread periodically wakes up and sends appropriate packets (based on the join state) to other nodes so that other members know we are still alive. For the heartbeat he sends "status"packets to the other nodes to tell them that they are alive. This can be seen at CSS trace level 2 or higher. Example:
[ CSSD]2007-09-06 18:37:07.857 [19] >TRACE: clssnmSendingThread: sending status msg to all nodes
Notice that the thread # for the clssnmSendingThread is 19 in this example. This is important to know so that you don't end up troubleshooting the wrong thread
With CSS trace level 4 + CLSC tracing you can see more details important details like:
[ CSSD]2007-09-06 18:38:31.584 [19] >TRACE: clssnmsendmsg: sending msg type 3 to node 1
[ CSSD]2007-09-06 18:38:31.584 [19] >TRACE: clscsendx: (b8aaf0) sending msg (f395c8) type 3, size 68, srqh (eed3d0)
[ CSSD]2007-09-06 18:38:31.587 [19] >TRACE: clscsendx: (b8aaf0) sent msg type 3, size 68, rc 0 srqh (eed3d0) If you also turn on CLSC NS tracing you can see the Oracle Net tracing for this. You can see something like:
(19) [000013 06-SEP-2007 18:38:31:586] nsdo: cid=1, opcode=67, *bl=68, *what=1, uflgs=0x2, cflgs=0x3
(19) [000013 06-SEP-2007 18:38:31:586] snsbitts_ts: acquired the bit
(19) [000013 06-SEP-2007 18:38:31:586] nsdo: rank=64, nsctxrnk=0
(19) [000013 06-SEP-2007 18:38:31:586] nsdo: nsctx: state=8, flg=0x400d, mvd=0
(19) [000013 06-SEP-2007 18:38:31:586] nsdo: 68 bytes to transport
(19) [000013 06-SEP-2007 18:38:31:586] nttmwr: entry
(19) [000013 06-SEP-2007 18:38:31:587] nttmwr: socket 26 had bytes written=68
(19) [000013 06-SEP-2007 18:38:31:587] nttmwr: exit And of course OS Watcher is good to look at things underneath CSS.
The code path for sending a heartbeat message is clssnmSendingThread-->clssnmsendmsg-->clscsendx
clssnmClusterListener thread - This thread listens for incoming packets from other nodes by calling clscselect and dispatches them for appropriate handling. When the clssnmClusterListener receives a packet, it calls clssnmProcessPkt to process the packet. If it is a status packet then clssnmProcessPkt calls clssnmHandleStatus. In clssnmHandleStatus we put the packet info in memory to let it get seen by the polling thread so it can decide what to do with them. At CSS trace level 3 or higher you can see the clssnmClusterListener thread waking up and going through it's loop. You can also see
[ CSSD]2007-09-06 18:38:31.299 [13] >TRACE: clssnmClusterListener: Entering select blocking
Notice that the thread # for the clssnmClusterListener thread is 13 in this example. This is important to know so that you don't end up troubleshooting the wrong thread
With trace level 4 + CLSC tracing you can see more details important details like:
[ CSSD]2007-09-06 18:38:30.070 [13] >TRACE: clsc_receive: (f16470) prepare to receive
[ CSSD]2007-09-06 18:38:30.074 [13] >TRACE: clsc_receive: (f16470) compl recv, rc 0, nsret 0, flgs 0x0000, size 68
[ CSSD]2007-09-06 18:38:30.074 [13] >TRACE: clsc_receive: (f16470, 1) recv msg type 3, size 68, msgsz 68
[ CSSD]2007-09-06 18:38:30.074 [13] >TRACE: clssnmHandleStatus: src[2] dest[0] dom[0] seq[0] sync[53]
[ CSSD]2007-09-06 18:38:31.299 [13] >TRACE: clssnmClusterListener: Entering select blocking If you also turn on CLSC NS tracing you can see the Oracle Net tracing for this. You can see something like:
(13) [000014 06-SEP-2007 18:38:30:071] nsdo: cid=2, opcode=68, *bl=131136, *what=0, uflgs=0x0, cflgs=0x3
(13) [000014 06-SEP-2007 18:38:30:071] snsbitts_ts: acquired the bit
(13) [000014 06-SEP-2007 18:38:30:071] nsdo: rank=64, nsctxrnk=0
(13) [000014 06-SEP-2007 18:38:30:071] nsdo: nsctx: state=8, flg=0x400c, mvd=0
(13) [000014 06-SEP-2007 18:38:30:072] nsdo: reading from transport...
(13) [000014 06-SEP-2007 18:38:30:072] nttmrd: entry
(13) [000014 06-SEP-2007 18:38:30:073] nttmrd: socket 95 had bytes read=68
(13) [000014 06-SEP-2007 18:38:30:073] nttmrd: exit And of course OS Watcher is good to look at things underneath CSS.
The code path for receiving a heartbeat message is clssnmClusterListener-->clscselect The code path to process a received heartbeat message is clssnmClusterListener-->clssnmProcessPkt-->clssnmHandleStatus clssnmPollingThread - Periodically wakes up and scans to see who is active and has been checking in regularly by reading from the node db in memory. If the last last packet time in memory reaches 1/2 of misscount you will see this famous message:
[ CSSD]2007-09-06 18:38:45.861 [18] >WARNING: clssnmPollingThread: node scadfrai11 (2) at 50% heartbeat fatal, eviction in 14.275 seconds Not much more useful trace info you can turn on for this guy. He just reads the last packet time in memory and takes action if we reach misscount (sends out poison packets, etc...).
Things to Look For:
- Is the clssnmSendingThread sending a status message to every other node continuously?
If the answer is no, see if the clssnmSendingThread is stuck (stack traces of all threads of CSS) or if there is a resource problem or network error in OS Watcher (netstat, vmstat, etc...)
- Is the clssnmClusterListener receiving a status message from every other node continuously?
Again, if the answer is no, see if the clssnmClusterListener is stuck (stack traces of all threads of CSS) or if there is a resource problem or network error in OS Watcher (netstat, vmstat, etc...)
As long as you can confirm that the sending thread from node x is sending and the listening thread from node y is receiving you should not see any missed checkins. For Extremely Detailed Tracing of CSS Heartbeats (Be Careful Suggesting This to Customers):
10.2.0.2 (Bundle Patch 2) and above:
Prior versions:
Then restart CRS. This would provide A LOT of detail about the underlying Oracle network layers under CSS but obviously would generate trace info very fast in CRS_HOME/log/
Sample script to archive CSS logs every 10 minutes (archcsslogs.sh):
# archcsslogs.sh
#
# Archive CSS logs Every 10 Minutes to /tmp
#
# Set the CSSLOGDIR before running the script..(<CRS_HOME>/log/nodename/cssd)
#
# Example:
# CSSLOGDIR=/u01/oracrs/product/11.1.0/log/node1/cssd
CSSLOGDIR=<insert path here>
while [ 1 -ne 0 ]; do
CSSFILE=/tmp/css_`date +%m%d%y"_"%H%M`.tar
tar cf $CSSFILE $CSSLOGDIR/*
compress $CSSFILE
sleep 600
done
exit To run:
chmod 755 archcsslogs.sh
nohup ./archcsslogs.sh & Then kill the archcsslogs.sh process when you want it to stop archiving...
References
@ BUG:6394860- NODE REBOOT/EVICTIONS DUE TO HEARTBEAT LOST ON NETWORK NOTE:265769.1- Troubleshooting CRS Reboots
@ NOTE:305689.1- CSS (Cluster Synchronization Services) Internals (INTERNAL ONLY) clssnm.c and clssnm.h