学习oracle 10.2.0.1 rac集群进程cssd的原理及机制之系列一

结论

1,cssd进程访问表决磁盘
2,如果RAC节点间私网通讯出现故障，不是马上会导致RAC节点驱逐，有个时间间隔，大约为1分钟
   由CSSD的日志看出
   [    CSSD]2015-11-19 03:13:19.281 [1205823808] >TRACE:   clssnmPollingThread: node jingfa2 (2) missed(2) checkin(s)
[    CSSD]2015-11-19 03:13:20.282 [1205823808] >TRACE:   clssnmPollingThread: node jingfa2 (2) missed(3) checkin(s)
[    CSSD]2015-11-19 03:13:21.283 [1205823808] >TRACE:   clssnmPollingThread: node jingfa2 (2) missed(4) checkin(s)         


中间略
[    CSSD]2015-11-19 03:14:13.340 [1205823808] >TRACE:   clssnmPollingThread: node jingfa2 (2) missed(56) checkin(s)
[    CSSD]2015-11-19 03:14:14.341 [1205823808] >TRACE:   clssnmPollingThread: node jingfa2 (2) missed(57) checkin(s)
[    CSSD]2015-11-19 03:14:15.341 [1205823808] >TRACE:   clssnmPollingThread: node jingfa2 (2) missed(58) checkin(s)
[    CSSD]2015-11-19 03:14:16.342 [1205823808] >TRACE:   clssnmPollingThread: node jingfa2 (2) missed(59) checkin(s)


[    CSSD]2015-11-19 03:14:14.341 [1205823808] >TRACE:   clssnmPollingThread: node jingfa2 (2) missed(57) checkin(s)
[    CSSD]2015-11-19 03:14:15.341 [1205823808] >TRACE:   clssnmPollingThread: node jingfa2 (2) missed(58) checkin(s)
[    CSSD]2015-11-19 03:14:16.342 [1205823808] >TRACE:   clssnmPollingThread: node jingfa2 (2) missed(59) checkin(s)


发生驱逐节点2
[    CSSD]2015-11-19 03:14:17.344 [1205823808] >TRACE:   clssnmPollingThread: Eviction started for node jingfa2 (2), flags 0x000d, state 3, wt4c 0 




3，RAC节点间私网出现通讯故障时，先是CSSD日志有信息，尔后是CRSD日志，最后或同时是ALERT日志（DB ALERT）
   所以分析cssd日志分析最为重要


4,一定要重点针对性分析cssd日志中的函数比如：clssnmPollingThread


5，RAC私网通讯故障，最终会在ALERT中出现LMON及LMD的TRC文件，可见LMON是监控RAC节点的健康运行的进程

引发问题

1, cssd日志中的函数比如：clssnmPollingThread含义是什么，从哪儿获知这些函数的含义
2, 分析RAC节点重启或驱逐这些函数的区别又是什么
3，故障出现时应重点关注哪些函数，并从这些函数获取到故障的原因呢


 

测试

---禁用节点2的私网网卡
[root@jingfa2 ~]# ifconfig eth1
eth1      Link encap:Ethernet  HWaddr 08:00:27:5C:4F:73  
          inet addr:10.10.10.9  Bcast:10.0.0.255  Mask:255.255.255.0
          inet6 addr: fe80::a00:27ff:fe5c:4f73/64 Scope:Link
          UP BROADCAST RUNNING MULTICAST  MTU:1500  Metric:1
          RX packets:120143 errors:0 dropped:0 overruns:0 frame:0
          TX packets:127532 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:1000 
          RX bytes:61973575 (59.1 MiB)  TX bytes:67650524 (64.5 MiB)
          Base address:0xd040 Memory:f0820000-f0840000 
[root@jingfa2 ~]# ifconfig eth1 down




---观察节点1的alert,crsd,cssd log


---先是cssd log出现如下信息
[    CSSD]2015-11-19 03:11:44.329 [1163864384] >TRACE:   clssgmClientConnectMsg: Connect from con(0xf9ecd60) proc(0xfa31db0) pid() proto(10:2:1:1)
[    CSSD]2015-11-19 03:12:44.621 [1163864384] >TRACE:   clssgmClientConnectMsg: Connect from con(0xf9ecfa0) proc(0xfa31db0) pid() proto(10:2:1:1)


用函数clssnmpollingthread检测到节点2通讯不正常,可见如果RAC 2个节点如果1分钟不能通讯，即发生节点驱逐，且重启有问题的节点（主机重启哟）
[    CSSD]2015-11-19 03:13:19.281 [1205823808] >TRACE:   clssnmPollingThread: node jingfa2 (2) missed(2) checkin(s)
[    CSSD]2015-11-19 03:13:20.282 [1205823808] >TRACE:   clssnmPollingThread: node jingfa2 (2) missed(3) checkin(s)
[    CSSD]2015-11-19 03:13:21.283 [1205823808] >TRACE:   clssnmPollingThread: node jingfa2 (2) missed(4) checkin(s)
[    CSSD]2015-11-19 03:13:22.285 [1205823808] >TRACE:   clssnmPollingThread: node jingfa2 (2) missed(5) checkin(s)
[    CSSD]2015-11-19 03:13:23.287 [1205823808] >TRACE:   clssnmPollingThread: node jingfa2 (2) missed(6) checkin(s)
[    CSSD]2015-11-19 03:13:24.287 [1205823808] >TRACE:   clssnmPollingThread: node jingfa2 (2) missed(7) checkin(s)
[    CSSD]2015-11-19 03:13:25.288 [1205823808] >TRACE:   clssnmPollingThread: node jingfa2 (2) missed(8) checkin(s)
[    CSSD]2015-11-19 03:13:26.289 [1205823808] >TRACE:   clssnmPollingThread: node jingfa2 (2) missed(9) checkin(s)
[    CSSD]2015-11-19 03:13:27.290 [1205823808] >TRACE:   clssnmPollingThread: node jingfa2 (2) missed(10) checkin(s)
[    CSSD]2015-11-19 03:13:28.291 [1205823808] >TRACE:   clssnmPollingThread: node jingfa2 (2) missed(11) checkin(s)
[    CSSD]2015-11-19 03:13:29.293 [1205823808] >TRACE:   clssnmPollingThread: node jingfa2 (2) missed(12) checkin(s)
[    CSSD]2015-11-19 03:13:30.293 [1205823808] >TRACE:   clssnmPollingThread: node jingfa2 (2) missed(13) checkin(s)
[    CSSD]2015-11-19 03:13:31.295 [1205823808] >TRACE:   clssnmPollingThread: node jingfa2 (2) missed(14) checkin(s)
[    CSSD]2015-11-19 03:13:32.296 [1205823808] >TRACE:   clssnmPollingThread: node jingfa2 (2) missed(15) checkin(s)
[    CSSD]2015-11-19 03:13:33.297 [1205823808] >TRACE:   clssnmPollingThread: node jingfa2 (2) missed(16) checkin(s)
[    CSSD]2015-11-19 03:13:34.297 [1205823808] >TRACE:   clssnmPollingThread: node jingfa2 (2) missed(17) checkin(s)          


中间略
[    CSSD]2015-11-19 03:14:13.340 [1205823808] >TRACE:   clssnmPollingThread: node jingfa2 (2) missed(56) checkin(s)
[    CSSD]2015-11-19 03:14:14.341 [1205823808] >TRACE:   clssnmPollingThread: node jingfa2 (2) missed(57) checkin(s)
[    CSSD]2015-11-19 03:14:15.341 [1205823808] >TRACE:   clssnmPollingThread: node jingfa2 (2) missed(58) checkin(s)
[    CSSD]2015-11-19 03:14:16.342 [1205823808] >TRACE:   clssnmPollingThread: node jingfa2 (2) missed(59) checkin(s)


[    CSSD]2015-11-19 03:14:14.341 [1205823808] >TRACE:   clssnmPollingThread: node jingfa2 (2) missed(57) checkin(s)
[    CSSD]2015-11-19 03:14:15.341 [1205823808] >TRACE:   clssnmPollingThread: node jingfa2 (2) missed(58) checkin(s)
[    CSSD]2015-11-19 03:14:16.342 [1205823808] >TRACE:   clssnmPollingThread: node jingfa2 (2) missed(59) checkin(s)


发生驱逐节点2
[    CSSD]2015-11-19 03:14:17.344 [1205823808] >TRACE:   clssnmPollingThread: Eviction started for node jingfa2 (2), flags 0x000d, state 3, wt4c 0
[    CSSD]2015-11-19 03:14:17.344 [1226803520] >TRACE:   clssnmDoSyncUpdate: Initiating sync 3
[    CSSD]2015-11-19 03:14:17.344 [1226803520] >TRACE:   clssnmSetupAckWait: Ack message type (11) 
[    CSSD]2015-11-19 03:14:17.344 [1226803520] >TRACE:   clssnmSetupAckWait: node(1) is ALIVE
[    CSSD]2015-11-19 03:14:17.344 [1226803520] >TRACE:   clssnmSetupAckWait: node(2) is ALIVE
[    CSSD]2015-11-19 03:14:17.344 [1226803520] >TRACE:   clssnmSendSync: syncSeqNo(3)
[    CSSD]2015-11-19 03:14:17.344 [1226803520] >TRACE:   clssnmWaitForAcks: Ack message type(11), ackCount(2)
[    CSSD]2015-11-19 03:14:17.344 [1153374528] >TRACE:   clssnmHandleSync: Acknowledging sync: src[1] srcName[jingfa1] seq[9] sync[3]
[    CSSD]2015-11-19 03:14:17.381 [577131712] >USER:    NMEVENT_SUSPEND [00][00][00][06]
[    CSSD]2015-11-19 03:14:18.346 [1226803520] >TRACE:   clssnmWaitForAcks: node(2) is expiring, msg type(11)
[    CSSD]2015-11-19 03:14:18.346 [1226803520] >TRACE:   clssnmWaitForAcks: done, msg type(11)
[    CSSD]2015-11-19 03:14:18.346 [1226803520] >TRACE:   clssnmDoSyncUpdate: node(0) missCount(20369) state(0)
[    CSSD]2015-11-19 03:14:18.346 [1226803520] >TRACE:   clssnmDoSyncUpdate: node(2) missCount(60) state(3)
[    CSSD]2015-11-19 03:14:18.346 [1226803520] >TRACE:   clssnmSetupAckWait: Ack message type (13) 
[    CSSD]2015-11-19 03:14:18.346 [1226803520] >TRACE:   clssnmSetupAckWait: node(1) is ACTIVE
[    CSSD]2015-11-19 03:14:18.346 [1226803520] >TRACE:   clssnmSendVote: syncSeqNo(3)
[    CSSD]2015-11-19 03:14:18.346 [1226803520] >TRACE:   clssnmWaitForAcks: Ack message type(13), ackCount(1)
[    CSSD]2015-11-19 03:14:18.346 [1153374528] >TRACE:   clssnmSendVoteInfo: node(1) syncSeqNo(3)  --可见cssd与表决磁盘有关
[    CSSD]2015-11-19 03:14:19.347 [1226803520] >TRACE:   clssnmWaitForAcks: done, msg type(13)
[    CSSD]2015-11-19 03:14:19.347 [1226803520] >TRACE:   clssnmCheckDskInfo: Checking disk info...


节点2 DOWN，一直持续读取节点2的磁盘心跳
[    CSSD]2015-11-19 03:14:20.364 [1132394816] >TRACE:   clssnmReadDskHeartbeat: node(2) is down. rcfg(3) wrtcnt(19832) LATS(19649184) Disk lastSeqNo(19832)
[    CSSD]2015-11-19 03:14:21.378 [1132394816] >TRACE:   clssnmReadDskHeartbeat: node(2) is down. rcfg(3) wrtcnt(19833) LATS(19650204) Disk lastSeqNo(19833)




然后crsd log出现信息
可见crsd进程和cssd进程的作用不同，所以RAC集群出问题先要查看crsd的log,也就是说crsd的日志只是现象
2015-11-19 03:15:16.749: [  CRSEVT][1607604544]0Processing member leave for jingfa2, incarnation: 3 --节点2离开即驱逐
2015-11-19 03:15:16.750: [  CRSEVT][1607604544]0Do failover for: jingfa2
2015-11-19 03:15:17.156: [  OCRSRV][1555155264]s_update_remote_cache_int: FAILED TO RCV ACK FROM node 2 retcode 7 --接受不到节点2的反馈
2015-11-19 03:15:19.805: [  CRSRES][1586624832]0startRunnable: setting CLI values
2015-11-19 03:15:19.966: [  CRSRES][1586624832]0Attempting to start `ora.jingfa2.vip` on member `jingfa1`  --在节点1 启动节点2原来的VIP
2015-11-19 03:15:24.288: [  CRSAPP][1586624832]0StartResource error for ora.jingfa2.vip error code = 1
2015-11-19 03:15:26.545: [  CRSRES][1586624832]0Start of `ora.jingfa2.vip` on member `jingfa1` failed.
2015-11-19 03:15:26.716: [  CRSRES][1586624832]0startRunnable: setting CLI values
2015-11-19 03:15:26.769: [  CRSRES][1628584256]0startRunnable: setting CLI values
2015-11-19 03:15:26.783: [  CRSRES][1628584256]0Attempting to start `ora.jingfa.db` on member `jingfa1` --在节点1启动原节点2的DB资源
2015-11-19 03:15:26.838: [  CRSRES][1586624832]0Attempting to start `ora.jingfa.zxy_jingfa.jingfa1.srv` on member `jingfa1`
2015-11-19 03:15:26.999: [  CRSRES][1712503104]0jingfa1 : CRS-1019: Resource ora.jingfa2.ASM2.asm (application) cannot run on jingfa1




2015-11-19 03:15:27.016: [  CRSRES][1691523392]0startRunnable: setting CLI values
2015-11-19 03:15:27.018: [  CRSRES][1691523392]0Attempting to start `ora.jingfa.jingfa1.inst` on member `jingfa1`  --原理同上
2015-11-19 03:15:27.919: [  CRSAPP][1586624832]0StartResource error for ora.jingfa.zxy_jingfa.jingfa1.srv error code = 1
2015-11-19 03:15:28.139: [  CRSRES][1586624832]0Start of `ora.jingfa.zxy_jingfa.jingfa1.srv` on member `jingfa1` failed.
2015-11-19 03:15:29.485: [  OCRSRV][1240459584]th_select_handler: Failed to retrieve procctx from ht. constr = [216713920] retval lht [-27] Signal CV.
2015-11-19 03:15:39.202: [  CRSAPP][1691523392]0StartResource error for ora.jingfa.jingfa1.inst error code = 1
2015-11-19 03:15:41.328: [  CRSRES][1691523392]0Start of `ora.jingfa.jingfa1.inst` on member `jingfa1` failed.
2015-11-19 03:15:41.380: [  CRSRES][1691523392]0CRS-1006: No more members to consider


2015-11-19 03:15:41.421: [  CRSAPP][1628584256]0StartResource error for ora.jingfa.db error code = 1
2015-11-19 03:15:41.578: [  CRSRES][1628584256]0Start of `ora.jingfa.db` on member `jingfa1` failed.
2015-11-19 03:15:41.593: [  CRSEVT][1607604544]0Post recovery done evmd event for: jingfa2
2015-11-19 03:15:41.595: [  CRSEVT][1607604544]0Processing RecoveryDone




同时alert出现信息
Thu Nov 19 03:15:27 2015
Starting ORACLE instance (normal)
LICENSE_MAX_SESSION = 0
LICENSE_SESSIONS_WARNING = 0
Interface type 1 eth1 10.10.10.0 configured from OCR for use as a cluster interconnect
Interface type 1 eth0 92.168.1.0 configured from OCR for use as  a public interface
Picked latch-free SCN scheme 1
Using LOG_ARCHIVE_DEST_1 parameter default value as /u01/app/oracle/product/10.2.0/db_1/dbs/arch
Autotune of undo retention is turned on. 
LICENSE_MAX_USERS = 0
SYS auditing is disabled
ksdpec: called for event 13740 prior to event group initialization
Starting up ORACLE RDBMS Version: 10.2.0.1.0.
System parameters with non-default values:
  processes                = 150
  event                    = 10708 trace name context forever,level 10
  __shared_pool_size       = 339738624
  __large_pool_size        = 4194304
  __java_pool_size         = 4194304
  __streams_pool_size      = 4194304
  spfile                   = +DATA/jingfa/spfilejingfa.ora
  _ksmg_lock_check_interval= 2
  _lm_dd_interval          = 120
  sga_target               = 599785472
  control_files            = +DATA/jingfa/control01.ctl, +DATA/jingfa/control02.ctl, +DATA/jingfa/control03.ctl
  db_block_size            = 8192
  __db_cache_size          = 243269632
  compatible               = 10.2.0.1.0
  db_file_multiblock_read_count= 16
  cluster_database         = TRUE
  cluster_database_instances= 2
  thread                   = 1
  instance_number          = 1
  undo_management          = AUTO
  undo_tablespace          = UNDOTBS1
  _kgl_time_to_wait_for_locks= 25
  remote_login_passwordfile= EXCLUSIVE
  db_domain                = 
  local_listener           = (address=(protocol=tcp)(host=92.168.1.21)(port=1521))
  remote_listener          = LISTENERS_JINGFA
  job_queue_processes      = 10
  background_dump_dest     = /u01/app/oracle/admin/jingfa/bdump
  user_dump_dest           = /u01/app/oracle/admin/jingfa/udump
  core_dump_dest           = /u01/app/oracle/admin/jingfa/cdump
  audit_file_dest          = /u01/app/oracle/admin/jingfa/adump
  db_name                  = jingfa
  open_cursors             = 300
  pga_aggregate_target     = 199229440
Cluster communication is configured to use the following interface(s) for this instance
  10.10.10.8
Thu Nov 19 03:15:28 2015
cluster interconnect IPC version:Oracle UDP/IP
IPC Vendor 1 proto 2
PMON started with pid=2, OS id=2618
DIAG started with pid=3, OS id=2625
PSP0 started with pid=4, OS id=2630
LMON started with pid=5, OS id=2632
LMD0 started with pid=6, OS id=2659
LMS0 started with pid=7, OS id=2661
MMAN started with pid=8, OS id=2665
DBW0 started with pid=9, OS id=2667
LGWR started with pid=10, OS id=2669
CKPT started with pid=11, OS id=2671
SMON started with pid=12, OS id=2673
RECO started with pid=13, OS id=2675
CJQ0 started with pid=14, OS id=2677
MMON started with pid=15, OS id=2679
MMNL started with pid=16, OS id=2681
Thu Nov 19 03:15:28 2015
lmon registered with NM - instance id 1 (internal mem no 0)
Thu Nov 19 03:15:28 2015
Reconfiguration started (old inc 0, new inc 2)
pseudo shared rm latch used 
List of nodes:
 0
 Global Resource Directory frozen
* allocate domain 0, invalid = TRUE 
 Communication channels reestablished
 Master broadcasted resource hash value bitmaps
 Non-local Process blocks cleaned out
Thu Nov 19 03:15:29 2015
 LMS 0: 0 GCS shadows cancelled, 0 closed
 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
Thu Nov 19 03:15:29 2015
 LMS 0: 0 GCS shadows traversed, 0 replayed
Thu Nov 19 03:15:29 2015
 Submitted all GCS remote-cache requests
 Post SMON to start 1st pass IR
 Fix write in gcs resources
Reconfiguration complete
LCK0 started with pid=17, OS id=2683
Thu Nov 19 03:15:29 2015
ALTER DATABASE   MOUNT
Thu Nov 19 03:15:29 2015
This instance was first to mount
Thu Nov 19 03:15:29 2015
Starting background process ASMB
ASMB started with pid=19, OS id=2713
Starting background process RBAL
RBAL started with pid=20, OS id=2717
Thu Nov 19 03:15:32 2015
SUCCESS: diskgroup DATA was mounted
Thu Nov 19 03:15:37 2015
Errors in file /u01/app/oracle/admin/jingfa/udump/jingfa1_ora_2710.trc:
ORA-00600: internal error code, arguments: [kccsbck_first], [2], [623757018], [], [], [], [], []
SUCCESS: diskgroup DATA was dismounted
Thu Nov 19 03:15:38 2015
ORA-600 signalled during: ALTER DATABASE   MOUNT...
Thu Nov 19 03:15:38 2015
Trace dumping is performing id=[cdmp_20151119031538]
Thu Nov 19 03:15:40 2015
Shutting down instance (abort)
License high water mark = 1
Instance terminated by USER, pid = 2991






同时查看节点2 的alert,crsd,cssd log


先是cssd log有信息：


然后是alert 
Thu Nov 19 04:06:51 2015
ospid 4607: network interface with IP address 10.10.10.9 shows failure
requested interface 10.10.10.9 is not UP. Check output from ifconfig command




过一会儿alert
Thu Nov 19 04:07:54 2015
Error: KGXGN aborts the instance (6)
Thu Nov 19 04:07:55 2015
Errors in file /u01/app/oracle/admin/jingfa/bdump/jingfa2_lmon_4605.trc:
ORA-29702: error occurred in Cluster Group Service operation
LMON: terminating instance due to error 29702
Thu Nov 19 04:07:55 2015
Errors in file /u01/app/oracle/admin/jingfa/bdump/jingfa2_lmd0_4607.trc:
ORA-29702: error occurred in Cluster Group Service operation