Oracle 12C Problem with datapatch. Part 2, the “fix”

so after much too-ing and fro-ing with Oracle Support, we finally have a solution to my datapatch problem. Prevent the timeout from happening when running datapatch! We know which part of the code was timing out, and we can do this by setting an undocumented event: 18219841.

Here’s a show test to show you how that was done:

SQL: select dbms_sqlpatch.verify_queryable_inventory from dual;

VERIFY_QUERYABLE_INVENTORY
--------------------------
ORA-20008: timed out. Job Load_opatch_inventory_1execution time is more than 120Secs

(wait a while for the background job to clean up)

SQL: alter session set events '18219841 trace name context forever';

Session Altered

SQL: select dbms_sqlpatch.verify_queryable_inventory from dual;

VERIFY_QUERYABLE_INVENTORY
--------------------------
OK

patch 19769480 installed in all nodes
patch 20299023 installed in all nodes
patch 28031110 installed in all nodes

and switch it back off

alter session set events '18219841 trace name context off';

You may note above that I was changing the context for the session only, as a test. To get it to work with datapatch, you will need to use “alter system” commands before and after running datapatch.

I would recommend that you do not set this event without first contacting Oracle Support. You may wish to quote “Bug 21121707” I would recommend you un-set it afterwards too – you don’t know what it’s doing and you don’t understand if there are any negative side-effects.

To check if the event is set in your session/system:

in sqlplus...

sql: var level number
sql: exec dbms_system.read_ev(1821984, :level);
sql: print :level

              LEVEL 
-------------------
                  1

Addendum: After a twitter conversation, it was noted by Martin Berger (@martinberx) that the nature of the query had changed with the event set, and that it was no longer calling the scheduler jobs. I did note, however, that it’s still calling the same pre-processor, but without the timeout (so it will run until it’s finished, however long that may be): $ORACLE_HOME/QOPatch/qopiprep.bat  – It’s getting information from GV$QPX_INVENTORY, whatever that view does. Answers on a post card (or comment) please.

Oracle 12C Problem with datapatch

I was minding my business, patching an Oracle 12C RAC Cluster when the darned patch failed

./datapatch -verbose

SQL Patching tool version 12.1.0.2.0 on Mon Aug  3 20:47:31 2015
Copyright (c) 2015, Oracle.  All rights reserved.
Log file for this invocation: /u01/app/oracle/cfgtoollogs/sqlpatch/sqlpatch_9841_2015_08_03_20_47_31/sqlpatch_invocation.log

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

Queryable inventory could not determine the current opatch status.
Execute 'select dbms_sqlpatch.verify_queryable_inventory from dual'
and/or check the invocation log
/u01/app/oracle/cfgtoollogs/sqlpatch/sqlpatch_9841_2015_08_03_20_47_31/sqlpatch_invocation.log
for the complete error.
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_9841_2015_08_03_20_47_31/sqlpatch_invocation.log
for information on how to resolve the above errors.

SQL Patching tool complete on Mon Aug 3 20:49:37 2015

So, following the instructions, I ran the query used to ID the inventory

[oracle@rac12c01 OPatch]$ sqlplus / as sysdba
SQL*Plus: Release 12.1.0.2.0 Production on Mon Aug 3 20:59:37 2015

Copyright (c) 1982, 2014, Oracle. All rights reserved.

Connected to:
Oracle Database 12c Enterprise Edition Release 12.1.0.2.0 - 64bit Production
With the Partitioning, Real Application Clusters, Automatic Storage Management, OLAP,
Advanced Analytics and Real Application Testing options

20:59:37 SYS @ ORCL1 > select dbms_sqlpatch.verify_queryable_inventory from dual;

VERIFY_QUERYABLE_INVENTORY
--------------------------
ORA-20008: Timed out, Job Load_opatch_inventory_2execution time is more than 120Secs

op_scpt_path :/u01/app/oracle/product/12.1.0/dbhome_1/QOpatchpos1

The code has timed out! So, there are some clues about what’s going on with this code. This procedure has a preprocessor, which needs to get information into the database. To do this, it invokes a scheduler job [Load_opatch_inventory_n where ‘n’ represents the cluster node executing the command], to pull in information from the o/s. Here’s a job running, with it’s definition – note the job name is mentioned in the failure above:

select job_name,state,job_action from dba_scheduler_jobs where job_name like '%PATCH%' order by job_name;
JOB_NAME                STATE    JOB_ACTION
----------------------- -------- ----------
LOAD_OPATCH_INVENTORY   DISABLED BEGIN dbms_qopatch.opatch_inv_refresh_job(); END;
LOAD_OPATCH_INVENTORY_1 DISABLED BEGIN dbms_qopatch.opatch_inv_refresh_job(); END;
LOAD_OPATCH_INVENTORY_2 RUNNING  BEGIN dbms_qopatch.opatch_inv_refresh_job(); END;

and dbms_qopatch.opatch_inv_refresh_job() also invokes a preprocessor. This preprocessor is a batch job. A shell script in /u01/app/oracle/product/12.1.0/dbhome_1/QOpatch called qopiprep.bat And this shell script basically runs…

opatch lsinventory -xml

to get the current patches, formatted as XML. It then tacks a delimiter onto the end and returns it to the calling job before cleaning up after itself. This command can be slow-ish to execute, but on the problem cluster in question, it was running particularly slowly.

This command runs on all nodes, which return the output to the calling job, which then has to process the inbound XML files and determine if all is OK in the world of opatch before continuing. You have 2 minutes. GO! If you don’t finish in 2 minutes, the who thing fails, with no obvious remedial action possible.

One option you have, should you encounter this problem and be desperate for a workaround is to preprocess the XML file, and just get the batch file to return your handywork:

NOTE: This is very much a one-off to keep things moving and you must return the preprocessor code to it’s normal state and raise a call with Oracle Support to get this fixed properly. Do this workaround at your own risk. I don’t recommend it. Raise a call with Oracle Support instead.

save the pre-processor to put back later:

cp -p qopiprep.bat qopiprep.bat.sav

run the commands in the file:

$ORACLE_HOME/OPatch/opatch lsinventory -xml $ORACLE_HOME/QOpatch/xml_file.xml -retry 0 -invPtrLoc $ORACLE_HOME/oraInst.loc >> $ORACLE_HOME/QOpatch/stout.txt

tack the delimiter string onto the end of the XML file

echo "UIJSVTBOEIZBEFFQBL" >> $ORACLE_HOME/QOpatch/xml_file.xml

edit the sciprt (qopiprep.bat) and remove the bottom 5 commands EXCEPT the “echo `cat…” bit, which returns the output to the calling code:

# Option: "-all" gives information on all Oracle Homes
# installed in the central inventory. With that information, the
# patches of non-RDBMS homes could be fetched.
$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

Now when you run, the dbms_sqlpatch command, you have taken the opatch lsinventory slow aspect of the preprocessor out of the equation:

21:04:13 SYS @ ORCL1 > select dbms_sqlpatch.verify_queryable_inventory from dual;
VERIFY_QUERYABLE_INVENTORY
--------------------------
OK
op_scpt_path :/u01/app/oracle/product/12.1.0/dbhome_1/QOpatchpos1
patch 19769480 installed in all nodes
patch 20299023 installed in all nodes
patch 20831110 installed in all nodes

don’t forget to put the correct processing code back once the datapatch -verbose has been completed successfully. And you need to clean up all of the output files you created, otherwise the code will fail again.

Hey, let’s be careful out there.

Oracle 12.1.0.2.0 ACFS on Linux 7 don’t work

I installed OEL 7.1…

uname -a
Linux rac12c01 3.8.13-55.1.6.el7uek.x86_64

Then I installed Grid Infrastructure and Database 12.1.0.2.0 and looked to configure ACFS for the database files, ready for DB create. And it won’t let me. In asmca, the tabs are greyed-out.

Lets just investigate that:

acfsdriverstate supported
ACFS-9459: ADVM/ACFS is not supported on this OS version: 'unknown'

Unknown! Great. This means…patching. After a bit of searching, I need:

Patch 20485724 – Oracle Grid Infrastructure Patch Set Update 12.1.0.2.3 (Apr2015) [p20485724_121020_Linux-x86-64.zip]

So, patch downloaded and onto each node to run:

/u01/app/grid/OPatch/opatchauto apply /u01/sw/20485724 -ocmrf *omf_reposnse*file*

Oh. An OMF response file is now mandatory for patching, and that’s new to me. Off to MOS Doc 966023.1 to find out how I do that!

First I need to download the latest Opatch, as the default install doesn’t have the binaries (emocmrsp) I need. Download and install Opatch: 6880880 (p6880880_121010_Linux-x86-64.zip) into the grid home.

Now, lets create an OCM response file:

ORACLE_HOME=/u01/app/grid
$ORACLE_HOME/OPatch/ocm/bin/emocmrsp -no_banner -output /u01/sw/grid_ocm.rsp

So lets check current releases before we start (note the versions and patching level):

/u01/app/grid/OPatch/opatch lsinventory  -oh /u01/app/grid
Oracle Interim Patch Installer version 12.1.0.1.8
Copyright (c) 2015, Oracle Corporation.  All rights reserved.

Oracle Home       : /u01/app/grid
Central Inventory : /u01/app/oraInventory
   from           : /u01/app/grid/oraInst.loc
OPatch version    : 12.1.0.1.8
OUI version       : 12.1.0.2.0
Log file location : /u01/app/grid/cfgtoollogs/opatch/opatch2015-07-11_17-19-01PM_1.log

Lsinventory Output file location : /u01/app/grid/cfgtoollogs/opatch/lsinv/lsinventory2015-07-11_17-19-01PM.txt

--------------------------------------------------------------------------------
Local Machine Information::
Hostname: rac12c02
ARU platform id: 226
ARU platform description:: Linux x86-64

Installed Top-level Products (1):

Oracle Grid Infrastructure 12c                                       12.1.0.2.0
There are 1 products installed in this Oracle Home.

There are no Interim patches installed in this Oracle Home.

Patch level status of Cluster nodes :

 Patching Level                  Nodes
 --------------                  -----
 0                               rac12c03,rac12c02,rac12c01
--------------------------------------------------------------------------------

And so let’s patch!

/u01/app/grid/OPatch/opatchauto apply /u01/sw/20485724 -ocmrf /u01/sw/grid_ocm.rsp
OPatch Automation Tool
Copyright (c)2014, Oracle Corporation. All rights reserved.

OPatchauto Version : 12.1.0.1.8
OUI Version        : 12.1.0.2.0
Running from       : /u01/app/grid

opatchauto log file: /u01/app/grid/cfgtoollogs/opatchauto/20485724/opatch_gi_2015-07-11_17-10-25_deploy.log

Parameter Validation: Successful

Configuration Validation: Successful

Patch Location: /u01/sw/20485724
Grid Infrastructure Patch(es): 19872484 20299018 20299022 20299023
DB Patch(es): 20299022 20299023

Patch Validation: Successful
Grid Infrastructure home:
/u01/app/grid


Performing prepatch operations on CRS Home... Successful

Applying patch(es) to "/u01/app/grid" ...
Patch "/u01/sw/20485724/19872484" successfully applied to "/u01/app/grid".
Patch "/u01/sw/20485724/20299018" successfully applied to "/u01/app/grid".
Patch "/u01/sw/20485724/20299022" successfully applied to "/u01/app/grid".
Patch "/u01/sw/20485724/20299023" successfully applied to "/u01/app/grid".

Performing postpatch operations on CRS Home... Successful

Apply Summary:
Following patch(es) are successfully installed:
GI Home: /u01/app/grid: 19872484,20299018,20299022,20299023

opatchauto succeeded.

on each node in turn…. then a quick check to make sure they are all patched to the same level:

/u01/app/grid/OPatch/opatch lsinventory  -oh /u01/app/grid
Oracle Interim Patch Installer version 12.1.0.1.8
Copyright (c) 2015, Oracle Corporation.  All rights reserved.


Oracle Home       : /u01/app/grid
Central Inventory : /u01/app/oraInventory
   from           : /u01/app/grid/oraInst.loc
OPatch version    : 12.1.0.1.8
OUI version       : 12.1.0.2.0
Log file location : /u01/app/grid/cfgtoollogs/opatch/opatch2015-07-11_20-34-00PM_1.log

Lsinventory Output file location : /u01/app/grid/cfgtoollogs/opatch/lsinv/lsinventory2015-07-11_20-34-00PM.txt

--------------------------------------------------------------------------------
Local Machine Information::
Hostname: rac12c01
ARU platform id: 226
ARU platform description:: Linux x86-64

Installed Top-level Products (1):

Oracle Grid Infrastructure 12c                                       12.1.0.2.0
There are 1 products installed in this Oracle Home.


Interim patches (4) :

Patch  20299023     : applied on Sat Jul 11 17:33:30 BST 2015
Unique Patch ID:  18703022
Patch description:  "Database Patch Set Update : 12.1.0.2.3 (20299023)"
   Created on 16 Mar 2015, 22:21:54 hrs PST8PDT
Sub-patch  19769480; "Database Patch Set Update : 12.1.0.2.2 (19769480)"
   Bugs fixed:
     19189525, 19065556, 19075256, 19723336, 19077215, 19865345, 18845653
[snip]
     19885321, 19163887, 19820247, 18715868, 18852058, 19538241, 19804032

Patch  20299018     : applied on Sat Jul 11 17:26:39 BST 2015
Unique Patch ID:  18582442
Patch description:  "ACFS Patch Set Update : 12.1.0.2.3 (20299018)"
   Created on 4 Mar 2015, 23:52:42 hrs PST8PDT
   Bugs fixed:
     19452723, 19078259, 19919907, 18900953, 20010980, 19127216, 18934139
[snip]
     18510745, 18915417, 19134464, 19060056, 18955907

Patch  19872484     : applied on Sat Jul 11 17:21:04 BST 2015
Unique Patch ID:  18291456
Patch description:  "WLM Patch Set Update: 12.1.0.2.2 (19872484)"
   Created on 2 Dec 2014, 23:18:41 hrs PST8PDT
   Bugs fixed:
     19016964, 19582630



Patch level status of Cluster nodes :

 Patching Level                  Nodes
 --------------                  -----
 3467666221                      rac12c03,rac12c02,rac12c01

--------------------------------------------------------------------------------

OPatch succeeded.

Well that looks good. All patching is complete, can we use ACFS?

[oracle@rac12c01 ~]$ acfsdriverstate supported
ACFS-9200: Supported
[oracle@rac12c01 ~]$ acfsdriverstate version
ACFS-9325:     Driver OS kernel version = 3.8.13-35.3.1.el7uek.x86_64(x86_64).
ACFS-9326:     Driver Oracle version = 150210.
[oracle@rac12c01 ~]$ acfsdriverstate installed
ACFS-9203: true
[oracle@rac12c01 ~]$ acfsdriverstate loaded
ACFS-9203: true

Sweet.

After creating a DG, creating a volume in the DG and mounting it on all nodes:

df -h
Filesystem             Size  Used Avail Use% Mounted on
/dev/mapper/ol00-root   20G  1.3G   19G   7% /
devtmpfs               2.2G     0  2.2G   0% /dev
tmpfs                  2.2G  1.3G  992M  56% /dev/shm
tmpfs                  2.2G  8.6M  2.2G   1% /run
tmpfs                  2.2G     0  2.2G   0% /sys/fs/cgroup
/dev/sdb1               52G   30G   23G  58% /u01
/dev/mapper/ol00-home   20G   33M   20G   1% /home
/dev/sda1              497M  140M  357M  29% /boot
/dev/asm/acfs_u02-433   19G  153M   19G   1% /u02