Skip to Main Content

Breadcrumb

Dev Live Dev Intro

This month we are celebrating Developers at AskTOM. We welcome Developers of all levels of experience to join us at our FREE Developer Live events coming in August. Just click on the left to register today! If you are brand new to Database Technology, then we also have got you covered. Just click on the right for your comprehensive FREE training program to kick start your Oracle Database Development journey!

Question and Answer

Connor McDonald

Thanks for the question, Mardy.

Asked: May 17, 2016 - 8:53 pm UTC

Answered by: Connor McDonald - Last updated: July 30, 2020 - 12:33 am UTC

Category: Database - Version: Oracle 11g

Viewed 1000+ times

You Asked

I'm trouble-shooting a very slow running delete statement in a stored procedure. The delete statement attempts to delete one record from 1 table. The record to be deleted contains a key field that is pervasive throughout the database. Call it Order_Header. Sixteen tables in the database have foreign keys containing cascade delete constraints referencing Order_Header (children tables). The database also contains 11 tables with foreign keys containing cascade delete constraints referencing the children tables (grand children). I had a similar situation with another large cascade delete that was resolved by adding indexes to the foreign keys. The only potential issue that I see in this case is that two of the grandchildren are also children of Order_Header. Stated a little differently, two of the children of Order_Header are also grandchildren of other children of Order_Header. Could this be the cause of the slow performing delete?

and we said...

Best way is to trace it - 'delete cascade' is just a normal delete operation which you'll see in the trace file, eg

SQL> create table t1 ( p int primary key, d char(100));

Table created.

SQL> create table t2 ( p int primary key, d char(100), t1p int references t1 ( p ) on delete cascade);

Table created.

SQL> create table t3 ( p int primary key, d char(100), t2p int references t2 ( p ) on delete cascade);

Table created.

SQL> create table t4 ( p int primary key, d char(100), t3p int references t3 ( p ) on delete cascade);

Table created.

SQL>
SQL> insert into t1 values (1,'x');

1 row created.

SQL> insert into t2 values (1,'x',1);

1 row created.

SQL> insert into t3 values (1,'x',1);

1 row created.

SQL> insert into t4 values (1,'x',1);

1 row created.

SQL> delete from t1;


and the trace file shows the 'hidden' deletes as well

SQL ID: 8gvp49tr474f2 Plan Hash: 1208020946

delete from t1


call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          2          0           0
Execute      1      0.00       0.00          0          4         12           1
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        2      0.00       0.00          0          6         12           1

Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 102  
Number of plan statistics captured: 1

Rows (1st) Rows (avg) Rows (max)  Row Source Operation
---------- ---------- ----------  ---------------------------------------------------
         0          0          0  DELETE  T1 (cr=43 pr=0 pw=0 time=16413 us)
         1          1          1   INDEX FAST FULL SCAN SYS_C0019864 (cr=4 pr=0 pw=0 time=49 us cost=2 size=13 card=1)(object id 146133)


Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  SQL*Net message to client                       1        0.00          0.00
  SQL*Net message from client                     1        0.00          0.00
********************************************************************************

SQL ID: 76tmmyf7g40xm Plan Hash: 1451993194

delete from "MCDONAC"."T2" 
where
 "T1P" = :1


call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      1      0.01       0.00          0          7         10           1
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        2      0.01       0.00          0          7         10           1

Misses in library cache during parse: 1
Misses in library cache during execute: 1
Optimizer mode: CHOOSE
Parsing user id: SYS   (recursive depth: 1)
Number of plan statistics captured: 1

Rows (1st) Rows (avg) Rows (max)  Row Source Operation
---------- ---------- ----------  ---------------------------------------------------
         0          0          0  DELETE  T2 (cr=33 pr=0 pw=0 time=10327 us)
         1          1          1   TABLE ACCESS FULL T2 (cr=7 pr=0 pw=0 time=76 us)

********************************************************************************

SQL ID: 20wpmkwvwrzw1 Plan Hash: 3886669427

delete from "MCDONAC"."T3" 
where
 "T2P" = :1


call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          3          0           0
Execute      1      0.00       0.00          0          4          8           1
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        2      0.00       0.00          0          7          8           1

Misses in library cache during parse: 1
Misses in library cache during execute: 1
Optimizer mode: CHOOSE
Parsing user id: SYS   (recursive depth: 2)
Number of plan statistics captured: 1

Rows (1st) Rows (avg) Rows (max)  Row Source Operation
---------- ---------- ----------  ---------------------------------------------------
         0          0          0  DELETE  T3 (cr=20 pr=0 pw=0 time=4580 us)
         1          1          1   TABLE ACCESS FULL T3 (cr=7 pr=0 pw=0 time=91 us)

********************************************************************************

SQL ID: 69c9c3ycwj33t Plan Hash: 1581231216

delete from "MCDONAC"."T4" 
where
 "T3P" = :1


call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          3          0           0
Execute      1      0.00       0.00          0          4          4           1
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        2      0.00       0.00          0          7          4           1

Misses in library cache during parse: 1
Misses in library cache during execute: 1
Optimizer mode: CHOOSE
Parsing user id: SYS   (recursive depth: 3)
Number of plan statistics captured: 1

Rows (1st) Rows (avg) Rows (max)  Row Source Operation
---------- ---------- ----------  ---------------------------------------------------
         0          0          0  DELETE  T4 (cr=7 pr=0 pw=0 time=95 us)
         1          1          1   TABLE ACCESS FULL T4 (cr=7 pr=0 pw=0 time=37 us)

********************************************************************************




So that will tell you where the slow down is.

and you rated our response

  (1 rating)

Is this answer out of date? If it is, please let us know via a Review

Reviews

Same situation on cascade no action

July 29, 2020 - 6:55 am UTC

Reviewer: Roman from Russia

Hi TOM! Thank you for a great example!
I have pretty the same situation but I have FK with no action option so I can't see any operations in my trace connected to checking on FK but my delete takes very long time. Could you please advice something to track time-leaks down? Any kind of traces or something.
Here's what I have in my trace.

SQL ID: 71vbsharan1f1 Plan Hash: 663052182

delete /*+ parallel(1) */  from DOCUMENTS s 
where
s.id IN (:c_id)


call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      6    264.88     460.49       2591     140034  245669840        6000
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        7    264.88     460.49       2591     140034  245669840        6000

Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 23     (recursive depth: 3)

Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  db file sequential read                      2539        0.01          2.06
  library cache: mutex X                        555        0.01          0.56
  log file switch completion                      3        0.05          0.11
  latch: cache buffers chains                     9        0.00          0.00
  buffer busy waits                            2373        0.00          0.02
  buffer deadlock                                 8        0.00          0.00
  Disk file operations I/O                        1        0.00          0.00
********************************************************************************



Connor McDonald

Followup  

July 30, 2020 - 12:33 am UTC

Even with no action (I assume you are talking about on-delete-cascade), we still have nearly just as much work to do, because for every row you delete, we must check the child table to see if any data exists.

Do you have a FK index in place ?