Страницы

понедельник, 17 августа 2015 г.

EM 12.1.0.4 Installing recommended Plug-Ins and Patches

In one of the project we will use DBaaS (Database as a Service) functionality of EM Cloud Control 12c.
We faced with a multiple issue and decided to upgrade EM and install Oracle recommended patches from note:
Enterprise Manager Cloud Control 12c Recommended Plug-Ins and Patches for Database as a Service (DBaaS) (Doc ID 1549855.1)
Specifically:
Patch 20870437: ENTERPRISE MANAGER BASE PLATFORM - OMS 12.1.0.4.4 PSU (GENERIC)
and
Patch 21415432: enterprise manager for oms plugins 12.1.0.4.14
We had vanilla EM 12.1.0.4 installation without any PSU or patches (except Cloud Framework Plug-In version 12.1.0.2.0).

ENTERPRISE MANAGER BASE PLATFORM - OMS 12.1.0.4.4 PSU
At the step of installation:
2.9 Run the following command on each OMS instance home to ensure that you do not have any issues with configuration and binary prerequisite checks,
I encountered an error:
[oracle@mgmt 20870437]$ 
/u01/app/oracle/oms12/oms/OPatch/opatchauto apply -analyze 
-property_file /u01/app/oracle/oms12/oms/OPatch/wlskeys/property_file 
-invPtrLoc /u01/app/oracle/oms12/oms/oraInst.loc  
OPatchAuto.OMS_DISABLE_HOST_CHECK=true
OPatch Automation Tool
Copyright (c) 2014, Oracle Corporation.  All rights reserved.
  
  
OPatchauto version : 11.1.0.10.4
OUI version        : 11.1.0.12.0
Running from       : /u01/app/oracle/oms12/oms
Log file location  : /u01/app/oracle/oms12/oms/cfgtoollogs/opatch/opatch2015-08-07_17-00-41PM_1.log
  
OPatchauto log file: /u01/app/oracle/oms12/oms/cfgtoollogs/opatchauto/20870437/opatch_oms_2015-08-07_17-00-43PM_analyze.log
  
  
  
OPatchauto
 failed to establish JMX connection to weblogic server. This could be 
because of one (or) more of the following reasons:
1. Weblogic admin server URL that manages OMS application may not be right.
2. Weblogic admin server credentials (username, password) may not be right.
3.
 Virtual host configuration. If OMS, weblogic server are on virtual host
 configuration, Please make sure to add 
OPatchAuto.OMS_DISABLE_HOST_CHECK=true to command line and run again. 
(example: /u01/app/oracle/oms12/oms/OPatch/opatchauto apply -analyze 
-property_file /u01/app/oracle/oms12/oms/OPatch/wlskeys/property_file 
-invPtrLoc /u01/app/oracle/oms12/oms/oraInst.loc 
OPatchAuto.OMS_DISABLE_HOST_CHECK=true 
OPatchAuto.OMS_DISABLE_HOST_CHECK=true)
  
Please check above conditions and if error(s) still persist, Please contact Oracle support.
  
  
[ Error during Get weblogic Admin Server information Phase]. Detail: OPatchauto was not able to find right interview inputs.
OPatchauto failed:
OPatchauto
 failed to establish JMX connection to weblogic server. This could be 
because of one (or) more of the following reasons:
1. Weblogic admin server URL that manages OMS application may not be right.
2. Weblogic admin server credentials (username, password) may not be right.
3.
 Virtual host configuration. If OMS, weblogic server are on virtual host
 configuration, Please make sure to add 
OPatchAuto.OMS_DISABLE_HOST_CHECK=true to command line and run again. 
(example: /u01/app/oracle/oms12/oms/OPatch/opatchauto apply -analyze 
-property_file /u01/app/oracle/oms12/oms/OPatch/wlskeys/property_file 
-invPtrLoc /u01/app/oracle/oms12/oms/oraInst.loc 
OPatchAuto.OMS_DISABLE_HOST_CHECK=true 
OPatchAuto.OMS_DISABLE_HOST_CHECK=true)
  
Please check above conditions and if error(s) still persist, Please contact Oracle support.
  
Log file location: /u01/app/oracle/oms12/oms/cfgtoollogs/opatchauto/20870437/opatch_oms_2015-08-07_17-00-43PM_analyze.log
  
Recommended actions: Please correct the interview inputs and run opatchauto again.
  
OPatchauto failed with error code 231
[oracle@mgmt 20870437]$
I searched through MOS knowledge base and have decided that this error due to the old OPatch version.
I found a note with a same error:
EM12c : OPatchauto fails with : opatchauto finds that weblogic credentials may not be right or admin server is down (Doc ID 1644317.1)
From which I concluded that issue should be resolved after OPatch 11.1.0.11 install.
As I seen from the logs, we have used OPatch version 11.1.0.10.4.
I installed latest OPatch version 11.1.0.x and installation of PSU was ended without any issues.

Enterprise Manager for OMS Plug-Ins 12.1.0.4.14
opatchauto apply -analyze command showed that from 18 sub-patches I could install only 1.
[oracle@mgmt 21415432]$ /u01/app/oracle/oms12/oms/OPatch/opatchauto apply -analyze -invPtrLoc /u01/app/oracle/oms12/oms/oraInst.loc  OPatchAuto.OMS_DISABLE_HOST_CHECK=true
OPatch Automation Tool
Copyright (c) 2014, Oracle Corporation.  All rights reserved.
 
OPatchauto version : 11.1.0.12.3
OUI version        : 11.1.0.12.0
Running from       : /u01/app/oracle/oms12/oms
Log file location  : /u01/app/oracle/oms12/oms/cfgtoollogs/opatch/opatch2015-08-10_15-52-13PM_1.log
 
OPatchauto log file: /u01/app/oracle/oms12/oms/cfgtoollogs/opatchauto/21415432/opatch_oms_2015-08-10_15-52-16PM_analyze.log
 
Please enter OMS weblogic admin server URL(t3s://mgmt.localdomain:7102):>
Please enter OMS weblogic admin server username:> weblogic
Please enter OMS weblogic admin server password:>
 
WARNING: Sub-patch "19060193" skipped for incompatibility with components installed in the OMS system.
WARNING: Sub-patch "19513319" skipped for incompatibility with components installed in the OMS system.
WARNING: Sub-patch "19512418" skipped for incompatibility with components installed in the OMS system.
WARNING: Sub-patch "20466650" skipped for incompatibility with components installed in the OMS system.
WARNING: Sub-patch "20623942" skipped for incompatibility with components installed in the OMS system.
WARNING: Sub-patch "20950018" skipped for incompatibility with components installed in the OMS system.
WARNING: Sub-patch "20950277" skipped for incompatibility with components installed in the OMS system.
WARNING: Sub-patch "21167953" skipped for incompatibility with components installed in the OMS system.
WARNING: Sub-patch "21167965" skipped for incompatibility with components installed in the OMS system.
WARNING: Sub-patch "21167991" skipped for incompatibility with components installed in the OMS system.
WARNING: Sub-patch "21174690" skipped for incompatibility with components installed in the OMS system.
WARNING: Sub-patch "21185095" skipped for incompatibility with components installed in the OMS system.
WARNING: Sub-patch "21324604" skipped for incompatibility with components installed in the OMS system.
WARNING: Sub-patch "21324646" skipped for incompatibility with components installed in the OMS system.
WARNING: Sub-patch "21324654" skipped for incompatibility with components installed in the OMS system.
WARNING: Sub-patch "21324861" skipped for incompatibility with components installed in the OMS system.
WARNING: Sub-patch "21324890" skipped for incompatibility with components installed in the OMS system.
 
Configuration Validation: Success
 
Running apply prerequisite checks for sub-patch(es) "21167573" and Oracle Home "/u01/app/oracle/oms12/plugins/oracle.sysman.cfw.oms.plugin_12.1.0.2.0"...
Please monitor OPatch log file: /u01/app/oracle/oms12/plugins/oracle.sysman.cfw.oms.plugin_12.1.0.2.0/cfgtoollogs/opatch/21167573_Aug_10_2015_15_52_13/ApplyPrereq2015-08-10_15-53-08PM_2.log
Sub-patch(es) "21167573" are successfully analyzed for Oracle Home "/u01/app/oracle/oms12/plugins/oracle.sysman.cfw.oms.plugin_12.1.0.2.0"
 
Complete Summary
================
 
All log file names referenced below can be accessed from the directory "/u01/app/oracle/oms12/oms/cfgtoollogs/opatch/2015-08-10_15-52-13PM_SystemPatch_21415432_1"
 
Prerequisites analysis summary:
-------------------------------
  
The following sub-patch(es) are applicable:
 
  Oracle Home Name   Sub-patches                                          Log file
  ----------------   -----------                                          --------
         OraHome18      21167573   21167573_ApplyPrereq2015-08-10_15-53-08PM_2.log
 
The following sub-patches are incompatible with components installed in the OMS system:
19060193,19513319,19512418,20466650,20623942,20950018,20950277,21167953,21167965,21167991,21174690,21185095,21324604,21324646,21324654,21324861,21324890
 
--------------------------------------------------------------------------------
 
The following warnings have occurred during OPatchauto execution:
1)  Sub-patch "19060193" skipped for incompatibility with components installed in the OMS system.
2)  Sub-patch "19513319" skipped for incompatibility with components installed in the OMS system.
3)  Sub-patch "19512418" skipped for incompatibility with components installed in the OMS system.
4)  Sub-patch "20466650" skipped for incompatibility with components installed in the OMS system.
5)  Sub-patch "20623942" skipped for incompatibility with components installed in the OMS system.
6)  Sub-patch "20950018" skipped for incompatibility with components installed in the OMS system.
7)  Sub-patch "20950277" skipped for incompatibility with components installed in the OMS system.
8)  Sub-patch "21167953" skipped for incompatibility with components installed in the OMS system.
9)  Sub-patch "21167965" skipped for incompatibility with components installed in the OMS system.
10)  Sub-patch "21167991" skipped for incompatibility with components installed in the OMS system.
11)  Sub-patch "21174690" skipped for incompatibility with components installed in the OMS system.
12)  Sub-patch "21185095" skipped for incompatibility with components installed in the OMS system.
13)  Sub-patch "21324604" skipped for incompatibility with components installed in the OMS system.
14)  Sub-patch "21324646" skipped for incompatibility with components installed in the OMS system.
15)  Sub-patch "21324654" skipped for incompatibility with components installed in the OMS system.
16)  Sub-patch "21324861" skipped for incompatibility with components installed in the OMS system.
17)  Sub-patch "21324890" skipped for incompatibility with components installed in the OMS system.
--------------------------------------------------------------------------------
 
OPatchauto Session completed with warnings.
 
Log file location: /u01/app/oracle/oms12/oms/cfgtoollogs/opatchauto/21415432/opatch_oms_2015-08-10_15-52-16PM_analyze.log
 
OPatchauto completed with warnings.
 
[oracle@mgmt 21415432]$
Most of the patches was skipped due to incompatibility checks:
WARNING: Sub-patch "21324890" skipped for incompatibility with components installed in the OMS system.
I searched through MOS knowledge base and found a note:
EM 12c: Applying a System Patch to the Enterprise Manager 12.1.0.4 Cloud Control OMS Oracle Home Fails at Analyze with Error: Sub-patch skipped for incompatibility with components installed in the OMS system (Doc ID 1921337.1) which tell us that:

Such incompatibility errors result from two scenarios:
Case 1:The Bundle Patch is comprised of patches for the OMS Oracle Home as well as Plug-in Homes. If one of these Plugins is not present in the environment, then these patches would be skipped automatically as they are not needed.
Case 2: If the plug-in is present but is of a lower version than the plug-in versions mentioned above, then such errors can also result.


Patch 21415432 (Enterprise Manager for OMS Plug-Ins 12.1.0.4.14) contains patches for the below list of plugins:
  • Enterprise Manager for Cloud: 12.1.0.8.0
  • Enterprise Manager for Fusion Middleware: 12.1.0.6.0
  • Enterprise Manager for Oracle Database: 12.1.0.6.0
  • Enterprise Manager for Fusion Applications: 12.1.0.6.0
  • Enterprise Manager for Storage Management Framework: 12.1.0.4.0
  • Enterprise Manager for Siebel: 12.1.0.5.0
  • Enterprise Manager for Exadata : 12.1.0.6.0
  • Enterprise Manager for Oracle Virtual Infrastructure: 12.1.0.1.0
  • Enterprise Manager for Virtualization: 12.1.0.6.0
  • Enterprise Manager for My Oracle Support: 12.1.0.6.0
  • Enterprise Manager for Chargeback and Capacity Planning: 12.1.0.6.0
  • Enterprise Manager for Apache Tomcat: 12.1.0.3.0
  • Enterprise Manager for Oracle Database: 12.1.0.7.0
  • Enterprise Manager for Storage Management Framework: 12.1.0.5.0
  • Enterprise Manager for Cloud: 12.1.0.9.0
  • Enterprise Manager for Fusion Middleware: 12.1.0.7.0
Reading further the note
EM 12c: Applying a System Patch to the Enterprise Manager 12.1.0.4 Cloud Control OMS Oracle Home Fails at Analyze with Error: Sub-patch skipped for incompatibility with components installed in the OMS system (Doc ID 1921337.1), I have found the emcli commands which can be used to verify versions of plugins installed on the OMS:
./emcli login -username=sysman
./emcli sync
./emcli list_plugins_on_server
I run above commands and found that I have plugin versions which should be patched by the Patch 21415432 (I highlight DB and SMF plugins for simplicity):
OMS name is mgmt.localdomain:4889_Management_Service
Plug-in Name                        Plugin-id                   Version [revision]
Oracle Cloud Framework              oracle.sysman.cfw           12.1.0.2.0
Oracle Database                     oracle.sysman.db            12.1.0.6.0
Oracle Fusion Middleware            oracle.sysman.emas          12.1.0.6.0
Oracle MOS (My Oracle Support)      oracle.sysman.mos           12.1.0.6.0
Oracle Storage Management Framework oracle.sysman.smf           12.1.0.4.0
Oracle Cloud Application            oracle.sysman.ssa           12.1.0.8.0
Oracle Virtual Infrastructure       oracle.sysman.vi            12.1.0.1.0
Oracle Virtualization               oracle.sysman.vt            12.1.0.6.0
Oracle Exadata                      oracle.sysman.xa            12.1.0.6.0
I continued searching through MOS and found the Bug 21287619 : OPATCHAUTO UNABLE TO IDENTIFY INSTALLED PLUGIN_HOME which was without the resolution but provided some ideas for further investigations.
I started to check them.
At first, I verified that I have correct plugin versions in PLUGIN_HOME:
[oracle@mgmt 21415432]$ ls -la /u01/app/oracle/oms12/plugins/
drwxr-xr-x 14 oracle oinstall 4096 Aug  4 15:05 .
drwxr-x--- 16 oracle oinstall 4096 Jul 11  2014 ..
drwxr-xr-x  2 oracle oinstall 4096 Aug  4 15:31 backup
drwxr-xr-x 12 oracle oinstall 4096 Jul 11  2014 oracle.sysman.cfw.oms.plugin_12.1.0.1.0
drwxr----- 14 oracle oinstall 4096 Aug 10 14:58 oracle.sysman.cfw.oms.plugin_12.1.0.2.0
drwxr-xr-x 18 oracle oinstall 4096 Aug  4 15:03 oracle.sysman.db.oms.plugin_12.1.0.6.0
drwxr-xr-x 18 oracle oinstall 4096 Jul 11  2014 oracle.sysman.emas.oms.plugin_12.1.0.6.0
drwxr-xr-x 13 oracle oinstall 4096 Jul 11  2014 oracle.sysman.mos.oms.plugin_12.1.0.6.0
drwxr-xr-x 12 oracle oinstall 4096 Jul 11  2014 oracle.sysman.smf.oms.plugin_12.1.0.4.0
drwxr-xr-x 14 oracle oinstall 4096 Jul 11  2014 oracle.sysman.ssa.oms.plugin_12.1.0.8.0
drwxr-xr-x 12 oracle oinstall 4096 Jul 11  2014 oracle.sysman.vi.oms.plugin_12.1.0.1.0
drwxr-xr-x 15 oracle oinstall 4096 Jul 11  2014 oracle.sysman.vt.oms.plugin_12.1.0.6.0
drwxr-xr-x 13 oracle oinstall 4096 Jul 11  2014 oracle.sysman.xa.oms.plugin_12.1.0.6.0
drwxr-xr-x  2 oracle oinstall 4096 Jul 11  2014 tmp
I reviewed opatch/opatchauto lspatches output:
[oracle@mgmt 21415432]$ opatch lspatches
20870437;ENTERPRISE MANAGER BASE PLATFORM - OMS 12.1.0.4.4 PSU (GENERIC)
[oracle@mgmt 21415432]$ opatchauto lspatches
OPatch Automation Tool
Copyright (c) 2014, Oracle Corporation.  All rights reserved.
Oracle Home:/u01/app/oracle/oms12/oms
20870437;ENTERPRISE MANAGER BASE PLATFORM - OMS 12.1.0.4.4 PSU (GENERIC)
The following groups of patch(es) are applied as System Patch bundle(s):
20870437
For more details on installed patch(es) in platform, plugin homes, Please do "/u01/app/oracle/oms12/oms/OPatch/opatch lsinventory -details -oh <desired home path>".
opatch lsinv output:
[oracle@mgmt 21415432]$ opatch lsinv
Oracle Interim Patch Installer version 11.1.0.12.7
Copyright (c) 2015, Oracle Corporation.  All rights reserved.
Oracle Home       : /u01/app/oracle/oms12/oms
Central Inventory : /u01/app/oraInventory
   from           : /u01/app/oracle/oms12/oms/oraInst.loc
OPatch version    : 11.1.0.12.7
OUI version       : 11.1.0.12.0
Log file location : /u01/app/oracle/oms12/oms/cfgtoollogs/opatch/opatch2015-08-11_08-41-48AM_1.log
OPatch detects the Middleware Home as "/u01/app/oracle/oms12"
Lsinventory Output file location : /u01/app/oracle/oms12/oms/cfgtoollogs/opatch/lsinv/lsinventory2015-08-11_08-41-48AM.txt
--------------------------------------------------------------------------------
Installed Top-level Products (1):
EM Platform (OMS)                                                    12.1.0.4.0
There are 1 products installed in this Oracle Home.
Interim patches (1) :
Patch  20870437     : applied on Mon Aug 10 15:19:39 MSK 2015
Unique Patch ID:  18978384
Patch description:  "ENTERPRISE MANAGER BASE PLATFORM - OMS 12.1.0.4.4 PSU (GENERIC)"
   Created on 2 Jul 2015, 03:07:25 hrs PST8PDT
   Bugs fixed:
     20010360, 20346629, 18599481, 19459173, 20646440, 18830050, 18244680
     19614772, 20492788, 18932882, 19355307, 20263906, 20556489, 20106145
     14301574, 18721562, 19328391, 19535114, 19861538, 19794113, 19604817
     20596437, 19892848, 19218456, 19978077, 18505219, 17843191, 20345612
     20748748, 20024779, 18256983, 19329809, 19300103, 17987955, 18351725
     18903783, 19430853, 19845101, 20870437, 20223681, 20019184, 20263188
     19069940, 19861412, 19136663, 18446798, 19474685, 18765545, 18038059
     17783148, 18041873, 19509780, 19030447, 20933667, 19574756, 19258481
     18938561, 17812648, 20377474, 19572261, 18945007, 20307428, 18388324
     19500609, 17991694, 19137411, 19474929, 19592446, 18710124, 20536095
     19352118, 19557054, 18726708, 19595813, 19170861, 19685443, 18353162
     19289270, 19367214, 18906451, 19458672, 20284029, 18490444, 19766881
     18509136, 20739088, 19511544, 18695961, 19812966, 20576148, 20623258
     19055251, 20260177, 19323634, 19941819, 18725891, 19824587, 19780847
     18359621, 19393211, 19211048, 20505155, 18476364, 18490468, 18247849
     19071602, 19068674, 18490455, 19524568, 19061168, 19077861, 20031287
     18756725, 19281252, 18977955, 18521731, 18485889, 19775544, 18900197
     17834366, 20460507, 19545505, 19823996, 20645335, 20633770, 17407918
     18706824, 20568225, 18805935, 19376082, 19146514, 18490432, 19694744
     18230284, 18726208, 20044313, 18516298, 20642633, 18999400, 20692416
     20392036, 19362386, 19452280, 18356966, 20617058, 19055979, 19830994
     20030493, 19823761, 18834216, 19196979, 19785223, 18389542
  
--------------------------------------------------------------------------------
OPatch succeeded.
I found an answer in an inventory.xml from Central Inventory:
<HOME NAME="oms12c1" LOC="/u01/app/oracle/oms12/oms" TYPE="O" IDX="3">
   <REFHOMELIST>
      <REFHOME LOC="/u01/app/oracle/oms12/plugins/oracle.sysman.db.oms.plugin_12.1.0.4.0"/>
      <REFHOME LOC="/u01/app/oracle/oms12/plugins/oracle.sysman.xa.oms.plugin_12.1.0.4.0"/>
      <REFHOME LOC="/u01/app/oracle/oms12/plugins/oracle.sysman.emas.oms.plugin_12.1.0.4.0"/>
      <REFHOME LOC="/u01/app/oracle/oms12/plugins/oracle.sysman.mos.oms.plugin_12.1.0.5.0"/>
      <REFHOME LOC="/u01/app/oracle/oms12/jdk16"/>
      <REFHOME LOC="/u01/app/oracle/oms12/plugins/oracle.sysman.vt.oms.plugin_12.1.0.5.0"/>
      <REFHOME LOC="/u01/app/oracle/oms12/plugins/oracle.sysman.ssa.oms.plugin_12.1.0.6.0"/>
      <REFHOME LOC="/u01/app/oracle/oms12/plugins/oracle.sysman.smf.oms.plugin_12.1.0.2.0"/>
      <REFHOME LOC="/u01/app/oracle/oms12/plugins/oracle.sysman.ssa.oms.plugin_12.1.0.7.0"/>
      <REFHOME LOC="/u01/app/oracle/oms12/plugins/oracle.sysman.db.oms.plugin_12.1.0.5.0"/>
      <REFHOME LOC="/u01/app/oracle/oms12/plugins/oracle.sysman.smf.oms.plugin_12.1.0.3.0"/>
      <REFHOME LOC="/u01/app/oracle/oms12/plugins/oracle.sun.oss7.oms.plugin_12.1.0.4.0"/>
      <REFHOME LOC="/u01/app/oracle/oms12/plugins/oracle.sysman.emas.oms.plugin_12.1.0.5.0"/>
      <REFHOME LOC="/u01/app/oracle/oms12/plugins/oracle.sysman.cfw.oms.plugin_12.1.0.2.0"/>
   </REFHOMELIST>
</HOME>
Notice, that inventory.xml contains old plugin versions! It's hard to say what exactly leads to a such behaviour and I didn't have enough time for further investigations.
It was enough for me, that inventory.xml dont contain actual plugin versions.

Example 1: oracle.sysman.smf.oms.plugin (Storage Management Framework).
emcli list_plugins_on_server shows version 12.1.0.4:
Oracle Storage Management Framework          oracle.sysman.smf             12.1.0.4.0
inventory.xml contains information about versions 12.1.0.2/12.1.0.3:
<HOME NAME="OraHome13" LOC="/u01/app/oracle/oms12/plugins/oracle.sysman.smf.oms.plugin_12.1.0.2.0" TYPE="O" IDX="24" PLUGIN="T">
<HOME NAME="OraHome16" LOC="/u01/app/oracle/oms12/plugins/oracle.sysman.smf.oms.plugin_12.1.0.3.0" TYPE="O" IDX="29" PLUGIN="T">
Patch 21415432 contains fixes for SMF plugin versions 12.1.0.4/12.1.0.5.

Example 2: oracle.sysman.db.oms.plugin (Database Plugin).
emcli list_plugins_on_server shows version 12.1.0.6:
Oracle Database                               oracle.sysman.db                12.1.0.6.0
inventory.xml contains information about versions 12.1.0.4/12.1.0.5:
<HOME NAME="oracle_sysman_db11" LOC="/u01/app/oracle/oms12/plugins/oracle.sysman.db.oms.plugin_12.1.0.4.0" TYPE="O" IDX="4" PLUGIN="T">
<HOME NAME="OraHome15" LOC="/u01/app/oracle/oms12/plugins/oracle.sysman.db.oms.plugin_12.1.0.5.0" TYPE="O" IDX="28" PLUGIN="T">
Patch 21415432 contains fixes for Database Plugin versions 12.1.0.6/12.1.0.7.
Due to such inconsistencies opatch reported a message like below:
WARNING: Sub-patch "19060193" skipped for incompatibility with components installed in the OMS system.
I decided to recover lost inventory entities by note:
EM 12c: How to Recover a Lost Inventory Record for the Enterprise Manager 12.1.0.1 Cloud Control OMS and Management Agent (Doc ID 1480237.1)

GOAL

In the case that recovering a lost inventory record may be necessary, this note describes how to accomplish this for the Enterprise Manager 12.1.0.1 Cloud Control OMS and Management Agent.


First of all, I had take backup of Central Inventory, local inventory, ORACLE_HOME of OMS.
8 plugins from 9 total didn't have an actual version in the inventory.xml.
For each of them, I executed steps from the note:
EM 12c: How to Recover a Lost Inventory Record for the Enterprise Manager 12.1.0.1 Cloud Control OMS and Management Agent (Doc ID 1480237.1)
I remind, that before my actions only 1 sub-patch (from 18) could be applied to the OMS.
And after that, opatchauto analyze showed that 9 sub-patches from 18 could be applied to the OMS. Bingo!
OMS Plug-Ins patches contains fixes for 2 versions of each plugin. And only one of them was installed in my environment.
[oracle@mgmt 21415432]$ /u01/app/oracle/oms12/oms/OPatch/opatchauto apply -analyze -invPtrLoc /u01/app/oracle/oms12/oms/oraInst.loc  OPatchAuto.OMS_DISABLE_HOST_CHECK=true
OPatch Automation Tool
Copyright (c) 2014, Oracle Corporation.  All rights reserved.
 
OPatchauto version : 11.1.0.12.3
OUI version        : 11.1.0.12.0
Running from       : /u01/app/oracle/oms12/oms
Log file location  : /u01/app/oracle/oms12/oms/cfgtoollogs/opatch/opatch2015-08-11_17-13-05PM_1.log
OPatchauto log file: /u01/app/oracle/oms12/oms/cfgtoollogs/opatchauto/21415432/opatch_oms_2015-08-11_17-13-08PM_analyze.log
 
Please enter OMS weblogic admin server URL(t3s://mgmt.localdomain:7102):>
Please enter OMS weblogic admin server username:> weblogic
Please enter OMS weblogic admin server password:>
 
WARNING: Sub-patch "19512418" skipped for incompatibility with components installed in the OMS system.
WARNING: Sub-patch "20466650" skipped for incompatibility with components installed in the OMS system.
WARNING: Sub-patch "20950277" skipped for incompatibility with components installed in the OMS system.
WARNING: Sub-patch "21167965" skipped for incompatibility with components installed in the OMS system.
WARNING: Sub-patch "21185095" skipped for incompatibility with components installed in the OMS system.
WARNING: Sub-patch "21324604" skipped for incompatibility with components installed in the OMS system.
WARNING: Sub-patch "21324646" skipped for incompatibility with components installed in the OMS system.
WARNING: Sub-patch "21324654" skipped for incompatibility with components installed in the OMS system.
WARNING: Sub-patch "21324861" skipped for incompatibility with components installed in the OMS system.
  
Configuration Validation: Success
 
Running apply prerequisite checks for sub-patch(es) "21324890" and Oracle Home "/u01/app/oracle/oms12/plugins/oracle.sysman.vi.oms.plugin_12.1.0.1.0"...
Please monitor OPatch log file: /u01/app/oracle/oms12/plugins/oracle.sysman.vi.oms.plugin_12.1.0.1.0/cfgtoollogs/opatch/21324890_Aug_11_2015_17_13_05/ApplyPrereq2015-08-11_17-13-58PM_2.log
Sub-patch(es) "21324890" are successfully analyzed for Oracle Home "/u01/app/oracle/oms12/plugins/oracle.sysman.vi.oms.plugin_12.1.0.1.0"
 
Running apply prerequisite checks for sub-patch(es) "21167573" and Oracle Home "/u01/app/oracle/oms12/plugins/oracle.sysman.cfw.oms.plugin_12.1.0.2.0"...
Please monitor OPatch log file: /u01/app/oracle/oms12/plugins/oracle.sysman.cfw.oms.plugin_12.1.0.2.0/cfgtoollogs/opatch/21167573_Aug_11_2015_17_13_05/ApplyPrereq2015-08-11_17-14-01PM_2.log
Sub-patch(es) "21167573" are successfully analyzed for Oracle Home "/u01/app/oracle/oms12/plugins/oracle.sysman.cfw.oms.plugin_12.1.0.2.0"
 
Running apply prerequisite checks for sub-patch(es) "21174690" and Oracle Home "/u01/app/oracle/oms12/plugins/oracle.sysman.db.oms.plugin_12.1.0.6.0"...
Please monitor OPatch log file: /u01/app/oracle/oms12/plugins/oracle.sysman.db.oms.plugin_12.1.0.6.0/cfgtoollogs/opatch/21174690_Aug_11_2015_17_13_05/ApplyPrereq2015-08-11_17-14-03PM_2.log
Sub-patch(es) "21174690" are successfully analyzed for Oracle Home "/u01/app/oracle/oms12/plugins/oracle.sysman.db.oms.plugin_12.1.0.6.0"
 
Running apply prerequisite checks for sub-patch(es) "21167953" and Oracle Home "/u01/app/oracle/oms12/plugins/oracle.sysman.xa.oms.plugin_12.1.0.6.0"...
Please monitor OPatch log file: /u01/app/oracle/oms12/plugins/oracle.sysman.xa.oms.plugin_12.1.0.6.0/cfgtoollogs/opatch/21167953_Aug_11_2015_17_13_05/ApplyPrereq2015-08-11_17-14-06PM_2.log
Sub-patch(es) "21167953" are successfully analyzed for Oracle Home "/u01/app/oracle/oms12/plugins/oracle.sysman.xa.oms.plugin_12.1.0.6.0"
 
Running apply prerequisite checks for sub-patch(es) "19060193" and Oracle Home "/u01/app/oracle/oms12/plugins/oracle.sysman.vt.oms.plugin_12.1.0.6.0"...
Please monitor OPatch log file: /u01/app/oracle/oms12/plugins/oracle.sysman.vt.oms.plugin_12.1.0.6.0/cfgtoollogs/opatch/19060193_Aug_11_2015_17_13_05/ApplyPrereq2015-08-11_17-14-09PM_2.log
Sub-patch(es) "19060193" are successfully analyzed for Oracle Home "/u01/app/oracle/oms12/plugins/oracle.sysman.vt.oms.plugin_12.1.0.6.0"
 
Running apply prerequisite checks for sub-patch(es) "20950018" and Oracle Home "/u01/app/oracle/oms12/plugins/oracle.sysman.emas.oms.plugin_12.1.0.6.0"...
Please monitor OPatch log file: /u01/app/oracle/oms12/plugins/oracle.sysman.emas.oms.plugin_12.1.0.6.0/cfgtoollogs/opatch/20950018_Aug_11_2015_17_13_05/ApplyPrereq2015-08-11_17-14-11PM_2.log
Sub-patch(es) "20950018" are successfully analyzed for Oracle Home "/u01/app/oracle/oms12/plugins/oracle.sysman.emas.oms.plugin_12.1.0.6.0"
 
Running apply prerequisite checks for sub-patch(es) "20623942" and Oracle Home "/u01/app/oracle/oms12/plugins/oracle.sysman.ssa.oms.plugin_12.1.0.8.0"...
Please monitor OPatch log file: /u01/app/oracle/oms12/plugins/oracle.sysman.ssa.oms.plugin_12.1.0.8.0/cfgtoollogs/opatch/20623942_Aug_11_2015_17_13_05/ApplyPrereq2015-08-11_17-14-14PM_2.log
Sub-patch(es) "20623942" are successfully analyzed for Oracle Home "/u01/app/oracle/oms12/plugins/oracle.sysman.ssa.oms.plugin_12.1.0.8.0"
 
Running apply prerequisite checks for sub-patch(es) "19513319" and Oracle Home "/u01/app/oracle/oms12/plugins/oracle.sysman.smf.oms.plugin_12.1.0.4.0"...
Please monitor OPatch log file: /u01/app/oracle/oms12/plugins/oracle.sysman.smf.oms.plugin_12.1.0.4.0/cfgtoollogs/opatch/19513319_Aug_11_2015_17_13_05/ApplyPrereq2015-08-11_17-14-17PM_2.log
Sub-patch(es) "19513319" are successfully analyzed for Oracle Home "/u01/app/oracle/oms12/plugins/oracle.sysman.smf.oms.plugin_12.1.0.4.0"
 
Running apply prerequisite checks for sub-patch(es) "21167991" and Oracle Home "/u01/app/oracle/oms12/plugins/oracle.sysman.mos.oms.plugin_12.1.0.6.0"...
Please monitor OPatch log file: /u01/app/oracle/oms12/plugins/oracle.sysman.mos.oms.plugin_12.1.0.6.0/cfgtoollogs/opatch/21167991_Aug_11_2015_17_13_05/ApplyPrereq2015-08-11_17-14-19PM_2.log
Sub-patch(es) "21167991" are successfully analyzed for Oracle Home "/u01/app/oracle/oms12/plugins/oracle.sysman.mos.oms.plugin_12.1.0.6.0"
 
Complete Summary
================
 
All log file names referenced below can be accessed from the directory "/u01/app/oracle/oms12/oms/cfgtoollogs/opatch/2015-08-11_17-13-05PM_SystemPatch_21415432_1"
 
Prerequisites analysis summary:
-------------------------------
 
The following sub-patch(es) are applicable:
 
                                 Oracle Home Name   Sub-patches                                          Log file
                                 ----------------   -----------                                          --------
                       oracle_home_MOS_12_1_0_6_0      21167991   21167991_ApplyPrereq2015-08-11_17-14-19PM_2.log
  oracle_home_Oracle_Fusion_Middleware_12_1_0_6_0      20950018   20950018_ApplyPrereq2015-08-11_17-14-11PM_2.log
                        oracle_home_OV_12_1_0_6_0      19060193   19060193_ApplyPrereq2015-08-11_17-14-09PM_2.log
                                        OraHome18      21167573   21167573_ApplyPrereq2015-08-11_17-14-01PM_2.log
                       oracle_home_OVI_12_1_0_1_0      21324890   21324890_ApplyPrereq2015-08-11_17-13-58PM_2.log
                        oracle_home_OE_12_1_0_6_0      21167953   21167953_ApplyPrereq2015-08-11_17-14-06PM_2.log
                       oracle_home_OCA_12_1_0_8_0      20623942   20623942_ApplyPrereq2015-08-11_17-14-14PM_2.log
           oracle_home_Oracle_Database_12_1_0_6_0      21174690   21174690_ApplyPrereq2015-08-11_17-14-03PM_2.log
                       oracle_home_SMF_12_1_0_4_0      19513319   19513319_ApplyPrereq2015-08-11_17-14-17PM_2.log
  
The following sub-patches are incompatible with components installed in the OMS system:
19512418,20466650,20950277,21167965,21185095,21324604,21324646,21324654,21324861
 
--------------------------------------------------------------------------------
 
The following warnings have occurred during OPatchauto execution:
1)  Sub-patch "19512418" skipped for incompatibility with components installed in the OMS system.
2)  Sub-patch "20466650" skipped for incompatibility with components installed in the OMS system.
3)  Sub-patch "20950277" skipped for incompatibility with components installed in the OMS system.
4)  Sub-patch "21167965" skipped for incompatibility with components installed in the OMS system.
5)  Sub-patch "21185095" skipped for incompatibility with components installed in the OMS system.
6)  Sub-patch "21324604" skipped for incompatibility with components installed in the OMS system.
7)  Sub-patch "21324646" skipped for incompatibility with components installed in the OMS system.
8)  Sub-patch "21324654" skipped for incompatibility with components installed in the OMS system.
9)  Sub-patch "21324861" skipped for incompatibility with components installed in the OMS system.
--------------------------------------------------------------------------------
OPatchauto Session completed with warnings.
 
Log file location: /u01/app/oracle/oms12/oms/cfgtoollogs/opatchauto/21415432/opatch_oms_2015-08-11_17-13-08PM_analyze.log
 
OPatchauto completed with warnings.
Further installation was ended without any issues.

понедельник, 3 августа 2015 г.

Reclaim unused space from MLOG$ segments after MVIEW Refresh

We are using fast-refreshable MVIEWs in some of our database for reporting purposes.
They are works fine most of the time.
However, periodically MLOG size is increased due to different reasons.
Such as: bulk data loading, other abnormal application activities, or delays with MVIEW refresh.
After that, even if you refresh MVIEW, HWM doesn't reset.
You need to reset it manually, using commands such as ALTER TABLE SHRINK/MOVE and so on.
Without resetting the HWM MVIEW refresh performance can be poor.

Good news: there are Patch 11072728 available for some platforms that can reset the HWM without manual intervention.
This patch was described in MOS note Space Not Reclaimed from MLOG$ Segments After MVIEW Refresh (Doc ID 1941137.1)
According to the note, the fix for bug 11072728 will be provided in upcoming 12.2 release.
I have already requested that patch for Solaris SPARC64 on top of 11.2.0.4.4/11.2.0.4.6.

Today I have decided to look closer on Patch 11072728 in one of non-production database.
I want to be sure that patch didn't harm production instance.

Reading the bug readme, I have found that fix for bug is not enabled by default.
You need to set underscope parameter _bug11072728_mv_refresh_truncate_log to 1 to enable it.
Worth to be noted, is that we can change this parameter on the session and on the system level:
SQL> select isses_modifiable,
  2         issys_modifiable
  3    from v$parameter
  4   where name = '_bug11072728_mv_refresh_truncate_log';

ISSES_MODIFIABLE ISSYS_MODIFIABLE
---------------- ----------------
TRUE             IMMEDIATE
Next script I have used to setup test schema:
SQL> grant connect to tc identified by tc;

Grant succeeded.

SQL> grant alter session to tc;

Grant succeeded.

SQL> grant create materialized view to tc;

Grant succeeded.

SQL> grant create table to tc;

Grant succeeded.

SQL> grant unlimited tablespace to tc;

Grant succeeded.

SQL> 
SQL> conn tc/tc
Connected.
SQL> 
SQL> create table t
  2  as
  3  select *
  4    from all_users;

Table created.

SQL> 
SQL> alter table t add constraint t_pk primary key(username);

Table altered.

SQL> 
SQL> create materialized view log on t with primary key;

Materialized view log created.

SQL> 
SQL> create materialized view mv_t
  2  refresh fast
  3  as
  4  select *
  5    from t;

Materialized view created.
    
In the above script I have created table, mat view log on it, and materialized view.
We can see that mat view log is empty, segment has 8 blocks allocated:
SQL> select count(*) from mlog$_t;

  COUNT(*)
----------
         0

SQL> 
SQL> select blocks
  2    from user_segments
  3   where segment_name = 'MLOG$_T';

    BLOCKS
----------
         8
I update table in loop, 100 times in total:
SQL> begin
  2    for i in 1..100
  3    loop
  4      update t
  5         set created = created
  6       where username <> 'SYS';
  7      commit;
  8    end loop;
  9  end;
 10  /
Check that mat view log is not empty, segment was extended:
SQL> select count(*) from mlog$_t;

  COUNT(*)
----------
     19400

SQL> 
SQL> select blocks
  2    from user_segments
  3   where segment_name = 'MLOG$_T';

    BLOCKS
----------
       104
Let's refresh materialized view now:
SQL> exec dbms_mview.refresh( 'mv_t', method=>'f')

PL/SQL procedure successfully completed.
If the patch 11072728 was not applied or the parameter "_bug11072728_mv_refresh_truncate_log" not set to 1, then the HWM is not reset and the segment space allocated is the same:
SQL> select count(*) from mlog$_t;

  COUNT(*)
----------
         0

SQL> 
SQL> select blocks
  2    from user_segments
  3   where segment_name = 'MLOG$_T';

    BLOCKS
----------
       104
In the production system with a high DML activity materialized view logs can grows to a much higher size.
And the materialized view refresh performance degrades.
As I said previously, before the patch 11072728 you need to reset the HWM manually.
With the patch 11072829 you dont need to do it anymore.
Just the set parameter "_bug11072728_mv_refresh_truncate_log" to 1:
SQL> exec dbms_mview.refresh( 'mv_t', method=>'f')

PL/SQL procedure successfully completed.

SQL> 
SQL> select count(*) from mlog$_t;

  COUNT(*)
----------
         0

SQL> 
SQL> select blocks
  2    from user_segments
  3   where segment_name = 'MLOG$_T';

    BLOCKS
----------
         8
You can see that segment allocated space was decreased.
How does it works under the hood?
I have setup sql tracing and event 10704 (enqueue trace) to investigate it:
SQL> alter session set events 'sql_trace bind=true:10704 level 10';

Session altered.

SQL> 
SQL> exec dbms_mview.refresh( 'mv_t', method=>'f')

PL/SQL procedure successfully completed.
I used below command to filter the irrelevant lines from output:
egrep "ksqgtl \*|ksqrcl: [^r]|^truncate|select count\(\*\) from .*MLOG" orcl_ora_18632.trc
  • ksqgtl - get lock function
  • ksqrcl - release lock function
  • We want to show the truncate command and the select count(*) from MLOG.
Below is the output of egrep command, in which some lines was skipped for brevity:
select count(*) from "TC"."MLOG$_T"
ksqgtl *** TM-001854e4-00000000 mode=6 flags=0x401 timeout=0 ***
select count(*) from "TC"."MLOG$_T"
ksqgtl *** TM-001854e6-00000000 mode=6 flags=0x401 timeout=0 ***
truncate table "TC"."MLOG$_T"
These commands was executed when the materialized view update already done.
Looks like that new algorithm with MLOG truncate works in following way:
  1. execute old refresh code
  2. check count of rows in MLOG
  3. if zero, lock master table in exclusive mode nowait (TM lock with timeout=0)
  4. check count of rows in MLOG again (because there are can be DML between step 2 and 3)
  5. lock MLOG in exclusive mode nowait (TM lock with timeout=0)
  6. truncate MLOG
At least, an open transaction will prevent the truncation of MLOG.
And that indirectly confirms my assumptions about internal workings of new refresh algorithm. Let's update the 1 row in table in session 1:
SQL> -- session 1
SQL> update t
  2     set created=created
  3   where username='SYS';

1 row updated.
Now we will check space of MLOG before refresh, perform actual refresh and check the space again (in other session):
SQL> -- session 2
SQL> select blocks
  2    from user_segments
  3   where segment_name = 'MLOG$_T';

    BLOCKS
----------
       104

SQL> exec dbms_mview.refresh( 'mv_t', method=>'f')

PL/SQL procedure successfully completed.
SQL> 
SQL> select count(*) from mlog$_t;

  COUNT(*)
----------
         0

SQL> 
SQL> select blocks
  2    from user_segments
  3   where segment_name = 'MLOG$_T';

    BLOCKS
----------
       104
And the truncate of MLOG was not executed.
Looks like, it's safe to use a patch 11072728 in the production environment.
If I will face any issue with that patch in the production, I will update this blog post.

среда, 22 июля 2015 г.

Edition-Based redefinition: adjunct schemas

EBR (Edition-Based Redefinition) - one of the killer feature of Oracle Database 11g R2, as said Tom Kyte at the 2010.
But I don't think that this feature widely used by Oracle community.
Why? Probably, because application must be "edition-aware", as described by Tom Kyte in his excellent articles.
I have been using EBR (Edition-Based Redefinition) since 2012.
In this blog post I would like to describe one of the basic component of EBR: adjunct schemas.
All of this information is a pure speculations based on blog posts and Oracle whitepapers, and my experience with EBR feature.
All of the tests are run in Oracle Database version 12.1.0.2 under Solaris SPARC.
Here is a code that I have used for this demo:
def tns_alias=orcl

doc
  connect as DBA user
#
conn /@&tns_alias.

set echo on timi off ti off sqlp "SQL> "

drop edition e1 cascade;
drop edition e2 cascade;
drop user tc cascade;

doc
  Create editions-enabled schema
#
grant create procedure, create session to tc identified by tc;

alter user tc enable editions;

doc
  Enable SQL tracing
#

alter session set events 'sql_trace bind=true';

doc
  Create 2 editions
#

create edition e1;
create edition e2;

alter session set events 'sql_trace off';

select value from v$diag_info where name='Default Trace File';
You can see that I have created edition-enabled schema TC and 2 editions: E1 and E2.
I would to point your attention to the below recursive SQL executed during "CREATE EDITION" command:
PARSING IN CURSOR #18446744071422692152 len=288 dep=1 uid=0 oct=2 lid=0 tim=9324454212634 hv=556673006 ad='430c59cc0' sqlid='fws71mhhkw9zf'
insert into user$(user#, name, password, ctime, ptime,                      datats#, tempts#, type#, defrole, resource$, ltime,                      astatus, lcount, spare1, spare2, ext_user
name)    values(:1, :2, NULL, sysdate, null, :3, :4, 2, :5, :6, null, :7, 0, 16,           :8, :9)
END OF STMT
PARSE #18446744071422692152:c=1199,e=1198,p=0,cr=0,cu=0,mis=1,r=0,dep=1,og=4,plh=0,tim=9324454212629
BINDS #18446744071422692152:
 Bind#0
  oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
  oacflg=00 fl2=1000001 frm=00 csi=00 siz=24 off=0
  kxsbbbfp=ffffffff77e77150  bln=22  avl=03  flg=05
  value=859
 Bind#1
  oacdty=01 mxl=32(30) mxlc=00 mal=00 scl=00 pre=00
  oacflg=10 fl2=0001 frm=01 csi=171 siz=32 off=0
  kxsbbbfp=ffffffff7fff8688  bln=32  avl=30  flg=09
  value="SYS_DZAYDZXFEF1OQRKZUBTDF4UHRF"
 Bind#2
  oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
  oacflg=00 fl2=1000001 frm=00 csi=00 siz=144 off=0
  kxsbbbfp=ffffffff77e770a8  bln=22  avl=02  flg=05
  value=3
 Bind#3
  oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
  oacflg=00 fl2=1000001 frm=00 csi=00 siz=0 off=24
  kxsbbbfp=ffffffff77e770c0  bln=22  avl=02  flg=01
  value=2
 Bind#4
  oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
  oacflg=00 fl2=1000001 frm=00 csi=00 siz=0 off=48
  kxsbbbfp=ffffffff77e770d8  bln=22  avl=01  flg=01
  value=0
 Bind#5
  oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
  oacflg=00 fl2=1000001 frm=00 csi=00 siz=0 off=72
  kxsbbbfp=ffffffff77e770f0  bln=22  avl=02  flg=01
  value=1
 Bind#6
  oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
  oacflg=00 fl2=1000001 frm=00 csi=00 siz=0 off=96
  kxsbbbfp=ffffffff77e77108  bln=22  avl=01  flg=01
  value=0
 Bind#7
  oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
  oacflg=00 fl2=1000001 frm=00 csi=00 siz=0 off=120
  kxsbbbfp=ffffffff77e77120  bln=22  avl=04  flg=01
  value=512690
 Bind#8
  oacdty=01 mxl=32(02) mxlc=00 mal=00 scl=00 pre=00
  oacflg=10 fl2=0001 frm=01 csi=171 siz=32 off=0
  kxsbbbfp=ffffffff7fff86c4  bln=32  avl=02  flg=09
  value="TC"
Using Tom Kyte print_table procedure I retrieve this row in more readable format:
SQL> exec print_table(q'#select * from sys.user$ where name='SYS_DZAYDZXFEF1OQRKZUBTDF4UHRF'#')
USER#                         : 859
NAME                          : SYS_DZAYDZXFEF1OQRKZUBTDF4UHRF
TYPE#                         : 2
PASSWORD                      :
DATATS#                       : 3
TEMPTS#                       : 2
CTIME                         : 22.07.2015 15:44:08
PTIME                         :
EXPTIME                       :
LTIME                         :
RESOURCE$                     : 1
AUDIT$                        :
DEFROLE                       : 0
DEFGRP#                       :
DEFGRP_SEQ#                   :
ASTATUS                       : 0
LCOUNT                        : 0
DEFSCHCLASS                   :
EXT_USERNAME                  : TC
SPARE1                        : 16
SPARE2                        : 512690
SPARE3                        :
SPARE4                        :
SPARE5                        :
SPARE6                        :
SPARE7                        :
SPARE8                        :
SPARE9                        :
SPARE10                       :
SPARE11                       :
-----------------
We can see that USER$ was populated with new row with obscure "NAME" SYS_%. New row has "TYPE#"=2.
According to a definition of SYS.USER$ table from @?/rdbms/admin/dcore.bsq this's "adjunct" schema:
create table user$                                             /* user table */
( user#         number not null,                   /* user identifier number */
  name          varchar2("M_IDEN") not null,                 /* name of user */
               /* 0 = role, 1 = user, 2 = adjunct schema, 3 = schema synonym */
Row has EXT_USERNAME same as original schema:
EXT_USERNAME                  : TC
SPARE2 - references to edition object:
SPARE2                        : 512690

SQL> exec print_table('select * from dba_objects where object_id=512690')
OWNER                         : SYS
OBJECT_NAME                   : E1
SUBOBJECT_NAME                :
OBJECT_ID                     : 512690
DATA_OBJECT_ID                :
OBJECT_TYPE                   : EDITION
CREATED                       : 22.07.2015 15:44:08
LAST_DDL_TIME                 : 22.07.2015 15:44:08
TIMESTAMP                     : 2015-07-22:15:44:08
STATUS                        : VALID
TEMPORARY                     : N
GENERATED                     : N
SECONDARY                     : N
NAMESPACE                     : 64
EDITION_NAME                  :
SHARING                       : NONE
EDITIONABLE                   :
ORACLE_MAINTAINED             : N
-----------------
Second adjunct schema points to E2 edition (some rows skipped for readability):
SQL> exec print_table(q'#select * from sys.user$ where name='SYS_D$8SPB$NEB3PDFCNYRJHBAV7MK'#')
USER#                         : 861
NAME                          : SYS_D$8SPB$NEB3PDFCNYRJHBAV7MK
TYPE#                         : 2
...
EXT_USERNAME                  : TC
SPARE1                        : 16
SPARE2                        : 512691
...

SQL> exec print_table('select * from dba_objects where object_id=512691')
OWNER                         : SYS
OBJECT_NAME                   : E2
SUBOBJECT_NAME                :
OBJECT_ID                     : 512691
DATA_OBJECT_ID                :
OBJECT_TYPE                   : EDITION
CREATED                       : 22.07.2015 15:44:08
LAST_DDL_TIME                 : 22.07.2015 15:44:08
TIMESTAMP                     : 2015-07-22:15:44:08
STATUS                        : VALID
TEMPORARY                     : N
GENERATED                     : N
SECONDARY                     : N
NAMESPACE                     : 64
EDITION_NAME                  :
SHARING                       : NONE
EDITIONABLE                   :
ORACLE_MAINTAINED             : N
-----------------
Below is the listing of adjunct schemas in one of production database with one edition (we purge old editions periodically).
SQL> select name from sys.user$ where type#=2;

NAME
------------------------------
SYS_CTO$G3UFDV01YXT$0I2IIAM1FW
SYS_#65J#JRLAO7834YSNCQ09MJB0#
SYS_CFV3AQP2WPEDH4WG#BC_OY_529
SYS_MAEDFDRVL4UF6O0_K#2IKFG332
SYS_ZTM78VJZ1NRBT0OZ7CX3QQYWO#
SYS_PBOZ#4GB#AZAEGM2DQ62ODWO1Q
SYS_4OYT_40J6MSQ9HK4L$R5K8ZD8G
SYS_7DT8CD#ARM8HF8LE5K6T7#G91K
SYS_DAL9_OKM$3EL#MH_IA4IYDJ6V8
SYS_7W7SDDSF#H6QO#D8F_CFH6HL5A
SYS_WW9CZFBWQZH45YCIQW9Z8QXDPG
SYS_R0CCNSCA$$67F4F3JASWEJXZMS
SYS___IC1EVBW5MA9VL6BUY958MFEQ
SYS_JY31UD09PBTXAUV#YLDG8ND1X$
SYS_CMD9YMUP#4W3IRHEA99$OA_2$H
SYS_375#5FX937$H68GJ_ZSX5ROSP3
SYS_U5$O#5LBHUX78D5M6C421CM_F#
SYS_FFQSGVBBM97GZCOVA7ZZCXOE6N
SYS_DX#I9P0FLCROTW5_FUQ0TG4L$M
SYS_7CFP28DK1RX$CV#ES#WEKAJ1WR
Sometimes we have 5-6 editions in place. That results in 100-120 additional schemas used by EBR!
Now you know, if you will find a row in user$ with type#=2 and with a obscure name like 'SYS_%' - it's a normal.
At least if you are using Editions.

четверг, 18 июня 2015 г.

Function-Based index changed its definition after a rebuild

One of our developers have discovered a problem when index column data type changed after index had been rebuild.
They asked me for help with that issue. Here's a demo script:
SQL> create table t(
  2    x int,
  3    y int);

Table created.

SQL> create index t_i on t(
  2    decode(x, 1, to_number(null), y));

Index created.

SQL> exec dbms_stats.gather_table_stats( '', 't')

PL/SQL procedure successfully completed.
I create a function-based index with one column.
The index column is defined to show "Y" column (with type int) if the "X" column isn't equal to 1 (or null).
According to a documentation:
http://docs.oracle.com/database/121/SQLRF/functions056.htm#SQLRF00631
Oracle automatically converts the return value to the same data type as the first result.
If the first result has the data type CHAR or if the first result is null, 
then Oracle converts the return value to the data type VARCHAR2.
Notice that index column data type is a NUMBER:
SQL> select column_name
  2    from user_ind_columns
  3   where index_name = 'T_I';

COLUMN_NAME
------------------------------
SYS_NC00003$

SQL> select data_type
  2    from user_tab_cols
  3   where table_name = 'T'
  4     and column_name = 'SYS_NC00003$';

DATA_TYPE
------------------------------
NUMBER
The developer have found that his query doesn't use the index:
SQL> explain plan for
  2  select *
  3    from t
  4   where decode(x, 1, to_number(null), y) = to_number(:1);

Explained.

SQL> 
SQL> @?/rdbms/admin/utlxpls

PLAN_TABLE_OUTPUT
--------------------------------------------------------------------------
Plan hash value: 2153619298

--------------------------------------------------------------------------
| Id  | Operation         | Name | Rows  | Bytes | Cost (%CPU)| Time     |
--------------------------------------------------------------------------
|   0 | SELECT STATEMENT  |      |     1 |    26 |     2   (0)| 00:00:01 |
|*  1 |  TABLE ACCESS FULL| T    |     1 |    26 |     2   (0)| 00:00:01 |
--------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------

   1 - filter(DECODE("X",1,TO_NUMBER(NULL),"Y")=TO_NUMBER(:1))
Index will be used when he changed his query to following:
SQL> explain plan for
  2  select *
  3    from t
  4   where decode(x, 1, null, y) = to_number(:1);

Explained.

SQL> 
SQL> @?/rdbms/admin/utlxpls

PLAN_TABLE_OUTPUT
--------------------------------------------------------------------------------------------
Plan hash value: 2858887366

--------------------------------------------------------------------------------------------
| Id  | Operation                           | Name | Rows  | Bytes | Cost (%CPU)| Time     |
--------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                    |      |     1 |    39 |     1   (0)| 00:00:01 |
|   1 |  TABLE ACCESS BY INDEX ROWID BATCHED| T    |     1 |    39 |     1   (0)| 00:00:01 |
|*  2 |   INDEX RANGE SCAN                  | T_I  |     1 |       |     1   (0)| 00:00:01 |
--------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------

   2 - access(DECODE("X",1,NULL,TO_CHAR("Y"))=TO_NUMBER(:1))
Why is this?
The index expression is not what I passed in the CREATE INDEX statement:
SQL> select column_expression
  2    from user_ind_expressions
  3   where index_name = 'T_I';

COLUMN_EXPRESSION
------------------------------
DECODE("X",1,NULL,"Y")
It looks like Oracle is "clever enough" to change our index expression from:
DECODE(X, 1, TO_NUMBER(NULL), Y)
to:
DECODE("X", 1, NULL, "Y")
This leads to unexpected results when index was rebuild:
alter index t_i rebuild;
The index column data type is VARCHAR2 after that!
SQL> select data_type
  2    from user_tab_cols
  3   where table_name = 'T'
  4     and column_name = 'SYS_NC00003$';

DATA_TYPE
------------------------------
VARCHAR2
Our query now suddenly has started using FTS where previously it was using an index:
SQL> explain plan for
  2  select *
  3    from t
  4   where decode(x, 1, null, y) = to_number(:1);

Explained.

SQL> 
SQL> @?/rdbms/admin/utlxpls

PLAN_TABLE_OUTPUT
---------------------------------------------------------------------------
Plan hash value: 2153619298

--------------------------------------------------------------------------
| Id  | Operation         | Name | Rows  | Bytes | Cost (%CPU)| Time     |
--------------------------------------------------------------------------
|   0 | SELECT STATEMENT  |      |     1 |    48 |     2   (0)| 00:00:01 |
|*  1 |  TABLE ACCESS FULL| T    |     1 |    48 |     2   (0)| 00:00:01 |
--------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------

   1 - filter(TO_NUMBER(DECODE("X",1,NULL,TO_CHAR("Y")))=TO_NUMBER(:1))

Index hint did not help either:
SQL> explain plan for
  2  select /*+ index(t t_i)*/*
  3    from t
  4   where decode(x, 1, null, y) = to_number(:1);

Explained.

SQL> 
SQL> @?/rdbms/admin/utlxpls

PLAN_TABLE_OUTPUT
--------------------------------------------------------------------------
Plan hash value: 2153619298

--------------------------------------------------------------------------
| Id  | Operation         | Name | Rows  | Bytes | Cost (%CPU)| Time     |
--------------------------------------------------------------------------
|   0 | SELECT STATEMENT  |      |     1 |    48 |     2   (0)| 00:00:01 |
|*  1 |  TABLE ACCESS FULL| T    |     1 |    48 |     2   (0)| 00:00:01 |
--------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------

   1 - filter(TO_NUMBER(DECODE("X",1,NULL,TO_CHAR("Y")))=TO_NUMBER(:1))
Notice TO_NUMBER conversion at line 1:
   1 - filter(TO_NUMBER(DECODE("X",1,NULL,TO_CHAR("Y")))=TO_NUMBER(:1))
We should rewrite our query as follows:
SQL> explain plan for
  2  select *
  3    from t
  4   where decode(x, 1, null, y) = to_char(:1);

Explained.

SQL> 
SQL> @?/rdbms/admin/utlxpls

PLAN_TABLE_OUTPUT
--------------------------------------------------------------------------------------------
Plan hash value: 2858887366

--------------------------------------------------------------------------------------------
| Id  | Operation                           | Name | Rows  | Bytes | Cost (%CPU)| Time     |
--------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                    |      |     1 |    48 |     1   (0)| 00:00:01 |
|   1 |  TABLE ACCESS BY INDEX ROWID BATCHED| T    |     1 |    48 |     1   (0)| 00:00:01 |
|*  2 |   INDEX RANGE SCAN                  | T_I  |     1 |       |     1   (0)| 00:00:01 |
--------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------

   2 - access(DECODE("X",1,NULL,TO_CHAR("Y"))=:1)
To workaround this issue, we could use an index on virtual columns.
We could prevent TO_NUMBER(NULL) to NULL conversion by changing TO_NUMBER(NULL) to CAST(NULL as NUMBER), or other such expression.
I have opened the SR with Oracle and they told me that this's due to:
Bug 17871767: FUNCTION BASE INDEX DEFINITION CHANGED ON 11.2, ADDED A TO_CHAR FUNCTION This bug is still under work and hasn't been resolved yet.
Actually, this issue with function-based indexes has been present for a long time.
I have reproduced it on 9.2.0.6 at least.

четверг, 21 мая 2015 г.

session cursor cache count statistics incorrect with parallel queries

Recently I investigated a issue with high 'session cursor cache count' statistics in one of database version 11.2.0.4. I found that some of the sessions have extremely high values of this statistics:
SQL> select s.sid, ss.value, s.logon_time, s.service_name, s.program
  2    from v$session s,
  3         v$statname sn,
  4         v$sesstat ss
  5   where sn.name='session cursor cache count'
  6     and ss.statistic#=sn.statistic#
  7     and ss.value > 100
  8     and s.sid=ss.sid;

       SID      VALUE LOGON_TIME          SERVICE_NAME PROGRAM
---------- ---------- ------------------- ------------ ----------------
       485        255 19.05.2015 02:47:52 dp_task      JDBC Thin Client
       705      12774 19.05.2015 02:47:51 dp_task      JDBC Thin Client
       800        267 19.05.2015 02:47:51 dp_task      JDBC Thin Client
session_cached_cursors parameter has default value of 50. My first thought was that sessions changed session_cached_cursors parameter. To confirm my hypothesis, I executed below oradebug command:
oradebug dump modified_parameters 1
Looking into trace file:
Received ORADEBUG command (#1) 'dump modified_parameters 1' from process 'Unix process pid: 13761, image: <none>'
DYNAMICALLY MODIFIED PARAMETERS:
  nls_language             = AMERICAN
  nls_territory            = AMERICA
  log_archive_dest_state_3 = ENABLE
  service_names            = drep_dp_stat, drep_dp_task, drep_ora_at, drep_dp_core

*** 2015-05-14 10:44:20.744
Finished processing ORADEBUG command (#1) 'dump modified_parameters 1'
So session_cached_cursors parameter wasn't changed by session. At the next step I decided to dump all cursors cached by session:
oradebug dump cursordump 1
Here is a relevant portion of trace file:
----- Session Cached Cursor Dump -----
----- Generic Session Cached Cursor Dump -----
-----------------------------------------------------------
-------------- Generic Session Cached Cursors Dump --------
-----------------------------------------------------------
hash table=ffffffff79d34228 cnt=50 LRU=ffffffff79d245f0 cnt=49 hit=64510 max=50 NumberOfTypes=6
From the above, there was no doubt that 'session cursor cache count' statistic is lying. I opened SR with Oracle and support engineer pointed to a Bug 5713223 : 'SESSION CURSOR CACHE COUNT' OF V$SYSSTAT IS NOT CURRENT VALUE
This bug was opened in 2006 for 10.2 version and still not resolved yet.
I have couple of SR with Oracle in which I waiting for resolution of such long-lived bugs. So, I decided to further diagnose this issue and provide additional information to the Oracle Support. All of the sessions are using dp_task database service. I created this service for reporting application that executes bunch of heavy SQL.
I wrote a simple job that takes a snapshots of v$session, v$sesstat on periodic interval. On a next day I check generated data and find couple of suspicious SQL for further investigation.
Most of them are used some of combination: PARALLEL hint, pipelined table functions, MATERIALIZE hint. Deeping into this further, I found that a incorrect statistics are due to PARALLEL hint.
I created a simple test case that was used to reproduce this issue.
create table t as select * from dba_objects;

sho parameter session_cached_cursors

select s.value 
  from v$statname n, 
       v$mystat s 
 where n.name = 'session cursor cache count' 
   and s.statistic#=n.statistic#;

select /*+ parallel(4)*/count(distinct owner) from t;

select s.value 
  from v$statname n, 
       v$mystat s 
 where n.name = 'session cursor cache count' 
   and s.statistic#=n.statistic#;

select /*+ parallel(4)*/count(distinct owner) from t;
    
Below is a SQL*Plus output of the script execution.
SQL> sho parameter session_cached_cursors

NAME                                 TYPE                              VALUE
------------------------------------ --------------------------------- ------------------------------
session_cached_cursors               integer                           50
SQL> 
SQL> select s.value
  2    from v$statname n,
  3         v$mystat s
  4   where n.name = 'session cursor cache count'
  5     and s.statistic#=n.statistic#;

     VALUE
----------
        49

SQL> 
SQL> select /*+ parallel(4)*/count(distinct owner) from t;

COUNT(DISTINCTOWNER)
--------------------
                  59

SQL> 
SQL> select s.value
  2    from v$statname n,
  3         v$mystat s
  4   where n.name = 'session cursor cache count'
  5     and s.statistic#=n.statistic#;

     VALUE
----------
        58
Notice that 'session cursor cache count' statistic is 49 before parallel query and 58 after. After I executed parallel query multiple times and checked a statistics at each step, I found that each query execution leads to increase of 'session cursor cache count' statistics by 2*(parallel_degree).
SQL> select /*+ parallel(4)*/count(distinct owner) from t;

COUNT(DISTINCTOWNER)
--------------------
                  59
SQL> 
SQL> select s.value
  2    from v$statname n,
  3         v$mystat s
  4   where n.name = 'session cursor cache count'
  5     and s.statistic#=n.statistic#;

     VALUE
----------
        98
SQL> 
SQL> select /*+ parallel(8)*/count(distinct owner) from t;

COUNT(DISTINCTOWNER)
--------------------
                  59

SQL> 
SQL> select s.value
  2    from v$statname n,
  3         v$mystat s
  4   where n.name = 'session cursor cache count'
  5     and s.statistic#=n.statistic#;

     VALUE
----------
       114
SQL> 
Good news: issue is not reproduced in 12.1.0.2. I hope that Oracle support resolve this issue in 11.2.0.4.

Update 17.06.2015: Oracle has released the patch 21135007: SESSION CURSOR CACHE COUNT STATISTICS IS INCORRECT
I applied it to 11.2.0.4 environment and it works as expected.
Now the 'session cursor cache count' statistics is correct.

среда, 11 февраля 2015 г.

Join elimination not performed in the presence of virtual columns on parent table

Today I observed poorly written SQL that performed unnecessary join between PARENT/CHILD tables:
SQL> select * from table(dbms_xplan.display_cursor( '23hbmd0xxv7p0'));

PLAN_TABLE_OUTPUT
----------------------------------------------------------------------------------------------------
SQL_ID  23hbmd0xxv7p0, child number 0
-------------------------------------
SELECT P.ID FROM PARENT P, CHILD C WHERE P.ID = :B1 AND P.ID = C.PARENT_ID

Plan hash value: 3267741206

----------------------------------------------------------------------------------------------------
| Id  | Operation                    | Name                | Rows  | Bytes | Cost (%CPU)| Time     |
----------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT             |                     |       |       |     5 (100)|          |
|   1 |  NESTED LOOPS                |                     |     2 |    36 |     5   (0)| 00:00:01 |
|*  2 |   INDEX UNIQUE SCAN          | PARENT_ID_PK        |     1 |     6 |     2   (0)| 00:00:01 |
|   3 |   TABLE ACCESS BY INDEX ROWID| CHILD               |     2 |    24 |     3   (0)| 00:00:01 |
|*  4 |    INDEX RANGE SCAN          | CHILD_PARENT_FK_IDX |     2 |       |     2   (0)| 00:00:01 |
-------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------

   2 - access("P"."ID"=:B1)
   4 - access("C"."PARENT_ID"=:B1)
PARENT table has primary key enabled and validated.
CHILD table with foreign key (enabled and validated) that references PARENT.
Without obvious reason JOIN ELIMINATION is not done when expected.
We are using Oracle database version 11.2.0.3.11 (PSU 11 applied).
I investigated this issue further and found that this's due to presence of virtual columns on PARENT table.
Below is a simple test case used to reproduce this issue (I copied this test case with little modification from Excellent Christian Antognini site):
SQL> CREATE TABLE t1 (
  2    id NUMBER NOT NULL,
  3    n NUMBER,
  4    pad VARCHAR2(4000),
  5    pad_virt varchar2(4000) generated always as (substr(pad,1,10)) virtual,
  6    CONSTRAINT t1_pk PRIMARY KEY(id)
  7  );
SQL> 
SQL> CREATE TABLE t2 (
  2    id NUMBER NOT NULL,
  3    t1_id NUMBER NOT NULL,
  4    n NUMBER,
  5    pad VARCHAR2(4000),
  6    CONSTRAINT t2_pk PRIMARY KEY(id),
  7    CONSTRAINT t2_t1_fk FOREIGN KEY (t1_id) REFERENCES t1
  8  );
SQL> 
SQL> CREATE OR REPLACE VIEW v AS
  2  SELECT t1.id AS t1_id, t1.n AS t1_n, t2.id AS t2_id, t2.n AS t2_n
  3    FROM t1, t2
  4   WHERE t1.id = t2.t1_id;
Lets select a rows only from child table:
SQL> EXPLAIN PLAN FOR SELECT t2_id, t2_n FROM v;
SQL> 
SQL> select * from table(dbms_xplan.display);

PLAN_TABLE_OUTPUT
-----------------------------------------------------------------------------
Plan hash value: 733458710

----------------------------------------------------------------------------
| Id  | Operation          | Name  | Rows  | Bytes | Cost (%CPU)| Time     |
----------------------------------------------------------------------------
|   0 | SELECT STATEMENT   |       |     1 |    52 |     2   (0)| 00:00:01 |
|   1 |  NESTED LOOPS      |       |     1 |    52 |     2   (0)| 00:00:01 |
|   2 |   TABLE ACCESS FULL| T2    |     1 |    39 |     2   (0)| 00:00:01 |
|*  3 |   INDEX UNIQUE SCAN| T1_PK |     1 |    13 |     0   (0)| 00:00:01 |
----------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------

   3 - access("T1"."ID"="T2"."T1_ID")
Join is not eliminated. Join is eliminated when I dropped virtual column:
SQL> ALTER TABLE t1 DROP COLUMN pad_virt;
SQL> 
SQL> EXPLAIN PLAN FOR SELECT t2_id, t2_n FROM v;
SQL> 
SQL> select * from table(dbms_xplan.display);

PLAN_TABLE_OUTPUT
---------------------------------------------------------------------------
Plan hash value: 2904382265

--------------------------------------------------------------------------
| Id  | Operation         | Name | Rows  | Bytes | Cost (%CPU)| Time     |
--------------------------------------------------------------------------
|   0 | SELECT STATEMENT  |      |     1 |    39 |     2   (0)| 00:00:01 |
|   1 |  TABLE ACCESS FULL| T2   |     1 |    39 |     2   (0)| 00:00:01 |
--------------------------------------------------------------------------
Could not find any obvious reason for this in 10053 trace file. But it looks like a problem is known since 2011: Bug 12739252 : JOIN ELIMINATION IS NOT DONE WHEN JOINING TABLE HAVE VIRTUAL COLUMN
Good news: problem is not reproduced in 11.2.0.4.4.

понедельник, 9 февраля 2015 г.

Suspending a users session on specific enqueue

Recently I faced a strange issue with EBR (Edition-Based Redefinition). In order to understand how things work internally I decided to use DTrace.
I wanted to suspend specific user session when session acquired AE lock. There are similar enq_trace.sh script that written by Tanel Poder. Tanel's script could be extended to accommodate to my specific requirements if needed.
My enq_suspend.d script is below:
#!/usr/sbin/dtrace -s

# pragma D option quiet
# pragma D option destructive

struct ksqrs_t {
  long     addr;
  char     b1[72];
  uint32_t id1;
  uint32_t id2;
  char     b2[4];
  char     idt[2];/*92=offset of X$KSQRS.KSQRSIDT column from x$kqfco*/
  char     b3[18];
};

struct ksqrs_t ksqrs;

pid$target:oracle:ksqgtl*:entry 
{ 
  ksqeq_lkadr = arg0; /* X$KSQEQ.KSQLKADR*/
  mode = arg1;
  timeout = arg3;
  lock_indx = arg4; /*X$KSIRESTYP.INDX*/
  flags = arg7;
} 

pid$target:oracle:ksqgtl*:return 
{
  ksqeq_lkres = *(long *)copyin(ksqeq_lkadr+8,8);
  ksqrs = *(struct ksqrs_t *)copyin(ksqeq_lkres,112);
  ksqrs.addr = ksqeq_lkres;
  printf("%d [%Y] %s: *** %s-%08x-%08x mode=%d flags=0x%x timeout=%d\n",
    timestamp,
    walltimestamp,
    probefunc,
    ksqrs.idt,
    ksqrs.id1,
    ksqrs.id2,
    mode, 
    flags, 
    timeout
  );
}

pid$target:oracle:ksqrcl*:entry 
{ 
  enqrs_addr = *(long *)copyin(arg0+8,8); /*X$KSQRS.ADDR enQueue Resource*/
  ksqrs = *(struct ksqrs_t *)copyin(enqrs_addr, 112);
  ksqrs.addr = enqrs_addr;
  printf("%d [%Y] %s: *** %s-%08x-%08x x$ksqrs.addr=0x%016x\n",
    timestamp,
    walltimestamp,
    probefunc,
    ksqrs.idt,
    ksqrs.id1,
    ksqrs.id2,
    ksqrs.addr
  );
} 

pid$target:oracle:ksqrcl*:entry 
/ksqrs.idt==$$1/
{
  printf("%d [%Y] %s.%s: lock_type=%s suspending execution\n", timestamp, walltimestamp, probefunc, probename, ksqrs.idt);
  stop();
}

pid$target:oracle:ksqrcl*:return {}
A brief description of the script.
  • # pragma D option quiet
    # pragma D option destructive
        
    Minimize output, allow destructive actions. We will use "stop()" call further.
  • struct ksqrs_t
    struct ksqrs_t {
      long     addr;
      char     b1[72];/*unknown not needed*/
      uint32_t id1;/*lock ID1*/
      uint32_t id2;/*lock ID2*/
      char     b2[4];/*unknown not needed*/
      char     idt[2];/*lock type, 92=offset of X$KSQRS.KSQRSIDT column from x$kqfco*/
      char     b3[18];/*unknown not needed*/
    };
        
    The above structure describes X$KSQRS entry (Kernel Services enQueue ReSource):
    SQL> select c.kqfconam column_name,
      2         c.kqfcodty datatype,
      3         c.kqfcosiz size_byte,
      4         c.kqfcooff offset
      5    from x$kqfta t,
      6         x$kqfco c
      7   where t.kqftanam = 'X$KSQRS'
      8     and c.kqfcotab = t.indx
      9   order by c.indx
     10  /
    
    COLUMN_NAME   DATATYPE  SIZE_BYTE     OFFSET
    ----------- ---------- ---------- ----------
    ADDR                23          8          0
    INDX                 2          4          0
    INST_ID              2          4          0
    KSQRSID1             2          4         80
    KSQRSID2             2          4         84
    KSQRSIDT             1          2         92
    KSQRSFLG             2          1        111
    
    ID1,ID2,IDT columns maps to relevant GV$LOCK columns, this can be obtained from V$FIXED_VIEW_DEFINITION:
    select s.inst_id, 
           l.laddr,
           l.kaddr,
           s.ksusenum,
           r.ksqrsidt,
           r.ksqrsid1, 
           r.ksqrsid2,
           l.lmode,
           l.request,
           l.ctime,
           decode(l.lmode,0,0,l.block)  
      from v$_lock l, 
           x$ksuse s, 
           x$ksqrs r  
     where l.saddr=s.addr 
       and concat(USERENV('Instance'),l.raddr)=concat(r.inst_id,r.addr)
    
  • ksqgtl.entry - get lock function, entry point
    pid$target:oracle:ksqgtl*:entry 
    { 
      ksqeq_lkadr = arg0; /* X$KSQEQ.KSQLKADR*/
      mode = arg1;
      timeout = arg3;
      lock_indx = arg4; /*X$KSIRESTYP.INDX*/
      flags = arg7;
    } 
    
    Interesting ksqgtl function arguments saved for further usage. In particularly, arg0 - is X$KSQEQ.KSQLKADR (lock address?).
  • ksqgtl.return - get lock function, return
    pid$target:oracle:ksqgtl*:return 
    {
      ksqeq_lkres = *(long *)copyin(ksqeq_lkadr+8,8);
      ksqrs = *(struct ksqrs_t *)copyin(ksqeq_lkres,112);
      ksqrs.addr = ksqeq_lkres;
      printf("%d [%Y] %s: *** %s-%08x-%08x mode=%d flags=0x%x timeout=%d\n",
        timestamp,
        walltimestamp,
        probefunc,
        ksqrs.idt,
        ksqrs.id1,
        ksqrs.id2,
        mode, 
        flags, 
        timeout
      );
    }
    
    We will interesting in "ID1", "ID2", "TYPE" lock attributes. We can fully decode them from X$KSQRS fixed table.
    But ksqgtl called with X$KSQEQ.KSQLKADR. X$KSQEQ.KSQLKRES maps to X$KSQRS.ADDR.
    SQL> select c.kqfconam column_name,
      2         c.kqfcodty datatype,
      3         c.kqfcosiz size_byte,
      4         c.kqfcooff offset
      5    from x$kqfta t,
      6         x$kqfco c
      7   where t.kqftanam = 'X$KSQEQ'
      8     and c.kqfcotab = t.indx
      9   order by c.indx
     10  /
    
    COLUMN_NAME   DATATYPE  SIZE_BYTE     OFFSET
    ----------- ---------- ---------- ----------
    ADDR                23          8          0
    INDX                 2          4          0
    INST_ID              2          4          0
    KSSOBFLG             2          4          0
    KSSOBOWN            23          8          0
    KSQLKADR            23          8         88
    KSQLKRES            23          8         96
    KSQLKMOD             2          1        176
    KSQLKREQ             2          1        177
    KSQLKMXH             2          2        178
    KSQLKSES            23          8          0
    KSQLKCTIM            2          4          0
    KSQLKLBLK            2          4          0
    
    We will print debug output similar to Tanel Poder script and 10704 event format.
  • pid$target:oracle:ksqrcl*:entry 
    { 
      enqrs_addr = *(long *)copyin(arg0+8,8); /*X$KSQRS.ADDR enQueue Resource*/
      ksqrs = *(struct ksqrs_t *)copyin(enqrs_addr, 112);
      ksqrs.addr = enqrs_addr;
      printf("%d [%Y] %s: *** %s-%08x-%08x x$ksqrs.addr=0x%016x\n",
        timestamp,
        walltimestamp,
        probefunc,
        ksqrs.idt,
        ksqrs.id1,
        ksqrs.id2,
        ksqrs.addr
      );
    } 
    
  • ksqrcl function (release lock) entry point:
    pid$target:oracle:ksqrcl*:entry 
    { 
      enqrs_addr = *(long *)copyin(arg0+8,8); /*X$KSQRS.ADDR enQueue Resource*/
      ksqrs = *(struct ksqrs_t *)copyin(enqrs_addr, 112);
      ksqrs.addr = enqrs_addr;
      printf("%d [%Y] %s: *** %s-%08x-%08x x$ksqrs.addr=0x%016x\n",
        timestamp,
        walltimestamp,
        probefunc,
        ksqrs.idt,
        ksqrs.id1,
        ksqrs.id2,
        ksqrs.addr
      );
    } 
    
    We will populate a ksqrs struct again.
  • If lock type equals to parameter passed to script, we will suspend process execution:
    pid$target:oracle:ksqrcl*:entry 
    /ksqrs.idt==$$1/
    {
      printf("%d [%Y] %s.%s: lock_type=%s suspending execution\n", timestamp, walltimestamp, probefunc, probename, ksqrs.idt);
      stop();
    }
    
Short demonstration how this works.
Suppose I will want suspend server process when session acquires TM lock. 1. I opened new session to the DB and determine server process ID and tracefile location:
SQL> select p.spid,
  2         p.tracefile
  3    from v$session s,
  4         v$process p
  5   where s.sid = sys_context( 'userenv', 'sid')
  6     and p.addr = s.paddr
  7  /

SPID  TRACEFILE
----- ----------------------------------------------------------------------------------------------------
1968  /pub/home/oracle/diag/rdbms/orcl/orcl/trace/orcl_ora_1968.trc
2. I created test table:
SQL> create table t (x int);

Table created.
SQL> select object_id,
  2         to_char(object_id, 'fm0xxxxxxx') object_id_hex
  3    from obj
  4   where object_name='T';

 OBJECT_ID OBJECT_ID_HEX
---------- ---------------------------
    349673 000555e9
3. Now I enable additional diagnostics: event 10704 to trace enqueues:
SQL> alter session set events '10704 level 2';

Session altered.
4. Next I will run DTrace script enq_suspend.d passing server process ID as parameter:
oracle@localhost dtrace$ ./enq_suspend.d -p 1968 TM
5. Trying to truncate table T:

Session suspending.
6. Observed output into console with DTrace script:
oracle@localhost dtrace$ ./enq_suspend.d -p 1968 TM
33969273235645237 [2015 Feb  9 12:42:21] ksqgtlctx: *** TM-000555e9-00000000 mode=6 flags=0x401 timeout=0
33969273240887878 [2015 Feb  9 12:42:21] ksqgtlctx: *** TX-0004001b-0000f92e mode=6 flags=0x401 timeout=0
33969273245689382 [2015 Feb  9 12:42:21] ksqrcl: *** TX-0004001b-0000f92e x$ksqrs.addr=0x000000041cda5c90
33969273245764458 [2015 Feb  9 12:42:21] ksqrcli: *** TX-0004001b-0000f92e x$ksqrs.addr=0x000000041cda5c90
33969273246279405 [2015 Feb  9 12:42:21] ksqrcl: *** TM-000555e9-00000000 x$ksqrs.addr=0x000000041cda25d0
33969273246301204 [2015 Feb  9 12:42:21] ksqrcl.entry: lock_type=TM suspending execution
You can see that when calling ksqrcl with TM-000555e9-00000000 (our object id) execution is suspending. We can gather any required diagnostic data at this step. 7. 10704 event data in the trace file:
*** 2015-02-09 12:42:21.102
ksqgtl *** TM-000555e9-00000000 mode=6 flags=0x401 timeout=0 ***
ksqgtl: xcb=0x419a6f068, ktcdix=2147483647, topxcb=0x419a6f068
        ktcipt(topxcb)=0x0
ksucti: init txn DID from session DID 
ksqgtl:
        ksqlkdid: 0001-0019-00000142
*** ksudidTrace: ksqgtl
        ktcmydid(): 0001-0019-00000142
        ksusesdi:   0001-0019-00000143
        ksusetxn:   0001-0019-00000142
ksqgtl: RETURNS 0
ksqgtl *** TX-0004001b-0000f92e mode=6 flags=0x401 timeout=0 ***
ksqgtl: xcb=0x419a6f068, ktcdix=2147483647, topxcb=0x419a6f068
        ktcipt(topxcb)=0x0
ksucti: init session DID from txn DID: 
ksqgtl:
        ksqlkdid: 0001-0019-00000142
*** ksudidTrace: ksqgtl
        ktcmydid(): 0001-0019-00000142
        ksusesdi:   0001-0019-00000143
        ksusetxn:   0001-0019-00000142
ksqgtl: RETURNS 0
ksqrcl: TX,4001b,f92e
ksqrcl: returns 0
enq_suspend.d script can be further extending for more complex conditions: such as stop when session acquires TM lock with particular object_id and mode, and so on. Script verified in my environment: Oracle Database version 11.2.0.3 on Solaris 10 SPARC64.