Parallelizing datapatch execution

When applying quarterly PSUs to an Oracle database, there are generally two steps - one step that applies updates to the binaries inside the Oracle home, and one step that updates objects inside the database catalog via registry$sqlpatch. The first step has long been performed with OPatch, but beginning with Oracle 12.1.0.1, the second task has a new script - datapatch. This script automates the post-patch actions, removing the need to run one script to roll a patch back and another to apply updates to the database. You can find the datapatch script in $ORACLE_HOME/OPatch inside your database home.

Prior to 12c, DBAs would have to run the catbundle.sql script after patching to apply updates to the database. Datapatch queries the OPatch inventory, compares it to what is listed in the dba_sqlpatch_registry view, and compiles a list of the SQL that needs to be run to patch the database objects. This means that if a patch was applied in the past and datapatch was not run, it will catch it on the next invocation. This also helps if a patch is removed - many times, administrators will forget to remove the patched objects from the database. The datapatch script is also useful for environments running Oracle’s multitenant feature - the script is aware of any pluggable databases and will run post-patch SQL against specific PDBs on an as-needed basis.

As with many newly automated features, one tradeoff of the dynamic nature of the script is that it can take more time to run datapatch than just running the catbundle.sql script provided in previous versions. One issue that I have found with the stock version of datapatch included with OPatch is that it does not do a good job of handling situations where the script is being run against multiple databases at once. While not an issue on some systems, I run across many hosts where there are dozens of databases running on a single host, and we prefer to do things in parallel wherever possible.

For example, we have a system freshly patched with the January 2017 PSU for 12.1.0.2. OPatch is running version 12.2.0.1.8.

$ /u01/app/oracle/product/12.1.0.2/dbhome_1/OPatch/opatch version
OPatch Version: 12.2.0.1.8

OPatch succeeded.

$ /u01/app/oracle/product/12.1.0.2/dbhome_1/OPatch/opatch lspatches -oh  /u01/app/oracle/product/12.1.0.2/dbhome_1
24326846;
24917972;Database PSU 12.1.0.2.170117, Oracle JavaVM Component (JAN2017)
25101514;OCW Interim patch for 25101514
24732088;DATABASE BUNDLE PATCH: 12.1.0.2.170117 (24732088)

OPatch succeeded.

We have 2 databases installed on the host - andycdb (with 2 pluggable databases) and e416. If I run the datapatch prerequisite check against andycdb, we can see that it checks the PDBs, and has determined which patches will be applied (24917972 and 24732088), and which will be rolled back (none):

$ ./datapatch -prereq
SQL Patching tool version 12.1.0.2.0 Production on Sun Mar 12 11:42:43 2017
Copyright (c) 2012, 2017, Oracle.  All rights reserved.

Connecting to database...OK
Note:  Datapatch will only apply or rollback SQL fixes for PDBs
       that are in an open state, no patches will be applied to closed PDBs.
       Please refer to Note: Datapatch: Database 12c Post Patch SQL Automation
       (Doc ID 1585822.1)
Bootstrapping registry and package to current versions...done
Determining current state...done
Adding patches to installation queue and performing prereq checks...done
Installation queue:
  For the following PDBs: CDB$ROOT PDB$SEED ANDYPDB1 ANDYPDB2
    Nothing to roll back
    The following patches will be applied:
      24917972 (Database PSU 12.1.0.2.170117, Oracle JavaVM Component (JAN2017))
      24732088 (DATABASE BUNDLE PATCH 12.1.0.2.170117)

SQL Patching tool complete on Sun Mar 12 11:43:17 2017

Since datapatch was run with the -prereq flag, it did not attempt to run the SQL scripts. It only checked to see what was needed to run. Now, let’s try and kick off datapatch on e416 and andycdb at the same time:

The andycdb datapatch run completed successfully, as shown below:

$ ./datapatch -verbose
SQL Patching tool version 12.1.0.2.0 Production on Sun Mar 12 11:48:38 2017
Copyright (c) 2012, 2017, Oracle.  All rights reserved.

Log file for this invocation: /u01/app/oracle/cfgtoollogs/sqlpatch/sqlpatch_246621_2017_03_12_11_48_38/sqlpatch_invocation.log

Connecting to database...OK
Note:  Datapatch will only apply or rollback SQL fixes for PDBs
       that are in an open state, no patches will be applied to closed PDBs.
       Please refer to Note: Datapatch: Database 12c Post Patch SQL Automation
       (Doc ID 1585822.1)
Bootstrapping registry and package to current versions...done
Determining current state...done

Current state of SQL patches:
Patch 24917972 (Database PSU 12.1.0.2.170117, Oracle JavaVM Component (JAN2017)):
  Installed in the binary registry only
Bundle series DBBP:
  ID 170117 in the binary registry and not installed in any PDB

Adding patches to installation queue and performing prereq checks...
Installation queue:
  For the following PDBs: CDB$ROOT PDB$SEED ANDYPDB1 ANDYPDB2
    Nothing to roll back
    The following patches will be applied:
      24917972 (Database PSU 12.1.0.2.170117, Oracle JavaVM Component (JAN2017))
      24732088 (DATABASE BUNDLE PATCH 12.1.0.2.170117)

Installing patches...
Patch installation complete.  Total patches installed: 8

Validating logfiles...
Patch 24917972 apply (pdb CDB$ROOT): SUCCESS
  logfile: /u01/app/oracle/cfgtoollogs/sqlpatch/24917972/20791781/24917972_apply_ANDYCDB_CDBROOT_2017Mar12_11_49_05.log (no errors)
Patch 24732088 apply (pdb CDB$ROOT): SUCCESS
  logfile: /u01/app/oracle/cfgtoollogs/sqlpatch/24732088/20933516/24732088_apply_ANDYCDB_CDBROOT_2017Mar12_11_49_58.log (no errors)
Patch 24917972 apply (pdb PDB$SEED): SUCCESS
  logfile: /u01/app/oracle/cfgtoollogs/sqlpatch/24917972/20791781/24917972_apply_ANDYCDB_PDBSEED_2017Mar12_11_51_27.log (no errors)
Patch 24732088 apply (pdb PDB$SEED): SUCCESS
  logfile: /u01/app/oracle/cfgtoollogs/sqlpatch/24732088/20933516/24732088_apply_ANDYCDB_PDBSEED_2017Mar12_11_52_16.log (no errors)
Patch 24917972 apply (pdb ANDYPDB1): SUCCESS
  logfile: /u01/app/oracle/cfgtoollogs/sqlpatch/24917972/20791781/24917972_apply_ANDYCDB_ANDYPDB1_2017Mar12_11_51_26.log (no errors)
Patch 24732088 apply (pdb ANDYPDB1): SUCCESS
  logfile: /u01/app/oracle/cfgtoollogs/sqlpatch/24732088/20933516/24732088_apply_ANDYCDB_ANDYPDB1_2017Mar12_11_52_19.log (no errors)
Patch 24917972 apply (pdb ANDYPDB2): SUCCESS
  logfile: /u01/app/oracle/cfgtoollogs/sqlpatch/24917972/20791781/24917972_apply_ANDYCDB_ANDYPDB2_2017Mar12_11_51_26.log (no errors)
Patch 24732088 apply (pdb ANDYPDB2): SUCCESS
  logfile: /u01/app/oracle/cfgtoollogs/sqlpatch/24732088/20933516/24732088_apply_ANDYCDB_ANDYPDB2_2017Mar12_11_52_16.log (no errors)
SQL Patching tool complete on Sun Mar 12 11:53:45 2017

Everything looks good here - you can see that the script identified all of my pluggable databases, and shows that each of them successfully applied the required patches. The e416 database, however, hit an issue:

$ ./datapatch -verbose
SQL Patching tool version 12.1.0.2.0 Production on Sun Mar 12 11:48:34 2017
Copyright (c) 2012, 2017, Oracle.  All rights reserved.

Log file for this invocation: /u01/app/oracle/cfgtoollogs/sqlpatch/sqlpatch_246353_2017_03_12_11_48_34/sqlpatch_invocation.log

Connecting to database...OK
Bootstrapping registry and package to current versions...done
Determining current state...
DBD::Oracle::st execute failed: ORA-31011: XML parsing failed
ORA-19213: error occurred in XML processing at lines 1
LPX-00210: expected '<' instead of 'd'
ORA-06512: at "SYS.DBMS_QOPATCH", line 1937
ORA-06512: at "SYS.DBMS_SQLPATCH", line 958
ORA-06512: at line 2 (DBD ERROR: OCIStmtExecute) [for Statement "BEGIN
         SELECT XMLSerialize(CONTENT dbms_sqlpatch.opatch_registry_state INDENT)
           INTO ?
           FROM dual;
       END;" with ParamValues: :p1=undef] at /u01/app/oracle/product/12.1.0.2/dbhome_1/sqlpatch/sqlpatch.pm line 1607,  line 112.


Please refer to MOS Note 1609718.1 and/or the invocation log
/u01/app/oracle/cfgtoollogs/sqlpatch/sqlpatch_246353_2017_03_12_11_48_34/sqlpatch_invocation.log
for information on how to resolve the above errors.

SQL Patching tool complete on Sun Mar 12 11:49:03 2017

If we look at the error, it’s failing with an error on DBMS_QOPATCH. The DBMS_QOPATCH package is the driving force behind datapatch. Mike Dietrich has a write up of some of the cool things that you can do with DBMS_QOPATCH at https://blogs.oracle.com/UPGRADE/entry/dbms_qopatch_datapatch_and_other. In our case, DBMS_QOPATCH calls a file named $ORACLE_HOME/QOpatch/qopiprep.bat - this script generates an XML copy of the OPatch inventory, which is then used to create and apply the patch plan. The meat of the script is found below. Unfortunately, the script generates the output with a hard coded file name:

$ORACLE_HOME/OPatch/opatch lsinventory -xml  $ORACLE_HOME/QOpatch/xml_file.xml -retry 0 -invPtrLoc $ORACLE_HOME/oraInst.loc >> $ORACLE_HOME/QOpatch/stout.txt
`echo "UIJSVTBOEIZBEFFQBL" >> $ORACLE_HOME/QOpatch/xml_file.xml`
echo `cat $ORACLE_HOME/QOpatch/xml_file.xml`
rm $ORACLE_HOME/QOpatch/xml_file.xml
rm $ORACLE_HOME/QOpatch/stout.txt

When multiple databases attempt to run datapatch at the same time, multiple processes trying to read/write the same file name cause issues, leading to the failure noted above. Thankfully, if you perform the right amount of magic in MOS, you will be led to note #2054286.1 (12.1:Parallel Execution Of Datapatch during Patching or Manual upgrade fails with error " ORA-12012:ORA-20001:ORA-06512:ORA-19202 “). This note suggests patch #19215058 to resolve the issue. Taking a look inside the patch, you will see a new version of the qopiprep.bat file. Note the difference:

DBSID=$ORACLE_SID
$ORACLE_HOME/OPatch/opatch lsinventory -xml  $ORACLE_HOME/QOpatch/xml_file_$DBSID.xml -retry 0 -invPtrLoc $ORACLE_HOME/oraInst.loc >> $ORACLE_HOME/QOpatch/stout_$DBSID.txt
`echo "UIJSVTBOEIZBEFFQBL" >> $ORACLE_HOME/QOpatch/xml_file_$DBSID.xml`
echo `cat $ORACLE_HOME/QOpatch/xml_file_$DBSID.xml`
rm $ORACLE_HOME/QOpatch/xml_file_$DBSID.xml
rm $ORACLE_HOME/QOpatch/stout_$DBSID.txt

The patched version of the script creates files with the Oracle SID in the file name, preventing the concurrent access issue. That’s great! Let’s try applying the patch:

$ /u01/app/oracle/product/12.1.0.2/dbhome_1/OPatch/opatch apply -oh  /u01/app/oracle/product/12.1.0.2/dbhome_1 -local -silent /archive/software/oracle/exadata/patches/12.1.0.2.170117/19215058
Oracle Interim Patch Installer version 12.2.0.1.8
Copyright (c) 2017, Oracle Corporation.  All rights reserved.


Oracle Home       : /u01/app/oracle/product/12.1.0.2/dbhome_1
Central Inventory : /u01/app/oraInventory
   from           : /u01/app/oracle/product/12.1.0.2/dbhome_1/oraInst.loc
OPatch version    : 12.2.0.1.8
OUI version       : 12.1.0.2.0
Log file location : /u01/app/oracle/product/12.1.0.2/dbhome_1/cfgtoollogs/opatch/opatch2017-03-12_12-45-08PM_1.log

Verifying environment and performing prerequisite checks...
Prerequisite check "CheckApplicable" failed.
The details are:

Patch 19215058:
Copy Action: Destination File "/u01/app/oracle/product/12.1.0.2/dbhome_1/QOpatch/qopiprep.bat" is not writeable.
'oracle.rdbms.rsf, 12.1.0.2.0': Cannot copy file from 'qopiprep.bat' to '/u01/app/oracle/product/12.1.0.2/dbhome_1/QOpatch/qopiprep.bat'

UtilSession failed:
Prerequisite check "CheckApplicable" failed.
Log file location: /u01/app/oracle/product/12.1.0.2/dbhome_1/cfgtoollogs/opatch/opatch2017-03-12_12-45-08PM_1.log

OPatch failed with error code 73

Oh dear…we have a misleading “CheckApplicable” prerequisite failure. Fortunately, the actual error message is listed above:

Patch 19215058:
Copy Action: Destination File "/u01/app/oracle/product/12.1.0.2/dbhome_1/QOpatch/qopiprep.bat" is not writeable.
'oracle.rdbms.rsf, 12.1.0.2.0': Cannot copy file from 'qopiprep.bat' to '/u01/app/oracle/product/12.1.0.2/dbhome_1/QOpatch/qopiprep.bat'

Looking at the file, we can see that out of the stock installation, it is in fact not writeable. Changing the permissions to 754 allows the patch to succeed

$ ls -al /u01/app/oracle/product/12.1.0.2/dbhome_1/QOpatch/qopiprep.bat
-r-xr-xr-- 1 oracle oinstall 1372 Apr  7  2013 /u01/app/oracle/product/12.1.0.2/dbhome_1/QOpatch/qopiprep.bat

$ chmod 754 /u01/app/oracle/product/12.1.0.2/dbhome_1/QOpatch/qopiprep.bat

$ /u01/app/oracle/product/12.1.0.2/dbhome_1/OPatch/opatch apply -oh  /u01/app/oracle/product/12.1.0.2/dbhome_1 -local -silent /archive/software/oracle/exadata/patches/12.1.0.2.170117/19215058
Oracle Interim Patch Installer version 12.2.0.1.8
Copyright (c) 2017, Oracle Corporation.  All rights reserved.


Oracle Home       : /u01/app/oracle/product/12.1.0.2/dbhome_1
Central Inventory : /u01/app/oraInventory
   from           : /u01/app/oracle/product/12.1.0.2/dbhome_1/oraInst.loc
OPatch version    : 12.2.0.1.8
OUI version       : 12.1.0.2.0
Log file location : /u01/app/oracle/product/12.1.0.2/dbhome_1/cfgtoollogs/opatch/opatch2017-03-12_12-48-51PM_1.log

Verifying environment and performing prerequisite checks...
OPatch continues with these patches:   19215058

Do you want to proceed? [y|n]
Y (auto-answered by -silent)
User Responded with: Y
All checks passed.

Please shutdown Oracle instances running out of this ORACLE_HOME on the local system.
(Oracle Home = '/u01/app/oracle/product/12.1.0.2/dbhome_1')


Is the local system ready for patching? [y|n]
Y (auto-answered by -silent)
User Responded with: Y
Backing up files...
Applying interim patch '19215058' to OH '/u01/app/oracle/product/12.1.0.2/dbhome_1'

Patching component oracle.rdbms.rsf, 12.1.0.2.0...
Patch 19215058 successfully applied.
Log file location: /u01/app/oracle/product/12.1.0.2/dbhome_1/cfgtoollogs/opatch/opatch2017-03-12_12-48-51PM_1.log

OPatch succeeded.

Moving on, we can now try to run datapatch against multiple databases at once. For fun, I’ll run a “watch” command listing out the contents of $ORACLE_HOME/QOPatch to see if we can catch both XML files in use:

$ ls -al /u01/app/oracle/product/12.1.0.2/dbhome_1/QOpatch
-rw-r-----  1 oracle dba        71077 Mar 12 13:03 qopatch_log.log
-rwxr-xr--  1 oracle oinstall    1580 Feb 25  2015 qopiprep.bat
-rw-r--r--  1 oracle oinstall     843 Mar 12 13:03 stout_andycdb1.txt
-rw-r--r--  1 oracle oinstall     840 Mar 12 13:03 stout_e4161.txt
-rw-r--r--  1 oracle oinstall 1853220 Mar 12 13:03 xml_file_andycdb1.xml
-rw-r--r--  1 oracle oinstall 1853220 Mar 12 13:03 xml_file_e4161.xml

Most importantly, here’s the output from the e416 database which had previously failed applying the patch:

$ ./datapatch -verbose
SQL Patching tool version 12.1.0.2.0 Production on Sun Mar 12 13:02:36 2017
Copyright (c) 2012, 2017, Oracle.  All rights reserved.

Log file for this invocation: /u01/app/oracle/cfgtoollogs/sqlpatch/sqlpatch_38217_2017_03_12_13_02_36/sqlpatch_invocation.log

Connecting to database...OK
Bootstrapping registry and package to current versions...done
Determining current state...done

Current state of SQL patches:
Patch 24917972 (Database PSU 12.1.0.2.170117, Oracle JavaVM Component (JAN2017)):
  Installed in the binary registry only
Bundle series DBBP:
  ID 170117 in the binary registry and not installed in the SQL registry

Adding patches to installation queue and performing prereq checks...
Installation queue:
  Nothing to roll back
  The following patches will be applied:
    24917972 (Database PSU 12.1.0.2.170117, Oracle JavaVM Component (JAN2017))
    24732088 (DATABASE BUNDLE PATCH 12.1.0.2.170117)

Installing patches...
Patch installation complete.  Total patches installed: 2

Validating logfiles...
Patch 24917972 apply: SUCCESS
  logfile: /u01/app/oracle/cfgtoollogs/sqlpatch/24917972/20791781/24917972_apply_E416_2017Mar12_13_03_14.log (no errors)
Patch 24732088 apply: SUCCESS
  logfile: /u01/app/oracle/cfgtoollogs/sqlpatch/24732088/20933516/24732088_apply_E416_2017Mar12_13_04_08.log (no errors)
SQL Patching tool complete on Sun Mar 12 13:05:44 2017

For the sake of the example, I rolled back the SQL in andycdb, which forced some old patch files to be applied. That’s the reason that the output here is a little different from before:

$ ./datapatch -verbose
SQL Patching tool version 12.1.0.2.0 Production on Sun Mar 12 13:02:26 2017
Copyright (c) 2012, 2017, Oracle.  All rights reserved.

Log file for this invocation: /u01/app/oracle/cfgtoollogs/sqlpatch/sqlpatch_36010_2017_03_12_13_02_26/sqlpatch_invocation.log

Connecting to database...OK
Note:  Datapatch will only apply or rollback SQL fixes for PDBs
       that are in an open state, no patches will be applied to closed PDBs.
       Please refer to Note: Datapatch: Database 12c Post Patch SQL Automation
       (Doc ID 1585822.1)
Bootstrapping registry and package to current versions...done
Determining current state...done

Current state of SQL patches:
Patch 21555660 (Database PSU 12.1.0.2.5, Oracle JavaVM Component (Oct2015)):
  Installed in CDB$ROOT PDB$SEED only
Patch 24917972 (Database PSU 12.1.0.2.170117, Oracle JavaVM Component (JAN2017)):
  Installed in the binary registry and ANDYPDB1 ANDYPDB2
Bundle series DBBP:
  ID 170117 in the binary registry and ID 13 in PDB CDB$ROOT, ID 13 in PDB PDB$SEED, ID 170117 in PDB ANDYPDB1, ID 170117 in PDB ANDYPDB2

Adding patches to installation queue and performing prereq checks...
Installation queue:
  For the following PDBs: CDB$ROOT PDB$SEED
    The following patches will be rolled back:
      21555660 (Database PSU 12.1.0.2.5, Oracle JavaVM Component (Oct2015))
    The following patches will be applied:
      24917972 (Database PSU 12.1.0.2.170117, Oracle JavaVM Component (JAN2017))
      24732088 (DATABASE BUNDLE PATCH 12.1.0.2.170117)
  For the following PDBs: ANDYPDB1 ANDYPDB2
    Nothing to roll back
    Nothing to apply

Installing patches...
Patch installation complete.  Total patches installed: 6

Validating logfiles...
Patch 21555660 rollback (pdb CDB$ROOT): SUCCESS
  logfile: /u01/app/oracle/cfgtoollogs/sqlpatch/21555660/19361790/21555660_rollback_ANDYCDB_CDBROOT_2017Mar12_13_02_49.log (no errors)
Patch 24917972 apply (pdb CDB$ROOT): SUCCESS
  logfile: /u01/app/oracle/cfgtoollogs/sqlpatch/24917972/20791781/24917972_apply_ANDYCDB_CDBROOT_2017Mar12_13_03_38.log (no errors)
Patch 24732088 apply (pdb CDB$ROOT): SUCCESS
  logfile: /u01/app/oracle/cfgtoollogs/sqlpatch/24732088/20933516/24732088_apply_ANDYCDB_CDBROOT_2017Mar12_13_03_39.log (no errors)
Patch 21555660 rollback (pdb PDB$SEED): SUCCESS
  logfile: /u01/app/oracle/cfgtoollogs/sqlpatch/21555660/19361790/21555660_rollback_ANDYCDB_PDBSEED_2017Mar12_13_04_50.log (no errors)
Patch 24917972 apply (pdb PDB$SEED): SUCCESS
  logfile: /u01/app/oracle/cfgtoollogs/sqlpatch/24917972/20791781/24917972_apply_ANDYCDB_PDBSEED_2017Mar12_13_05_23.log (no errors)
Patch 24732088 apply (pdb PDB$SEED): SUCCESS
  logfile: /u01/app/oracle/cfgtoollogs/sqlpatch/24732088/20933516/24732088_apply_ANDYCDB_PDBSEED_2017Mar12_13_05_23.log (no errors)
SQL Patching tool complete on Sun Mar 12 13:06:17 2017

For one final check, I like to look at the dba_registry_sqlpatch view, which tells me if the patches have been successfully applied inside the database:

SQL> set lines 200
SQL> col ACTION_TIME for A30
SQL> col DESCRIPTION for A75
SQL> select PATCH_ID, VERSION, ACTION, STATUS, ACTION_TIME, DESCRIPTION from DBA_REGISTRY_SQLPATCH;

  PATCH_ID VERSION              ACTION          STATUS          ACTION_TIME                    DESCRIPTION
---------- -------------------- --------------- --------------- ------------------------------ ---------------------------------------------------------------------------
  24917972 12.1.0.2             APPLY           SUCCESS         12-MAR-17 01.05.42.447389 PM   Database PSU 12.1.0.2.170117, Oracle JavaVM Component (JAN2017)
  24732088 12.1.0.2             APPLY           SUCCESS         12-MAR-17 01.05.44.506995 PM   DATABASE BUNDLE PATCH 12.1.0.2.170117