I encountered this issue now multiple times in my own environment. And I searched MOS and tried different things. But I couldn’t solve it yet. My Upgrade fails with ORA-20001 during datapatch run – and I’d like to show you how to bring the upgrade to an successful end.
Photo by chuttersnap on Unsplash
It all starts with an upgrade
In my lab environment I upgrade two databases often in parallel. An 11.2.0.4 database and a 12.2.0.1. The 11.2.0.4 upgrades always flawless. But the 12.2.0.1 occasionally fails. This is the screen AutoUpgrade is showing me – but this is not an AutoUpgrade problem. It is not even a “upgrade” but a patching problem.
At first, my source databases are patched to the most recent patch bundles. At the moment while I write this, it means the July 2020 patch bundles.
I use AutoUpgrade here simply because it is easier. Why should I type instead or click DBUA screens. Especially as DBUA wouldn’t be able to upgrade two databases in parallel.
This is my config file:
global.autoupg_log_dir=/home/oracle/upg_logs # # Database number 1 # upg1.dbname=DB12 upg1.start_time=NOW upg1.source_home=/u01/app/oracle/product/12.2.0.1 upg1.target_home=/u01/app/oracle/product/19 upg1.sid=DB12 upg1.log_dir=/home/oracle/upg_logs upg1.upgrade_node=localhost upg1.target_version=19 upg1.timezone_upg=no upg1.restoration=no # # Database number 2 # upg2.dbname=FTEX upg2.start_time=NOW upg2.source_home=/u01/app/oracle/product/11.2.0.4 upg2.target_home=/u01/app/oracle/product/19 upg2.sid=FTEX upg2.log_dir=/home/oracle/upg_logs upg2.upgrade_node=localhost upg2.target_version=19 upg2.timezone_upg=no upg2.restoration=no
Nothing unusual.
Upgrade is failing
And while the 11.2.0.4 database upgrades nicely, the 12.2.0.1 fails.
$ java -jar $OH19/rdbms/admin/autoupgrade.jar -config UP19.cfg -mode deploy AutoUpgrade tool launched with default options Processing config file ... +--------------------------------+ | Starting AutoUpgrade execution | +--------------------------------+ 2 databases will be processed Type 'help' to list console commands upg> ------------------------------------------------- Errors in database [DB12] Stage [DBUPGRADE] Operation [STOPPED] Status [ERROR] Info [ Error: UPG-1400 UPGRADE FAILED [DB12] Cause: Database upgrade failed with errors For further details, see the log file located at /home/oracle/upg_logs/DB12/103/autoupgrade_20200730_user.log] ------------------------------------------------- Logs: [/home/oracle/upg_logs/DB12/103/autoupgrade_20200730_user.log] ------------------------------------------------- Job 102 completed
Let me find out what has happend.
autoupgrade_user.log
As the output proposed, I will start with: /home/oracle/upg_logs/DB12/103/autoupgrade_20200730_user.log
---------+-------------+
| DB12|UPGRADE [95%]|
+---------+-------------+
2020-07-30 12:24:30.259 ERROR
DATABASE NAME: DB12
CAUSE: ERROR at Line 756922 in [/home/oracle/upg_logs/DB12/103/dbupgrade/catupgrd20200730114721db120.log]
REASON: Error: prereq checks failed!
ACTION: [MANUAL]
DETAILS:
2020-07-30 12:24:30.287 ERROR Database Upgrade Error in File [/home/oracle/upg_logs/DB12/103/dbupgrade/catupgrd20200730114721db120.log] on Database [/home/oracle/upg_logs/DB12/103/dbupgrade/catupgrd20200730114721db120.log]
2020-07-30 12:24:31.945 ERROR UPGRADE FAILED [DB12]
2020-07-30 12:24:31.945 ERROR Exception Error in Database Upgrade [UPG-1400#UPGRADE FAILED [DB12]]
2020-07-30 12:24:31.945 INFO End Upgrade on Database [DB12]
2020-07-30 12:24:34.524 ERROR UPGRADE FAILED [DB12]
2020-07-30 12:24:34.533 ERROR Exception Error in Database Upgrade [DB12]
2020-07-30 12:24:34.570 ERROR db12 Return status is ERROR
2020-07-30 12:24:34.572 ERROR Dispatcher failed: AutoUpgException [UPG-1400#UPGRADE FAILED [DB12]]
2020-07-30 12:24:34.574 INFO Starting error management routine
2020-07-30 12:24:34.585 INFO Ended error management routine
2020-07-30 12:24:34.590 ERROR Error running dispatcher for job 103
Cause: Database upgrade failed with errors
2020-07-30 12:24:34.590 ERROR Dispatcher failed:
Error: UPG-1400
UPGRADE FAILED [DB12]
Cause: Database upgrade failed with errors
For further details, see the log file located at /home/oracle/upg_logs/DB12/103/autoupgrade_20200730_user.log; aborting job 103 for database DB12
Hm … CAUSE: ERROR at Line 756922 in [/home/oracle/upg_logs/DB12/103/dbupgrade/catupgrd20200730114721db120.log]
The main worker’s catupgr0.log
This is the main worker’s upgrade logfile.
[..]
Serial Phase #:105 [DB12] Files:1 Time: 3s
Serial Phase #:106 [DB12] Files:1 Time: 0s
Serial Phase #:107 [DB12] Files:1 Time: 23s
------------------------------------------------------
Phases [0-107] End Time:[2020_07_30 12:24:07]
------------------------------------------------------
Grand Total Time: 1869s
*** WARNING: ERRORS FOUND DURING UPGRADE ***
1. Evaluate the errors found in the upgrade logs
and determine the proper action.
2. Rerun the upgrade when the problem is resolved
REASON:
ERRORS FOUND: During Upgrade
FILENAME: /home/oracle/upg_logs/DB12/103/dbupgrade/catupgrd20200730114721db120.log AT LINE NUMBER: 754911
------------------------------------------------------
Identifier DATAPATCH_ 20-07-30 12:21:32
SCRIPT = [/home/oracle/upg_logs/DB12/103/dbupgrade/catupgrd20200730114721db12_datapatch_upgrade.log]
ERROR = [Error: prereq checks failed!
]
STATEMENT = []
------------------------------------------------------
LOG FILES: (/home/oracle/upg_logs/DB12/103/dbupgrade/catupgrd20200730114721db12*.log)
Upgrade Summary Report Located in:
/home/oracle/upg_logs/DB12/103/dbupgrade/upg_summary.log
End of Input Commands
------------------------------------------------------
Start of DataPatch Logs
------------------------------------------------------
stdout from running datapatch to install upgrade SQL patches and PSUs:
SQL Patching tool version 19.8.0.0.0 Production on Thu Jul 30 12:19:29 2020
Copyright (c) 2012, 2020, Oracle. All rights reserved.
Log file for this invocation: /u01/app/oracle/cfgtoollogs/sqlpatch/sqlpatch_30237_2020_07_30_12_19_29/sqlpatch_invocation.log
Connecting to database...OK
Gathering database info...done
Bootstrapping registry and package to current versions...done
Error: prereq checks failed!
verify_queryable_inventory returned ORA-20001: Latest xml inventory is not loaded into table
Prereq check failed, exiting without installing any patches.
Please refer to MOS Note 1609718.1 and/or the invocation log
/u01/app/oracle/cfgtoollogs/sqlpatch/sqlpatch_30237_2020_07_30_12_19_29/sqlpatch_invocation.log
for information on how to resolve the above errors.
SQL Patching tool complete on Thu Jul 30 12:21:31 2020
stderr from running datapatch to install upgrade SQL patches and PSUs:
End of DataPatch Logs
------------------------------------------------------
So the upgrade itself completed successfully. But datapatch had an issue in the post upgrade phase.
ORA-20001
And this seems to be the problem:
Error: prereq checks failed! verify_queryable_inventory returned ORA-20001: Latest xml inventory is not loaded into table
The most famous ORA-20001. On MyOracle Support you will find this note: MOS Note:1602089.1 – Queryable Patch Inventory – Issues/Solutions for ORA-20001: Latest xml inventory is not loaded into table. But I need more information to get an idea what’s wrong in my case.
And again for the records, I upgrade to an 19.8.0 home, but I saw the same issue with 19.7.0 already, too.
sqlpatch_invocation.log
Ok, let’s go to the next logfile – the /u01/app/oracle/cfgtoollogs/sqlpatch/sqlpatch_30237_2020_07_30_12_19_29/sqlpatch_invocation.log. Maybe it has more details?
[2020-07-30 12:21:29] verify_queryable_inventory returned ORA-20001: Latest xml inventory is not loaded into table [2020-07-30 12:21:29] Error: prereq checks failed! [2020-07-30 12:21:29] verify_queryable_inventory returned ORA-20001: Latest xml inventory is not loaded into table [2020-07-30 12:21:29] Prereq check failed, exiting without installing any patches. ... [2020-07-30 12:21:29] *** END final state end of patching *** [2020-07-30 12:21:31] Please refer to MOS Note 1609718.1 and/or the invocation log [2020-07-30 12:21:31] /u01/app/oracle/cfgtoollogs/sqlpatch/sqlpatch_30237_2020_07_30_12_19_29/sqlpatch_invocation.log[2020-07-30 12:21:31] for information on how to resolve the above errors.
That is not really helpful.
But there is an sqlpatch_debug.log in the same directory. And this has this error sequence:
[2020-07-30 12:21:29] QPI: Caught error while querying opatch_xml_inv [2020-07-30 12:21:29] QPI: in REFRESH_OPATCH_DATA, ERROR code -29913 : ORA-29913: error in executing ODCIEXTTABLEFETCH callout ORA-29400: data cartridge error KUP-04095: preprocessor command /u01/app [2020-07-30 12:21:29] QPI: Releasing lock SUCCESSFUL, qp_result=0 at : 30-JUL-20 12.21.29.797707000 PM +02:00 [2020-07-30 12:21:29] QPI: Releasing lock FAILED, qp_result=4 at : 30-JUL-20 12.21.29.798750000 PM +02:00 [2020-07-30 12:21:29] QPI: in get_pending_activity, ERROR code -20001 : ORA-20001: Latest xml inventory is not loaded into table
Unfortunately this doesn’t bring me forward either as my error pattern isn’t covered in MOS Note:1602089.1.
alert.log?
Maybe the alert.log has more information?
SERVER COMPONENT id=DP_UPG_BGN: timestamp=2020-07-30 12:19:27 2020-07-30T12:19:47.883482+02:00 XDB initialized. 2020-07-30T12:19:49.188762+02:00 QPI: opatch file present, opatch QPI: qopiprep.bat file present 2020-07-30T12:21:32.945903+02:00 SERVER COMPONENT id=DP_UPG_END: timestamp=2020-07-30 12:21:32
No.
Basically I know that the inventory couldn’t be queried at the end of the upgrade. But my database is upgraded. Hence, no need to restore it. But how do I solve this?
Query the inventory or cleanup metadata
At this stage I wanted to save my upgrade. So I queried the inventory by myself – and it takes quite a bit as you can see here:
SQL*Plus: Release 19.0.0.0.0 - Production on Thu Jul 30 15:18:48 2020 Version 19.8.0.0.0 Copyright (c) 1982, 2020, Oracle. All rights reserved. Connected to: Oracle Database 19c Enterprise Edition Release 19.0.0.0.0 - Production Version 19.8.0.0.0 SQL> set timing on SQL> select * from OPATCH_XML_INV; XML_INVENTORY -------------------------------------------------------------------------------- <?xml version="1.0" encoding="UTF-8" standalone="yes"?> <Inv entoryInstance> <ora Elapsed: 00:00:35.22 SQL> exit
It may be also a solution to cleanup metadata with:
EXEC dbms_qopatch.clean_metadata();
Complete the upgrade
AutoUpgrade still waits for me – another reason why I don’t use the DBUA which typically is non-resumable. I will resume now my upgrade:
upg> lsj +----+-------+-----------+---------+--------+--------------+--------+-----------------+ |Job#|DB_NAME| STAGE|OPERATION| STATUS| START_TIME| UPDATED| MESSAGE| +----+-------+-----------+---------+--------+--------------+--------+-----------------+ | 102| FTEX|POSTUPGRADE| STOPPED|FINISHED|20/07/30 11:47|12:30:11|Completed job 102| | 103| DB12| DBUPGRADE| STOPPED| ERROR|20/07/30 11:48|12:24:34| UPG-1400| +----+-------+-----------+---------+--------+--------------+--------+-----------------+ Total jobs 2 upg> resume -job 103 Resuming job: [103][DB12]
The output looks promising:
And yes, my database upgrade finished now.
Alternative Workaround
You may use the following workaround – it will increase the threshold to read the inventory:
alter system set "_bug27355984_xt_preproc_timeout"=180 scope=both;
In this case, I set it to 180 seconds.
Summary
The root cause for this issue may have been incorrect metadata from a previous patch run. Let me emphasize again that this is not an upgrade or AutoUpgrade error. It happens when datapatch gets invoked.
I’m very happy that AutoUpgrade (and the command line upgrade with “dbupgrade -R” are both resumable). Otherwise I wouldn’t have had a chance to fix this so easily. In case you still used the DBUA, you can still jump in with “dbupgrade -R” and complete the upgrade after cleaning up the metadata.
Why do I write such a blog post? Actually, when I hit such an issue with my limited number of upgrades, you may see it another day, too. And the solution is simple. But as I couldn’t find the key in MOS, I would like to show you here how easily you can resume a potentially failed database upgrade – even when the upgrade itself completed fully.
Further Links and Information
- Opatch … oh Opatch … why is Opatch so stubborn? – Dec 15, 2018
- MOS Note:1602089.1 – Queryable Patch Inventory – Issues/Solutions for ORA-20001: Latest xml inventory is not loaded into table
–Mike
