β

The Oracle Listener ofen restart and ora.net1.net

ANBOB 275 阅读

上个月有套库的listener总是自动stop, 因为是crs的资源又被agent重新拉起,前几次的监听故障中都提到过listener依赖于network资源, 以前也处理过网络打嗝可能会导致监听频繁重启的案例,本次参照该案例修改弱依赖的方式无法避免该问题,从操作系统日志未发现network的物理错误信息, 同时也是因为network 资源频繁失败导致, 后来分析又是一个bug, 在这里简单的记录下。

环境 oracle 11.2.0.3 2nodes RAC on hpux ia 11.31

# GI Alert LOG

-10-14 17:13:02.364
[crsd(22934)]CRS-2765:Resource 'ora.net1.network' has failed on server 'anbob1'.
-10-14 17:13:02.366
[crsd(22934)]CRS-2771:Maximum restart attempts reached for resource 'ora.net1.network'; will not restart.
-10-14 17:13:02.993
[/oracle/app/11.2.0.3/grid/bin/oraagent.bin(22990)]CRS-5016:Process "/oracle/app/11.2.0.3/grid/bin/lsnrctl" spawned by agent "/oracle/app/11.2.0.3/grid/bin/oraagent.bin" for action "check" failed: details at "(:CLSN00010:)" in "/oracle/app/11.2.0.3/grid/log/anbob1/agent/crsd/oraagent_grid/oraagent_grid.log"
-10-14 17:13:03.038
[/oracle/app/11.2.0.3/grid/bin/oraagent.bin(22990)]CRS-5016:Process "/oracle/app/11.2.0.3/grid/bin/lsnrctl" spawned by agent "/oracle/app/11.2.0.3/grid/bin/oraagent.bin" for action "check" failed: details at "(:CLSN00010:)" in "/oracle/app/11.2.0.3/grid/log/anbob1/agent/crsd/oraagent_grid/oraagent_grid.log"
-10-14 17:13:03.209
[/oracle/app/11.2.0.3/grid/bin/oraagent.bin(22990)]CRS-5016:Process "/oracle/app/11.2.0.3/grid/bin/lsnrctl" spawned by agent "/oracle/app/11.2.0.3/grid/bin/oraagent.bin" for action "check" failed: details at "(:CLSN00010:)" in "/oracle/app/11.2.0.3/grid/log/anbob1/agent/crsd/oraagent_grid/oraagent_grid.log"
-10-14 17:13:03.366
[/oracle/app/11.2.0.3/grid/bin/oraagent.bin(22990)]CRS-5016:Process "/oracle/app/11.2.0.3/grid/opmn/bin/onsctli" spawned by agent "/oracle/app/11.2.0.3/grid/bin/oraagent.bin" for action "check" failed: details at "(:CLSN00010:)" in "/oracle/app/11.2.0.3/grid/log/anbob1/agent/crsd/oraagent_grid/oraagent_grid.log"
-10-15 03:01:02.053
[crsd(22934)]CRS-2765:Resource 'ora.net1.network' has failed on server 'anbob1'.
-10-15 03:01:02.055
[crsd(22934)]CRS-2771:Maximum restart attempts reached for resource 'ora.net1.network'; will not restart.
-10-15 03:01:02.692
[/oracle/app/11.2.0.3/grid/bin/oraagent.bin(22990)]CRS-5016:Process "/oracle/app/11.2.0.3/grid/bin/lsnrctl" spawned by agent "/oracle/app/11.2.0.3/grid/bin/oraagent.bin" for action "check" failed: details at "(:CLSN00010:)" in "/oracle/app/11.2.0.3/grid/log/anbob1/agent/crsd/oraagent_grid/oraagent_grid.log"
-10-15 03:01:02.698
[/oracle/app/11.2.0.3/grid/bin/oraagent.bin(22990)]CRS-5016:Process "/oracle/app/11.2.0.3/grid/bin/lsnrctl" spawned by agent "/oracle/app/11.2.0.3/grid/bin/oraagent.bin" for action "check" failed: details at "(:CLSN00010:)" in "/oracle/app/11.2.0.3/grid/log/anbob1/agent/crsd/oraagent_grid/oraagent_grid.log"
-10-15 03:01:03.077
[/oracle/app/11.2.0.3/grid/bin/oraagent.bin(22990)]CRS-5016:Process "/oracle/app/11.2.0.3/grid/opmn/bin/onsctli" spawned by agent "/oracle/app/11.2.0.3/grid/bin/oraagent.bin" for action "check" failed: details at "(:CLSN00010:)" in "/oracle/app/11.2.0.3/grid/log/anbob1/agent/crsd/oraagent_grid/oraagent_grid.log"
-10-15 03:29:03.185
[crsd(22934)]CRS-2765:Resource 'ora.net1.network' has failed on server 'anbob1'.
-10-15 03:29:03.186
[crsd(22934)]CRS-2771:Maximum restart attempts reached for resource 'ora.net1.network'; will not restart.
-10-15 03:29:03.824
[/oracle/app/11.2.0.3/grid/bin/oraagent.bin(22990)]CRS-5016:Process "/oracle/app/11.2.0.3/grid/bin/lsnrctl" spawned by agent "/oracle/app/11.2.0.3/grid/bin/oraagent.bin" for action "check" failed: details at "(:CLSN00010:)" in "/oracle/app/11.2.0.3/grid/log/anbob1/agent/crsd/oraagent_grid/oraagent_grid.log"
-10-15 03:29:03.872
[/oracle/app/11.2.0.3/grid/bin/oraagent.bin(22990)]CRS-5016:Process "/oracle/app/11.2.0.3/grid/bin/lsnrctl" spawned by agent "/oracle/app/11.2.0.3/grid/bin/oraagent.bin" for action "check" failed: details at "(:CLSN00010:)" in "/oracle/app/11.2.0.3/grid/log/anbob1/agent/crsd/oraagent_grid/oraagent_grid.log"
-10-15 03:29:04.039
[/oracle/app/11.2.0.3/grid/bin/oraagent.bin(22990)]CRS-5016:Process "/oracle/app/11.2.0.3/grid/bin/lsnrctl" spawned by agent "/oracle/app/11.2.0.3/grid/bin/oraagent.bin" for action "check" failed: details at "(:CLSN00010:)" in "/oracle/app/11.2.0.3/grid/log/anbob1/agent/crsd/oraagent_grid/oraagent_grid.log"
-10-15 03:29:04.190
[/oracle/app/11.2.0.3/grid/bin/oraagent.bin(22990)]CRS-5016:Process "/oracle/app/11.2.0.3/grid/opmn/bin/onsctli" spawned by agent "/oracle/app/11.2.0.3/grid/bin/oraagent.bin" for action "check" failed: details at "(:CLSN00010:)" in "/oracle/app/11.2.0.3/grid/log/anbob1/agent/crsd/oraagent_grid/oraagent_grid.log"
-10-15 07:35:02.711
[crsd(22934)]CRS-2765:Resource 'ora.net1.network' has failed on server 'anbob2'.
-10-15 10:03:02.532
[crsd(22934)]CRS-2765:Resource 'ora.net1.network' has failed on server 'anbob2'.
-10-15 10:06:02.082
[crsd(22934)]CRS-2765:Resource 'ora.net1.network' has failed on server 'anbob1'.
-10-15 10:07:07.791
[/oracle/app/11.2.0.3/grid/bin/orarootagent.bin(22985)]CRS-5818:Aborted command 'check' for resource 'ora.net1.network'. Details at (:CRSAGF00113:) {0:1:41523} in /oracle/app/11.2.0.3/grid/log/anbob1/agent/crsd/orarootagent_root/orarootagent_root.log.

Note:
看到最近两天多次出现’ora.net1.network’ 资源的监测失败。

# crsd log

-10-15 07:35:02.710: [   CRSPE][46] {0:5:27202} State change received from anbob2 for ora.net1.network anbob2 1
-10-15 07:35:02.710: [   CRSPE][46] {0:5:27202} Processing PE command id=2896747. Description: [Resource State Change (ora.net1.network anbob2 1) : 60000000037dbba0]
-10-15 07:35:02.710: [   CRSPE][46] {0:5:27202} RI [ora.net1.network anbob2 1] new external state [OFFLINE] old value: [ONLINE] on anbob2 label = [] 
-10-15 07:35:02.711: [   CRSPE][46] {0:5:27202} Resource Resource Instance ID[ora.net1.network anbob2 1]. Values: 
STATE=OFFLINE
TARGET=ONLINE
LAST_SERVER=anbob2
CURRENT_RCOUNT=5
LAST_RESTART=1444753923
FAILURE_COUNT=0
FAILURE_HISTORY=
STATE_DETAILS=
INCARNATION=159
STATE_CHANGE_VERS=115
LAST_FAULT=1444795202
LAST_STATE_CHANGE=1444865702
INTERNAL_STATE=0
DEGREE_ID=1
ID=ora.net1.network anbob2 1
Lock Info:
Write Locks:none
ReadLocks:|STATE INITED||INITIAL CHECK DONE| has failed!
-10-15 07:35:02.712: [  CRSRPT][47] {0:5:27202} Published to EVM CRS_RESOURCE_STATE_CHANGE for ora.net1.network
-10-15 07:35:02.713: [   CRSPE][46] {0:5:27202} Processing unplanned state change for [ora.net1.network anbob2 1]
-10-15 07:35:02.713: [   CRSPE][46] {0:5:27202} ora.net1.network anbob2 1: uptime exceeds uptime threshold , resetting restart count
-10-15 07:35:02.714: [   CRSPE][46] {0:5:27202} Scheduled local recovery for [ora.net1.network anbob2 1]
-10-15 07:35:02.715: [   CRSPE][46] {0:5:27202} Op 6000000002665a10 has 3 WOs
-10-15 07:35:02.721: [   CRSPE][46] {0:5:27202} RI [ora.net1.network anbob2 1] new internal state: [STARTING] old value: [STABLE]
-10-15 07:35:02.721: [   CRSPE][46] {0:5:27202} Sending message to agfw: id = 15463328
-10-15 07:35:02.722: [   CRSPE][46] {0:5:27202} CRS-2672: Attempting to start 'ora.net1.network' on 'anbob2'
-10-15 07:35:03.078: [   CRSPE][46] {2:46001:13048} Processing PE command id=2896748. Description: [Stat Resource : 6000000001a86210]
-10-15 07:35:03.079: [   CRSPE][46] {2:46001:13048} Expression Filter : ((NAME == ora.scan1.vip) AND (LAST_SERVER == anbob2))
-10-15 07:35:03.397: [   CRSPE][46] {0:5:27202} Received reply to action [Start] message ID: 15463328
-10-15 07:35:03.422: [   CRSPE][46] {0:5:27202} Received reply to action [Start] message ID: 15463328
-10-15 07:35:03.422: [   CRSPE][46] {0:5:27202} RI [ora.net1.network anbob2 1] new internal state: [STABLE] old value: [STARTING]
-10-15 07:35:03.422: [   CRSPE][46] {0:5:27202} RI [ora.net1.network anbob2 1] new external state [ONLINE] old value: [OFFLINE] on anbob2 label = [] 
-10-15 07:35:03.423: [   CRSPE][46] {0:5:27202} CRS-2676: Start of 'ora.net1.network' on 'anbob2' succeeded

# oraagent_grid log

-10-15 03:29:03.417: [    AGFW][10] {0:1:40647} Agent received the message: RESOURCE_STOP[ora.ons anbob1 1] ID 4099:15441558
-10-15 03:29:03.417: [    AGFW][10] {0:1:40647} Preparing STOP command for: ora.ons anbob1 1
-10-15 03:29:03.417: [    AGFW][10] {0:1:40647} ora.ons anbob1 1 state changed from: ONLINE to: STOPPING
-10-15 03:29:03.419: [    AGFW][10] {0:1:40647} Agent received the message: RESOURCE_STOP[ora.LISTENER.lsnr anbob1 1] ID 4099:15441560
-10-15 03:29:03.419: [    AGFW][10] {0:1:40647} Preparing STOP command for: ora.LISTENER.lsnr anbob1 1
-10-15 03:29:03.419: [    AGFW][10] {0:1:40647} ora.LISTENER.lsnr anbob1 1 state changed from: ONLINE to: STOPPING
-10-15 03:29:03.419: [ora.ons][291943] {0:1:40647} [stop] (:CLSN00108:) clsn_agent::stop {
-10-15 03:29:03.419: [ora.ons][291943] {0:1:40647} [stop] OnsAgent::stop {
-10-15 03:29:03.420: [ora.LISTENER.lsnr][290918] {0:1:40647} [stop] (:CLSN00108:) clsn_agent::stop {
-10-15 03:29:03.421: [ora.LISTENER.lsnr][290918] {0:1:40647} [stop] LsnrAgent::stop {
-10-15 03:29:03.421: [ USRTHRD][290918] {0:1:40647} Thread:RegEndpointThread:LISTENER stop {
-10-15 03:29:03.421: [    AGFW][10] {0:1:40647} Agent received the message: RESOURCE_STOP[ora.LISTENER_TUX.lsnr anbob1 1] ID 4099:15441562
-10-15 03:29:03.421: [    AGFW][10] {0:1:40647} Preparing STOP command for: ora.LISTENER_TUX.lsnr anbob1 1
-10-15 03:29:03.421: [    AGFW][10] {0:1:40647} ora.LISTENER_TUX.lsnr anbob1 1 state changed from: ONLINE to: STOPPING
-10-15 03:29:03.423: [ora.LISTENER_TUX.lsnr][283884] {0:1:40647} [stop] (:CLSN00108:) clsn_agent::stop {
-10-15 03:29:03.424: [ora.LISTENER_TUX.lsnr][283884] {0:1:40647} [stop] LsnrAgent::stop {
-10-15 03:29:03.424: [ USRTHRD][283884] {0:1:40647} Thread:RegEndpointThread:LISTENER_TUX stop {
-10-15 03:29:03.428: [ USRTHRD][291929] {0:1:40647} Thread:RegEndpointThread:LISTENER isRunning is reset to false here
-10-15 03:29:03.428: [ USRTHRD][290918] {0:1:40647} Thread:RegEndpointThread:LISTENER stop }
-10-15 03:29:03.429: [ora.LISTENER.lsnr][290918] {0:1:40647} [stop] lsnrctl stop LISTENER
-10-15 03:29:03.429: [ora.LISTENER.lsnr][290918] {0:1:40647} [stop] getOracleHomeAttrib: oracle_home = /oracle/app/11.2.0.3/grid
-10-15 03:29:03.429: [ora.LISTENER.lsnr][290918] {0:1:40647} [stop] getOracleHomeAttrib: oracle_home = /oracle/app/11.2.0.3/grid
-10-15 03:29:03.429: [ora.LISTENER.lsnr][290918] {0:1:40647} [stop] Utils::getCrsHome crsHome /oracle/app/11.2.0.3/grid
-10-15 03:29:03.429: [ora.LISTENER.lsnr][290918] {0:1:40647} [stop] Utils::execCmd 1 USR_ORA_ENV:ORACLE_BASE=/oracle/app/grid oracleHome:/oracle/app/11.2.0.3/grid CrsHome:/oracle/app/11.2.0.3/grid
-10-15 03:29:03.430: [ora.LISTENER.lsnr][290918] {0:1:40647} [stop] Utils::getCrsHome crsHome /oracle/app/11.2.0.3/grid
-10-15 03:29:03.430: [ora.LISTENER.lsnr][290918] {0:1:40647} [stop] Utils::getCrsHome crsHome /oracle/app/11.2.0.3/grid
-10-15 03:29:03.430: [ora.LISTENER.lsnr][290918] {0:1:40647} [stop] Adding Environment Variables ORACLE_HOME=/oracle/app/11.2.0.3/grid
-10-15 03:29:03.430: [ora.LISTENER.lsnr][290918] {0:1:40647} [stop] Adding Environment Variables TNS_ADMIN=/oracle/app/11.2.0.3/grid/network/admin/
-10-15 03:29:03.430: [ora.LISTENER.lsnr][290918] {0:1:40647} [stop] Adding Environment variable from USR_ORA_ENV ORACLE_BASE=/oracle/app/grid
-10-15 03:29:03.430: [ora.LISTENER.lsnr][290918] {0:1:40647} [stop] Utils:execCmd action = 2 flags = 38 ohome = (null) cmdname = lsnrctl. 
-10-15 03:29:03.430: [ora.LISTENER.lsnr][290918] {0:1:40647} [stop] getOracleHomeAttrib: oracle_home = /oracle/app/11.2.0.3/grid
-10-15 03:29:03.480: [ USRTHRD][291931] {0:1:40647} Thread:RegEndpointThread:LISTENER_TUX isRunning is reset to false here
-10-15 03:29:03.483: [ USRTHRD][283884] {0:1:40647} Thread:RegEndpointThread:LISTENER_TUX stop }
-10-15 03:29:03.484: [ora.LISTENER_TUX.lsnr][283884] {0:1:40647} [stop] lsnrctl stop LISTENER_TUX

# orarootagent_root.log

-10-15 10:06:00.953: [ default][239542]ICMP Ping from 133.96.43.51 to 133.96.43.254
-10-15 10:06:02.068: [ora.net1.network][239542] {0:1:37724} [check] NetworkAgent::checkLink returned false
-10-15 10:06:02.070: [    AGFW][10] {0:1:37724} ora.net1.network anbob1 1 state changed from: ONLINE to: OFFLINE
-10-15 10:06:02.070: [    AGFW][10] {0:1:37724} Switching online monitor to offline one
-10-15 10:06:02.071: [    AGFW][10] {0:1:37724} Started implicit monitor for [ora.net1.network anbob1 1] interval=60000 delay=60000
-10-15 10:06:02.071: [    AGFW][10] {0:1:41523} Generating new Tint for unplanned state change. Original Tint: {0:1:37724}
-10-15 10:06:02.071: [    AGFW][10] {0:1:41523} Agent sending message to PE: RESOURCE_STATUS[Proxy] ID 20481:77250752
-10-15 10:06:02.088: [    AGFW][10] {0:1:41523} Agent received the message: RESOURCE_PROBE[ora.anbob1.vip 1 1] ID 4097:15476951
-10-15 10:06:02.089: [    AGFW][10] {0:1:41523} Preparing CHECK command for: ora.anbob1.vip 1 1
-10-15 10:06:02.093: [    AGFW][10] {0:1:41523} Agent sending last reply for: RESOURCE_PROBE[ora.anbob1.vip 1 1] ID 4097:15476951
-10-15 10:06:02.100: [    AGFW][10] {0:1:41523} Agent received the message: RESOURCE_START[ora.net1.network anbob1 1] ID 4098:15476956
-10-15 10:06:02.100: [    AGFW][10] {0:1:41523} Preparing START command for: ora.net1.network anbob1 1
-10-15 10:06:02.100: [    AGFW][10] {0:1:41523} ora.net1.network anbob1 1 state changed from: OFFLINE to: STARTING
-10-15 10:06:02.102: [ora.net1.network][239542] {0:1:41523} [start] (:CLSN00107:) clsn_agent::start {
-10-15 10:06:02.102: [ora.net1.network][239542] {0:1:41523} [start] NetworkAgent::init enter {
-10-15 10:06:02.454: [ora.net1.network][239542] {0:1:41523} [start] Checking if lan900 Interface is fine
-10-15 10:06:02.718: [ora.net1.network][239542] {0:1:41523} [start] ifname=lan900
-10-15 10:06:02.719: [ora.net1.network][239542] {0:1:41523} [start] subnetmask=255.255.255.0
-10-15 10:06:02.719: [ora.net1.network][239542] {0:1:41523} [start] subnetnumber=133.96.43.0
-10-15 10:06:02.719: [ora.net1.network][239542] {0:1:41523} [start] Interface Name = lan900
-10-15 10:06:02.719: [ora.net1.network][239542] {0:1:41523} [start] Primary IP = 133.96.43.51
-10-15 10:06:02.719: [ora.net1.network][239542] {0:1:41523} [start] NetworkAgent::init exit }
-10-15 10:06:02.719: [ USRTHRD][239542] {0:1:41523} Thread:[VipRelocate:]stop {
-10-15 10:06:02.720: [ USRTHRD][239542] {0:1:41523} Thread:[VipRelocate:]stop }
-10-15 10:06:02.723: [ora.net1.network][239542] {0:1:41523} [start] Ocr Context init default level 40108160
-10-15 10:06:02.725: [ora.net1.network][239542] {0:1:41523} [start] Ocr Context init default level 40108160
-10-15 10:06:02.737: [ora.net1.network][239542] {0:1:41523} [start] (:CLSN00107:) clsn_agent::start }
-10-15 10:06:02.737: [    AGFW][239542] {0:1:41523} Command: start for resource: ora.net1.network anbob1 1 completed with status: SUCCESS
-10-15 10:06:02.739: [ USRTHRD][239541] {0:1:41523} Thread:[VipRelocate:]start {
-10-15 10:06:02.739: [    AGFW][10] {0:1:41523} Agent sending reply for: RESOURCE_START[ora.net1.network anbob1 1] ID 4098:15476956
-10-15 10:06:02.742: [ USRTHRD][239541] {0:1:41523} Thread:[VipRelocate:]start }
-10-15 10:06:02.743: [    AGFW][10] {0:1:41523} ora.net1.network anbob1 1 state changed from: STARTING to: ONLINE
-10-15 10:06:02.743: [    AGFW][10] {0:1:41523} Switching offline monitor to online one
-10-15 10:06:02.744: [    AGFW][10] {0:1:41523} Started implicit monitor for [ora.net1.network anbob1 1] interval=1000 delay=1000
-10-15 10:06:02.745: [    AGFW][10] {0:1:41523} Agent sending last reply for: RESOURCE_START[ora.net1.network anbob1 1] ID 4098:15476956
-10-15 10:06:02.825: [ USRTHRD][239543] {0:1:41523} Thread:[VipRelocate:]isRunning is reset to false here
-10-15 10:06:02.850: [CLSFRAME][1] TM [MultiThread] is changing desired thread # to 3. Current # is 4
-10-15 10:06:02.850: [CLSFRAME][239541] {0:1:41525} Worker thread is exiting in TM [MultiThread] to meet the desired count of 3. New count is 3
-10-15 10:06:03.462: [ USRTHRD][239539] {1:13432:61868} Thread:[StartorphanSrvThread:]stop {
-10-15 10:06:03.463: [ USRTHRD][239539] {1:13432:61868} Thread:[StartorphanSrvThread:]stop }
-10-15 10:06:03.463: [ora.anbob1.vip][239539] {1:13432:61868} [check] InterfaceName = lan900
-10-15 10:06:03.463: [ora.anbob1.vip][239539] {1:13432:61868} [check] NetworkMask = 255.255.255.0
-10-15 10:06:03.463: [ora.anbob1.vip][239539] {1:13432:61868} [check] NetworkAuto = static
-10-15 10:06:03.463: [ora.anbob1.vip][239539] {1:13432:61868} [check] Checking if lan900 Interface is fine
-10-15 10:06:03.723: [ora.anbob1.vip][239539] {1:13432:61868} [check] ifname=lan900
-10-15 10:06:03.724: [ora.anbob1.vip][239539] {1:13432:61868} [check] subnetmask=255.255.255.0
-10-15 10:06:03.724: [ora.anbob1.vip][239539] {1:13432:61868} [check] subnetnumber=133.96.43.0
-10-15 10:06:03.724: [ora.anbob1.vip][239539] {1:13432:61868} [check] InterfaceName = lan900
-10-15 10:06:03.725: [ora.anbob1.vip][239539] {1:13432:61868} [check] HostName anbob1_vip translated to 133.96.43.151
-10-15 10:06:03.725: [ora.anbob1.vip][239539] {1:13432:61868} [check] Interface Name = lan900
-10-15 10:06:03.725: [ora.anbob1.vip][239539] {1:13432:61868} [check] Ip Address = 133.96.43.151
-10-15 10:06:03.726: [ USRTHRD][239539] {1:13432:61868} Thread:[StartorphanSrvThread:]start {
-10-15 10:06:03.727: [ USRTHRD][239539] {1:13432:61868} Thread:[StartorphanSrvThread:]start }
-10-15 10:06:03.730: [ USRTHRD][239546] {1:13432:61868} VipAgent::startOrphanSrv {
-10-15 10:06:03.752: [ USRTHRD][239542] {0:1:41523} Thread:[VipRelocate:]start {
-10-15 10:06:03.752: [ USRTHRD][239542] {0:1:41523} Thread:[VipRelocate:]start }
-10-15 10:06:03.757: [ COMMCRS][239548]clscugblmini: (6000000000c40030) Monitor thread spawn failed
-10-15 10:06:03.777: [ USRTHRD][239546] {1:13432:61868} VipAgent::startOrphanSrv }
-10-15 10:06:03.777: [ USRTHRD][239546] {1:13432:61868} Thread:[StartorphanSrvThread:]isRunning is reset to false here
-10-15 10:06:03.795: [ USRTHRD][239548] {0:1:41523} Thread:[VipRelocate:]isRunning is reset to false here
-10-15 10:06:04.752: [ USRTHRD][239539] {0:1:41523} Thread:[VipRelocate:]start {
-10-15 10:06:04.755: [ USRTHRD][239539] {0:1:41523} Thread:[VipRelocate:]start }
-10-15 10:06:04.845: [ USRTHRD][239550] {0:1:41523} Thread:[VipRelocate:]isRunning is reset to false here
-10-15 10:06:05.762: [ USRTHRD][239542] {0:1:41523} Thread:[VipRelocate:]start {
-10-15 10:06:05.762: [ USRTHRD][239542] {0:1:41523} Thread:[VipRelocate:]start }
-10-15 10:06:05.856: [ USRTHRD][239551] {0:1:41523} Thread:[VipRelocate:]isRunning is reset to false here
-10-15 10:06:06.771: [ USRTHRD][239539] {0:1:41523} Thread:[VipRelocate:]start {
-10-15 10:06:06.772: [ USRTHRD][239539] {0:1:41523} Thread:[VipRelocate:]thread failed to spawn
-10-15 10:06:06.773: [ora.net1.network][239539] {0:1:41523} [check] Spawn of RelocateVipThread failed
-10-15 10:06:07.781: [ USRTHRD][239542] {0:1:41523} Thread:[VipRelocate:]start {
-10-15 10:06:09.533: [CLSFRAME][1] TM [MultiThread] is changing desired thread # to 4. Current # is 3
-10-15 10:06:09.533: [CLSFRAME][1] FAILED TO SPAWN THREAD in TM [MultiThread] , rc=-1
-10-15 10:06:10.544: [CLSFRAME][1] TM [MultiThread] is changing desired thread # to 4. Current # is 3
-10-15 10:06:10.544: [CLSFRAME][1] FAILED TO SPAWN THREAD in TM [MultiThread] , rc=-1
-10-15 10:06:11.553: [CLSFRAME][1] TM [MultiThread] is changing desired thread # to 4. Current # is 3
-10-15 10:06:11.553: [CLSFRAME][1] FAILED TO SPAWN THREAD in TM [MultiThread] , rc=-1
-10-15 10:06:12.563: [CLSFRAME][1] TM [MultiThread] is changing desired thread # to 4. Current # is 3
-10-15 10:06:12.563: [CLSFRAME][1] FAILED TO SPAWN THREAD in TM [MultiThread] , rc=-1

该问题是oracle 在HPUX platform的bug 16875342, 同时还有几个bug现象相似。我们安装了下面的补丁该问题得到解决(需要重启CRS)

The solution is to implement all the following:
1. Ensure APA and IETHER are at least the following version:
– APA B.11.31.1209
– IETHER B.11.31.1209
2. Apply OS kernel patch PHKL_42850
3. Install patch 16875342

作者:ANBOB
A No Bad Oracle Blog
原文地址:The Oracle Listener ofen restart and ora.net1.net, 感谢原作者分享。

发表评论