Evolution of a SQL Plan Baseline Based on a DELETE Statement

During an evolution the database engine compares the performance of two execution plans. The aim is to find out which one provides the better performance. For that purpose it has to run the SQL statement on which the SQL plan baseline is based and compare some execution statistics. The following output of the DBMS_SPM.EVOLVE_SQL_PLAN_BASELINE function shows which statistics are compared.

Plan was verified: Time used .06 seconds.
Plan passed performance criterion: 360.12 times better than baseline plan.
Plan was changed to an accepted plan.

                          Baseline Plan      Test Plan       Stats Ratio
                          -------------      ---------       -----------
Execution Status:              COMPLETE       COMPLETE
Rows Processed:                     100            100
Elapsed Time(ms):                 2.173           .033             65.85
CPU Time(ms):                     2.444              0
Buffer Gets:                        720              2               360
Physical Read Requests:               0              0
Physical Write Requests:              0              0
Physical Read Bytes:                  0              0
Physical Write Bytes:                 0              0
Executions:                           1              1

For queries a regular execution can be performed. But, what happens for INSERT/UPDATE/MERGE/DELETE statements? Do the SQL engine really execute them and modify data?

To answer these questions let’s have a look to an example based on a DELETE statement…

Setup a table used for the test:

SQL> CREATE TABLE t (id, n, pad, CONSTRAINT t_pk PRIMARY KEY (id))
  2  AS
  3  SELECT rownum, mod(rownum,100), rpad('*',500,'*')
  4  FROM dual
  5  CONNECT BY level <= 10000;

SQL> execute dbms_stats.gather_table_stats(ownname => user, tabname => 't', method_opt => 'for all columns size 254')

Create a SQL plan baseline:

SQL> ALTER SESSION SET optimizer_capture_sql_plan_baselines = TRUE;

SQL> DELETE t WHERE n = 42;

SQL> ROLLBACK;

SQL> DELETE t WHERE n = 42;

SQL> ROLLBACK;

SQL> ALTER SESSION SET optimizer_capture_sql_plan_baselines = FALSE;

Add a non-accepted execution plan to the SQL plan baseline:

SQL> CREATE INDEX i ON t (n);

SQL> DELETE t WHERE n = 42;

SQL> ROLLBACK;

SQL> DELETE t WHERE n = 42;

SQL> ROLLBACK;

Display the content of the SQL plan baseline (notice that two execution plans are available):

SQL> SELECT * FROM table(dbms_xplan.display_sql_plan_baseline('SYS_SQL_373d78bbba048c24', NULL, 'basic'));

PLAN_TABLE_OUTPUT
--------------------------------------------------------------------------------

--------------------------------------------------------------------------------
SQL handle: SYS_SQL_373d78bbba048c24
SQL text: DELETE t WHERE n = 42
--------------------------------------------------------------------------------

--------------------------------------------------------------------------------
Plan name: SQL_PLAN_3fgbsrfx093143bad20a0         Plan id: 1001201824
Enabled: YES     Fixed: NO      Accepted: YES     Origin: AUTO-CAPTURE
--------------------------------------------------------------------------------

Plan hash value: 3335594643

-----------------------------------
| Id  | Operation          | Name |
-----------------------------------
|   0 | DELETE STATEMENT   |      |
|   1 |  DELETE            | T    |
|   2 |   TABLE ACCESS FULL| T    |
-----------------------------------

--------------------------------------------------------------------------------
Plan name: SQL_PLAN_3fgbsrfx093144198692b         Plan id: 1100507435
Enabled: YES     Fixed: NO      Accepted: NO      Origin: AUTO-CAPTURE
--------------------------------------------------------------------------------

Plan hash value: 1582806765

----------------------------------
| Id  | Operation         | Name |
----------------------------------
|   0 | DELETE STATEMENT  |      |
|   1 |  DELETE           | T    |
|   2 |   INDEX RANGE SCAN| I    |
----------------------------------

Trace the evolution to find out what happens (notice that I deleted the output of the function because it is the one it is shown at the top of this post):

SQL> execute dbms_monitor.session_trace_enable(plan_stat=>'ALL_EXECUTIONS')

SQL> SELECT dbms_spm.evolve_sql_plan_baseline(
  2           sql_handle => 'SYS_SQL_373d78bbba048c24',
  3           plan_name  => '',
  4           time_limit => 10,
  5           verify     => 'yes',
  6           commit     => 'yes'
  7         )
  8  FROM dual;

SQL> execute dbms_monitor.session_trace_disable

SQL> SELECT value
  2  FROM v$diag_info
  3  WHERE name = 'Default Trace File';

VALUE
-------------------------------------------------------------------
/u00/app/oracle/diag/rdbms/dba112/DBA112/trace/DBA112_ora_17200.trc

Now that the trace file was generated, let’s have a look to its content. The relevant parts are two: the first one is related to the execution of the accepted execution plan, and the second one is related to the execution of the non-accepted one.

PARSING IN CURSOR #11 len=45 dep=1 uid=90 oct=7 lid=90 tim=1275524159625080 hv=4077337184 ad='325c9f10' sqlid='5fwyncmthffm0'
/* SQL Analyze(25,0) */ DELETE t WHERE n = 42
END OF STMT
PARSE #11:c=1000,e=652,p=0,cr=0,cu=0,mis=1,r=0,dep=1,og=1,plh=1001201824,tim=1275524159625078
EXEC #11:c=4999,e=5670,p=0,cr=720,cu=0,mis=0,r=0,dep=1,og=1,plh=1001201824,tim=1275524159630752
EXEC #11:c=2000,e=1718,p=0,cr=720,cu=0,mis=0,r=0,dep=1,og=1,plh=1001201824,tim=1275524159632613
EXEC #11:c=2000,e=1511,p=0,cr=720,cu=0,mis=0,r=0,dep=1,og=1,plh=1001201824,tim=1275524159634156
EXEC #11:c=2000,e=1542,p=0,cr=720,cu=0,mis=0,r=0,dep=1,og=1,plh=1001201824,tim=1275524159636144
EXEC #11:c=2000,e=1552,p=0,cr=720,cu=0,mis=0,r=0,dep=1,og=1,plh=1001201824,tim=1275524159638151
EXEC #11:c=3998,e=4015,p=0,cr=720,cu=0,mis=0,r=0,dep=1,og=1,plh=1001201824,tim=1275524159642613
EXEC #11:c=3000,e=2905,p=0,cr=720,cu=0,mis=0,r=0,dep=1,og=1,plh=1001201824,tim=1275524159645549
EXEC #11:c=2000,e=1506,p=0,cr=720,cu=0,mis=0,r=0,dep=1,og=1,plh=1001201824,tim=1275524159647151
EXEC #11:c=2000,e=1562,p=0,cr=720,cu=0,mis=0,r=0,dep=1,og=1,plh=1001201824,tim=1275524159649160
EXEC #11:c=2999,e=2440,p=0,cr=720,cu=0,mis=0,r=0,dep=1,og=1,plh=1001201824,tim=1275524159652037
CLOSE #11:c=0,e=3,dep=1,type=0,tim=1275524159652065

PARSING IN CURSOR #5 len=45 dep=1 uid=90 oct=7 lid=90 tim=1275524159657503 hv=4077337184 ad='325c9f10' sqlid='5fwyncmthffm0'
/* SQL Analyze(25,0) */ DELETE t WHERE n = 42
END OF STMT
PARSE #5:c=1000,e=859,p=0,cr=0,cu=0,mis=1,r=0,dep=1,og=1,plh=1100507435,tim=1275524159657499
EXEC #5:c=0,e=52,p=0,cr=2,cu=0,mis=0,r=0,dep=1,og=1,plh=1100507435,tim=1275524159657625
EXEC #5:c=0,e=0,p=0,cr=2,cu=0,mis=0,r=0,dep=1,og=1,plh=1100507435,tim=1275524159657647
EXEC #5:c=0,e=31,p=0,cr=2,cu=0,mis=0,r=0,dep=1,og=1,plh=1100507435,tim=1275524159657972
EXEC #5:c=0,e=5,p=0,cr=2,cu=0,mis=0,r=0,dep=1,og=1,plh=1100507435,tim=1275524159658071
EXEC #5:c=0,e=0,p=0,cr=2,cu=0,mis=0,r=0,dep=1,og=1,plh=1100507435,tim=1275524159658071
EXEC #5:c=0,e=0,p=0,cr=2,cu=0,mis=0,r=0,dep=1,og=1,plh=1100507435,tim=1275524159658071
EXEC #5:c=0,e=0,p=0,cr=2,cu=0,mis=0,r=0,dep=1,og=1,plh=1100507435,tim=1275524159658071
EXEC #5:c=0,e=0,p=0,cr=2,cu=0,mis=0,r=0,dep=1,og=1,plh=1100507435,tim=1275524159658071
EXEC #5:c=0,e=0,p=0,cr=2,cu=0,mis=0,r=0,dep=1,og=1,plh=1100507435,tim=1275524159658071
EXEC #5:c=0,e=0,p=0,cr=2,cu=0,mis=0,r=0,dep=1,og=1,plh=1100507435,tim=1275524159658071
CLOSE #5:c=0,e=0,dep=1,type=0,tim=1275524159658071

In the previous output notice that:

The PLH attribute of the EXEC lines shows that two execution plans are used.
Each execution plan was executed 10 times (in practice the number varies according to the elapsed time; i.e. for longer executions a single run might be enough to determine whether an execution plan has to be accepted).
Even though I set the PLAN_STAT parameter to ALL_EXECUTIONS (if you don’t know what the PLAN_STAT parameter is for, have a look to this post) the STAT lines (the execution plan) are not available in the trace file.

According to this information the SQL statement is executed. But, if you check the table after the evolution, the data is still there. And that, honestly, is not an option! In addition, no ROLLBACK is executed (no XCTEND lines are present in the trace file). So, it seems that the SQL statement is not executed.

What I really miss in the trace file are the execution plans associated to the executions to check what the different operations of the execution plan did. The only way I found to have them, it is to add the GATHER_PLAN_STATISTICS hint into the SQL statement itself (also setting the STATISTICS_LEVEL parameter and checking a view like V$SQL_PLAN_STATISTICS_ALL did not help). The content of the trace file, formatted by TVD$XTAT, is the following:

Optimizer Mode       ALL_ROWS
Hash Value           1001201824
Number of Executions 10

        Rows Operation
------------ ---------------------------------------------------------------------------------------
           0 DELETE  T (cr=720 pr=25 pw=0 time=0 us)
           0   TABLE ACCESS FULL T (cr=720 pr=25 pw=0 time=0 us cost=84 size=700 card=100)

Optimizer Mode       ALL_ROWS
Hash Value           1100507435
Number of Executions 10

        Rows Operation
------------ ---------------------------------------------------------------------------------------
           0 DELETE  T (cr=2 pr=0 pw=0 time=0 us)
           0   INDEX RANGE SCAN I (cr=2 pr=0 pw=0 time=0 us cost=1 size=700 card=100) (object id 93840)

Notice that while the number of logical reads (CR attribute) matches the report generated by the evolution, the number of rows returned by both steps of the execution plans is 0. And that, even though the index range scan should return 100 rows.

In summary, during an evolution the SQL engine processes the SQL statements in a special way. The data is accessed, but not modified. Hence, SQL statements are only partially executed. I do not regard this fact as a problem, though. In fact, the operations that modify data should always perform the same work independently on how the data to be modified is located (in the example given here, either with a full table scan or an index range scan).

2 Comments

2 Pings/Trackbacks

Flado

11 June 2010 - 14:23
Very nice. It got me thinking:

This “special mode” seems quite detached from reality: surely one cannot find (and delete) 100 of your relatively big rows with just two LIOs, even if they were perfectly clustered (and they are not; quite the opposite, in fact). I’m willing to accept that all of their ROWIDs are in a single leaf block, but the table still needs to be accessed for the DELETE, and that’s 100 extra LIOs given your clustering factor. This, and the impact of index maintenance is nowhere to be seen.
I understand that the execution can plan only affect the SELECT part of an INSERT, DELETE, or UPDATE statement (i.e., the work needed to identify the affected rows), so I guess that’s the part being tested in this “special mode”. In other words,
```
insert into t select ...
```
gets tested as if it were just
```
select ...
```
,
```
delete T where ...
```
gets tested as if it were
```
select rowid from t where ...
```
, and
```
update t set c1=(select...), c2=(select...), ... where ...
```
gets tested as
```
select rowid, (select ...), (select ...), ... from t where ...
```
BUT this puts plans that access the target table as part of the SELECT at a disadvantage compared to index-only plans. It would be interesting to see what happens with your example if you delete a bit more rows such that the full scan would become cheaper than the indexed access path: would the SPM still accept the indexed plan (I think – yes)?

Sorry, but I don’t have an 11g at hand to test this myself. Maybe over the weekend…

Cheers,
Flado
1. Christian Antognini
  
  13 June 2010 - 10:57
  Hi Flado
  
  > It would be interesting to see what happens with your example
  > if you delete a bit more rows such that the full scan would
  > become cheaper than the indexed access path
  
  I tried it and a the SPM is accepted. That said, notice that the runtime behavior is probably different from what you might expect… Here are the execution statistics for five executions of the SQL statement “DELETE t WHERE n > 5”:
  
  – Without index (FTS)
```
call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        5      0.01       0.01          0          0          0           0
Execute      5      1.67       2.76        123       3633     161757       46500
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total       10      1.69       2.77        123       3633     161757       46500
```
  – With index
```
call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        5      0.00       0.00          0          0          0           0
Execute      5      0.99       3.21         75        129      68805       46500
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total       10      0.99       3.21         75        129      68805       46500
```
  HTH
  Chris
SQL Plan Baselines « Oracle Scratchpad Pingback

7 January 2011 - 21:09

[…] Christian Anognini: An interesting observation on evolving baselines for delete statements […]

SQL Plan Management | IT World Pingback

17 October 2012 - 13:18

[…] Evolution of a SQL Plan Baseline Based on a DELETE Statement […]

Striving for Optimal Performance

Evolution of a SQL Plan Baseline Based on a DELETE Statement

2 Comments

2 Pings/Trackbacks

Leave a Reply Cancel reply