Shulou(Shulou.com)05/31 Report--

This article mainly introduces "how to solve the ORA-12547: TNS:lost contact error encountered when 12cRAC makes quarterly patches". In daily operation, I believe many people have doubts about how to solve the problem of ORA-12547: TNS:lost contact errors encountered when 12cRAC fixes quarterly patches. The editor consulted all kinds of materials and sorted out simple and easy-to-use methods of operation. I hope it will be helpful for you to answer the question "how to solve the problem that 12cRAC encountered ORA-12547: TNS:lost contact error when making quarterly patches"! Next, please follow the editor to study!

I. description of the environment:

Operating system: RHEL7.4

Database version: 12.2.0.1

Patched: quarterly patch for October 2019

Due to confidentiality, the relevant naming and IP have been changed

Second, problem description

In the quarterly patch of GI, after node 1 runs opatchauto apply, CRS shuts down normally, but when the CRS is pulled automatically, ORA-12547: TNS:lost contact reports an error, which causes the patch to fail.

The details are as follows:

CRS-4123: Starting Oracle High Availability Services-managed resourcesCRS-2672: Attempting to start 'ora.mdnsd' on' db1'CRS-2672: Attempting to start 'ora.evmd' on' db1'CRS-2676: Start of 'ora.mdnsd' on' db1' succeededCRS-2676: Start of 'ora.evmd' on' db1' succeededCRS-2672: Attempting to start 'ora.gpnpd' on' db1'CRS-2676: Start of 'ora.gpnpd' on' db1' succeededCRS-2672: Attempting to start 'ora.gipcd' on' db1' CRS-2676: Start of 'ora.gipcd' on' db1' succeededCRS-2672: Attempting to start' ora.cssdmonitor' on' db1'CRS-2676: Start of 'ora.cssdmonitor' on' db1' succeededCRS-2672: Attempting to start' ora.cssd' on' db1'CRS-2672: Attempting to start 'ora.diskmon' on' db1'CRS-2676: Start of' ora.diskmon' on' db1' succeededCRS-2676: Start of 'ora.cssd' on' db1' succeededCRS-2672: Attempting to start' ora.cluster_ Interconnect.haip' on 'db1'CRS-2672: Attempting to start' ora.ctssd' on 'db1'CRS-2676: Start of' ora.ctssd' on 'db1' succeededCRS-2676: Start of' ora.cluster_interconnect.haip' on 'db1' succeededCRS-2672: Attempting to start' ora.asm' on 'db1'CRS-2676: Start of' ora.asm' on 'db1' succeededCRS-2672: Attempting to start' ora.storage' on 'db1'ORA-12547: TNS:lost contactORA-12547: TNS:lost contactORA -15077: could not locate ASM instance serving a required diskgroupCRS-2883: Resource 'ora.storage' failed during Clusterware stack start.CRS-4406: Oracle High Availability Services synchronous start failed.CRS-4000: Command Start failed Or completed with errors.2020/06/10 16:46:12 CLSRSC-117: Failed to start Oracle Clusterware stack After fixing the cause of failure Run opatchauto resume] OPATCHAUTO-68061: The orchestration engine failed.OPATCHAUTO-68061: The orchestration engine failed with return code 1OPATCHAUTO-68061: Check the log for more details.OPatchAuto failed.OPatchauto session completed at Wed Jun 10 16:46:13 2020Time taken to complete the session 17 minutes, 25 seconds opatchauto failed with error code 42

Call crsctl check crs to view the cluster service and find Cluster Ready Services and Event Manager exceptions. Check the / u01/app/grid/diag/crs/db1/crs/trace/alert.log log and find the following information:

2020-06-10 16 ORAROOTAGENT 3615 [ORAROOTAGENT (679524)] CRS-5019: All OCR locations are on ASM disk groups [OCR], and none of these disk groups are mounted. Details are at "(: CLSN00140:)" in "/ u01/app/grid/diag/crs/db1/crs/trace/ohasd_orarootagent_root.trc". 2020-06-10 16 in 45 Details are at 58.112 [ORAROOTAGENT (679524)] CRS-5818: Aborted command 'start' for resource' ora.storage'. Details at (: CRSAGF00113:) {0:5:3} in / u01/app/grid/diag/crs/db1/crs/trace/ohasd_orarootagent_root.trc.2020-06-10 1615 4615 00.427 [ORAROOTAGENT (679524)] CRS-5017: The resource action "ora.storage start" encountered the following error: 2020-06-10 16:46:00.427+Storage agent start action aborted. For details refer to "(: CLSN00107:)" in "/ u01/app/grid/diag/crs/db1/crs/trace/ohasd_orarootagent_root.trc". 2020-06-10 16 For details refer to 46V 00.429 [OHASD (679429)] CRS-2757: Command 'Start' timed out waiting for response from the resource' ora.storage'. Details at (: CRSPE00221:) {0:5:3} in / u01/app/grid/diag/crs/db1/crs/trace/ohasd.trc.2020-06-10 16 purl 47 purl 12.689 [OSYSMOND (684959)] CRS-8500: Oracle Clusterware OSYSMOND process is starting with operating system process ID 684959

/ u01/app/grid/diag/crs/db1/crs/trace/ohasd_orarootagent_root.trc log is as follows:

2020-06-09 16 StorageAgent::parsekgforetcodes retcode 34 StorageAgent::parsekgforetcodes retcode = 0, kgfoCheckMount (OCR), flag 42020-06-09 16 34 CLSDYNAM:3429529344: CLSDYNAM:3440035584: [check] StorageAgent::check kgfo returncode 02020-06-09 1634 Check return = 0: CLSDYNAM:3429529344: [ora.crf] {0:5:3} [check] Check return = 0 State detail = NULL2020-06-09 16gh34 check 15.926: CLSDYNAM:2525263616: [ora.ctssd] {0:5:3} [check] translateReturnCodes, return = 0 State detail = OBSERVERCheckcb data [0x7f2369c293d0]: mode [0xee] offset [0 ms]. 2020-06-09 16 Suzhou 3419. 107: CLSDYNAM:3425326848: [ora.drivers.acfs] {0:0:2} [check] Arg Value = check2020-06-09 16 16 check2020-06-09 16 check2020-06-09 16 16 [check] Utils::getOracleHomeAttrib getEnvVar oracle_home:/u01/app/12.2.0/grid2020-06-09 16 : 34Utils::getOracleHomeAttrib oracle_home:/u01/app/12.2.0/grid2020 19.107: CLSDYNAM:3425326848: [ora.drivers.acfs] {0:0:2} [check] Utils::getOracleHomeAttrib oracle_home:/u01/app/12.2.0/grid2020-06-09 16ambigu.34ambigu19.107: CLSDYNAM:3425326848: [ora.drivers.acfs] {0:0:2} [check] Utils::execCmd 1 USR_ORA_ENV: oracleHome:/u01/app/12.2.0/grid CrsHome:/u01/app/12.2 .0 / grid2020-06-09 16gh34 check 19.107: CLSDYNAM:3425326848: [ora.drivers.acfs] {0:0:2} [check] Adding Environment Variables ORA_DAEMON_LOGGING_LEVELS=GIPCLIB=2 GIPC=2,GIPCGEN=2,GIPCTRAC=2,GIPCWAIT=2,GIPCXCPT=2,GIPCOSD=2,GIPCBASE=2,GIPCCLSA=2,GIPCCLSC=2,GIPCEXMP=2,GIPCGMOD=2,GIPCHEAD=2,GIPCMUX=2,GIPCNET=2,GIPCNULL=2,GIPCPKT=2,GIPCSMEM=2,GIPCHAUP=2,GIPCHALO=2,GIPCHTHR=2,GIPCHGEN=2,GIPCHLCK=2,GIPCHDEM=2,GIPCHWRK=2,GIPCTLS=2,GIPCHGNS=22020-06-09 16 ora.drivers.acfs 3419. 107: CLSDYNAM:3425326848: [ora.drivers.acfs] {0:0:2} [check] Adding Environment Variables ORA_DAEMON_TRACE_FILE_OPTIONS=filesize=26214400 Numsegments=102020-06-09 16 check 34 IS_HASD_AGENT=2020 19.107: CLSDYNAM:3425326848: [ora.drivers.acfs] {0:0:2} [check] Adding Environment Variables _ ORA_AGENT_ACTION=TRUE2020-06-09 16 34 ora.drivers.acfs 19.107: CLSDYNAM:3425326848: [ora.drivers.acfs] {0:0:2} [check] Adding Environment Variables _ _ IS_HASD_AGENT=2020-06-09 1634 34 Switzerland 19.107: CLSDYNAM:3425326848: [ora.drivers.acfs] {0:0:2 } [check] Utils:execCmd action = 3 flags = 6 ohome = (null) cmdname = acfsload. 2020-06-09 16 Utils::getOracleHomeAttrib getEnvVar oracle_home:/u01/app/12.2.0/grid2020 3419. 108: CLSDYNAM:3425326848: [ora.drivers.acfs] {0:0:2} [check] Utils::getOracleHomeAttrib getEnvVar oracle_home:/u01/app/12.2.0/grid2020-06-09 16 14: 34 19. 108: CLSDYNAM:3425326848: [ora.drivers.acfs] {0:0:2} [check] Utils::getOracleHomeAttrib oracle_home:/u01/app/12.2.0/grid2020-06-09 16:34: 19.219: CLSDYNAM:3425326848: [ora.drivers.acfs] {0:0:2} [check] execCmd ret = 02020-06-09 16 purge 34execCmd ret 20.911: CLSDYNAM:3427428096: [ora.driver.afd] {0:0:2} [check] Utils:execCmd action = 3 flags = 38 ohome = (null) cmdname = afddriverstate. 2020-06-09 16 Frey 34 Utils::getOracleHomeAttrib getEnvVar oracle_home:/u01/app/12.2.0/grid2020 20.911: CLSDYNAM:3427428096: [ora.driver.afd] {0:0:2} [check] Utils::getOracleHomeAttrib getEnvVar oracle_home:/u01/app/12.2.0/grid2020-06-09 16 purge 34 Utils::getOracleHomeAttrib getEnvVar oracle_home:/u01/app/12.2.0/grid2020 20.911: CLSDYNAM:3427428096: [ora.driver.afd] {0:0:2} [check] Utils::getOracleHomeAttrib oracle_home:/u01/app/12.2.0/grid2020-06-09 16:34: 21.121: CLSDYNAM:3427428096: [ora.driver.afd] {0:0:2} [check] execCmd ret = 02020-06-09 16purl 34demon22.763: USRTHRD:2548033280: {0:5:3} Check: 0-12020-06-09 16demons26.337: AGFW:3435833088: {0:0:2} Agent received the message: AGENT_ HB [engine] ID 12293MOT20865052020-06-09 1634Flt 32.281: CLSDMC:3425326848: command 0 Failed with status 168432652020-06-09 16ambigu340 32.282: CLSDYNAM:3425326848: [ora.crsd] {0:1:52} [check] DaemonAgent::check returned 02020-06-09 16Freder34demon32.282: CLSDYNAM:3425326848: [ora.crsd] {0:1:52} [check] DaemonAgent::check checkErrorCode=16843265 Pestate=512,perole=65536, pemode=12020-06-09 16Frey 34ora.storage 38.611: CLSDYNAM:3427428096: [ora.storage] {0VERV 1VR 251} [check] StorageAgent::check NODEROLE_HUB getOCRdetails2020-06-0916VOUR 34MAV 38.686: CLSDYNAM:3427428096: [ora.storage] {0VERV 1VR 251} [check] StorageAgent::parsekgforetcodes retcode = 0, kgfoCheckMount (OCR) Flag 22020-06-09 16 check 341. 239: CLSDYNAM:3444238080: [ora.crf] {0:5:3} [check] Check return = 0, state detail = NULL2020-06-09 16 34 CLSDYNAM:3444238080: CLSDYNAM:3444238080: [ora.ctssd] {0:5:3} [check] translateReturnCodes, return = 0 State detail = OBSERVERCheckcb data [0x7f23baa99360]: mode [0xee] offset [0 ms]. 2020-06-09 16 AGENT_ 3414: 52.763: USRTHRD:2548033280: {0:5:3} Check: 0-12020-06-09 16 34 32: 56.341: AGFW:3435833088: {0:0:2} Agent received the message: AGENT_ HB [engine] ID 12293 22 2086522 2020-06-09 16 35 Switzerland 02.285: CLSDMC:2525263616: command 0 failed with status 16843265 2020-06-09 : 02.285: CLSDYNAM:2525263616: [ora.crsd] {0:1:52} [check] DaemonAgent::check returned 0

Third, fault analysis

As can be seen from the alarm log, the CRS process failed to recognize that the mount of the OCR disk caused the CRS service to fail to start.

An attempt was made to start the ASM instance manually, and CRS started successfully:

Sqlplus / as sysasmstartup

The call to the crsctl start crs,ASM instance after CRS is closed can not be started automatically, and can only be done through startup.

Check the / u01/app/grid/diag/crs/db1/crs/trace/crsd.trc log and find the following information:

2020-06-10 16:48:24.867*:kgfn.c@1370: kgfnFindLocalNode: found no members2020-06-10 16 OCRRAW:633798784: 24. 867: OCRRAW:633798784: kgfnFindLocalNode: not ok2020-06-10 16:48:24.867*:kgfn.c@1422: kgfnFindLocalNode: not ok2020-06-10 16 14: 24. 867: OCRRAW:633798784: kgfnTgtInit: local node not found Free kgfnpds2020-06-10 16:48:24.867*:kgfn.c@2208: kgfnTgtInit: not found2020-06-10 16 bank 48 purl 24.867: OCRRAW:633798784: kgfnGetBeqData failed init target Inst= (null) flags=0x60002020-06-10 16:48:24.867*:kgfn.c@5791: kgfnGetBeqData: kgfnTgtInit failed Inst=NULL flags=0x60002020-06-10 16 inst=NULL flags=0x60002020-06-10 16 OCRRAW:633798784: 8154 Error 4 querying length of attr ASM_DISCOVERY_ADDRESS2020-06-10 16 16 OCRRAW:633798784: 24.904: OCRRAW:633798784: 8154 Error 4 querying length of attr ASM_STATIC_DISCOVERY_ADDRESS2020-06-10 16 16 opening dom root in 0x5fb60d02020 24.940: OCRRAW:633798784: 7872 Error 4 opening dom root in 0x5fb60d02020-06-10 16 : 48 16:48:24.958*:kgfn.c@5012 24.958: OCRRAW:633798784: kgfnConnect2: kgfnGetBeqData failed2020-06-10 16:48:24.958*:kgfn.c@5012: kgfnConnect2: kgfnGetBeqData failed2020-06-10 16 purge 48V 24.992: OCRRAW:633798784: kgfnConnect2Int: cstr= (DESCRIPTION= (TCP_USER_TIMEOUT=1) (TRANSPORT_CONNECT_TIMEOUT=60) (EXPIRE_TIME=1) (ADDRESS_LIST= (LOAD_BALANCE=ON) (ADDRESS= (PROTOCOL=tcp) (HOST=10.10.10.43) (PORT=1526) (CONNECT_DATA= (SERVICE_NAME=+ASM)) 2020 -06-10 16:48:24.992*:kgfn.c@6788: kgfnConnect2Int: cstr= (DESCRIPTION= (TCP_USER_TIMEOUT=1) (TRANSPORT_CONNECT_TIMEOUT=60) (EXPIRE_TIME=1) (ADDRESS_LIST= (LOAD_BALANCE=ON) (ADDRESS= (PROTOCOL=tcp) (HOST=10.10.10.43) (PORT=1526) (CONNECT_DATA= (SERVICE_NAME=+ASM) 2020-06-10 16 lance 4824. 993: OCRRAW:633798784: kgfnConnect2Int: ServerAttach2020-06-10 16 purse 48 24. 993 purl kgfn.c @ 6811: kgfnConnect2Int: OCIServerAttach failedFailed to connect to ASM 100 (nil) 02020-06-10 16 OCRRAW:633798784 4815 25.994: OCRRAW:633798784: kgfnRecordErr 12547 OCI error:ORA-12547: TNS:lost contact2020-06-10 16:48:25.994*:kgfn.c@1740: kgfnRecordErrPriv: 12547 error=ORA-12547: TNS:lost contact2020-06-10 16 16 OCRRAW:633798784: kgfnConnect2: failed to connect2020-06-10 16:48:25.995*:kgfn.c@5333: kgfnConnect2: Failed to connect2020-06-10 16 kgfnConnect2Retry 48V 25.995: OCRRAW:633798784: kgfnConnect2Retry: failed to connect connect after 2 attempts 331s elapsed2020-06-10 161s elapsed2020-06-10 16V 48V 25.995: OCRRAW:633798784: kgfo_kge2slos error stack at kgfoAl06: ORA-12547: TNS:lost contact

ORA-12547: the error reported by TNS:lost contact appears in the log file, and the error is caused by a failure to access the private network IP10.10.10.43 1526 port.

Fourth, the cause of the problem

Port 1526 runs on ASMNET1LSNR_ASM snooping. In 12cRAC, starting with FLEXASM, crsd.bin uses ASMNET1LSNR_ASM snooping for remote connections. Port 1526 on 10.10.10.43 will be connected.

So why did port 1526 of Node 2 fail?

Looking at the sqlnet.ora configuration of node 2, it is found that the whitelist is configured, but the private network IP of node 1 is not added.

V. Solutions

1) Modify the file sqlnet.oravi $GRID_HOME/network/admin/sqlnet.ora2) Add the IP which are used for Private interconnect.e.g.TCP.VALIDNODE_CHECKING = YESTCP.INVITED_NODES= (node1.localhost, node2.localhost,node1-priv.localhost,node2-priv.localhost, node1-vip.localhost, node2-vip.localhost, application server VIPS) 3) Restart the CRS in issue node. At this point, the study on "how to solve the ORA-12547: TNS:lost contact error encountered when 12cRAC makes quarterly patches" is over. I hope to be able to solve everyone's doubts. The collocation of theory and practice can better help you learn, go and try it! If you want to continue to learn more related knowledge, please continue to follow the website, the editor will continue to work hard to bring you more practical articles!

Welcome to subscribe "Shulou Technology Information " to get latest news, interesting things and hot topics in the IT industry, and controls the hottest and latest Internet news, technology news and IT industry trends.