Troubleshooting a failure when upgrading to Oracle 18c
WhenI was upgrading Grid to 18c, the final step was to run gridSetup.sh -executeConfigTools, which failed. Unfortunately, the error provided was not very descriptive or useful. In this post, I will demonstrate how I went about troubleshooting the failure. To start the 18c upgrade, run script gridSetup_applyRU.sh (Please note: I have scripted the process.) [code] [oracle@racnode-dc1-1 ~]$ /media/patch/gridSetup_applyRU.sh + . /media/patch/gi.env ++ set +x The Oracle base has been set to /u01/app/oracle ORACLE_SID=+ASM1 ORACLE_BASE=/u01/app/oracle GRID_HOME=/u01/app/12.1.0.1/grid ORACLE_HOME=/u01/app/12.1.0.1/grid Oracle Instance alive for sid "+ASM1" + crsctl query crs releaseversion Oracle High Availability Services release version on the local node is [12.1.0.2.0] + crsctl query crs softwareversion Oracle Clusterware version on node [racnode-dc1-1] is [12.1.0.2.0] + crsctl query crs softwarepatch Oracle Clusterware patch level on node racnode-dc1-1 is [1721139106]. + crsctl query crs releasepatch Oracle Clusterware release patch level is [1721139106] and the complete list of patches [20243804 20415006 20594149 20788771 20950328 21125181 21359749 21527488 21694919 21949015 22806133 23144544 24340679 24732088 25397136 25869760 26609798 26717470 26925263 26983807 27338029 27547374 28259867 28729213 28729220 28731800 ] have been applied on the local node. + crsctl query crs activeversion -f Oracle Clusterware active version on the cluster is [12.1.0.2.0]. The cluster upgrade state is [NORMAL]. The cluster active patch level is [1721139106]. + exit + unset ORACLE_HOME ORACLE_BASE ORACLE_SID GRID_HOME ORACLE_UNQNAME + env + egrep -i 'ora|home' USER=oracle PATH=/usr/local/bin:/bin:/usr/bin:/usr/local/sbin:/usr/sbin:/home/oracle/.local/bin:/home/oracle/bin MAIL=/var/spool/mail/oracle PWD=/home/oracle HOME=/home/oracle LOGNAME=oracle + cat /etc/oratab #Backup file is /u01/app/12.1.0.1/grid/srvm/admin/oratab.bak.racnode-dc1-1 line added by Agent +ASM1:/u01/app/12.1.0.1/grid:N hawk1:/u01/app/oracle/12.1.0.1/db1:N hawk:/u01/app/oracle/12.1.0.1/db1:N # line added by Agent -MGMTDB:/u01/app/12.1.0.1/grid:N # line added by Agent + ssh racnode-dc1-2 'ls -lh /u01/18.3.0.0/grid' total 0 + ssh racnode-dc1-2 'cat /etc/oratab' #Backup file is /u01/app/oracle/12.1.0.1/db1/srvm/admin/oratab.bak.racnode-dc1-2 line added by Agent +ASM2:/u01/app/12.1.0.1/grid:N hawk2:/u01/app/oracle/12.1.0.1/db1:N -MGMTDB:/u01/app/12.1.0.1/grid:N # line added by Agent hawk:/u01/app/oracle/12.1.0.1/db1:N # line added by Agent + ls -lh /media/patch/Jan2019/28828717 total 128K drwxrwxrwx 1 vagrant vagrant 0 Feb 27 19:24 28435192 drwxrwxrwx 1 vagrant vagrant 0 Feb 27 19:24 28547619 drwxrwxrwx 1 vagrant vagrant 0 Feb 27 19:26 28822489 drwxrwxrwx 1 vagrant vagrant 0 Feb 27 19:27 28864593 drwxrwxrwx 1 vagrant vagrant 0 Feb 27 19:29 28864607 drwxrwxrwx 1 vagrant vagrant 4.0K Feb 27 19:26 automation -rwxrwxrwx 1 vagrant vagrant 5.7K Jan 9 16:02 bundle.xml -rwxrwxrwx 1 vagrant vagrant 115K Jan 9 15:43 README.html -rwxrwxrwx 1 vagrant vagrant 0 Jan 9 23:37 README.txt -------------------------------------------------------------------------------- + /u01/18.3.0.0/grid/gridSetup.sh -silent -applyRU /media/patch/Jan2019/28828717 -responseFile /sf_OracleSoftware/18cLinux/gridsetup_upgrade.rsp -J-Doracle.install.mgmtDB=false -J-Doracle.install.mgmtDB.CDB=false -J Doracle.install.crs.enableRemoteGIMR=false -------------------------------------------------------------------------------- Preparing the home to patch... Applying the patch /media/patch/Jan2019/28828717... Successfully applied the patch. The log can be found at: /u01/app/oraInventory/logs/GridSetupActions2019-04-14_11-29-28PM/installerPatchActions_2019-04-14_11-29-28PM.log Launching Oracle Grid Infrastructure Setup Wizard... [WARNING] [INS-13014] Target environment does not meet some optional requirements. CAUSE: Some of the optional prerequisites are not met. See logs for details. /u01/app/oraInventory/logs/GridSetupActions2019-04-14_11-29-28PM/gridSetupActions2019-04-14_11-29-28PM.log ACTION: Identify the list of failed prerequisite checks from the log: /u01/app/oraInventory/logs/GridSetupActions2019-04-14_11-29-28PM/gridSetupActions2019-04-14_11-29-28PM.log. Then either from the log file or from installation manual find the appropriate configuration to meet the prerequisites and fix it manually. The response file for this session can be found at: /u01/18.3.0.0/grid/install/response/grid_2019-04-14_11-29-28PM.rsp You can find the log of this install session at: /u01/app/oraInventory/logs/GridSetupActions2019-04-14_11-29-28PM/gridSetupActions2019-04-14_11-29-28PM.log As a root user, execute the following script(s): 1. /u01/18.3.0.0/grid/rootupgrade.sh Execute /u01/18.3.0.0/grid/rootupgrade.sh on the following nodes: [racnode-dc1-1, racnode-dc1-2] Run the script on the local node first. After successful completion, you can start the script in parallel on all other nodes, except a node you designate as the last node. When all the nodes except the last node are done successfully, run the script on the last node. Successfully Setup Software with warning(s). -------------------------------------------------------------------------------- As install user, execute the following command to complete the configuration. /u01/18.3.0.0/grid/gridSetup.sh -executeConfigTools -responseFile /sf_OracleSoftware/18cLinux/gridsetup_upgrade.rsp [-silent] -------------------------------------------------------------------------------- [oracle@racnode-dc1-1 ~]$ [/code] The last step: gridSetup.sh -executeConfigTools resulted in WARNINGS. [code] [oracle@racnode-dc1-1 ~]$ /u01/18.3.0.0/grid/gridSetup.sh -executeConfigTools -responseFile /sf_OracleSoftware/18cLinux/gridsetup_upgrade.rsp -silent Launching Oracle Grid Infrastructure Setup Wizard... -------------------------------------------------------------------------------- You can find the logs of this session at: /u01/app/oraInventory/logs/GridSetupActions2019-04-15_01-02-06AM -------------------------------------------------------------------------------- [WARNING] [INS-43080] Some of the configuration assistants failed, were cancelled or skipped. ACTION: Refer to the logs or contact Oracle Support Services. [oracle@racnode-dc1-1 ~]$ [/code] Check directory: /u01/app/oraInventory/logs/GridSetupActions2019-04-15_01-02-06AM [code] [oracle@racnode-dc1-1 ~]$ cd /u01/app/oraInventory/logs/GridSetupActions2019-04-15_01-02-06AM [oracle@racnode-dc1-1 GridSetupActions2019-04-15_01-02-06AM]$ ls -alrt total 1072 -rw-r----- 1 oracle oinstall 129 Apr 15 01:02 installerPatchActions_2019-04-15_01-02-06AM.log -rw-r----- 1 oracle oinstall 0 Apr 15 01:02 gridSetupActions2019-04-15_01-02-06AM.err drwxrwx--- 5 oracle oinstall 4096 Apr 15 01:03 .. -rw-r----- 1 oracle oinstall 1004340 Apr 15 01:03 gridSetupActions2019-04-15_01-02-06AM.out -rw-r----- 1 oracle oinstall 2171 Apr 15 01:03 time2019-04-15_01-02-06AM.log -rw-r----- 1 oracle oinstall 72336 Apr 15 01:03 gridSetupActions2019-04-15_01-02-06AM.log drwxrwx--- 2 oracle oinstall 4096 Apr 15 01:03 . [oracle@racnode-dc1-1 GridSetupActions2019-04-15_01-02-06AM]$ [/code] Check time2019-04-15_01-02-06AM.log was useful to identify failure. [code] [oracle@racnode-dc1-1 GridSetupActions2019-04-15_01-02-06AM]$ cat time2019-04-15_01-02-06AM.log # Message # ElapsedTime # Current Time ( ms ) # Starting step:INITIALIZE_ACTION of state:init # 0 # 1555282933690 # Finished step:INITIALIZE_ACTION of state:init # 0 # 1555282933690 # Starting step:EXECUTE of state:init # 0 # 1555282933692 # Finished step:EXECUTE of state:init # 3 # 1555282933696 # Starting step:VALIDATE of state:init # 0 # 1555282933698 # Finished step:VALIDATE of state:init # 3 # 1555282933701 # Starting step:TRANSITION of state:init # 0 # 1555282933701 # Finished step:TRANSITION of state:init # 2 # 1555282933703 # Starting step:EXECUTE of state:CRSConfigTools # 0 # 1555282933703 # Finished step:EXECUTE of state:CRSConfigTools # 714 # 1555282934417 # Starting step:VALIDATE of state:CRSConfigTools # 0 # 1555282934418 # Finished step:VALIDATE of state:CRSConfigTools # 0 # 1555282934418 # Starting step:TRANSITION of state:CRSConfigTools # 0 # 1555282934418 # Finished step:TRANSITION of state:CRSConfigTools # 20962 # 1555282955381 # Starting step:INITIALIZE_ACTION of state:setup # 0 # 1555282955381 # Finished step:INITIALIZE_ACTION of state:setup # 0 # 1555282955381 # Starting step:EXECUTE of state:setup # 0 # 1555282955382 # Finished step:EXECUTE of state:setup # 3 # 1555282955385 # Configuration in progress. # 0 # 1555282958962 # Update Inventory in progress. # 0 # 1555282959678 # Update Inventory successful. # 41125 # 1555283000803 # Upgrading RHP Repository in progress. # 0 # 1555283000839 -------------------------------------------------------------------------------- # Upgrading RHP Repository failed. # 5904 # 1555283006743 -------------------------------------------------------------------------------- # Starting step:VALIDATE of state:setup # 0 # 1555283006854 # Finished step:VALIDATE of state:setup # 11 # 1555283006865 # Starting step:TRANSITION of state:setup # 0 # 1555283006865 # Finished step:TRANSITION of state:setup # 0 # 1555283006865 # Starting step:EXECUTE of state:finish # 0 # 1555283006866 # Finished step:EXECUTE of state:finish # 6 # 1555283006872 # Starting step:VALIDATE of state:finish # 0 # 1555283006873 # Finished step:VALIDATE of state:finish # 0 # 1555283006873 # Starting step:TRANSITION of state:finish # 0 # 1555283006873 # Finished step:TRANSITION of state:finish # 0 # 1555283006873 [oracle@racnode-dc1-1 GridSetupActions2019-04-15_01-02-06AM]$ [/code] Check gridSetupActions2019-04-15_01-02-06AM.log to find the same and Exit Status is -1 [code] [oracle@racnode-dc1-1 GridSetupActions2019-04-15_01-02-06AM]$ grep -B2 -A100 'Executing RHPUPGRADE' gridSetupActions2019-04-15_01-02-06AM.log INFO: [Apr 15, 2019 1:03:20 AM] Starting 'Upgrading RHP Repository' INFO: [Apr 15, 2019 1:03:20 AM] Starting 'Upgrading RHP Repository' INFO: [Apr 15, 2019 1:03:20 AM] Executing RHPUPGRADE INFO: [Apr 15, 2019 1:03:20 AM] Command /u01/18.3.0.0/grid/bin/rhprepos upgradeSchema -fromversion 12.1.0.2.0 INFO: [Apr 15, 2019 1:03:20 AM] ... GenericInternalPlugIn.handleProcess() entered. INFO: [Apr 15, 2019 1:03:20 AM] ... GenericInternalPlugIn: getting configAssistantParmas. INFO: [Apr 15, 2019 1:03:20 AM] ... GenericInternalPlugIn: checking secretArguments. INFO: [Apr 15, 2019 1:03:20 AM] No arguments to pass to stdin INFO: [Apr 15, 2019 1:03:20 AM] ... GenericInternalPlugIn: starting read loop. INFO: [Apr 15, 2019 1:03:26 AM] Completed Plugin named: rhpupgrade INFO: [Apr 15, 2019 1:03:26 AM] ConfigClient.saveSession method called INFO: [Apr 15, 2019 1:03:26 AM] Upgrading RHP Repository failed. INFO: [Apr 15, 2019 1:03:26 AM] Upgrading RHP Repository failed. INFO: [Apr 15, 2019 1:03:26 AM] ConfigClient.executeSelectedToolsInAggregate action performed INFO: [Apr 15, 2019 1:03:26 AM] Exiting ConfigClient.executeSelectedToolsInAggregate method INFO: [Apr 15, 2019 1:03:26 AM] Adding ExitStatus SUCCESS_MINUS_RECTOOL to the exit status set INFO: [Apr 15, 2019 1:03:26 AM] ConfigClient.saveSession method called INFO: [Apr 15, 2019 1:03:26 AM] Calling event ConfigSessionEnding INFO: [Apr 15, 2019 1:03:26 AM] ConfigClient.endSession method called INFO: [Apr 15, 2019 1:03:26 AM] Completed Configuration INFO: [Apr 15, 2019 1:03:26 AM] Adding ExitStatus FAILURE to the exit status set INFO: [Apr 15, 2019 1:03:26 AM] All forked task are completed at state setup INFO: [Apr 15, 2019 1:03:26 AM] Completed background operations INFO: [Apr 15, 2019 1:03:26 AM] Validating state <setup> -------------------------------------------------------------------------------- WARNING: [Apr 15, 2019 1:03:26 AM] [WARNING] [INS-43080] Some of the configuration assistants failed, were cancelled or skipped. ACTION: Refer to the logs or contact Oracle Support Services. -------------------------------------------------------------------------------- INFO: [Apr 15, 2019 1:03:26 AM] Advice is CONTINUE INFO: [Apr 15, 2019 1:03:26 AM] Completed validating state <setup> INFO: [Apr 15, 2019 1:03:26 AM] Verifying route success INFO: [Apr 15, 2019 1:03:26 AM] Waiting for completion of background operations INFO: [Apr 15, 2019 1:03:26 AM] Completed background operations INFO: [Apr 15, 2019 1:03:26 AM] Waiting for completion of background operations INFO: [Apr 15, 2019 1:03:26 AM] Completed background operations INFO: [Apr 15, 2019 1:03:26 AM] Executing action at state finish INFO: [Apr 15, 2019 1:03:26 AM] FinishAction Actions.execute called INFO: [Apr 15, 2019 1:03:26 AM] Finding the most appropriate exit status for the current application INFO: [Apr 15, 2019 1:03:26 AM] Completed executing action at state <finish> INFO: [Apr 15, 2019 1:03:26 AM] Waiting for completion of background operations INFO: [Apr 15, 2019 1:03:26 AM] Completed background operations INFO: [Apr 15, 2019 1:03:26 AM] Waiting for completion of background operations INFO: [Apr 15, 2019 1:03:26 AM] Completed background operations INFO: [Apr 15, 2019 1:03:26 AM] Moved to state <finish> INFO: [Apr 15, 2019 1:03:26 AM] Waiting for completion of background operations INFO: [Apr 15, 2019 1:03:26 AM] Completed background operations INFO: [Apr 15, 2019 1:03:26 AM] Validating state <finish> WARNING: [Apr 15, 2019 1:03:26 AM] Validation disabled for the state finish INFO: [Apr 15, 2019 1:03:26 AM] Completed validating state <finish> INFO: [Apr 15, 2019 1:03:26 AM] Terminating all background operations INFO: [Apr 15, 2019 1:03:26 AM] Terminated all background operations INFO: [Apr 15, 2019 1:03:26 AM] Successfully executed the flow in SILENT mode INFO: [Apr 15, 2019 1:03:26 AM] Finding the most appropriate exit status for the current application INFO: [Apr 15, 2019 1:03:26 AM] inventory location is/u01/app/oraInventory INFO: [Apr 15, 2019 1:03:26 AM] Finding the most appropriate exit status for the current application -------------------------------------------------------------------------------- INFO: [Apr 15, 2019 1:03:26 AM] Exit Status is -1 INFO: [Apr 15, 2019 1:03:26 AM] Shutdown Oracle Grid Infrastructure 18c Installer INFO: [Apr 15, 2019 1:03:26 AM] Unloading Setup Driver -------------------------------------------------------------------------------- INFO: [Apr 15, 2019 1:03:26 AM] inventory location is/u01/app/oraInventory [oracle@racnode-dc1-1 GridSetupActions2019-04-15_01-02-06AM]$ [/code] In conclusion, following the two steps provided may help to simply troubleshooting for gridSetup.sh -executeConfigTools failure since the information provided by the upgrade process is not very clear as to what logs need to be reviewed 1. Check time*.log to identify which step failed. 2. Check gridSetupActions*.log to identify more details.
