首页 » ORACLE [C]系列 » Troubleshooting Oracle 19c GIPC start fail with “EXCEPTION[ ret gipcretBadArg (37) ] “

Troubleshooting Oracle 19c GIPC start fail with “EXCEPTION[ ret gipcretBadArg (37) ] “

最近一套ORACLE 19C RAC 因一个节点主机故障重启后,其中1节点启动失败, 2节点正常启动,网络traceroute 、 ping 、多播测试均正常,幸存节点也有尝试重启、包括Kill gipc gpnp 进程,及重建过node 1的tmp 下的network soket临时文件, node1 依旧启动失败, 启动分析Init启动进程发现是gipcd启动后直接terminal中断, 并有如下报错信息:

2022-08-27 02:20:22.167 : CLSCRED:742008576: clsCredCommonInit: Inited singleton credctx.
2022-08-27 02:20:22.167 : GIPCTLS:742008576:  gipcmodTlsGetWalletObjFromCred: using rootCredDomName: NULL, baseCredDomName:nodecert
2022-08-27 02:20:22.177 : GIPCTLS:742008576:  gipcmodTlsGetWalletObjFromCred: found base dom: nodecert
2022-08-27 02:20:22.187 :GIPCXCPT:742008576:  gipcmodTlsGetWalletObjFromCred: invalid certificate count[! = 1]in credSet:0, ret gipcretBadArg (37)
2022-08-27 02:20:22.188 : default:742008576: clsCredDomClose: Credctx deleted 0x7f170c0bd7f0   
2022-08-27 02:20:22.188 :GIPCXCPT:742008576:  gipcListenF [gipcdNodeThread : gipcdNodeThread.c : 5433]: EXCEPTION[ ret gipcretBadArg (37) ]  failed to listen on endp 0x7f170c0addc0 [0000000000000540] { gipcEndpoint : localAddr 'gipcha://anbob1:gipcdha_anbob1_', remoteAddr '', numPend 1, numReady 0, numDone 0, numDead 0, numTransfer 0, objFlags 0x0, pidPeer 0, readyRef (nil), ready 0, wobj 0x7f170c0c5180, sendp (nil) status 13flags 0x20038602, flags-2 0x10, usrFlags 0x0 }, flags 0x0
2022-08-27 02:20:22.188 :GIPCDNDE:742008576:  gipcdNodeThread: gipcListen() failed (37) on endp 0000000000000540    
2022-08-27 02:20:22.188 :GIPCDNDE:742008576:  gipcdNodeThreadShutdown: deleting all the peer connections

GI ALERT LOG(NO ERROR)

2022-08-27 11:55:17.878 [OCRCONFIG(46835)]CRS-1013: The OCR location in an ASM disk group is inaccessible. Details in /anbob/app/19.3/diag/crs/anbob1/crs/trace/ocrconfig_46835.trc.
2022-08-27 12:02:31.447 [OCRCONFIG(52981)]CRS-1013: The OCR location in an ASM disk group is inaccessible. Details in /anbob/app/19.3/diag/crs/anbob1/crs/trace/ocrconfig_52981.trc.
2022-08-27 12:18:49.104 [OHASD(21052)]CRS-2791: Starting shutdown of Oracle High Availability Services-managed resources on 'anbob1'
2022-08-27 12:18:49.132 [GPNPD(21337)]CRS-2329: GPNPD on node anbob1 shut down. 
2022-08-27 12:18:49.130 [MDNSD(21300)]CRS-5602: mDNS service stopping by request.
2022-08-27 12:18:49.157 [MDNSD(21300)]CRS-8504: Oracle Clusterware MDNSD process with operating system process ID 21300 is exiting
2022-08-27 12:18:50.167 [OHASD(21052)]CRS-2793: Shutdown of Oracle High Availability Services-managed resources on 'anbob1' has completed
2022-08-27 12:18:50.256 [ORAROOTAGENT(21182)]CRS-5822: Agent '/anbob/app/grid/bin/orarootagent_root' disconnected from server. Details at (:CRSAGF00117:) {0:2:26} in /anbob/app/19.3/diag/crs/anbob1/crs/trace/ohasd_orarootagent_root.trc.
2022-08-27 12:22:00.285 [OHASD(71920)]CRS-8500: Oracle Clusterware OHASD process is starting with operating system process ID 71920
2022-08-27 12:22:00.547 [OHASD(71920)]CRS-0714: Oracle Clusterware Release 19.0.0.0.0.
2022-08-27 12:22:00.583 [OHASD(71920)]CRS-2112: The OLR service started on node anbob1.
2022-08-27 12:22:00.753 [OHASD(71920)]CRS-8017: location: /etc/oracle/lastgasp has 2 reboot advisory log files, 0 were announced and 0 errors occurred
2022-08-27 12:22:00.754 [OHASD(71920)]CRS-1301: Oracle High Availability Service started on node anbob1.
2022-08-27 12:22:03.369 [CSSDMONITOR(72072)]CRS-8500: Oracle Clusterware CSSDMONITOR process is starting with operating system process ID 72072
2022-08-27 12:22:03.391 [CSSDAGENT(72070)]CRS-8500: Oracle Clusterware CSSDAGENT process is starting with operating system process ID 72070
2022-08-27 12:22:03.428 [ORAROOTAGENT(72061)]CRS-8500: Oracle Clusterware ORAROOTAGENT process is starting with operating system process ID 72061
2022-08-27 12:22:03.440 [ORAAGENT(72051)]CRS-8500: Oracle Clusterware ORAAGENT process is starting with operating system process ID 72051
2022-08-27 12:22:04.819 [ORAAGENT(72146)]CRS-8500: Oracle Clusterware ORAAGENT process is starting with operating system process ID 72146
2022-08-27 12:22:05.779 [MDNSD(72175)]CRS-8500: Oracle Clusterware MDNSD process is starting with operating system process ID 72175
2022-08-27 12:22:05.807 [EVMD(72177)]CRS-8500: Oracle Clusterware EVMD process is starting with operating system process ID 72177
2022-08-27 12:22:06.936 [GPNPD(72213)]CRS-8500: Oracle Clusterware GPNPD process is starting with operating system process ID 72213
2022-08-27 12:22:08.564 [GPNPD(72213)]CRS-2328: GPNPD started on node anbob1. 
2022-08-27 12:22:08.913 [GIPCD(72328)]CRS-8500: Oracle Clusterware GIPCD process is starting with operating system process ID 72328
2022-08-27 12:22:57.465 [GIPCD(73369)]CRS-8500: Oracle Clusterware GIPCD process is starting with operating system process ID 73369
2022-08-27 12:23:45.930 [GIPCD(74251)]CRS-8500: Oracle Clusterware GIPCD process is starting with operating system process ID 74251
2022-08-27 12:24:34.295 [GIPCD(75045)]CRS-8500: Oracle Clusterware GIPCD process is starting with operating system process ID 75045
2022-08-27 12:25:22.729 [OSYSMOND(75527)]CRS-8500: Oracle Clusterware OSYSMOND process is starting with operating system process ID 75527

gpnp trace

2022-08-27 12:22:07.256 :    GPNP:2807901440: clsgpnpkwf_initwfloc: [at clsgpnpkwf.c:416] Wallet readable. Path: /anbob/app/grid/gpnp/anbob1/wallets/peer/

2022-08-27 12:22:07.256 :    GPNP:2807901440: clsgpnp_InitCKProviders: [at clsgpnp0.c:5276] Init gpnp local security key provider 1 of 2: file wallet (LSKP-FSW) OK
2022-08-27 12:22:07.256 :    GPNP:2807901440: clsgpnp_InitCKProviders: [at clsgpnp0.c:5282] Init gpnp local security key proveders 2 of 2: OLR wallet (LSKP-CLSW-OLR)
2022-08-27 12:22:07.265 :    GPNP:2807901440: clsgpnp_InitCKProviders: [at clsgpnp0.c:5306] Init gpnp local security key provider 2 of 2: OLR wallet (LSKP-CLSW-OLR) OK
2022-08-27 12:22:07.265 :    GPNP:2807901440: clsgpnp_getCK: [at clsgpnp0.c:2844] 
2022-08-27 12:22:07.413 :    GPNP:2807901440: clsgpnp_getCK: [at clsgpnp0.c:2844] 
2022-08-27 12:22:07.453 :    GPNP:2807901440: clsgpnp_InitLocalPrfCacheProvs: [at clsgpnp0.c:5399] Init gpnp local profile cache providers LCP-FS,OLR.
2022-08-27 12:22:07.453 :    GPNP:2807901440: clsgpnpcf_initProfilePath: [at clsgpnpcf.c:419] SlfStatn
Internal Error Information: 
  Category: SLF_NOENT(-5)
  Operation: stat failed
  Location: SlfStat1
  Other: 
  Dep: 2
  Dep Message: No such file or directory

2022-08-27 12:22:07.453 :    GPNP:2807901440: clsgpnpcf_initProfilePath: [at clsgpnpcf.c:426] FSCache Profile 1: '/anbob/app/grid/gpnp/anbob1/profiles/peer/profile.xml' not found or not accessible. 
2022-08-27 12:22:07.453 :    GPNP:2807901440: clsgpnpou_getOlrCrsHome: [at clsgpnpou.c:430] Initializing CLSE context : clsgpnpou_getOlrCrsHome

2022-08-27 12:22:07.453 :    GPNP:2807901440: clsgpnpou_getOlrCrsHome: [at clsgpnpou.c:444] Trying to fetch ORA_CRS_HOME : clsgpnpou_getOlrCrsHome

2022-08-27 12:22:07.453 :    GPNP:2807901440: clsgpnpou_getOlrCrsHome: [at clsgpnpou.c:463] ORA_CRS_HOME value is : /anbob/app/grid 

2022-08-27 12:22:07.453 :    GPNP:2807901440: clsgpnpcf_initProfilePath: GPnP api clsgpnpcf_initProfilePath failed
2022-08-27 12:22:07.453 :    GPNP:2807901440: clsgpnpcf_initProfilePath: GPnP error code : 1 (CLSGPNP_ERR)
2022-08-27 12:22:07.453 :    GPNP:2807901440: clsgpnpcfProviderInit: GPnP api clsgpnpcfProviderInit failed
2022-08-27 12:22:07.453 :    GPNP:2807901440: clsgpnpcfProviderInit: GPnP error code : 1 (CLSGPNP_ERR)
2022-08-27 12:22:07.453 :    GPNP:2807901440: clsgpnp_InitLocalPrfCacheProvs: [at clsgpnp0.c:5417] Result: (1) CLSGPNP_ERR. (:GPNP00258:)Error initializing gpnp local profile cache provider 1 of 2 (LCP-FS).
2022-08-27 12:22:07.455 :    GPNP:2807901440: clsgpnpou_initocr: [at clsgpnpou.c:144] OLR Initialized at level 458752
2022-08-27 12:22:07.455 : default:2807901440: GPNPD tracelevel 3
2022-08-27 12:22:07.456 :    GPNP:2807901440: clsgpnp_getDaemonLocalName: [at clsgpnp0.c:3507] Result: (0) CLSGPNP_OK. Local gpnp connect: 'ipc://GPNPD_anbob1'
2022-08-27 12:22:07.456 :    GPNP:2807901440: clsgpnpm_connect: [at clsgpnpm.c:2245] Connecting to ipc://GPNPD_anbob1
2022-08-27 12:22:07.457 :    GPNP:2807901440: clsgpnpm_connect: [at clsgpnpm.c:2324] Result: (48) CLSGPNP_COMM_ERR. no alt connect to "ipc://GPNPD_anbob1" - not tcp or no req
2022-08-27 12:22:07.457 :    GPNP:2807901440: clsgpnp_getDaemonLocalName: [at clsgpnp0.c:3507] Result: (0) CLSGPNP_OK. Local gpnp connect: 'ipc://GPNPD_anbob1'
2022-08-27 12:22:07.457 :    GPNP:2807901440: clsgpnpd_lOpenEP: [at clsgpnpd.c:1956] Listening on "ipc://GPNPD_anbob1"
2022-08-27 12:22:07.467 :  CLSDMT:2639734528: [     INFO] PID for the Process [72213], connkey GPNPD
2022-08-27 12:22:08.463 :    GPNP:2807901440: clsgpnpd_openLocalProfile: [at clsgpnpd.c:2263] Get local best profile.
2022-08-27 12:22:08.463 :    GPNP:2807901440: clsgpnpd_openLocalProfile: [at clsgpnpd.c:2324] Local OLR profile cache provider (OLR-CP) available, try to get best profile
2022-08-27 12:22:08.463 :    GPNP:2807901440: clsgpnpco_ocr2profile: [at clsgpnpco.c:578] OLR (r/w) READ profile id=1 ctyp=1
2022-08-27 12:22:08.463 :    GPNP:2807901440: clsgpnpou_checkinitreocr: [at clsgpnpou.c:328] OLR is ready - already open at level 70000 
2022-08-27 12:22:08.463 :    GPNP:2639734528: CLSDM requested check alive. Ready:0 [x:0,lopn:0,ini:1,eq:1,stp:0,apick:0,drdy:0]
2022-08-27 12:22:08.465 :    GPNP:2807901440: clsgpnpco_ocr2profile: [at clsgpnpco.c:640] OLR - calling procr_get_value_ext SYSTEM.GPnP.profiles.peer.best blen=20480
2022-08-27 12:22:08.465 :    GPNP:2639734528: CLSDM requested check alive. Ready:0 [x:0,lopn:0,ini:1,eq:1,stp:0,apick:0,drdy:0]
2022-08-27 12:22:08.466 :    GPNP:2807901440: clsgpnpco_ocr2profile: [at clsgpnpco.c:704] Result: (0) CLSGPNP_OK. OLR - profile read (tlen=1928 blen=1929 dt=5)
2022-08-27 12:22:08.466 :    GPNP:2807901440: clsgpnpd_validateProfile: [at clsgpnpdcmn.c:911] Profile p=0x55aa715b20d0 ProfileSequence=5.
2022-08-27 12:22:08.467 :    GPNP:2807901440: clsgpnpd_validateProfile: [at clsgpnpdcmn.c:995] Result: (87) CLSGPNP_SIG_VALPEER. Profile verified.  prf=0x55aa715b20d0
2022-08-27 12:22:08.467 :    GPNP:2807901440: clsgpnpd_validateProfile: [at clsgpnpdcmn.c:1013] GPnPD taken cluster guid '77afe26a92c6cfdfff124fc8ba403843'
2022-08-27 12:22:08.467 :    GPNP:2807901440: clsgpnpd_validateProfile: [at clsgpnpdcmn.c:1040] GPnPD taken cluster name 'tyscdb-cluster'
2022-08-27 12:22:08.467 :    GPNP:2807901440: clsgpnpd_openLocalProfile: [at clsgpnpd.c:2373] Got local profile from OLR cache provider (LCP-OLR).
2022-08-27 12:22:08.467 :    GPNP:2807901440: clsgpnpd_openLocalProfile: [at clsgpnpd.c:2397] Local best profiles available, compare.
2022-08-27 12:22:08.467 :    GPNP:2807901440: clsgpnpd_openLocalProfile: [at clsgpnpd.c:2415] Local best file profile (LCP-FS) 0x55aa715b20d0 too old.
2022-08-27 12:22:08.467 :    GPNP:2807901440: clsgpnpd_openLocalProfile: [at clsgpnpd.c:2422] Result: (3) CLSGPNP_INIT_FAILED. (:GPNPD00109:)best profile was not saved in file local cache provider (LCP-FS) p=0x55aa715b20d0
2022-08-27 12:22:08.467 :    GPNP:2807901440: clsgpnpd_openLocalProfile: [at clsgpnpd.c:2472] Valid local profile type 1 p=0x55aa715b20d0 fs_seq=0 olr_seq=5
2022-08-27 12:22:08.468 :    GPNP:2807901440: clsgpnpd_setLockedLBestProfile: [at clsgpnpdcmn.c:285] Result: (0) CLSGPNP_OK. PALocation=
2022-08-27 12:22:08.468 :    GPNP:2807901440: clsgpnpd_setLockedLBestProfile: [at clsgpnpdcmn.c:300] Result: (5) CLSGPNP_NOT_FOUND. DiscoveryVIP=
2022-08-27 12:22:08.468 :    GPNP:2807901440: clsgpnpd_openLocalProfile: [at clsgpnpd.c:2263] Get local pending profile.
2022-08-27 12:22:08.468 :    GPNP:2807901440: clsgpnpd_openLocalProfile: [at clsgpnpd.c:2324] Local OLR profile cache provider (OLR-CP) available, try to get pending profile
2022-08-27 12:22:08.468 :    GPNP:2807901440: clsgpnpco_ocr2profile: [at clsgpnpco.c:578] OLR (r/w) READ profile id=1 ctyp=2
2022-08-27 12:22:08.468 :    GPNP:2807901440: clsgpnpou_checkinitreocr: [at clsgpnpou.c:328] OLR is ready - already open at level 70000 
2022-08-27 12:22:08.472 :    GPNP:2807901440: clsgpnpco_ocr2profile: [at clsgpnpco.c:640] OLR - calling procr_get_value_ext SYSTEM.GPnP.profiles.peer.pending blen=20480
2022-08-27 12:22:08.476 :    GPNP:2807901440: clsgpnpco_ocr2profile: [at clsgpnpco.c:704] Result: (0) CLSGPNP_OK. OLR - profile read (tlen=1928 blen=1929 dt=5)
2022-08-27 12:22:08.477 :    GPNP:2807901440: clsgpnpd_validateProfile: [at clsgpnpdcmn.c:911] Profile p=0x55aa718bc120 ProfileSequence=5.
2022-08-27 12:22:08.478 :    GPNP:2807901440: clsgpnpd_validateProfile: [at clsgpnpdcmn.c:995] Result: (87) CLSGPNP_SIG_VALPEER. Profile verified.  prf=0x55aa718bc120
2022-08-27 12:22:08.478 :    GPNP:2807901440: clsgpnpd_openLocalProfile: [at clsgpnpd.c:2373] Got local profile from OLR cache provider (LCP-OLR).
2022-08-27 12:22:08.478 :    GPNP:2807901440: clsgpnpd_openLocalProfile: [at clsgpnpd.c:2397] Local pending profiles available, compare.
2022-08-27 12:22:08.478 :    GPNP:2807901440: clsgpnpd_openLocalProfile: [at clsgpnpd.c:2415] Local pending file profile (LCP-FS) 0x55aa718bc120 too old.
2022-08-27 12:22:08.478 :    GPNP:2807901440: clsgpnpd_openLocalProfile: [at clsgpnpd.c:2422] Result: (3) CLSGPNP_INIT_FAILED. (:GPNPD00109:)pending profile was not saved in file local cache provider (LCP-FS) p=0x55aa718bc120
2022-08-27 12:22:08.478 :    GPNP:2807901440: clsgpnpd_openLocalProfile: [at clsgpnpd.c:2472] Valid local profile type 2 p=0x55aa718bc120 fs_seq=0 olr_seq=5
2022-08-27 12:22:08.478 :    GPNP:2807901440: clsgpnpd_setBestAsPending: [at clsgpnpdcmn.c:1307] Pending best p=0x55aa718bc120 available, compare with local best p=0x55aa715b20d0.
2022-08-27 12:22:08.478 :    GPNP:2807901440: clsgpnpd_setPending: [at clsgpnpdcmn.c:1402] Result: (3) CLSGPNP_INIT_FAILED. Deleting local pending from FS-CP, old pending p=0x55aa718bc120, seq=5
2022-08-27 12:22:08.478 :    GPNP:2807901440: clsgpnpco_ocrdelprofile: [at clsgpnpco.c:761] OLR (r/w) DELETE profile id=1 ctyp=2
2022-08-27 12:22:08.478 :    GPNP:2807901440: clsgpnpou_checkinitreocr: [at clsgpnpou.c:328] OLR is ready - already open at level 70000 
2022-08-27 12:22:08.490 :    GPNP:2807901440: clsgpnpco_ocrdelprofile: [at clsgpnpco.c:830] Result: (0) CLSGPNP_OK. OLR - profile deleted
2022-08-27 12:22:08.490 :    GPNP:2807901440: clsgpnpd_setPending: [at clsgpnpdcmn.c:1410] Result: (0) CLSGPNP_OK. Deleting local pending from OLR-CP, old pending p=0x55aa718bc120, seq=5
2022-08-27 12:22:08.490 :    GPNP:2807901440: clsgpnpd_openProfile: [at clsgpnpd.c:2561] Result: (0) CLSGPNP_OK. cheked lbest as newer pending 
2022-08-27 12:22:08.491 :    GPNP:2807901440: clsgpnpx_prfGetHostNetInfo: [at clsgpnpx.c:1470] Result: (5) CLSGPNP_NOT_FOUND. profile 0x55aa715b20d0 Network-Profile section: Network info does not specify 'anbob1' host-specific override; there is a generic host info.
2022-08-27 12:22:08.491 :    GPNP:2807901440: clsgpnpx_prfGetNNetIntf: [at clsgpnpx.c:3014] Result: (0) CLSGPNP_OK. returning net {eth0,10.***.**.0,public} 1/64, copyout=1
2022-08-27 12:22:08.491 :    GPNP:2807901440: clsgpnpx_prfGetNNetIntf: [at clsgpnpx.c:3014] Result: (0) CLSGPNP_OK. returning net {eth1,192.***.**.0,asm,cluster_interconnect} 2/64, copyout=1
2022-08-27 12:22:08.492 :    GPNP:2807901440: clsgpnpd_lCheckIpTypes: [at clsgpnpd.c:1657] Profile Networks Definitions - 2 total
2022-08-27 12:22:08.492 :    GPNP:2807901440: clsgpnpd_lFilterIpTypes: [at clsgpnpd.c:1564]   - eth0/10.***.**.0 public (ip=,mask=,mac=,typ=1) 
2022-08-27 12:22:08.492 :    GPNP:2807901440: clsgpnpd_lFilterIpTypes: [at clsgpnpd.c:1564]   - eth1/192.***.**.0 cluster_interconnect,asm (ip=,mask=,mac=,typ=1) 
2022-08-27 12:22:08.492 :    GPNP:2807901440: clsgpnpd_lFilterIpTypes: [at clsgpnpd.c:1581]   of 2 net interfaces, 1 publics (1 ipv4, 0 ipv6), 1 privates (1 ipv4, 0 ipv6).
2022-08-27 12:22:08.494 :    GPNP:2807901440: clsgpnpx_prfGetHostNetInfo: [at clsgpnpx.c:1470] Result: (5) CLSGPNP_NOT_FOUND. profile 0x55aa715b20d0 Network-Profile section: Network info does not specify 'anbob1' host-specific override; there is a generic host info.
2022-08-27 12:22:08.495 :    GPNP:2807901440: clsgpnpx_prfGetNNetIntf: [at clsgpnpx.c:3014] Result: (0) CLSGPNP_OK. returning net {eth0,10.***.**.0,public} 1/64, copyout=1
2022-08-27 12:22:08.495 :    GPNP:2807901440: clsgpnpx_prfGetNNetIntf: [at clsgpnpx.c:3014] Result: (0) CLSGPNP_OK. returning net {eth1,192.***.**.0,asm,cluster_interconnect} 2/64, copyout=1
2022-08-27 12:22:08.495 :    GPNP:2807901440: clsgpnpd_lCheckIpTypes: [at clsgpnpd.c:1694] GPnP Node Network Interfaces - 2 total
2022-08-27 12:22:08.495 :    GPNP:2807901440: clsgpnpd_lFilterIpTypes: [at clsgpnpd.c:1564]   - eth0/10.***.**.0 public (ip=10.***.**.121,mask=255.255.255.0,mac=00-50-56-86-46-6f,typ=1) 
2022-08-27 12:22:08.495 :    GPNP:2807901440: clsgpnpd_lFilterIpTypes: [at clsgpnpd.c:1564]   - eth1/192.***.**.0 cluster_interconnect,asm (ip=192.***.**.121,mask=255.255.255.0,mac=00-50-56-86-53-71,typ=1) 
2022-08-27 12:22:08.495 :    GPNP:2807901440: clsgpnpd_lFilterIpTypes: [at clsgpnpd.c:1581]   of 2 net interfaces, 1 publics (1 ipv4, 0 ipv6), 1 privates (1 ipv4, 0 ipv6).
2022-08-27 12:22:08.495 :    GPNP:2807901440: clsgpnpd_lCheckIpTypes: [at clsgpnpd.c:1728] (:GPNPD00127:) GPnP network interfaces do not use IPv6.
2022-08-27 12:22:08.516 :    GPNP:2807901440: clsgpnpd_lOpen: (:GPNPD00010:)clssecGetPortNumber() returned port=0
2022-08-27 12:22:08.517 :    GPNP:2807901440: clsgpnpd_lOpenEP: [at clsgpnpd.c:1950] Listening on "tcp://0.0.0.0:14912", call address "tcp://anbob1:14912" ipv4
2022-08-27 12:22:08.564 :    GPNP:2807901440: clsgpnpd_assumeRole: [at clsgpnpdbc.c:335] Starting gpnpd in node role "hub" clsuerr=SUCC (0), bcvip="" cnr="hub" tnr="hub" gpnpd cli-nr="auto"
2022-08-27 12:22:08.564 : default:2807901440: GPNPD started on node anbob1. 
2022-08-27 12:22:08.566 :    GPNP:2807901440: clsgpnpd_main: [at clsgpnpd.c:485] --- Local best profile:
2022-08-27 12:22:08.566 :    GPNP:2807901440: clsgpnpd_main: <gpnp:Network-P[cont] 2022-08-27 12:22:08.566 : GPNP:2807901440: clsgpnpd_main: rofile><gpnp:Netw[cont] 2022-08-27 12:22:08.566 : GPNP:2807901440: clsgpnpd_main: ork id="net2" IP="192.***.**.0" Adapter="eth1" Use="asm,cluster_[cont] 2022-08-27 12:22:08.566 : GPNP:2807901440: clsgpnpd_main: interconnect"/><orcl:[cont] 2022-08-27 12:22:08.566 : GPNP:2807901440: clsgpnpd_main: CSS-Profile id="css" DiscoveryString="+asm" LeaseDuration="400"[cont] 2022-08-27 12:22:08.566 : GPNP:2807901440: clsgpnpd_main: /><ds:Canonicalizati[cont] 2022-08-27 12:22:08.566 : GPNP:2807901440: clsgpnpd_main: onMethod Algorithm="http://www.w3.org/2001/10/xml-exc-c14n#"/><[cont] 2022-08-27 12:22:08.566 : GPNP:2807901440: clsgpnpd_main: ds:SignatureMethod Algorithm="http://www.w3.org/2000/09/xmldsig[cont] 2022-08-27 12:22:08.566 : GPNP:2807901440: clsgpnpd_main: #rsa-sha1"/> </ds:Tr[cont] 2022-08-27 12:22:08.566 : GPNP:2807901440: clsgpnpd_main: ansforms>0TkipB0VEUI/eRrudpgJOTIIhi4=</ds[cont] 2022-08-27 12:22:08.566 : GPNP:2807901440: clsgpnpd_main: :DigestValue>[cont]
2022-08-27 12:22:08.566 :    GPNP:2807901440: clsgpnpd_main: NKGpi01KVjBj8XTsrslwj/723WChHqUjLI1ys7q6ET4k4PpJC2b5VY5zACs7UNQ[cont]
2022-08-27 12:22:08.566 :    GPNP:2807901440: clsgpnpd_main: /3LFE4FRM/oDardR9EpOnp3G6nnegZRY1i+0UKDHKCTpuwGaLznOgOwlsSgrqCO[cont]
2022-08-27 12:22:08.566 :    GPNP:2807901440: clsgpnpd_main: MKXkTMWvj5xvbcgh3nzHK/sTVM9DdnDsOreP8ssAwFJW8=</ds:SignatureVal[cont] 2022-08-27 12:22:08.566 : GPNP:2807901440: clsgpnpd_main: ue>
2022-08-27 12:22:08.576 :   CLSNS:2807901440: clsns_SetTraceLevel:trace level set to 1

GIPC TRACE

2022-08-27 02:20:21.829 :GIPCHGEN:742008576:  gipchaInternalGetActiveSoftVersion: active software version 19.0.0.0.0 [318767104]
2022-08-27 02:20:21.829 : GIPCGEN:742008576:  gipchaInternalIsDualPortODA: hctx->activeVersion 318767104, vsnNum 301989888, hctx 0x55dd44b33490 [0000000000000011] { gipchaContext : host 'anbob1', name 'gipcd_ha_name', luid '', name2 , numNode 0, numInf 0, maxPriority 0, clientMode 1, nodeIncarnation 00000000-00000000 usrFlags 0x0, flags 0x1c000 }
2022-08-27 02:20:21.870 :GIPCHGEN:742008576:  gipchaNodeCreate: adding new node 0x7f170c12d2e0 { host '', haName 'gipcd_ha_name', srcLuid d0b23286-00000000, dstLuid 00000000-00000000 numInf 0, sentRegister 0, localMonitor 0, baseStream 0x7f170c132290 type gipchaNodeType12001 (20), nodeIncarnation 00000000-00000000, incarnation 0, cssIncarnation 0, negDigest 4294967295, roundTripTime 4294967295 lastSeenPingAck 0 nextPingId 1 latencySrc 0 latencyDst 0 flags 0x200001}
2022-08-27 02:20:21.881 :GIPCXCPT:742008576:  gipchaInternalReadGpnp: No HAIP network info configured in GPNP profile, using defaults, ret gipcretFail (1)
2022-08-27 02:20:21.881 :GIPCHGEN:742008576:  gipchaInternalReadGpnp: configuring default IPV4 multicast addresses
2022-08-27 02:20:21.881 :GIPCHGEN:742008576:  gipchaInternalReadGpnp: configuring default IPV6 multicast addresses
2022-08-27 02:20:21.881 :GIPCHGEN:742008576:  gipchaInternalReadGpnp: configuring default bootstrap communications modes
2022-08-27 02:20:21.881 :GIPCHGEN:742008576:  gipchaInternalReadGpnp: configuring bootstrap communications using:  broadcast and multicast
2022-08-27 02:20:21.881 :GIPCHGEN:742008576:  gipchaInternalReadGpnp: mcast address[  0 ]  224.0.0.251
2022-08-27 02:20:21.882 :GIPCHGEN:742008576:  gipchaInternalReadGpnp: mcast address[  1 ]  230.0.1.0
2022-08-27 02:20:21.882 :GIPCHGEN:742008576:  gipchaInternalReadGpnp: mcast address[  0 ]  [FF02::FB]
2022-08-27 02:20:21.882 :GIPCHGEN:742008576:  gipchaGetClusterMode: gipchaGetClusterMode():REGULAR Cluster mode
2022-08-27 02:20:21.890 :    GIPC:742008576:  gipchaInternalRegister: TLS flag 1
2022-08-27 02:20:21.892 :GIPCHTHR:520029952:  gipchaWorkerThread: starting worker thread hctx 0x55dd44b33490 [0000000000000011] { gipchaContext : host 'anbob1', name 'gipcd_ha_name', luid 'd0b23286-00000000', name2 6198-df2a-6e33-8f25, numNode 0, numInf 0, maxPriority 0, clientMode 1, nodeIncarnation 00000000-00000000 usrFlags 0x0, flags 0x5c860 }
2022-08-27 02:20:21.893 : GIPCLIB:520029952:  gipclibGetClusterGuid: retrieved cluster guid 77afe26a92c6cfdfff124fc8ba403843
2022-08-27 02:20:21.894 :    GIPC:520029952:  gipcdsContextInitialize: no subscriber using the existing map file smem://gipcDS_anbob1_gipcd_77afe26a92c6cfdfff124fc8ba403843_gipc_diag
2022-08-27 02:20:21.895 :    GIPC:520029952:  gipcdsInitializeF: gipcds init successful
2022-08-27 02:20:21.897 :GIPCHDEM:517928704:  gipchaDaemonThread: starting daemon thread hctx 0x55dd44b33490 [0000000000000011] { gipchaContext : host 'anbob1', name 'gipcd_ha_name', luid 'd0b23286-00000000', name2 6198-df2a-6e33-8f25, numNode 0, numInf 0, maxPriority 0, clientMode 1, nodeIncarnation 00000000-00000000 usrFlags 0x0, flags 0x5c860 }
2022-08-27 02:20:21.902 : GIPCLIB:517928704:  gipclibGetClusterGuid: retrieved cluster guid 77afe26a92c6cfdfff124fc8ba403843
2022-08-27 02:20:21.902 :GIPCHDEM:517928704:  gipchaDaemonConnect: connecting to daemon addr ipc://gipcd_anbob1
2022-08-27 02:20:22.126 :    GPNP:517928704:  clsgpnp_InitLocalPrfCacheProvs: [at clsgpnp0.c:5417] Result: (1) CLSGPNP_ERR. (:GPNP00258:)Error initializing gpnp local profile cache provider 1 of 2 (LCP-FS).
2022-08-27 02:20:22.131 :GIPCHGEN:517928704:  gipchaNodeMarkInfAsTransientF [gipchaDaemonCheckInterfaces : gipchaDaemonThread.c : 7428]: marking infs of node 0x7f170c12d2e0 { host '', haName 'gipcd_ha_name', srcLuid d0b23286-00000000, dstLuid 00000000-00000000 numInf 0, sentRegister 0, localMonitor 0, baseStream 0x7f170c132290 type gipchaNodeType12001 (20), nodeIncarnation 00000000-00000000, incarnation 0, cssIncarnation 0, negDigest 4294967295, roundTripTime 4294967295 lastSeenPingAck 0 nextPingId 1 latencySrc 0 latencyDst 0 flags 0x200001} as TRANSIENT
2022-08-27 02:20:22.131 :GIPCHGEN:517928704:  gipchaNodeAddInterfaceF [gipchaDaemonCheckInterfaces : gipchaDaemonThread.c : 7466]: adding interface info 0x7f16fc1bcaf0 { host '', haName 'gipcd_ha_name', local (nil), ip '192.***.**.121', subnet '192.***.**.0', mask '255.255.255.0', mac '00-50-56-86-53-71', ifname 'eth1', numRef 0, numFail 0, idxBoot 0, flags 0x1841 }
2022-08-27 02:20:22.131 :GIPCHDEM:517928704:  gipchaDaemonProcessClientReq: processing req 0x7f170c149dc0 type gipchaClientReqTypePublish (1)
2022-08-27 02:20:22.132 :GIPCHTHR:520029952:  gipchaWorkerCreateInterface: created local interface for node 'anbob1', haName 'gipcd_ha_name', inf 'udp://192.***.**.121:21264' inf 0x7f16fc1bcaf0
2022-08-27 02:20:22.133 :GIPCHTHR:520029952:  gipchaWorkerCreateInterface: created local bootstrap multicast interface for node 'anbob1', haName 'gipcd_ha_name', inf 'mcast://224.0.0.251:42424/192.***.**.121' inf 0x7f16fc1bcaf0
2022-08-27 02:20:22.133 :GIPCHTHR:520029952:  gipchaWorkerCreateInterface: created local bootstrap multicast interface for node 'anbob1', haName 'gipcd_ha_name', inf 'mcast://230.0.1.0:42424/192.***.**.121' inf 0x7f16fc1bcaf0
2022-08-27 02:20:22.133 :GIPCHTHR:520029952:  gipchaWorkerCreateInterface: created local bootstrap broadcast interface for node 'anbob1', haName 'gipcd_ha_name', inf 'udp://192.***.**.255:42424' inf 0x7f16fc1bcaf0
2022-08-27 02:20:22.133 :GIPCHDEM:517928704:  gipchaDaemonProcessClientReq: processing req 0x7f170806d790 type gipchaClientReqTypeInfPublish (7)
2022-08-27 02:20:22.151 : default:742008576: Inited LSF context: 0x7f170c150c50 
2022-08-27 02:20:22.167 : CLSCRED:742008576: clsCredCommonInit: Inited singleton credctx.
2022-08-27 02:20:22.167 : GIPCTLS:742008576:  gipcmodTlsGetWalletObjFromCred: using rootCredDomName: NULL, baseCredDomName:nodecert
2022-08-27 02:20:22.177 : GIPCTLS:742008576:  gipcmodTlsGetWalletObjFromCred: found base dom: nodecert
2022-08-27 02:20:22.187 :GIPCXCPT:742008576:  gipcmodTlsGetWalletObjFromCred: invalid certificate count[! = 1]in credSet:0, ret gipcretBadArg (37)
2022-08-27 02:20:22.188 : default:742008576: clsCredDomClose: Credctx deleted 0x7f170c0bd7f0   
2022-08-27 02:20:22.188 :GIPCXCPT:742008576:  gipcListenF [gipcdNodeThread : gipcdNodeThread.c : 5433]: EXCEPTION[ ret gipcretBadArg (37) ]  failed to listen on endp 0x7f170c0addc0 [0000000000000540] { gipcEndpoint : localAddr 'gipcha://anbob1:gipcdha_anbob1_', remoteAddr '', numPend 1, numReady 0, numDone 0, numDead 0, numTransfer 0, objFlags 0x0, pidPeer 0, readyRef (nil), ready 0, wobj 0x7f170c0c5180, sendp (nil) status 13flags 0x20038602, flags-2 0x10, usrFlags 0x0 }, flags 0x0
2022-08-27 02:20:22.188 :GIPCDNDE:742008576:  gipcdNodeThread: gipcListen() failed (37) on endp 0000000000000540    
2022-08-27 02:20:22.188 :GIPCDNDE:742008576:  gipcdNodeThreadShutdown: deleting all the peer connections
2022-08-27 02:20:22.188 : GIPCTLS:742008576:  gipcmodTlsDisconnect: [tls] disconnect issued on endp 0x7f170c0addc0 [0000000000000540] { gipcEndpoint : localAddr 'gipcha://anbob1:gipcdha_anbob1_', remoteAddr '', numPend 1, numReady 0, numDone 0, numDead 0, numTransfer 0, objFlags 0x0, pidPeer 0, readyRef (nil), ready 0, wobj 0x7f170c0c5180, sendp (nil) status 13flags 0x26038602, flags-2 0x10, usrFlags 0x0 }
2022-08-27 02:20:22.188 :GIPCGMOD:742008576:  gipcmodGipcDisconnect: [gipc]  Issued endpoint close for endp 0x7f170c0addc0 [0000000000000540] { gipcEndpoint : localAddr 'gipcha://anbob1:gipcdha_anbob1_', remoteAddr '', numPend 1, numReady 0, numDone 0, numDead 0, numTransfer 0, objFlags 0x0, pidPeer 0, readyRef (nil), ready 0, wobj 0x7f170c0c5180, sendp (nil) status 13flags 0x26038602, flags-2 0x10, usrFlags 0x0 }
2022-08-27 02:20:22.189 :   GIPCD:938990848:  gipcdMain: invalid status of gipcd Threads. Status of clientThread gipcdThreadStatusReady  Status of nodeThread gipcdThreadStatusInit Status of monitorThread gipcdThreadStatusReady 
2022-08-27 02:20:22.189 :   GIPCD:742008576:  gipcdSetThreadState: changing the status of nodeThread. current status gipcdThreadStatusInit desired status gipcdThreadStatusOffline
2022-08-27 02:20:22.189 :   GIPCD:526378752:  gipcdThreadWait: GIPCD received a shutdown msg from agent framework or client/node/monitor thread died
2022-08-27 02:20:22.189 :GIPCDNDE:742008576:  gipcdNodeThread: Node thread has exited
2022-08-27 02:20:22.189 :GIPCDMON:526378752:  gipcdMonitorThread: clientThread/nodeThread did not came into 'READY' state 
2022-08-27 02:20:22.189 :   GIPCD:744109824:  gipcdThreadWait: GIPCD received a shutdown msg from agent framework or client/node/monitor thread died
2022-08-27 02:20:22.189 :GIPCDCLT:744109824:  gipcdClientThread: nodeThread/moniTorThread did not came into 'READY' State
2022-08-27 02:20:22.190 :   GIPCD:524277504:  gipcdThreadWait: GIPCD received a shutdown msg from agent framework or client/node/monitor thread died
2022-08-27 02:20:22.190 :GIPCDEVENT:524277504:  gipcdEventThread: clientThread/nodeThread/monitorThread did not came into 'READY' state 
2022-08-27 02:20:22.190 :   GIPCD:524277504:  gipcdSetThreadState: changing the status of eventThread. current status gipcdThreadStatusReady desired status gipcdThreadStatusOffline
2022-08-27 02:20:22.190 :GIPCDEVENT:524277504:  gipcdEventThread: Event thread is exiting..
2022-08-27 02:20:22.190 :   GIPCD:526378752:  gipcdSetThreadState: changing the status of monitorThread. current status gipcdThreadStatusReady desired status gipcdThreadStatusOffline
2022-08-27 02:20:22.190 :GIPCDMON:526378752:  gipcdMonitorThread: Monitor thread is exiting..
2022-08-27 02:20:22.190 :   GIPCD:744109824:  gipcdSetThreadState: changing the status of clientThread. current status gipcdThreadStatusReady desired status gipcdThreadStatusOffline
2022-08-27 02:20:22.190 :GIPCDCLT:744109824:  gipcdClientThread: Client thread has exited
2022-08-27 02:20:22.191 :GIPCHGEN:517928704:  gipchaNodeMarkInfAsTransientF [gipchaDaemonProcessDisconnect : gipchaDaemonThread.c : 7071]: marking infs of node 0x7f170c12d2e0 { host '', haName 'gipcd_ha_name', srcLuid d0b23286-00000000, dstLuid 00000000-00000000 numInf 1, sentRegister 0, localMonitor 0, baseStream 0x7f170c132290 type gipchaNodeType12001 (20), nodeIncarnation 00000000-00000000, incarnation 0, cssIncarnation 0, negDigest 4294967295, roundTripTime 4294967295 lastSeenPingAck 0 nextPingId 1 latencySrc 0 latencyDst 0 flags 0x200001} as TRANSIENT
2022-08-27 02:20:22.194 :GIPCHGEN:517928704:  gipchaNodeMarkInfAsTransientF [gipchaDaemonCheckInterfaces : gipchaDaemonThread.c : 7428]: marking infs of node 0x7f170c12d2e0 { host '', haName 'gipcd_ha_name', srcLuid d0b23286-00000000, dstLuid 00000000-00000000 numInf 1, sentRegister 0, localMonitor 0, baseStream 0x7f170c132290 type gipchaNodeType12001 (20), nodeIncarnation 00000000-00000000, incarnation 0, cssIncarnation 0, negDigest 4294967295, roundTripTime 4294967295 lastSeenPingAck 0 nextPingId 1 latencySrc 0 latencyDst 0 flags 0x200001} as TRANSIENT
2022-08-27 02:20:22.194 :GIPCHGEN:517928704:  gipchaNodeAddInterfaceF: recovered TRANSIENT inf 0x7f16fc1bcaf0 { host '', haName 'gipcd_ha_name', local (nil), ip '192.***.**.121:21264', subnet '192.***.**.0', mask '255.255.255.0', mac '00-50-56-86-53-71', ifname 'eth1', numRef 0, numFail 0, idxBoot 0, flags 0x184d }
2022-08-27 02:20:22.198 :   GIPCD:938990848:  gipcdMain: All threads terminated
2022-08-27 02:20:22.198 :   GIPCD:938990848:  gipcdMain: GIPCD terminated

提示:
gipcdNodeThread: gipcListen() failed (37) 根据报错信息在MOS中唯一找到相匹配的是GPNPPROFILE中的node name长度超过15个字符, 已确认本案例node name不足15位, 怀疑是传参数就会报37 code,如长于15 或是null, 那就是有可能没有取到node name,也就是gpnp 取值失败。

除了 ($GRID_HOME/gpnp/$HOSTNAME/profiles/peer/profile.xml) 下的 profile.xml 文件和 OCR 之外,GI 还在多个位置缓存 profile.xml。OLR($GRID_HOME/cdata/$HOSTNAME.olr) 是另一个位置。

当 gpnpd 尝试出现时,它会从位置(olr、ocr、profile.xml)中寻找best profile。而我对best profile的理解是 ProfileSequence 最高的配置文件。然后这个“best profile”会覆盖其他缓存的较低版本。

Grid Plug and Play (GPnP) 11g 第 2 版 (11.2) 中的一个新特性,它主要由网格即插即用守护程序 (GPnPD)。 GPnPD 提供对 GPnP 配置文件的访问,并在集群的节点之间协调对配置文件的更新,以确保所有节点都具有最新的配置文件。

GPnP 配置分为 profile 和 wallet,每个节点是相同的,在安装CLUSTER时有OUI创建和复制(root script) ,。 GPnP profile文件是一个 XML 测试文件,其中包含形成集群所需的引导信息: 集群名称、GUID、发现字符串、预期的网络连接等信息。 它不包含特定于节点的内容。 切勿直接更改 XML 文件; 相反,使用支持的工具,如 OUI、ASMCA、asmcd、oifcfg 等来修改 GPnP 配置文件信息。不鼓励使用 gpnptool 更改 GPnP 配置文件,因为必须执行多个步骤才能修改。该配置文件由 GPnPD 管理,它存在于 GPnP 缓存中的每个节点上。 当配置文件没有更新时,它在所有集群节点上都是相同的。 判断最佳配置文件的方式是通过序列号ProfileSequence.

GPnP  wallet钱包只是一个包含公共/私有 RSA 密钥的二进制 blob,用于签署和验证 GPnP 配置文件。 钱包对于所有 GPnP 对等点都是相同的,并且一旦由 Oracle 通用安装程序创建; 它永远不会改变并且永远存在。

Grid Interprocess Communication   (GIPC) 是一种新的通用communications infrastructure,用于替代 CLSC/NS。 它提供了对从操作系统到使用它的任何客户端库的通信堆栈的完全控制。 删除了对 11.2 之前的网络服务 (NS) 的依赖,GIPC可以支持多种通信类型:CLSC、TCP、UDP、IPC和通信类型GIPC。
使用 GIPC 监听端点的配置略有不同。相同接口在所有节点上以相同名称存在的要求更加宽松,只要建立通信即可。

Oracle Local Registry (OLR) OLR 在结构上与 OCR 类似,是一个节点本地存储库,由 OHASD 管理。 OLR 中的配置数据只属于本地节点,不与其他节点共享。配置存储在“/etc/oracle/olr.loc”(Linux 上)或其他操作系统上的等效项中。

使用cluvfy 工具验证RAC安装时发现提示少文件,看来这个环境安装时应该是带着报错安装完成的,同时从日志中可也有提示gpnp profile 不存在,但是另一节点的gpnp profile xml也不存在, 当不存在会从olr 获取,在11g是会自动生成文件,这套19c环境并没有生成,不确认是否是版本行为改变。

解决方法:
手动创建gpnp profile xml文件

gpnptool get -o=/tmp/p.xml
cp /tmp/p.xml  /u01/app/19c/grid/gpnp//profiles/peer/profile.xml

打赏

目前这篇文章还没有评论(Rss)

我要评论