I woke up this morning and did what I do most days - doomscroll through twitter. One of the benefits of being in the US is that there are usually some interesting discussions going on with people I follow in Europe. I saw an interesting question from Martin Berger:
I've had my fights with datapatch over the years, so I was curious by what I saw. Initially, you may suspect it's a bug, but I thought about the issue being with the OJVM patch, and how that particular patch is handled by datapatch.
Patching the Oracle database is a two-step process. First, the Oracle binaries are patched by the opatch command. After the Oracle home is patched, the datapatch script must be run on a database to apply any fixes that include post-patch SQL.
The OJVM patch in particular has been a thorn in the side of many DBAs. In database 19c and lower, a mismatch between the Java classes in the database and the files in the home will cause an ORA-29548 error to occur.
Operations performed by datapatch will create rows in the dba_registry_sqlpatch view, which goes back to Martin's original question. Why was the 19.9 OJVM patch listed twice when querying the view? I believe the hint lies in the data that we see from the ACTION_TIME column.
To confirm, I went to my lab system with the same 19.9 patch set installed:
SQL> select PATCH_ID, PATCH_TYPE, ACTION_TIME, DESCRIPTION, STATUS from dba_registry_sqlpatch;
PATCH_ID PATCH_TYPE ACTION_TIME DESCRIPTION STATUS
---------- ---------- ------------------------------ ------------------------------------------------------------ -------
31668882 INTERIM 20-OCT-21 06.27.39.120263 PM OJVM RELEASE UPDATE: 19.9.0.0.201020 (31668882) SUCCESS
31771877 RU 20-OCT-21 06.27.39.117792 PM Database Release Update : 19.9.0.0.201020 (31771877) SUCCESS
I applied the 19.13 patches, as shown below:
[oracle@acolvin-dg-1 ~]$ $ORACLE_HOME/OPatch/opatch lspatches
33192694;OJVM RELEASE UPDATE: 19.13.0.0.211019 (33192694)
33208123;OCW RELEASE UPDATE 19.13.0.0.0 (33208123)
33192793;Database Release Update : 19.13.0.0.211019 (33192793)
OPatch succeeded.
Once I finished, I ran datapatch, which completed successfully. I checked the dba_registry_sqlpatch, and I saw the same thing:
SQL> select PATCH_ID, PATCH_TYPE, ACTION_TIME, DESCRIPTION, STATUS from dba_registry_sqlpatch;
PATCH_ID PATCH_TYPE ACTION_TIME DESCRIPTION STATUS
---------- ---------- ------------------------------ ------------------------------------------------------------ -------
31668882 INTERIM 20-OCT-21 06.27.39.120263 PM OJVM RELEASE UPDATE: 19.9.0.0.201020 (31668882) SUCCESS
31771877 RU 20-OCT-21 06.27.39.117792 PM Database Release Update : 19.9.0.0.201020 (31771877) SUCCESS
31668882 INTERIM 08-FEB-22 06.00.13.069042 PM OJVM RELEASE UPDATE: 19.9.0.0.201020 (31668882) SUCCESS
33192694 INTERIM 08-FEB-22 06.00.18.341368 PM OJVM RELEASE UPDATE: 19.13.0.0.211019 (33192694) SUCCESS
33192793 RU 08-FEB-22 06.00.18.335540 PM Database Release Update : 19.13.0.0.211019 (33192793) SUCCESS
Sure enough, we have 2 entries for the 19.9 OJVM patch. What could be causing this? If you look at the output from datapatch, you can see that the script performs a rollback of the 19.9 OJVM patch before applying the 19.13 version:
[oracle@acolvin-dg-1 OPatch]$ ./datapatch -verbose
SQL Patching tool version 19.13.0.0.0 Production on Tue Feb 8 17:54:18 2022
Copyright (c) 2012, 2021, Oracle. All rights reserved.
Log file for this invocation: /u01/app/oracle/cfgtoollogs/sqlpatch/sqlpatch_6659_2022_02_08_17_54_18/sqlpatch_invocation.log
Connecting to database...OK
Gathering database info...done
Bootstrapping registry and package to current versions...done
Determining current state...done
Current state of interim SQL patches:
Interim patch 31668882 (OJVM RELEASE UPDATE: 19.9.0.0.201020 (31668882)):
Binary registry: Not installed
SQL registry: Applied successfully on 20-OCT-21 06.27.39.120263 PM
Interim patch 33192694 (OJVM RELEASE UPDATE: 19.13.0.0.211019 (33192694)):
Binary registry: Installed
SQL registry: Not installed
Current state of release update SQL patches:
Binary registry:
19.13.0.0.0 Release_Update 211004165050: Installed
SQL registry:
Applied 19.9.0.0.0 Release_Update 200930183249 successfully on 20-OCT-21 06.27.39.117792 PM
Adding patches to installation queue and performing prereq checks...done
Installation queue:
The following interim patches will be rolled back:
31668882 (OJVM RELEASE UPDATE: 19.9.0.0.201020 (31668882))
Patch 33192793 (Database Release Update : 19.13.0.0.211019 (33192793)):
Apply from 19.9.0.0.0 Release_Update 200930183249 to 19.13.0.0.0 Release_Update 211004165050
The following interim patches will be applied:
33192694 (OJVM RELEASE UPDATE: 19.13.0.0.211019 (33192694))
Installing patches...
Patch installation complete. Total patches installed: 3
Validating logfiles...done
Patch 31668882 rollback: SUCCESS
logfile: /u01/app/oracle/cfgtoollogs/sqlpatch/31668882/23790068/31668882_rollback_COLVINP_2022Feb08_17_54_43.log (no errors)
Patch 33192793 apply: SUCCESS
logfile: /u01/app/oracle/cfgtoollogs/sqlpatch/33192793/24462514/33192793_apply_COLVINP_2022Feb08_17_55_28.log (no errors)
Patch 33192694 apply: SUCCESS
logfile: /u01/app/oracle/cfgtoollogs/sqlpatch/33192694/24421575/33192694_apply_COLVINP_2022Feb08_17_55_28.log (no errors)
SQL Patching tool complete on Tue Feb 8 18:00:18 2022
When checking dba_registry_sqlpatch there is another column, ACTION. This column shows what happened during the operation in euqstion. When I add this column to my query, it all comes in to focus:
SQL> select PATCH_ID, PATCH_TYPE, ACTION, ACTION_TIME, DESCRIPTION, STATUS from dba_registry_sqlpatch;
PATCH_ID PATCH_TYPE ACTION ACTION_TIME DESCRIPTION STATUS
---------- ---------- --------------- ------------------------------ ------------------------------------------------------- --------
31668882 INTERIM APPLY 20-OCT-21 06.27.39.120263 PM OJVM RELEASE UPDATE: 19.9.0.0.201020 (31668882) SUCCESS
31771877 RU APPLY 20-OCT-21 06.27.39.117792 PM Database Release Update : 19.9.0.0.201020 (31771877) SUCCESS
31668882 INTERIM ROLLBACK 08-FEB-22 06.00.13.069042 PM OJVM RELEASE UPDATE: 19.9.0.0.201020 (31668882) SUCCESS
33192694 INTERIM APPLY 08-FEB-22 06.00.18.341368 PM OJVM RELEASE UPDATE: 19.13.0.0.211019 (33192694) SUCCESS
33192793 RU APPLY 08-FEB-22 06.00.18.335540 PM Database Release Update : 19.13.0.0.211019 (33192793) SUCCESS
Going back to Martin's original question, I believe this is what he is seeing. Checking the ACTION_TIME column in his results shows that the second operation on the 19.9 OJVM patch occurred three seconds before the operation on the 19.11 OJVM patch.
Hi Andy!
Today I accidentally stumbled across exactly the same topic when I was creating new golden images for Oracle 19.14. I was also struck by the two entries. Displaying the column “ACTION” was also the solution for me.
Best regards,
Martin