故障描述
某客戶資料庫在2014年10月31號22點23分接到值班人員電話，告知RAC一節點監聽及cvu服務down，由於無法遠端，電話並QQ聯絡首先手工啟動一節點監聽及cvu服務，後續問題在2014年10月3號透過後臺日志詳細檢查服務停止原因。

故障分析

我們檢查了在故障期間的叢集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跟蹤
crsctl set log res ora.rac1.vip=0
crsctl set log res ora.rac1.vip=2
level 0 = turn off
level 2 = default
level 3 = verbose
level 4 = super verbose

相應的跟蹤日誌為
/log//agent/crsd/orarootagent_root/orarootagent_root.log

包括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)
-------------------------------------------------------------------------------------

一次RAC監聽停止分析

相關文章