OS:HP-UX 11.31 DB:Oracle 10.0.2.5 RAC (2nodes)
问题描述:节点二在服务启动后,经过1分钟至3分钟会发生VIP导致的服务切换,切换后节点二VIP在节点一上启动,检查日志主要报错为:
1
| Invalid parameters, or failed to bring up VIP (host=essrzc2) |
Invalid parameters, or failed to bring up VIP (host=essrzc2)
经过检查,系统网关配置正常,响应速度正常,系统日志无异常。开启服务debug后收获如下日志:
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
| 2013-12-16 14:57:08.192: [ RACG][1] [21721][1][ora.essrzc2.vip]: Mon Dec 16 14:57:03 EAT 2013 [ 21730 ] Checking interface existance
Mon Dec 16 14:57:03 EAT 2013 [ 21730 ] Calling getifbyip
Mon Dec 16 14:57:03 EAT 2013 [ 21730 ] getifbyip: started for 132.42.37.144
2013-12-16 14:57:08.192: [ RACG][1] [21721][1][ora.essrzc2.vip]: Mon Dec 16 14:57:03 EAT 2013 [ 21730 ] Completed getifbyip lan900:801
Mon Dec 16 14:57:03 EAT 2013 [ 21730 ] Completed with initial interface test
Mon Dec 16 14:57:03 EAT 2013 [ 21730 ] Broadcast = 132.42.37.255
<span id="more-707"></span>
2013-12-16 14:57:08.192: [ RACG][1] [21721][1][ora.essrzc2.vip]: Mon Dec 16 14:57:03 EAT 2013 [ 21730 ] checkIf: start for if=lan900
Mon Dec 16 14:57:07 EAT 2013 [ 21730 ] checkIf: RX packets checked if=lan900 ok
Mon Dec 16 14:57:07 EAT 2013 [ 21730 ] checkIf: end for if=lan900
2013-12-16 14:57:08.192: [ RACG][1] [21721][1][ora.essrzc2.vip]: Mon Dec 16 14:57:07 EAT 2013 [ 21730 ] main: interface is okay, exit success
2013-12-16 14:57:08.192: [ RACG][1] [21721][1][ora.essrzc2.vip]: clsrcexecut: env ORACLE_CONFIG_HOME=/oracle/product/10.2/crs
2013-12-16 14:57:08.192: [ RACG][1] [21721][1][ora.essrzc2.vip]: clsrcexecut: cmd = /oracle/product/10.2/crs/bin/racgeut -e _USR_ORA_DEBUG=5 54 /oracle/product/10.2/crs/bin/racgvip check essrzc2
2013-12-16 14:57:08.192: [ RACG][1] [21721][1][ora.essrzc2.vip]: clsrcexecut: rc = 0, time = 4.624s
2013-12-16 14:57:08.192: [ RACG][1] [21721][1][ora.essrzc2.vip]: clsrcaction: restyp=0 act_typ=2 stat=0
2013-12-16 14:57:08.192: [ RACG][1] [21721][1][ora.essrzc2.vip]: clsrcaction: return CLSR_CAA_SUCCESS
2013-12-16 14:57:08.192: [ RACG][1] [21721][1][ora.essrzc2.vip]: clsrcaction: init 0.000s
2013-12-16 14:57:08.192: [ RACG][1] [21721][1][ora.essrzc2.vip]: clsrcaction: action ok, 4.653s
2013-12-16 14:57:08.192: [ RACG][1] [21721][1][ora.essrzc2.vip]: clsrcaction: post 0.000s
2013-12-16 14:57:08.192: [ RACG][1] [21721][1][ora.essrzc2.vip]: clsrcaction: all 4.653s
2013-12-16 14:57:08.192: [ RACG][1] [21721][1][ora.essrzc2.vip]: end for resource = ora.essrzc2.vip, action = check, status = 0, time = 4.692s
2013-12-16 14:57:08.192: [ RACG][1] [21721][1][ora.essrzc2.vip]: clsrccln: exiting ora.essrzc2.vip refcount=1
2013-12-16 14:57:08.192: [ RACG][1] [21721][1][ora.essrzc2.vip]: clsrcprsrgter: gctx->prsrcfgref_clsrcgctx = 0
2013-12-16 14:57:38.420: [ RACG][1] [21974][1][ora.essrzc2.vip]: clsrcprsrgini: gctx->prsrcfgref_clsrcgctx = 0
2013-12-16 14:57:38.420: [ RACG][1] [21974][1][ora.essrzc2.vip]: clsrcini_ext: starting ora.essrzc2.vip refcount=1 global
2013-12-16 14:57:38.421: [ RACG][1] [21974][1][ora.essrzc2.vip]: begin for resource = ora.essrzc2.vip, action = check
2013-12-16 14:57:38.428: [ RACG][1] [21974][1][ora.essrzc2.vip]: clsrccssgetctx: all 0.007s
2013-12-16 14:57:38.436: [ RACG][1] [21974][1][ora.essrzc2.vip]: clsrcgetprsrctx: all 0.015s
2013-12-16 14:57:38.448: [ RACG][1] [21974][1][ora.essrzc2.vip]: clsrcnodeapp: prsr num_env = 0
2013-12-16 14:57:38.449: [ RACG][1] [21974][1][ora.essrzc2.vip]: clsrcnodeapp: setting ORACLE_CONFIG_HOME=/oracle/product/10.2/crs
2013-12-16 14:57:43.181: [ RACG][1] [21974][1][ora.essrzc2.vip]: Unable to get IPv6 interface information.
Permission denied to 127.0.0.1
cmviewcl: Cannot view the cluster configuration: Permission denied.
This user doesn't have access to view the cluster configuration.
2013-12-16 14:57:43.181: [ RACG][1] [21974][1][ora.essrzc2.vip]: Mon Dec 16 14:57:38 EAT 2013 [ 21979 ] Checking interface existance
Mon Dec 16 14:57:38 EAT 2013 [ 21979 ] Calling getifbyip
Mon Dec 16 14:57:38 EAT 2013 [ 21979 ] getifbyip: started for 132.42.37.144
2013-12-16 14:57:43.181: [ RACG][1] [21974][1][ora.essrzc2.vip]: Mon Dec 16 14:57:38 EAT 2013 [ 21979 ] Completed getifbyip lan900:801
Mon Dec 16 14:57:38 EAT 2013 [ 21979 ] Completed with initial interface test
Mon Dec 16 14:57:38 EAT 2013 [ 21979 ] Broadcast = 132.42.37.255
2013-12-16 14:57:43.181: [ RACG][1] [21974][1][ora.essrzc2.vip]: Mon Dec 16 14:57:38 EAT 2013 [ 21979 ] checkIf: start for if=lan900
Mon Dec 16 14:57:42 EAT 2013 [ 21979 ] checkIf: RX packets checked if=lan900 failed
Interface lan900 checked failed (host=essrzc2)
2013-12-16 14:57:43.181: [ RACG][1] [21974][1][ora.essrzc2.vip]: Mon Dec 16 14:57:42 EAT 2013 [ 21979 ] checkIf: end for if=lan900
Mon Dec 16 14:57:42 EAT 2013 [ 21979 ] Performing CRS_STAT testing
Mon Dec 16 14:57:42 EAT 2013 [ 21979 ] Completed CRS_STAT testing
2013-12-16 14:57:43.181: [ RACG][1] [21974][1][ora.essrzc2.vip]: Mon Dec 16 14:57:43 EAT 2013 [ 21979 ] Completed second gateway test
Mon Dec 16 14:57:43 EAT 2013 [ 21979 ] Interface tests
Mon Dec 16 14:57:43 EAT 2013 [ 21979 ] DEBUG: FAIL_WHEN_ALL_LINK_DOWN = 1 and IF_USING = lan900
2013-12-16 14:57:43.181: [ RACG][1] [21974][1][ora.essrzc2.vip]: Invalid parameters, or failed to bring up VIP (host=essrzc2)
2013-12-16 14:57:43.181: [ RACG][1] [21974][1][ora.essrzc2.vip]: clsrcexecut: env ORACLE_CONFIG_HOME=/oracle/product/10.2/crs
2013-12-16 14:57:43.181: [ RACG][1] [21974][1][ora.essrzc2.vip]: clsrcexecut: cmd = /oracle/product/10.2/crs/bin/racgeut -e _USR_ORA_DEBUG=5 54 /oracle/product/10.2/crs/bin/racgvip check essrzc2
2013-12-16 14:57:43.181: [ RACG][1] [21974][1][ora.essrzc2.vip]: clsrcexecut: rc = 1, time = 4.731s
2013-12-16 14:57:43.182: [ RACG][1] [21974][1][ora.essrzc2.vip]: clsrcaction: restyp=0 act_typ=2 stat=1
2013-12-16 14:57:43.182: [ RACG][1] [21974][1][ora.essrzc2.vip]: clsrcaction: init 0.000s
2013-12-16 14:57:43.182: [ RACG][1] [21974][1][ora.essrzc2.vip]: clsrcaction: action failed, 4.761s
2013-12-16 14:57:43.182: [ RACG][1] [21974][1][ora.essrzc2.vip]: clsrcaction: post 0.000s
2013-12-16 14:57:43.182: [ RACG][1] [21974][1][ora.essrzc2.vip]: clsrcaction: all 4.761s
2013-12-16 14:57:43.182: [ RACG][1] [21974][1][ora.essrzc2.vip]: end for resource = ora.essrzc2.vip, action = check, status = 1, time = 4.801s
2013-12-16 14:57:43.182: [ RACG][1] [21974][1][ora.essrzc2.vip]: clsrccln: exiting ora.essrzc2.vip refcount=1
2013-12-16 14:57:43.182: [ RACG][1] [21974][1][ora.essrzc2.vip]: clsrcprsrgter: gctx->prsrcfgref_clsrcgctx = 0
2013-12-16 14:57:43.434: [ RACG][1] [22058][1][ora.essrzc2.vip]: clsrcprsrgini: gctx->prsrcfgref_clsrcgctx = 0
2013-12-16 14:57:43.434: [ RACG][1] [22058][1][ora.essrzc2.vip]: clsrcini_ext: starting ora.essrzc2.vip refcount=1 global
2013-12-16 14:57:43.435: [ RACG][1] [22058][1][ora.essrzc2.vip]: begin for resource = ora.essrzc2.vip, action = stop
2013-12-16 14:57:43.466: [ RACG][1] [22058][1][ora.essrzc2.vip]: clsrccssgetnodename: all 0.030s
2013-12-16 14:57:43.466: [ RACG][1] [22058][1][ora.essrzc2.vip]: clsrcnodeapps: calling FAILSRVSA
2013-12-16 14:57:43.483: [ RACG][1] [22058][1][ora.essrzc2.vip]: clsrcrundetach: cmd = /oracle/product/10.2/crs/bin/racgmain ora.essrzc2.vip rundetach 1 failsrvsa essrzc2, rc = 0, time = 0.016s
2013-12-16 14:57:43.483: [ RACG][1] [22058][1][ora.essrzc2.vip]: clsrcnodeapps: Posting PNWDOWN_EVENT
2013-12-16 14:57:43.484: [ RACG][1] [22058][1][ora.essrzc2.vip]: clsrccssgetnodename: all 0.000s
2013-12-16 14:57:43.484: [ RACG][1] [22058][1][ora.essrzc2.vip]: clsrccssgetnodename: all 0.000s
2013-12-16 14:57:43.484: [ RACG][1] [22058][1][ora.essrzc2.vip]: clsrcssgetrhost: using cached local host name
2013-12-16 14:57:43.486: [ RACG][1] [22058][1][ora.essrzc2.vip]: clsrccssgetlhost: all 0.002s
2013-12-16 14:57:43.493: [ RACG][1] [22058][1][ora.essrzc2.vip]: clsrcpostevt: EvmEventPost 1 0.001s
2013-12-16 14:57:43.493: [ RACG][1] [22058][1][ora.essrzc2.vip]: clsrcposthaevt: forward to EVM |
2013-12-16 14:57:08.192: [ RACG][1] [21721][1][ora.essrzc2.vip]: Mon Dec 16 14:57:03 EAT 2013 [ 21730 ] Checking interface existance
Mon Dec 16 14:57:03 EAT 2013 [ 21730 ] Calling getifbyip
Mon Dec 16 14:57:03 EAT 2013 [ 21730 ] getifbyip: started for 132.42.37.144
2013-12-16 14:57:08.192: [ RACG][1] [21721][1][ora.essrzc2.vip]: Mon Dec 16 14:57:03 EAT 2013 [ 21730 ] Completed getifbyip lan900:801
Mon Dec 16 14:57:03 EAT 2013 [ 21730 ] Completed with initial interface test
Mon Dec 16 14:57:03 EAT 2013 [ 21730 ] Broadcast = 132.42.37.255
<span id="more-707"></span>
2013-12-16 14:57:08.192: [ RACG][1] [21721][1][ora.essrzc2.vip]: Mon Dec 16 14:57:03 EAT 2013 [ 21730 ] checkIf: start for if=lan900
Mon Dec 16 14:57:07 EAT 2013 [ 21730 ] checkIf: RX packets checked if=lan900 ok
Mon Dec 16 14:57:07 EAT 2013 [ 21730 ] checkIf: end for if=lan900
2013-12-16 14:57:08.192: [ RACG][1] [21721][1][ora.essrzc2.vip]: Mon Dec 16 14:57:07 EAT 2013 [ 21730 ] main: interface is okay, exit success
2013-12-16 14:57:08.192: [ RACG][1] [21721][1][ora.essrzc2.vip]: clsrcexecut: env ORACLE_CONFIG_HOME=/oracle/product/10.2/crs
2013-12-16 14:57:08.192: [ RACG][1] [21721][1][ora.essrzc2.vip]: clsrcexecut: cmd = /oracle/product/10.2/crs/bin/racgeut -e _USR_ORA_DEBUG=5 54 /oracle/product/10.2/crs/bin/racgvip check essrzc2
2013-12-16 14:57:08.192: [ RACG][1] [21721][1][ora.essrzc2.vip]: clsrcexecut: rc = 0, time = 4.624s
2013-12-16 14:57:08.192: [ RACG][1] [21721][1][ora.essrzc2.vip]: clsrcaction: restyp=0 act_typ=2 stat=0
2013-12-16 14:57:08.192: [ RACG][1] [21721][1][ora.essrzc2.vip]: clsrcaction: return CLSR_CAA_SUCCESS
2013-12-16 14:57:08.192: [ RACG][1] [21721][1][ora.essrzc2.vip]: clsrcaction: init 0.000s
2013-12-16 14:57:08.192: [ RACG][1] [21721][1][ora.essrzc2.vip]: clsrcaction: action ok, 4.653s
2013-12-16 14:57:08.192: [ RACG][1] [21721][1][ora.essrzc2.vip]: clsrcaction: post 0.000s
2013-12-16 14:57:08.192: [ RACG][1] [21721][1][ora.essrzc2.vip]: clsrcaction: all 4.653s
2013-12-16 14:57:08.192: [ RACG][1] [21721][1][ora.essrzc2.vip]: end for resource = ora.essrzc2.vip, action = check, status = 0, time = 4.692s
2013-12-16 14:57:08.192: [ RACG][1] [21721][1][ora.essrzc2.vip]: clsrccln: exiting ora.essrzc2.vip refcount=1
2013-12-16 14:57:08.192: [ RACG][1] [21721][1][ora.essrzc2.vip]: clsrcprsrgter: gctx->prsrcfgref_clsrcgctx = 0
2013-12-16 14:57:38.420: [ RACG][1] [21974][1][ora.essrzc2.vip]: clsrcprsrgini: gctx->prsrcfgref_clsrcgctx = 0
2013-12-16 14:57:38.420: [ RACG][1] [21974][1][ora.essrzc2.vip]: clsrcini_ext: starting ora.essrzc2.vip refcount=1 global
2013-12-16 14:57:38.421: [ RACG][1] [21974][1][ora.essrzc2.vip]: begin for resource = ora.essrzc2.vip, action = check
2013-12-16 14:57:38.428: [ RACG][1] [21974][1][ora.essrzc2.vip]: clsrccssgetctx: all 0.007s
2013-12-16 14:57:38.436: [ RACG][1] [21974][1][ora.essrzc2.vip]: clsrcgetprsrctx: all 0.015s
2013-12-16 14:57:38.448: [ RACG][1] [21974][1][ora.essrzc2.vip]: clsrcnodeapp: prsr num_env = 0
2013-12-16 14:57:38.449: [ RACG][1] [21974][1][ora.essrzc2.vip]: clsrcnodeapp: setting ORACLE_CONFIG_HOME=/oracle/product/10.2/crs
2013-12-16 14:57:43.181: [ RACG][1] [21974][1][ora.essrzc2.vip]: Unable to get IPv6 interface information.
Permission denied to 127.0.0.1
cmviewcl: Cannot view the cluster configuration: Permission denied.
This user doesn't have access to view the cluster configuration.
2013-12-16 14:57:43.181: [ RACG][1] [21974][1][ora.essrzc2.vip]: Mon Dec 16 14:57:38 EAT 2013 [ 21979 ] Checking interface existance
Mon Dec 16 14:57:38 EAT 2013 [ 21979 ] Calling getifbyip
Mon Dec 16 14:57:38 EAT 2013 [ 21979 ] getifbyip: started for 132.42.37.144
2013-12-16 14:57:43.181: [ RACG][1] [21974][1][ora.essrzc2.vip]: Mon Dec 16 14:57:38 EAT 2013 [ 21979 ] Completed getifbyip lan900:801
Mon Dec 16 14:57:38 EAT 2013 [ 21979 ] Completed with initial interface test
Mon Dec 16 14:57:38 EAT 2013 [ 21979 ] Broadcast = 132.42.37.255
2013-12-16 14:57:43.181: [ RACG][1] [21974][1][ora.essrzc2.vip]: Mon Dec 16 14:57:38 EAT 2013 [ 21979 ] checkIf: start for if=lan900
Mon Dec 16 14:57:42 EAT 2013 [ 21979 ] checkIf: RX packets checked if=lan900 failed
Interface lan900 checked failed (host=essrzc2)
2013-12-16 14:57:43.181: [ RACG][1] [21974][1][ora.essrzc2.vip]: Mon Dec 16 14:57:42 EAT 2013 [ 21979 ] checkIf: end for if=lan900
Mon Dec 16 14:57:42 EAT 2013 [ 21979 ] Performing CRS_STAT testing
Mon Dec 16 14:57:42 EAT 2013 [ 21979 ] Completed CRS_STAT testing
2013-12-16 14:57:43.181: [ RACG][1] [21974][1][ora.essrzc2.vip]: Mon Dec 16 14:57:43 EAT 2013 [ 21979 ] Completed second gateway test
Mon Dec 16 14:57:43 EAT 2013 [ 21979 ] Interface tests
Mon Dec 16 14:57:43 EAT 2013 [ 21979 ] DEBUG: FAIL_WHEN_ALL_LINK_DOWN = 1 and IF_USING = lan900
2013-12-16 14:57:43.181: [ RACG][1] [21974][1][ora.essrzc2.vip]: Invalid parameters, or failed to bring up VIP (host=essrzc2)
2013-12-16 14:57:43.181: [ RACG][1] [21974][1][ora.essrzc2.vip]: clsrcexecut: env ORACLE_CONFIG_HOME=/oracle/product/10.2/crs
2013-12-16 14:57:43.181: [ RACG][1] [21974][1][ora.essrzc2.vip]: clsrcexecut: cmd = /oracle/product/10.2/crs/bin/racgeut -e _USR_ORA_DEBUG=5 54 /oracle/product/10.2/crs/bin/racgvip check essrzc2
2013-12-16 14:57:43.181: [ RACG][1] [21974][1][ora.essrzc2.vip]: clsrcexecut: rc = 1, time = 4.731s
2013-12-16 14:57:43.182: [ RACG][1] [21974][1][ora.essrzc2.vip]: clsrcaction: restyp=0 act_typ=2 stat=1
2013-12-16 14:57:43.182: [ RACG][1] [21974][1][ora.essrzc2.vip]: clsrcaction: init 0.000s
2013-12-16 14:57:43.182: [ RACG][1] [21974][1][ora.essrzc2.vip]: clsrcaction: action failed, 4.761s
2013-12-16 14:57:43.182: [ RACG][1] [21974][1][ora.essrzc2.vip]: clsrcaction: post 0.000s
2013-12-16 14:57:43.182: [ RACG][1] [21974][1][ora.essrzc2.vip]: clsrcaction: all 4.761s
2013-12-16 14:57:43.182: [ RACG][1] [21974][1][ora.essrzc2.vip]: end for resource = ora.essrzc2.vip, action = check, status = 1, time = 4.801s
2013-12-16 14:57:43.182: [ RACG][1] [21974][1][ora.essrzc2.vip]: clsrccln: exiting ora.essrzc2.vip refcount=1
2013-12-16 14:57:43.182: [ RACG][1] [21974][1][ora.essrzc2.vip]: clsrcprsrgter: gctx->prsrcfgref_clsrcgctx = 0
2013-12-16 14:57:43.434: [ RACG][1] [22058][1][ora.essrzc2.vip]: clsrcprsrgini: gctx->prsrcfgref_clsrcgctx = 0
2013-12-16 14:57:43.434: [ RACG][1] [22058][1][ora.essrzc2.vip]: clsrcini_ext: starting ora.essrzc2.vip refcount=1 global
2013-12-16 14:57:43.435: [ RACG][1] [22058][1][ora.essrzc2.vip]: begin for resource = ora.essrzc2.vip, action = stop
2013-12-16 14:57:43.466: [ RACG][1] [22058][1][ora.essrzc2.vip]: clsrccssgetnodename: all 0.030s
2013-12-16 14:57:43.466: [ RACG][1] [22058][1][ora.essrzc2.vip]: clsrcnodeapps: calling FAILSRVSA
2013-12-16 14:57:43.483: [ RACG][1] [22058][1][ora.essrzc2.vip]: clsrcrundetach: cmd = /oracle/product/10.2/crs/bin/racgmain ora.essrzc2.vip rundetach 1 failsrvsa essrzc2, rc = 0, time = 0.016s
2013-12-16 14:57:43.483: [ RACG][1] [22058][1][ora.essrzc2.vip]: clsrcnodeapps: Posting PNWDOWN_EVENT
2013-12-16 14:57:43.484: [ RACG][1] [22058][1][ora.essrzc2.vip]: clsrccssgetnodename: all 0.000s
2013-12-16 14:57:43.484: [ RACG][1] [22058][1][ora.essrzc2.vip]: clsrccssgetnodename: all 0.000s
2013-12-16 14:57:43.484: [ RACG][1] [22058][1][ora.essrzc2.vip]: clsrcssgetrhost: using cached local host name
2013-12-16 14:57:43.486: [ RACG][1] [22058][1][ora.essrzc2.vip]: clsrccssgetlhost: all 0.002s
2013-12-16 14:57:43.493: [ RACG][1] [22058][1][ora.essrzc2.vip]: clsrcpostevt: EvmEventPost 1 0.001s
2013-12-16 14:57:43.493: [ RACG][1] [22058][1][ora.essrzc2.vip]: clsrcposthaevt: forward to EVM