GI rootupgrade.sh failure due to OCR import: CRS-1111: Error upgrading the Oracle Clusterware. Details [Upgrade Coordinator failed] (Doc ID 2195551.1)

Last updated on OCTOBER 22, 2016

Applies to:

Oracle Database - Enterprise Edition - Version 11.2.0.3 to 12.1.0.2 [Release 11.2 to 12.1]
Information in this document applies to any platform.

Symptoms

Grid Infrastructure rootupgrade.sh fails on last node, then CRSD is not coming online on any node anymore: 

2016/10/05 07:51:18 CLSRSC-482: Running command: '/u01/app/grid/product/12.1.0/grid/bin/crsctl set crs activeversion'

Started to upgrade the Oracle Clusterware. This operation may take a few minutes.
Started to upgrade the OCR.
CRS-1111: Error upgrading the Oracle Clusterware. Details [Upgrade Coordinator failed].
CRS-1112: Failed to set the Oracle Clusterware operating version 12.1.0.2.0
CRS-4000: Command Set failed, or completed with errors.
2016/10/05 07:51:34 CLSRSC-180: An error occurred while executing the command '/u01/app/grid/product/12.1.0/grid/bin/crsctl set crs activeversion' (error code 1)

2016/10/05 07:51:50 CLSRSC-281: Failed to set active version of Oracle Clusterware

Died at /u01/app/grid/product/12.1.0/grid/crs/install/crsupgrade.pm line 4149.

Re-run fails with:

2016/10/05 07:58:24 CLSRSC-464: Starting retrieval of the cluster configuration data

2016/10/05 07:58:28 CLSRSC-507: The root script cannot proceed on this node racnode3 because either the first-node operations have not completed on node racnode1 or there was an error in obtaining the status of the first-node operations.

Died at /u01/app/grid/product/12.1.0/grid/crs/install/crsutils.pm line 3681.

"crsctl stat res -t -init" shows ora.crsd is offline on all nodes:

ora.crsd
1 ONLINE OFFLINE STABLE <<================

 

ocrcheck fails:

PROT-601: Failed to initialize ocrcheck
PROC-47: Cannot proceed while the Oracle Cluster Registry format upgrade is in progress.

crsd.trc:

2016-10-05 07:51:30.719369 : OCRSRV:431953664: proas_amiwriter: ctx is INITIATING/EXPORTING/IMPORTING/IMPORTED/UPGRADED
2016-10-05 07:51:30.869449 : OCRSRV:431953664: proas_amiwriter: ctx is INITIATING/EXPORTING/IMPORTING/IMPORTED/UPGRADED
....
....
2016-10-05 07:51:35.133555 : default:440358656: LIST_LOGS: 2016-10-05 07:51:35.133: prom_send: Before gipcSend
2016-10-05 07:51:35.133557 : default:440358656: LIST_LOGS: 2016-10-05 07:51:35.133: prom_send:Failed to send [12]
2016-10-05 07:51:35.133558 : default:440358656: LIST_LOGS: 2016-10-05 07:51:35.133: th_process_request: Completed op [3] return [0]
2016-10-05 07:51:35.133559 : default:440358656: LIST_LOGS: 2016-10-05 07:51:35.133: th_select_w_f_t: Processed request constr [000000000000128d] retval [0]
2016-10-05 07:51:35.134099 : OCRMAS:452966144: proath_master:20: reconfig/grpmaster event [20] happened. Incarnation:[0]
2016-10-05 07:51:35.134110 : OCRSRV:452966144: th_not_master_change: Invoking master change callback. Master [1] Inc [3]
2016-10-05 07:51:35.134205 : OCRMAS:452966144: proath_master: GRPMASTER event. Ignored. Waiting for RCFG event for the old OCR Cache Writer:[2]. New Cache Writer:[1]
2016-10-05 07:51:35.134285 : OCRMAS:452966144: proath_master:20: reconfig/grpmaster event [1] happened. Incarnation:[5]
2016-10-05 07:51:35.134298 : OCRMAS:452966144: rcfg_con:2: Member [2] left. Inc [5].
2016-10-05 07:51:35.134313 : CRSSE:3076499200: {3:17683:448} Master Change Event; New Master Node ID:1 This Node's ID:3
2016-10-05 07:51:35.134359 : OCRMAS:452966144: proath_master:24: Set context state to master_changing: last established Cache Writer [2] new Cahe Writer [1].
OCRMAS:452966144: (:PROCR00003:)proath_master: Master node failed during IMPORTING state and I am not the new master. Exiting...
2016-10-05 07:51:35.134488 : OCRAPI:452966144: procr_ctx_set_invalid_no_abort: ctx is in state [16].
2016-10-05 07:51:35.134491 : OCRAPI:452966144: procr_ctx_set_invalid_no_abort: ctx set to invalid
2016-10-05 07:51:35.134493 : OCRAPI:452966144: procr_ctx_set_invalid_no_abort: Exiting...

 

Then crsd repeatedly restarting:

2016-10-05 07:51:42.692196 : OCRAPI:3611395680: th_upg_oper[21]: output from ocrconfig: [PROT-1: Failed to initialize ocrconfig
PROC-27: Error in authentication layer Authentication error [[SLOS: cat=-2, opn=getpwnam_r, dep=0, loc=addusrnam1
name = öŸ°¤¸WÔÛÙÿ†Üàðˆ’ABimZg‡”®q5 .Ձ ±‘¡Kb°d²©xÚ7jÒ”Q{+“
7ùü(×_?
]] [1]
]
2016-10-05 07:51:42.692249 : OCRAPI:3611395680: th_upg_oper[21]: ocrconfig returned with error [255].
2016-10-05 07:51:42.692285 : OCRAPI:3611395680: proa_upgrade: Failed to import the OCR by CacheWriter. Retval [14].
OCRAPI:3611395680: a_upgrade_cluster_failure: Failed to continue the OCR upgrade. Return:[14]
2016-10-05 07:51:42.696314 : OCRAPI:3611395680: a_init:17.1: Failed in a_upgrade_cluster_failure. Retval [14]
2016-10-05 07:51:42.696314*:kgfn.c@3203: kgfnEnvDestroy: env=0x30c5c80
OCRUTL:3611395680: u_check_tag: Tag check failed on 0th comparison for [PROPCTXT]. Ptr passed was [30f0db8] Byte was [0]
2016-10-05 07:51:42.696739 : OCRRAW:3611395680: proprterminate: Null or invalid context passed
2016-10-05 07:51:42.696849 : CRSOCR:3611395680: OCR context init failure. Error: PROC-14: Unknown error occurred
2016-10-05 07:51:42.697120 : CRSD:3611395680: Created alert : (:CRSD00111:) : Could not init OCR, error: PROC-14: Unknown error occurred
2016-10-05 07:51:42.697140 : CRSD:3611395680: [PANIC] CRSD exiting: Could not init OCR, code: 14
2016-10-05 07:51:42.697248 : CRSD:3611395680: Done.

 

crsd.trc on OCR master:

2016-10-05 07:51:38.643352 : OCRSRV:2269091584: proas_amiwriter: ctx is INITIATING/EXPORTING/IMPORTING/IMPORTED/UPGRADED
2016-10-05 07:51:38.644879 : OCRSRV:2254382848: proas_amiwriter: ctx is INITIATING/EXPORTING/IMPORTING/IMPORTED/UPGRADED
2016-10-05 07:51:38.712251 : OCRAPI:2279597824: th_upg_oper[21]: output from ocrconfig: [PROT-1: Failed to initialize ocrconfig
PROC-27: Error in authentication layer Authentication error [[SLOS: cat=-2, opn=getpwnam_r, dep=0, loc=addusrnam1
name = öŸ°¤¸WÔÛÙÿ†Üàðˆ’ABimZg‡”®q5 .Ձ ±‘¡Kb°d²©xÚ7jÒ”Q{+“
7ùü(×_?
]] [1]
]
2016-10-05 07:51:38.712267 : OCRAPI:2279597824: th_upg_oper[21]: ocrconfig returned with error [255].
2016-10-05 07:51:38.712289 : OCRAPI:2279597824: proa_upgrade: Failed to import the OCR by CacheWriter. Retval [14].
OCRMAS:2279597824: th_master:12.3: OCR upgrade is in IMPORTING state. Failed to continue the OCR upgrade. Returned [14]
2016-10-05 07:51:38.715489 : OCRAPI:2279597824: procr_ctx_set_invalid: ctx is in state [16].
2016-10-05 07:51:38.715491 : OCRAPI:2279597824: procr_ctx_set_invalid: ctx set to invalid
2016-10-05 07:51:38.715608 : OCRAPI:2279597824: procr_ctx_set_invalid: Aborting...

 

Trace file /u01/app/oracle/diag/crs/racnode1/crs/trace/ocrconfig_43742.trc

Oracle Database 12c Clusterware Release 12.1.0.2.0 - Production Copyright 1996, 2014 Oracle. All rights reserved.
2016-10-05 07:51:35.236151 : OCRCONF: ocrconfig starts...
2016-10-05 07:51:35.256464 : OCRCONF: Importing OCR data from /u01/app/grid/product/12.1.0/grid/cdata/cltprac17-clust/ocr12.1.0.2.0_upg_cltpldb171.ocr
2016-10-05 07:51:35.256516 : OCRCONF: Importing OCR data online
....

2016-10-05 07:51:37.288377 : OCRRAW: proprinitb: Using OCR ID passed [1301733519]
2016-10-05 07:51:37.313691 : OCRRAW: iniconfig:No 92 configuration
OCRAPI: a_is_valid_user_group: User name [öŸ°¤¸WÔÛÙÿ†Üàðˆ’ABimZg‡”®q5 .Ձ ±‘¡Kb°d²©xÚ7jÒ”Q{+“
7ùü(×_?] not in user database
OCRAPI: a_is_valid_user_group: scls ret [1] retval [27]
OCRAPI: SLOS : SLOS: cat=-2, opn=getpwnam_r, dep=0, loc=addusrnam1
name = öŸ°¤¸WÔÛÙÿ†Üàðˆ’ABimZg‡”®q5 .Ձ ±‘¡Kb°d²©xÚ7jÒ”Q{+“
7ùü(×_?

OCRUTL: u_fill_errorbuf: Error Info : [[SLOS: cat=-2, opn=getpwnam_r, dep=0, loc=addusrnam1
name = öŸ°¤¸WÔÛÙÿ†Üàðˆ’ABimZg‡”®q5 .Ձ ±‘¡Kb°d²©xÚ7jÒ”Q{+“
7ùü(×_?
]]
OCRAPI: a_create_n_set_key:THE SECURITY ATTRIBUTE PASSED is invalid
2016-10-05 07:51:38.701932 : OCRAPI: a_batch_execute: Check batch exec failed [27]
2016-10-05 07:51:38.701962 : OCRAPI: a_batch_execute: Failed to execute batch. Return [27]
2016-10-05 07:51:38.702073 : OCRCONF: batchexecute: Error executing the batch. Retval [27].
2016-10-05 07:51:38.702100 : OCRCONF: batchexecute: Detailed error message:[PROC-27: Error in authentication layer Authentication error [[SLOS: cat=-2, opn=getpwnam_r, dep=0, loc=addusrnam1
name = öŸ°¤¸WÔÛÙÿ†Üàðˆ’ABimZg‡”®q5 .Ձ ±‘¡Kb°d²©xÚ7jÒ”Q{+“
7ùü(×_?
]] [1]]
2016-10-05 07:51:38.702121 : OCRCONF: An error occured while executing the batch.
2016-10-05 07:51:38.702192 : OCRCONF: Error[117]: Failed to initialize OCR context. Error:[PROC-27: Error in authentication layer Authentication error [[SLOS: cat=-2, opn=getpwnam_r, dep=0, loc=addusrnam1
name = öŸ°¤¸WÔÛÙÿ†Üàðˆ’ABimZg‡”®q5 .Ձ ±‘¡Kb°d²©xÚ7jÒ”Q{+“
7ùü(×_?
]] [1]] Retval:[-1]
2016-10-05 07:51:38.702473 : OCRCONF: Exiting [status=failed]...

 

Cause

Sign In with your My Oracle Support account

Don't have a My Oracle Support account? Click to get started

My Oracle Support provides customers with access to over a
Million Knowledge Articles and hundreds of Community platforms