[java.lang.ClassNotFoundException][oracle.bpel.services.workflow.task.impl.TaskService.startup][soa-infra]

It’s not very often I have to deal with administration of WebLogic and SOA. However I do administer small installation for development purposes in one company. 

One of the servers crushed few dayes ago and from that moment we were unable to correctly start SOA infrastructure.

Main log showed very strange error:

<feb 26, 2016 9:51:40 AM CET> <emergency> <oracle.dfw.incident> <BEA-000000> <incident 6 created with problem key "DFW-99998 [java.lang.ClassNotFoundException][oracle.bpel.services.workflow.task.impl.TaskService.startup][soa-infra]">

I tried to search the web with very little success. Later I’ve got a "great" idea “Hey, let’s check diagnostic logs!” …. Next time I’ll do it right at the start. The error in the log was as follows:

####<feb 26, 2016 11:12:09 AM CET> <error> <deployer> <hp02.elso-systems.com> <wls_soa1> <[ACTIVE] ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)'> <<wls Kernel>> <> <0000lct3knd3j4wvlyvh8a1mo2gy000002> <1456481529274> <BEA-149231> <unable to set the activation state to true for the application 'soa-infra'. weblogic.application.ModuleException: [HTTP:101216]Servlet: "FabricInit" failed to preload on startup in Web application: "/soa-infra". oracle.fabric.common.FabricException: Error in getting XML input stream: oramds:/deployed-composites/Name_rev1.0/composite.xml: oracle.mds.exception.MDSException: MDS-00054: The file to be loaded oramds:/deployed-composites/Name_rev1.0/composite.xml does not exist. ...

Well that's much more precise! Now if you do search for that, you’ll probably get to Oracle Support Doc ID 1380835.1 - SOA/BPM: Solving MDS-00054 error preventing soa-infra to start correctly. Basically what you are dealing with here is incorrectly deployed component and until the problem is fixed; your soa infra will not come up. And the only way  to deal with it when your soa infra is not up is by removing it. There is a nice guide on how to remove component which is causing the problem:

Check the SOA logs and determine which composite is causing the problem and then follow the below process to undeploy the composite by editing deployed-composites.xml:

1. Download and copy the ShareSoaInfraPartition.ear file to $MIDDLEWARE_HOME/oracle_common/common/bin

2. cd to $MIDDLEWARE_HOME/oracle_common/common/bin and run wlst.sh

3.  Connect to a SOA server:

wls:/offline> connect()
Please enter your username :weblogic
Please enter your password :
Please enter your server URL [t3://localhost:7001] :server
Connecting to t3://server:7014 with userid weblogic ...
Successfully connected to Admin Server 'AdminServer' that belongs to domain 'name'.

4. run the below command to deploy ShareSoaInfraPartition.ear to the server:

wls:/vzpsoa/serverConfig> deploy('ShareSoaInfraPartition','ShareSoaInfraPartition.ear',upload='true')
Deploying application from /opt/oracle/middleware/soa111/oracle_common/common/bin/ShareSoaInfraPartition.ear to targets  (upload=true) ...
<Feb 26, 2016 12:28:50 PM CET> <Info> <J2EE Deployment SPI> <BEA-260121> <Initiating deploy operation for application, ShareSoaInfraPartition [archive: /opt/oracle/middleware/soa111/oracle_common/common/bin/ShareSoaInfraPartition.ear], to AdminServer .>
.......Completed the deployment of Application with status completed
Current Status of your Deployment:
Deployment command type: deploy
Deployment State       : completed
Deployment Message     : [Deployer:149194]Operation 'deploy' on application 'ShareSoaInfraPartition' has succeeded on 'AdminServer'

5. Now run the below command by changing the "toLocation" ('/fmw11g/fmw1115/Middleware' is some location path on SOA machine)

wls:/vzpsoa/serverConfig> exportMetadata(application='ShareSoaInfraPartition',server='AdminServer',toLocation='/opt/oracle/middleware/soa111',docs='/deployed-composites/deployed-composites.xml')
Location changed to domainRuntime tree. This is a read-only tree with DomainMBean as the root.
For more help, use help(domainRuntime)

Executing operation: exportMetadata.

Operation "exportMetadata" completed. Summary of "exportMetadata" operation is:
1 documents successfully transferred.
List of documents successfully transferred:

/deployed-composites/deployed-composites.xml

6. A deployed-composites folder will be created at "toLocation" path with deployed-composites.xml in it

7. Delete the composite which is causing the problem and save the file

For example, the MediatorTest composite:

<composite-series name="default/MediatorTest" default="default/MediatorTest!1.0">
<composite-revision dn="default/MediatorTest!1.0" state="on" mode="active" location="dc/soa_58b98be8-9ec8-41af-bb83-590f6004d1aa">
<composite dn="default/MediatorTest!1.0*soa_58b98be8-9ec8-41af-bb83-590f6004d1aa" deployedTime="2011-11-17T09:01:54.750+05:30"/>

8. Now run the below command by changing the "fromLocation" (this should be the same location as previous)

wls:/vzpsoa/serverConfig> importMetadata(application='ShareSoaInfraPartition',server='AdminServer',fromLocation='/opt/oracle/middleware/soa111',docs='/deployed-composites/deployed-composites.xml')

Executing operation: importMetadata.

Operation "importMetadata" completed. Summary of "importMetadata" operation is:
1 documents successfully transferred.
List of documents successfully transferred:

/deployed-composites/deployed-composites.xml

9. Now bounce your server and the composite will not be deployed by SOA when it comes up and hence that should bring your soa-infra up.

Note:  When you remove a composite that contains task definitions manually, the Task definition references to the composite are still in WFTASKMETADATA table. Even though the composite is not loaded during startup there will be an  exception when loading the task definition,

<Error> <oracle.soa.services.workflow.task>
<BEA-000000> <<.> Could not locate composite.

The references to WFTASKMETADATA for that specific composite/version can only be removed when a composite containing task definitions is cleanly undeployed using em/wlst.

Night-time quiz

Since I do not have anything I think would be interesting for you guys, I’ve created a little quiz for you.





You have a following table definition and data:

CREATE TABLE my_table
(
 id       NUMBER(3),
 item_cnt NUMBER(3),
 log_time DATE
)
/
CREATE UNIQUE INDEX my_table_ix1 ON my_table(id)
/
ALTER TABLE my_table ADD CONSTRAINT my_table_pk PRIMARY KEY (id)
/

INSERT INTO my_table VALUES (1, NULL, NULL)
/
INSERT INTO my_table VALUES (2, NULL, NULL)
/
INSERT INTO my_table VALUES (3, NULL, NULL)
/
COMMIT
/

Now we have following anonymous PL/SQL block:

DECLARE
 v_id my_table.id%TYPE := 1;
 --
 PROCEDURE ins (p_id my_table.id%TYPE)
 IS
 BEGIN
  INSERT INTO my_table VALUES (p_id, NULL, NULL);
END;
 --
BEGIN
 DELETE my_table WHERE id = v_id;
 ins (v_id);
END;
/

The question is … With what change to the code would you force a dead lock using same id?

Looking forward to your ideas …

UPDATE:

Thank you all for your comments :) He is the solotion:

DECLARE
 v_id my_table.id%TYPE := 1;
 --
 PROCEDURE ins (p_id my_table.id%TYPE)
 IS PRAGMA AUTONOMOUS_TRANSACTION;
 BEGIN
  INSERT INTO my_table VALUES (p_id, NULL, NULL);
END;
 --
BEGIN
 DELETE my_table WHERE id = v_id;
 ins (v_id);
END;
/

00060. 00000 - "deadlock detected while waiting for resource"
*Cause: Transactions deadlocked one another while waiting for resources.
*Action: Look at the trace file to see the transactions and resources
involved. Retry if necessary.

Index on sub partition column

I was about to name this blog post “Index mud” but no one would ever google it. So we’ll go with simple name “Index on sub partition column”.

You might call this another OTN post and you would be right. But I think it is a good example of usual – how to NOT do it.

The question was following:

Hi,

I am working on oracle 11g R2 on HP-UX platform.

We need to create a partition table have range (date) and sub partition by list (values) partition. I want to know if column we are using for sub partition (values ) is also need to index as we need to use that column in many of our select queries in where clause.

One member jump in and gave a simple answer:

Yes

.. And I was marked useful? Yap ... simple answer simple click. Not good guys, not good at all.

I presented a different opinion:

Since you are sub partitioning by list, I would expect there are not many values in list for particular sub partition? I would expect that selectivity will be quite low and index might not be of any use at all ... Unless you are selecting only indexed columns, for example.

With low selectivity partition prune will probably suffice. In your case I would do some testing with representative queries as index value is questionable here.

Ok. Let’s have a little presentation here. I’ve created table table1 with four indexes:

CREATE TABLE TABLE1
(
 P NUMBER(3),
 S NUMBER(1),
 filler VARCHAR2(100)
)
PARTITION BY RANGE (P) SUBPARTITION BY LIST (S)
(PARTITION P10 VALUES LESS THAN (11)
 (SUBPARTITION P10_3 VALUES (1,2,3),
  SUBPARTITION P10_6 VALUES (4,5,6),
  SUBPARTITION P10_9 VALUES (7,8,9)),
PARTITION P20 VALUES LESS THAN (21)
 (SUBPARTITION P20_3 VALUES (1,2,3),
  SUBPARTITION P20_6 VALUES (4,5,6),
  SUBPARTITION P20_9 VALUES (7,8,9)),
PARTITION P30 VALUES LESS THAN (31)
 (SUBPARTITION P30_3 VALUES (1,2,3),
  SUBPARTITION P30_6 VALUES (4,5,6),
  SUBPARTITION P30_9 VALUES (7,8,9)));

CREATE INDEX TABLE1_IX1 ON TABLE1(P,S) LOCAL;

TABLE1 has 379MB and TABLE1_IX1 has 54MB.

Each sub partition has around 100 000 rows for each list value (filler column has maximum size in each row). We are not going to go into the index details like testing different column combinations, etc. That is not important right now.

Now if you think about it, why would Oracle have any use for an index in following SQL?

SELECT * FROM TABLE1 WHERE P=10 AND S=4;

We are selecting all columns and selectivity of predicates in given sub partition is 33,3%. Let’s check the run statistics:

----------------------------------------------------------------------------------------------------- | Id  | Operation               | Name   | Starts | E-Rows | A-Rows |   A-Time   | Buffers | Reads  |<br /> ----------------------------------------------------------------------------------------------------- |   0 |  SELECT STATEMENT       |        |      1 |        |      0 |00:00:01.61 |    8098 |   5271 | |   1 |   PARTITION RANGE SINGLE|        |      1 |    112K|    112K|00:00:01.16 |    5266 |   5264 | |   2 |    PARTITION LIST SINGLE|        |      1 |    112K|    112K|00:00:01.12 |    5266 |   5264 | |*  3 |     TABLE ACCESS FULL   | TABLE1 |      1 |    112K|    112K|00:00:01.07 |    5266 |   5264 | ---------------------------------------------------------------------------------------------------------

Ok. Now let’s force our index:

SELECT /*+ INDEX(TABLE1(P,S)) */ * FROM TABLE1 WHERE P=10 AND S=4;

---------------------------------------------------------------------------------------------------------------------- | Id  | Operation                            | Name       | Starts | E-Rows | A-Rows |   A-Time   | Buffers | Reads  | ---------------------------------------------------------------------------------------------------------------------- | 0 | SELECT STATEMENT | | 1 | | 0 |00:00:02.78 | 8196 | 5480 | |   1 |   PARTITION RANGE SINGLE             |            |      1 |    112K|    112K|00:00:02.34 |    5473 |   5473 | |   2 |    PARTITION LIST SINGLE             |            |      1 |    112K|    112K|00:00:02.30 |    5473 |   5473 | |   3 |     TABLE ACCESS BY LOCAL INDEX ROWID| TABLE1     |      1 |    112K|    112K|00:00:02.25 |    5473 |   5473 | |*  4 |      INDEX RANGE SCAN                | TABLE1_IX1 |      1 |    112K|    112K|00:00:00.20 |     270 |    270 | ----------------------------------------------------------------------------------------------------------------------

Now as you can see (check Buffers and Reads), there is no point of using our index in this case as it is more expensive then sub partition full table scan.

Now there are queries, where index will be beneficial, like:

SELECT P,S FROM TABLE1 WHERE P=10 AND S=4;

--------------------------------------------------------------------------------------------------------- | Id  | Operation               | Name       | Starts | E-Rows | A-Rows |   A-Time   | Buffers | Reads  | --------------------------------------------------------------------------------------------------------- |   0 |  SELECT STATEMENT       |            |      1 |        |      0 |00:00:00.57 |     974 |    275 | |   1 |   PARTITION RANGE SINGLE|            |      1 |    112K|    112K|00:00:00.40 |     270 |    270 | |   2 |    PARTITION LIST SINGLE|            |      1 |    112K|    112K|00:00:00.36 |     270 |    270 | |*  3 |     INDEX RANGE SCAN    | TABLE1_IX2 |      1 |    112K|    112K|00:00:00.31 |     270 |    270 | ---------------------------------------------------------------------------------------------------------

So what should you take from this is, that you should not jump into rush conclusions when adding index but think it through. You should ask yourself questions like

• What kind of queries will you use?
• Which columns will you be most likely selecting?
• What is selectivity of predicates?

It’s no point in wasting space and performance on maintaining index you don’t need.

ORA-02014:cannot select FOR UPDATE when using ROWNUM

9am, morning ...


I’m drinking my coffee and doing my morning run through my emails …

As I’m doing this, I’m regretting I have ever bought anything online …

Few emails not being spam contain some useful stuff for me. A friend of mine emailed me asking if I could help him with his problem.

He had a specific SQL with FOR UPDATE clause which was throwing ORA-02014 at him. Here is his SQL

SELECT tab.*
FROM
  (SELECT tab.ROWID AS rid, tab.*
   FROM changes tab
   WHERE state IN ('N', 'E')
   ORDER BY company, id, change_date
   ) tab
WHERE ROWNUM <= 10
FOR UPDATE OF tab.state;

Full error message is as follows

SQL Error: ORA-02014: cannot select FOR UPDATE from view with DISTINCT, GROUP BY, etc.

*Cause:    An attempt was made to select FOR UPDATE from a view which had not been merged because the view used syntax (for example, DISTINCT or GROUP BY) preventing the merge, or because of initialization file parameter settings.

*Action:   Determine the reason the view will not merge and, if possible, make changes so that it can.

Table was basically sort of a FIFO stack and he always wanted to process only first 10 oldest rows ordered by given columns. Because he is a very careful fellow he wanted to lock the rows as he was selecting them, because after that there was some processing of the data before changing them.

After few dead ends SQL which did the trick looks as follows

SELECT *
FROM changes
WHERE rowid IN
  (SELECT rid
   FROM
    (SELECT ROWID AS rid
     FROM changes
     WHERE state IN ('N', 'E')
     ORDER BY company, id, change_date
    )
  WHERE ROWNUM <= 10
  )
FOR UPDATE OF state;

I hope this post will save you some time … if not today then maybe some other day :)

One does not simply create table with 300 columns

There was quite an interesting post on Oracle OTN, which is worth of this blog post and meme.

Problem was defined as follows:

I have a table which has 300 columns and keeps records 60,00,000 at this time. Records are increasing day by day. When I run a simple query like:

select * from table where store_no = 17

this query takes 30 to 60 seconds for fetching the data against this query which is to much time, while I'll use this table with more filters. Can anyone help me that how i can increase data fetching performance, i have also used a primary key indexing.

If you check supplied DDL against given SQL, you'll likely come to two points

1. There is no index on column store_no and so Oracle will have to do full table scan
2. ... 300 columns!?

My suggestion was to reconsider the data model. 300 columns are pretty rough and columns like IT_CLERK_ID2. IT_CLERK_ID3, ... , IT_CLERK_ID5 tend to be suspicious.

Reason for my suggestion was that Oracle will have to split rows in this table in two pieces because they have more than 255 columns. Interestingly enough, the split will be done from the end of the row. So first piece of the row will have first 45 columns and second piece will contain 255 columns. What should come to your mind now is that order of columns in such table is very important and you should place columns you are going to select as close as possible to the start of the row.

Result of this split will be extra CPU usage when selecting rows from second piece. Secondary result might come in form of row chaining between database blocks which will introduce additional single block reads to walk your rows.

Now let's have a little test. I've created two tables where all columns are VARCHAR2 with value 'X' except first and last column which is NUMBER with value 1. First table has 250 columns and second has 300.

I've traced four following SQL statements:

SELECT SUM(c1) from table_250;
SELECT SUM(c250) from table_250;
SELECT SUM(c1) from table_300;
SELECT SUM(c300) from table_300;

Let's check important parts of trace files:

SELECT SUM(c1) from table_250 call count cpu elapsed disk query current rows ------- ------ -------- ---------- ---------- ---------- ---------- ---------- Parse 1 0.00 0.02 1 1 0 0 Execute 1 0.00 0.00 0 0 0 0 Fetch 1 1.27 10.58 71553 142903 0 1 ------- ------ -------- ---------- ---------- ---------- ---------- ---------- total 3 1.27 10.60 71554 142904 0 1 SELECT SUM(c250) from table_250 call count cpu elapsed disk query current rows ------- ------ -------- ---------- ---------- ---------- ---------- ---------- Parse 1 0.02 0.59 326 113 0 0 Execute 1 0.00 0.00 0 0 0 0 Fetch 1 2.06 11.30 71554 142903 0 1 ------- ------ -------- ---------- ---------- ---------- ---------- ---------- total 3 2.08 11.90 71880 143016 0 1 SELECT SUM(c1) from table_300 call count cpu elapsed disk query current rows ------- ------ -------- ---------- ---------- ---------- ---------- ---------- Parse 1 0.00 0.00 1 1 0 0 Execute 1 0.00 0.00 0 0 0 0 Fetch 1 1.60 16.12 90933 181767 0 1 ------- ------ -------- ---------- ---------- ---------- ---------- ---------- total 3 1.60 16.13 90934 181768 0 1 SELECT SUM(c300) from table_300 call count cpu elapsed disk query current rows ------- ------ -------- ---------- ---------- ---------- ---------- ---------- Parse 1 0.02 0.24 148 82 0 0 Execute 1 0.00 0.00 0 0 0 0 Fetch 1 6.92 18.01 90934 2181767 0 1 ------- ------ -------- ---------- ---------- ---------- ---------- ---------- total 3 6.94 18.26 91082 2181849 0 1

As you can see, sum of column c300 is quite CPU heavy. There are also other consequences of row chaining with connection to table full scan and buffer cache ... which is not as good as you can guess by now.

I would encourage you to check blog post by Jonathan Lewis which covers buffer cache and other important things.

So remember folks ... one does not simply create 300 columns table. You have to have very good reason for that and you have to think about order of columns and consequences.

2015 BGOUG Autumn Conference

Few photos from my visit at 2015 BGOUG Autumn Conference

Oracle hint ignore_row_on_dupkey_index - part 2

Last time we’ve seen that there is something really sneaky going on when we use hint ignore_row_on_dupkey_index. We have several clues for that:

1. 1.85 seconds vs 1:27.96 with hint. That’s about 50x slower.
2. 133 369 logical reads vs 1 156 645. That’s almost 9x more.

Another thing you would definitely find strange is the difference in sizes of trace files: 22 KB vs 35 MB … that’s quite huge.

So let’s open the larger one and see if we can spot anything strange:

… *** 2015-11-19 12:08:07.979 *** SESSION ID:(95.53) 2015-11-19 12:08:07.979 *** CLIENT ID:() 2015-11-19 12:08:07.979 *** SERVICE NAME:(SYS$USERS) 2015-11-19 12:08:07.979 *** MODULE NAME:(sqlplus@localhost.localdomain (TNS V1-V3)) 2015-11-19 12:08:07.979 *** ACTION NAME:() 2015-11-19 12:08:07.979 WAIT #140056955617216: nam='SQL*Net message to client' ela= 2 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1447931287979703 *** 2015-11-19 12:08:18.806 WAIT #140056955617216: nam='SQL*Net message from client' ela= 10826864 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1447931298806851 CLOSE #140056955617216:c=0,e=11,dep=0,type=1,tim=1447931298806957 ===================== PARSING IN CURSOR #140056955763032 len=113 dep=0 uid=0 oct=2 lid=0 tim=1447931298808784 hv=688533685 ad='b89b3418' sqlid='5v0vfdcnhnc5p' insert /*+ rule ignore_row_on_dupkey_index(table1, table1_pk) */ into mydbdba.table1 select * from mydbdba.table2 END OF STMT PARSE #140056955763032:c=2000,e=1770,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=3,plh=1708808563,tim=1447931298808778 ===================== PARSING IN CURSOR #140056955737968 len=131 dep=1 uid=0 oct=3 lid=0 tim=1447931298809899 hv=1635361899 ad='b8e8eb30' sqlid='2jfqzrxhrm93b' select /*+ rule */ c.name, u.name from con$ c, cdef$ cd, user$ u  where c.con# = cd.con# and cd.enabled = :1 and c.owner# = u.user# END OF STMT PARSE #140056955737968:c=0,e=74,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=3,plh=1027684349,tim=1447931298809895 EXEC #140056955737968:c=0,e=85,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=3,plh=1027684349,tim=1447931298810084 FETCH #140056955737968:c=1000,e=180,p=0,cr=8,cu=0,mis=0,r=1,dep=1,og=3,plh=1027684349,tim=1447931298810294 STAT #140056955737968 id=1 cnt=1 pid=0 pos=1 obj=0 op='NESTED LOOPS  (cr=8 pr=0 pw=0 time=204 us)' STAT #140056955737968 id=2 cnt=1 pid=1 pos=1 obj=0 op='NESTED LOOPS  (cr=6 pr=0 pw=0 time=154 us)' STAT #140056955737968 id=3 cnt=1 pid=2 pos=1 obj=31 op='TABLE ACCESS BY INDEX ROWID CDEF$ (cr=3 pr=0 pw=0 time=102 us)' STAT #140056955737968 id=4 cnt=1 pid=3 pos=1 obj=56 op='INDEX RANGE SCAN I_CDEF4 (cr=2 pr=0 pw=0 time=63 us)' STAT #140056955737968 id=5 cnt=1 pid=2 pos=2 obj=28 op='TABLE ACCESS BY INDEX ROWID CON$ (cr=3 pr=0 pw=0 time=44 us)' STAT #140056955737968 id=6 cnt=1 pid=5 pos=1 obj=52 op='INDEX UNIQUE SCAN I_CON2 (cr=2 pr=0 pw=0 time=28 us)' STAT #140056955737968 id=7 cnt=1 pid=1 pos=2 obj=22 op='TABLE ACCESS CLUSTER USER$ (cr=2 pr=0 pw=0 time=34 us)' STAT #140056955737968 id=8 cnt=1 pid=7 pos=1 obj=11 op='INDEX UNIQUE SCAN I_USER# (cr=1 pr=0 pw=0 time=12 us)' CLOSE #140056955737968:c=0,e=105,dep=1,type=1,tim=1447931298810435 PARSE #140056955737968:c=0,e=20,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=3,plh=1027684349,tim=1447931298810877 EXEC #140056955737968:c=0,e=43,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=3,plh=1027684349,tim=1447931298810985 FETCH #140056955737968:c=0,e=73,p=0,cr=8,cu=0,mis=0,r=1,dep=1,og=3,plh=1027684349,tim=1447931298811098 CLOSE #140056955737968:c=0,e=23,dep=1,type=3,tim=1447931298811162 PARSE #140056955737968:c=0,e=21,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=3,plh=1027684349,tim=1447931298811475 EXEC #140056955737968:c=0,e=70,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=3,plh=1027684349,tim=1447931298811601 FETCH #140056955737968:c=0,e=93,p=0,cr=8,cu=0,mis=0,r=1,dep=1,og=3,plh=1027684349,tim=1447931298811722 CLOSE #140056955737968:c=0,e=12,dep=1,type=3,tim=1447931298811766 PARSE #140056955737968:c=0,e=22,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=3,plh=1027684349,tim=1447931298812046 EXEC #140056955737968:c=0,e=40,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=3,plh=1027684349,tim=1447931298812137 FETCH #140056955737968:c=0,e=80,p=0,cr=8,cu=0,mis=0,r=1,dep=1,og=3,plh=1027684349,tim=1447931298812278 CLOSE #140056955737968:c=0,e=12,dep=1,type=3,tim=1447931298812321 PARSE #140056955737968:c=0,e=19,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=3,plh=1027684349,tim=1447931298812625 EXEC #140056955737968:c=0,e=31,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=3,plh=1027684349,tim=1447931298812720 FETCH #140056955737968:c=0,e=72,p=0,cr=8,cu=0,mis=0,r=1,dep=1,og=3,plh=1027684349,tim=1447931298812819 CLOSE #140056955737968:c=0,e=11,dep=1,type=3,tim=1447931298812861 PARSE #140056955737968:c=0,e=34,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=3,plh=1027684349,tim=1447931298813149 EXEC #140056955737968:c=0,e=41,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=3,plh=1027684349,tim=1447931298813268 FETCH #140056955737968:c=0,e=82,p=0,cr=8,cu=0,mis=0,r=1,dep=1,og=3,plh=1027684349,tim=1447931298813379 CLOSE #140056955737968:c=0,e=12,dep=1,type=3,tim=1447931298813422 PARSE #140056955737968:c=0,e=20,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=3,plh=1027684349,tim=1447931298813774 EXEC #140056955737968:c=0,e=28,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=3,plh=1027684349,tim=1447931298813868 FETCH #140056955737968:c=0,e=71,p=0,cr=8,cu=0,mis=0,r=1,dep=1,og=3,plh=1027684349,tim=1447931298813966 CLOSE #140056955737968:c=0,e=11,dep=1,type=3,tim=1447931298814008 …

It’s cursor #140056955737968 craziness! It’s getting called again and again and ….

Ok, let’s have a look how many times it’s actually called

SQL ID: 2jfqzrxhrm93b Plan Hash: 1027684349 select /*+ rule */ c.name, u.name from  con$ c, cdef$ cd, user$ u  where c.con# = cd.con# and cd.enabled = :1 and   c.owner# = u.user# call     count       cpu    elapsed       disk      query    current        rows ------- ------  -------- ---------- ---------- ---------- ----------  ---------- Parse    99001      2.63       2.72          0          0          0           0 Execute  99001      5.44       4.02          0          0          0           0 Fetch    99001     11.73       8.65          0     792008          0       99001 ------- ------  -------- ---------- ---------- ---------- ----------  ---------- total   297003     19.81      15.40          0     792008          0       99001 Misses in library cache during parse: 0 Optimizer mode: RULE Parsing user id: SYS   (recursive depth: 1) Number of plan statistics captured: 1 Rows (1st) Rows (avg) Rows (max)  Row Source Operation ---------- ---------- ----------  ---------------------------------------------------          1          1          1  NESTED LOOPS  (cr=8 pr=0 pw=0 time=204 us)          1          1          1   NESTED LOOPS  (cr=6 pr=0 pw=0 time=154 us)          1          1          1    TABLE ACCESS BY INDEX ROWID CDEF$ (cr=3 pr=0 pw=0 time=102 us)          1          1          1     INDEX RANGE SCAN I_CDEF4 (cr=2 pr=0 pw=0 time=63 us)(object id 56)          1          1          1    TABLE ACCESS BY INDEX ROWID CON$ (cr=3 pr=0 pw=0 time=44 us)          1          1          1     INDEX UNIQUE SCAN I_CON2 (cr=2 pr=0 pw=0 time=28 us)(object id 52)          1          1          1   TABLE ACCESS CLUSTER USER$ (cr=2 pr=0 pw=0 time=34 us)<          1          1          1    INDEX UNIQUE SCAN I_USER# (cr=1 pr=0 pw=0 time=12 us)(object id 11) ********************************************************************************

Remember how many rows which table had? Let me remind you

• table1 with 100 000 rows 
• table2 with 199 001 rows from which 99 001 have same primary key value like rows in table1

So this SQL is called EXACLY as many times as there are matching keys (duplicates)!

What this query seems to do is to select names of owners and names of constraints enabled for table1. Why would you do that and why for EVERY failed row is really beyond me …