20 June, 2008

Delete PARENT checks every CHILD row for Parent Key !

I just came across Eric S. Emric's blog today and one of many usefule posts was this one on Bug#5504961 which he calls "SQL Gone Wild !".

When deleting a row from a Parent table, Oracle must first verify that there exists no Child row. If there does a exist a single Child row, the Parent delete must fail (unless ON DELETE CASCADE is specified). However, what he found is that where a Parent has multiple Child rows, Oracle still (stupidly ?) checks every Child row before returning the expected "ORA-2292 : integrity constraint (constraint_name) violated - child record found".

He presents a simple test case which I took up and tested in 10.2.0.4 and then 10.2.0.1

The Bug (5504961) which you can see described in MetaLink Note#5504961.8 *IS* fixed in 10.2.0.4.

This the test script (almost exactly the same, in key statements) as Eric S. Emric's :


set echo on
spool Test_Bug_5504961

REM See http://esemrick.blogspot.com/2006/08/sql-gone-wild.html

DROP TABLE CHILD;
DROP TABLE PARENT;
CREATE TABLE PARENT (COL1 NUMBER);
ALTER TABLE PARENT ADD CONSTRAINT PARENT_PK PRIMARY KEY (COL1);
CREATE TABLE CHILD (COL1 NUMBER);
CREATE INDEX CHILD_IX_01 ON CHILD (COL1);
ALTER TABLE CHILD ADD CONSTRAINT CHILD_FK_01 FOREIGN KEY (COL1) REFERENCES PARENT;
INSERT INTO PARENT VALUES (999999999999);
INSERT INTO CHILD VALUES (999999999999);
COMMIT;

-- Insert approximately 1 million records into CHILD
alter table child nologging;
begin
for i in 1..20 loop
insert /*+ APPEND */ into child select * from child;
commit;
end loop;
end;
/

-- in the 10.2.0.1 test, create a new session to get session statistics as well
connect hemant/hemant

alter session set max_dump_file_size='UNLIMITED';
alter session set tracefile_identifier='Test_Bug_5504961';

alter session set events '10046 trace name context forever, level 8';

set time on
set timing on
DELETE FROM PARENT WHERE COL1 = 999999999999;


spool off




First, my 10.2.0.4 results :


23:17:03 SQL> DELETE FROM PARENT WHERE COL1 = 999999999999;
DELETE FROM PARENT WHERE COL1 = 999999999999
*
ERROR at line 1:
ORA-02292: integrity constraint (HEMANT.CHILD_FK_01) violated - child record
found


Elapsed: 00:00:00.05
23:17:03 SQL>


DELETE FROM PARENT
WHERE
COL1 = 999999999999


call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.02 0 0 0 0
Execute 1 0.00 0.00 0 1 11 0
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2 0.00 0.02 0 1 11 0

Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 64

Rows Row Source Operation
------- ---------------------------------------------------
0 DELETE PARENT (cr=0 pr=0 pw=0 time=12 us)
1 INDEX UNIQUE SCAN PARENT_PK (cr=1 pr=0 pw=0 time=37 us)(object id 52936)


So, there was no signficant overhead in 10.2.0.4 (although I'm
not sure where those 11 current gets came from.


Next, my 10.2.0.1 results :


23:36:47 SQL> DELETE FROM PARENT WHERE COL1 = 999999999999;
DELETE FROM PARENT WHERE COL1 = 999999999999
*
ERROR at line 1:
ORA-02292: integrity constraint (HEMANT.CHILD_FK_01) violated - child record
found


Elapsed: 00:00:00.36
23:36:48 SQL>

DELETE FROM PARENT
WHERE
COL1 = 999999999999


call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.01 0.02 0 0 0 0
Execute 1 0.29 0.31 0 4243 4495 0
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2 0.30 0.33 0 4243 4495 0

Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 61

Rows Row Source Operation
------- ---------------------------------------------------
0 DELETE PARENT (cr=0 pr=0 pw=0 time=171 us)
1 INDEX UNIQUE SCAN PARENT_PK (cr=1 pr=0 pw=0 time=285 us)(object id 52945)

10.2.0.1 statistics for the UPDATE satement session only :

SQL> @report_session_waits_and_statistics
Enter value for sid: 105

Statistic or Wait Val or Cnt Time MS
---------------------------------------- -------------- -------------
CPU : CPU used by this session 0 340.00
Statistic : consistent changes 0
Statistic : consistent gets 4,300
Statistic : db block changes 4,476
Statistic : db block gets 4,500
Statistic : physical reads 0
Statistic : redo blocks written 0
Statistic : redo entries 4,471
Statistic : redo size 354,344
Statistic : table fetch by rowid 14
Statistic : table scan blocks gotten 3
Statistic : table scan rows gotten 62
Statistic : undo change vector size 256
Statistic : user calls 33


The 10.2.0.1 environment ended up doing 4,500 "current gets" and even 4,476 "db block changes" and 354K of Redo (delayed block cleanout).

Unfortunately, the "effort" to scan all matching Index entries of the CHILD table does not appear in the Row Source Operations.

No comments: