我们检查了在故障期间的集群crsd日志，发现在服务停止之前，即2014-10-31 22:23:10.574时，一节点的ora.net1.network服务停止，ora.net1.network服务是当前节点负责所有的网络通信的服务：
|
2014-10-31 22:23:10.574: [ AGFW][10025] {0:2:13826} Agfw Proxy Server received the message: RESOURCE_STATUS[Proxy] ID 20481:285859857 2014-10-31 22:23:10.574: [ AGFW][10025] {0:2:13826} Received state change for ora.net1.network tydb1 1 [old state = ONLINE, new state = UNKNOWN] 2014-10-31 22:23:10.574: [ AGFW][10025] {0:2:13826} Received state LABEL change for ora.net1.network tydb1 1 [old label = , new label = CHECK TIMED OUT] 2014-10-31 22:23:10.575: [ AGFW][10025] {0:2:13826} Agfw Proxy Server sending message to PE, Contents = [MIDTo:2|OpID:3|FromA:{Invalid|Node:0|Process:0|Type:0}|ToA:{Invalid|Node:-1|Process:-1|Type:-1}|MIDFrom:0|Type:4|Pri2|Id:7676882:Ver:2] 2014-10-31 22:23:10.575: [ AGFW][10025] {0:2:13826} Agfw Proxy Server replying to the message: RESOURCE_STATUS[Proxy] ID 20481:285859857 2014-10-31 22:23:10.575: [ CRSPE][11310] {0:2:13826} State change received from tydb1 for ora.net1.network tydb1 1 2014-10-31 22:23:10.575: [ CRSPE][11310] {0:2:13826} Processing PE command id=680382. Description: [Resource State Change (ora.net1.network tydb1 1) : 117d9f4b0] 2014-10-31 22:23:10.576: [ CRSPE][11310] {0:2:13826} RI [ora.net1.network tydb1 1] new external state [INTERMEDIATE] old value: [ONLINE] on tydb1 label = [CHECK TIMED OUT] 2014-10-31 22:23:10.576: [ CRSPE][11310] {0:2:13826} Set State Details to [CHECK TIMED OUT] from [ ] for [ora.net1.network tydb1 1] |
在以上日志中，我们可以很清楚的看到ora.net1.network资源停止。而在11gR2RAC中Listener资源依赖于VIP， 而VIP资源依赖于ora.net1.network；这就造成了当public network短时不可用(或曰network hiccup)时会造成ora.net1.network资源OFFLINE，这就将造成该节点上VIP资源的FAILOVER和LISTENER的OFFLINE。
且由于在11.2上ora.net1.network资源的默认CHECK_INTERVAL=1，
|
[root@s1-11g ~]# su - grid [grid@s1-11g ~]$ crsctl status resource ora.net1.network -f NAME=ora.net1.network TYPE=ora.network.type STATE=ONLINE TARGET=ONLINE ACL=owner:root:rwx,pgrp:root:r-x,other::r--,group:oinstall:r-x,user:grid:r-x ACTION_FAILURE_TEMPLATE= ACTION_SCRIPT= AGENT_FILENAME=%CRS_HOME%/bin/orarootagent%CRS_EXE_SUFFIX% ALIAS_NAME= AUTO_START=restore CHECK_INTERVAL=1
|
即每秒都会对该NETWORK资源进行监控，所以NETWORK资源变得十分敏感，不管是由于硬件网络亦或者较高的主机负载造成短时的Public Network不可用，都可能导致VIP和LISTENER由于NETWORK依赖资源OFFLINE而受到影响。
所以在后续的日志中，我们发现后续的scan IP漂移到二节点，而Vip资源及listener资源都停止，由于是瞬间的网络资源不稳定，所以后续的vip资源及cvu资源马上自动起来了，而一节点的listener资源在自动启动一次不成功后，便没有在启动，这也是导致之前在10月31号，我们只看到listener资源及cvu资源没有启动的原因。
|
2014-10-31 22:23:10.612: [ AGFW][10025] {0:2:13826} Agfw Proxy Server received the message: RESOURCE_STOP[ora.LISTENER.lsnr tydb1 1] ID 4099:7676884 2014-10-31 22:23:10.612: [ CRSPE][11310] {0:2:13826} CRS-2673: Attempting to stop ‘ora.LISTENER.lsnr‘ on ‘tydb1‘
2014-10-31 22:23:10.612: [ AGFW][10025] {0:2:13826} Agfw Proxy Server forwarding the message: RESOURCE_STOP[ora.LISTENER.lsnr tydb1 1] ID 4099:7676884 to the agent /grid/database/11.2.0/bin/oraagent_grid 2014-10-31 22:23:10.615: [ CRSPE][11310] {0:2:13826} ICE has queued an operation. Details: Operation [STOP of [ora.tydb1.vip 1 1] on [tydb1] : 117e450d0] cannot run cause it needs W lock for: WO for Placement Path RI:[ora.tydb1.vip 1 1] server [] target states [OFFLINE ], locked by op [START of [ora.tydb1.vip 1 1] on [tydb2] : local=0, unplanned=1117e485f0]. Owner: CRS-2683: It is locked by ‘SYSTEM‘ for command ‘Unplanned Resource State Change : ora.net1.network‘
2014-10-31 22:23:10.617: [ CRSPE][11310] {0:2:13826} RI [ora.LISTENER_SCAN1.lsnr 1 1] new internal state: [STOPPING] old value: [STABLE] 2014-10-31 22:23:10.618: [ CRSPE][11310] {0:2:13826} Sending message to agfw: id = 7676886 2014-10-31 22:23:10.618: [ AGFW][10025] {0:2:13826} Agfw Proxy Server received the message: RESOURCE_STOP[ora.LISTENER_SCAN1.lsnr 1 1] ID 4099:7676886 2014-10-31 22:23:10.618: [ CRSPE][11310] {0:2:13826} CRS-2673: Attempting to stop ‘ora.LISTENER_SCAN1.lsnr‘ on ‘tydb1‘
2014-10-31 22:23:10.618: [ AGFW][10025] {0:2:13826} Agfw Proxy Server forwarding the message: RESOURCE_STOP[ora.LISTENER_SCAN1.lsnr 1 1] ID 4099:7676886 to the agent /grid/database/11.2.0/bin/oraagent_grid 2014-10-31 22:23:10.622: [ CRSPE][11310] {0:2:13826} RI [ora.cvu 1 1] new internal state: [STOPPING] old value: [STABLE] 2014-10-31 22:23:10.623: [ CRSPE][11310] {0:2:13826} Sending message to agfw: id = 7676888 2014-10-31 22:23:10.623: [ AGFW][10025] {0:2:13826} Agfw Proxy Server received the message: RESOURCE_STOP[ora.cvu 1 1] ID 4099:7676888 2014-10-31 22:23:10.623: [ CRSPE][11310] {0:2:13826} CRS-2673: Attempting to stop ‘ora.cvu‘ on ‘tydb1‘ |
从以上的简单日志中，我们可以得到一个基本的结论，2014年10月31号的故障并不是单一的listener资源停止，而是由于network资源停止导致了后续的vip，scan listener cvu等依赖于网络的资源停止，而由于后续的网络资源没有及时的恢复，导致listener没有自动的启动。在11gR2 RAC中由于ora.net1.network资源的默认CHECK_INTERVAL=1，即每秒都会对该NETWORK资源进行监控，所以NETWORK资源变得十分敏感，不管是由于硬件网络亦或者较高的主机负载造成短时的Public Network不可用，都可能导致VIP和LISTENER由于NETWORK依赖资源OFFLINE而受到影响。而我们并没有在操作系统日志中检查出相关的errpt日志，所以我们可以大致排除由于硬件原因导致的网络不稳定。但是我们并不能排除当时一节点的网络是否存在异常，由于相关的日志缺乏，我们并不能非常肯定导致ora.net1.network资源停止的原因。
故障解决方案
在这里，我们通过分析listener服务停止的原因后，我们可以从两方面入手来排查或者解决这个问题：
1. 通过追加对listenert vip等资源的更详细debug日志，来观察是否能进一步捕获服务停止的原因。具体的跟踪命令如下：
|
开启节点一的vip跟踪
相应的跟踪日志为
|
包括listener等资源都可以通过以上的命令去跟踪，规避由于network资源敏感导致的vip或者listener服务停止的依赖性：
|
解决由于Network资源过于敏感导致的不必要的vip和listener的方法： 打补丁12378938 该补丁被包含在” 11.2.0.2 GI PSU4, 11.2.0.3 GI PSU3, 11.2.0.3 Windows Patch 7, 11.2.0.4 and above”;并修改vip资源的依赖属性： crsctl modify res ora.LISTENER.lsnr -attr "STOP_DEPENDENCIES=hard(intermediate:ora.net1.network)" crsctl modify res ora.s2-11g.vip -attr "STOP_DEPENDENCIES=hard(intermediate:ora.net1.network)" crsctl modify res ora.scan1.vip -attr "STOP_DEPENDENCIES=hard(intermediate:ora.net1.network)" |
由于数据系统版本及补丁均高于该选项，建议可以直接调整。
------------------------------------------------------------------------------------
<版权所有，文章允许转载，但必须以链接方式注明源地址，否则追究法律责任!>
原博客地址：http://blog.itpub.net/23732248/
原作者：应以峰 (frank-ying)
-------------------------------------------------------------------------------------
原文：http://blog.itpub.net/23732248/viewspace-1449356/