CSSD terminated from clssnmvDiskPingMonitorThread without disk timeout countdown

One node's cluster suddenly terminated.
Below is the message in cluster's alert.log：

2012-09-11 11:41:30.328
[ctssd(22428)]CRS-2409:The clock on host node8 is not synchronous with the mean cluster time. No action has been taken as the Cluster Time Synchroniza
tion Service is running in observer mode.
2012-09-11 12:30:03.122
[cssd(21061)]CRS-1606:The number of voting files available, 0, is less than the minimum number of voting files required, 1, resulting in CSSD termination to
ensure data integrity; details at (:CSSNM00018:) in /prod/grid/11.2.0/grid/log/node8/cssd/ocssd.log
2012-09-11 12:30:03.123
[cssd(21061)]CRS-1656:The CSS daemon is terminating due to a fatal error; Details at (:CSSSC00012:) in /prod/grid/11.2.0/grid/log/node8/cssd/ocssd.log 
2012-09-11 12:30:03.233 [cssd(21061)]CRS-1652:Starting clean up of CRSD resources.

Let‘s check ocssd.log：

2012-09-11 12:30:02.543: [    CSSD][1113450816]clssnmSendingThread: sending status msg to all nodes
2012-09-11 12:30:02.543: [    CSSD][1113450816]clssnmSendingThread: sent 5 status msgs to all nodes
2012-09-11 12:30:03.122: [    CSSD][1082489152](:CSSNM00018:)clssnmvDiskCheck: Aborting, 0 of 1 configured voting disks available, need 1
2012-09-11 12:30:03.123: [    CSSD][1082489152]###################################
2012-09-11 12:30:03.123: [    CSSD][1082489152]clssscExit: CSSD aborting from thread clssnmvDiskPingMonitorThread
2012-09-11 12:30:03.123: [    CSSD][1082489152]###################################
2012-09-11 12:30:03.123: [    CSSD][1082489152](:CSSSC00012:)clssscExit: A fatal error occurred and the CSS daemon is terminating abnormally

So it looks like an IO issue to VOTEDISK.
But after checking we didn't find any abnormal or error message from neither OS level nor storage side.

Then i reviewed the ocssd.log, and with surprise i found there is no long-disk timeout countdown in log.

We know if ocssd failed to reach Votedisk, then it will start to count 200s. Only if after 200s the votedisk still unavailable, then occsd will terminated itself.
The countdown information should be like:
clssscMonitorThreads clssnmvDiskPingThread not scheduled for 16020 msecs

But in our case, there is not such countdown, the occssd just terminated from clssnmvDiskPingMonitorThread all of a sudden.
It should be a bug instead of VOTEDISK IO issue. I will raise an SR with oracle support for further checking.
More......

ctssd will prevent cluster starting when exist an significant time gap

ctssd (Oracle Cluster Time Synchronization Services) is a good new feature which introduced in 11gR2.  It is used for sync the time gap among nodes, replacing old NTP method.


By default the ctssd run in observe mode, which means, it will detect time gap, but won't make any action when found a gap. In this mode you can see below information in alert$hostname.log:
[ctssd(13443)]CRS-2409:The clock on host node2 is not synchronous with the mean cluster time. No action has been taken as the Cluster Time Synchronization Service is running in observer mode.

To enable the ctssd service, you need to disable NTP and all other vendor's time service, then ctssd will become active automatic:
2012-05-23 20:36:55.586
[ctssd(4781)]CRS-2408:The clock on host node2 has been updated by the Cluster Time Synchronization Service to be synchronous with the mean cluster time.

It looks good, but ctssd still have many defects.
For example, if the time gap among nodes are very big, then the ctssd will be failed to sync at once.
To instead, the ctssd will turn a minor period of time every second, and that may take days to sync your nodes when the gap is big.

What is worse, there are still many bugs for ctssd. For example, i found a repeatable bug is that if ctssd is enabled in ACTIVE mode, and the time gap is big, then after first node come up, rest nodes' cluster will fail to startup.

That ctssd first check and report that it can’t fix the time sync, and then terminated.
----alert$hostname.log:
2012-05-25 00:09:40.690
[ctssd(24841)]CRS-2401:The Cluster Time Synchronization Service started on host node2.
2012-05-25 00:09:40.690
[ctssd(24841)]CRS-2402:The Cluster Time Synchronization Service aborted on host node2. Details at  in /prod/grid/app/11.2.0/grid/log/node2/ctssd/octssd.log.

----octssd.log:

2012-05-25 00:09:40.431: [    CTSS][2988911504]ctssslave_msh: Forming connection with CTSS master node [1]

2012-05-25 00:09:40.432: [    CTSS][2988911504]ctssslave_msh: Successfully connected to master [1]

2012-05-25 00:09:40.433: [    CTSS][2988911504]ctssslave_swm: The magnitude [86413354867 usec] of the offset [-86413354867 usec] is larger than [86400000000 usec] sec which is the CTSS limit.

2012-05-25 00:09:40.433: [    CTSS][2988911504]ctsselect_mmg9_3: Failed in clsctsselect_select_mode [12]: Time offset is too much to be corrected

2012-05-25 00:09:40.690: [    CTSS][2978421648]ctss_checkcb: clsdm requested check alive. Returns [40000050]

2012-05-25 00:09:40.690: [    CTSS][3046659776]ctss_init: Spawn completed. Waiting for threads to join

2012-05-25 00:09:40.690: [    CTSS][2988911504]ctsselect_mmg: CTSS daemon exiting [12].

2012-05-25 00:09:40.690: [    CTSS][2988911504]CTSS daemon aborting

And then CRSD will also fail to startup, but the error it reports is very misleading:

2012-05-25 00:09:44.235
[ohasd(24419)]CRS-2765:Resource 'ora.crsd' has failed on server 'node2'.
2012-05-25 00:09:44.387
[crsd(24930)]CRS-1013:The OCR location in an ASM disk group is inaccessible. Details in /prod/grid/app/11.2.0/grid/log/node2/crsd/crsd.log.

The solution is to either sync the time gap, or disable ctssd by enable vendor's time service.

And then re-bring up rest nodes can success.

More......