Yesterday, during the talk “The Query Optimizer in Oracle Database 12c – What’s New?” at OakTable World UK 2013, an attendee asked me an interesting question that can be summarized as follows: does ASH show the switch of execution plan that takes place for an adaptive plan?
Since I didn’t know the answer, here are some tests I did to find out how it works.
First of all, it’s important to recognize that the plan hash value related to an adaptive plan changes depending on which subplan is activated. Let’s take as example the following query (notice that the execution plan is adaptive and that the hash value of the default plan is 1837274416):
SQL> EXPLAIN PLAN FOR SELECT * FROM t1, t2 WHERE t1.id = t2.id AND t1.n = 666; SQL> SELECT * FROM table(dbms_xplan.display(format=>'basic +adaptive +note')); Plan hash value: 1837274416 ----------------------------------------------- | Id | Operation | Name | ----------------------------------------------- | 0 | SELECT STATEMENT | | |- 1 | HASH JOIN | | | 2 | NESTED LOOPS | | | 3 | NESTED LOOPS | | |- 4 | STATISTICS COLLECTOR | | | 5 | TABLE ACCESS FULL | T1 | | 6 | INDEX UNIQUE SCAN | T2_PK | | 7 | TABLE ACCESS BY INDEX ROWID| T2 | |- 8 | TABLE ACCESS FULL | T2 | ----------------------------------------------- Note ----- - this is an adaptive plan (rows marked '-' are inactive)
If the query is executed and the default plan is used (I completely deactivate adaptive plans to ensure it), the plan hash value is the same as the one we have seen before, i.e. 1837274416):
SQL> ALTER SESSION SET optimizer_adaptive_features = FALSE; SQL> SELECT * 2 FROM t1, t2 3 WHERE t1.id = t2.id 4 AND t1.n = 666; SQL> SELECT * FROM table(dbms_xplan.display_cursor(format=>'basic +note')); Plan hash value: 1837274416 ---------------------------------------------- | Id | Operation | Name | ---------------------------------------------- | 0 | SELECT STATEMENT | | | 1 | NESTED LOOPS | | | 2 | NESTED LOOPS | | | 3 | TABLE ACCESS FULL | T1 | | 4 | INDEX UNIQUE SCAN | T2_PK | | 5 | TABLE ACCESS BY INDEX ROWID| T2 | ----------------------------------------------
However, if a switch of execution plan takes place, the plan hash value changes (the new value is 1838229974):
SQL> ALTER SESSION SET optimizer_adaptive_features = TRUE; SQL> SELECT * 2 FROM t1, t2 3 WHERE t1.id = t2.id 4 AND t1.n = 666; SQL> SELECT * FROM table(dbms_xplan.display_cursor(format=>'basic +note')); Plan hash value: 1838229974 ----------------------------------- | Id | Operation | Name | ----------------------------------- | 0 | SELECT STATEMENT | | | 1 | HASH JOIN | | | 2 | TABLE ACCESS FULL| T1 | | 3 | TABLE ACCESS FULL| T2 | ----------------------------------- Note ----- - this is an adaptive plan
Now, back to the question… Since the switch of execution plan takes place during the execution, are we able to spot the switch in the ASH samples? In other words, can we see different plan hash values for a single execution or does the database engine implements a fix-up for the plan hash value?
To test the behaviour I decided to artificially slow down my test query to make sure that ASH captures plenty of samples for a single execution. For that purpose, I usually use a function that burns a lot of CPU like the following one (notice that the parameter specifies, in seconds, how long an execution should last):
CREATE OR REPLACE FUNCTION burn_cpu(p_wait IN INTEGER) RETURN INTEGER IS l_begin NUMBER; BEGIN l_begin := dbms_utility.get_time(); LOOP EXIT WHEN l_begin+(p_wait*100) < dbms_utility.get_time(); END LOOP; RETURN 1; END burn_cpu;
To slow down the access to both tables, I added a predicate based on the burn_cpu function for each of them. In one case, 1 second of CPU is added to the processing of every row. In the other one, just few milliseconds are added (the parameter specifies 1 millisecond, but the overhead is much higher…). According to the runtime statistics the execution lasted 2.5 minutes (50 second for one table, 1 minute and 40 seconds for the other).
SQL> SELECT * 2 FROM t1, t2 3 WHERE t1.id = t2.id 4 AND t1.n = 666 5 AND burn_cpu(t1.n/t1.n) = 1 6 AND burn_cpu(t2.n/t2.n/1000) = 1; SQL> SELECT * FROM table(dbms_xplan.display_cursor(format=>'iostats last')); Plan hash value: 1838229974 ------------------------------------------------------------------------------------- | Id | Operation | Name | Starts | E-Rows | A-Rows | A-Time | Buffers | ------------------------------------------------------------------------------------- | 0 | SELECT STATEMENT | | 1 | | 1 |00:02:29.53 | 1319 | |* 1 | HASH JOIN | | 1 | 1 | 1 |00:02:29.53 | 1319 | |* 2 | TABLE ACCESS FULL| T1 | 1 | 1 | 49 |00:00:49.52 | 1155 | |* 3 | TABLE ACCESS FULL| T2 | 1 | 1 | 10000 |00:01:39.98 | 164 | ------------------------------------------------------------------------------------- Predicate Information (identified by operation id): --------------------------------------------------- 1 - access("T1"."ID"="T2"."ID") 2 - filter(("T1"."N"=666 AND "BURN_CPU"("T1"."N"/"T1"."N")=1)) 3 - filter("BURN_CPU"("T2"."N"/"T2"."N"/1000)=1) Note ----- - this is an adaptive plan
Note that the inflection point of the test query is 48 rows. Therefore, the decision to switch to the alternative execution plan can only take place after 48 seconds from the beginning of the execution.
For this specific execution the content of ASH is the following:
SQL> SELECT sql_exec_id, sql_plan_hash_value, sql_plan_operation, sql_plan_options, sql_plan_line_id, 2 count(*), min(sample_id), max(sample_id) 3 FROM v$active_session_history 4 WHERE session_id = 16 5 AND session_serial# = 25 6 AND sql_id = 'ckwcszvtggvxx' 7 AND sql_child_number = 0 8 GROUP BY sql_exec_id, sql_plan_hash_value, sql_plan_operation, sql_plan_options, sql_plan_line_id 9 ORDER BY min(sample_time), max(sample_time); SQL_EXEC_ID SQL_PLAN_HASH_VALUE SQL_PLAN_OPERATION SQL_PLAN_OPTIONS SQL_PLAN_LINE_ID COUNT(*) MIN(SAMPLE_ID) MAX(SAMPLE_ID) ----------- ------------------- ------------------ ---------------- ---------------- -------- -------------- -------------- 16777216 1837274416 TABLE ACCESS FULL 5 49 4121942 4121990 16777216 1837274416 TABLE ACCESS FULL 8 7 4121991 4121997 16777216 1838229974 TABLE ACCESS FULL 8 93 4121998 4122090
The most important things to notice are the following:
- During the execution the plan hash value changed.
- According to ASH the plan hash value changed during the execution of the second FTS. This is not what I would expect. It should change before activating the row source operation with the id 8. It seems that there is a short delay before the plan hash value is update. As a result, you might not always be able to observe the switch.
- The amount of time spent on each FTS matches the runtime statistics shown by DBMS_XPLAN.
In conclusion, the short answer to the question is… yes, it’s visible.
Fantastic – good proof!
In the UKOUG Tech13 Optimizer round table, this question was posed and nobody could answer definitively, although Jonathan Lewis speculated it would appear, and I believe Tom Kyte agreed.
Thanks Christian – saved me a couple of hours trying to work out how to prove it (I am loving that CPU_BURN function and will be stealing it)
Neil.
You are welcome, Neil.
[…] http://www.antognini.ch/2013/12/adaptive-plans-in-active-session-history/ […]
Hi Christian,
I’m wondering how the plan ca be dynamically changed if some rows have already been sent to the client.
For example, Imagine you have a plan that includes NESTED LOOP operations, some rows may have already been returned when Oracle detects that a better plan can be chosen?
Do you have any idea on this?
regards,
Ahmed
Hi Ahmed
One of the roles of the STATISTICS COLLECTOR operation is to shortly buffer data until the decision is taken. Therefore, no rows are sent to the client before the final plan has been decided.
Best,
Chris
Ok it’s clear for me now.
Thanks
Nice Article !
Hi,
what is the difference b/w optimizer_adaptive_features=false & optimizer_adaptive_features=True and how does it affect the database performance & if we set the parameter optimizer_adaptive_features=false at session lever do we need to increase the gather stats ? Please help me understand
Hi Anil
when optimizer_adaptive_features is set to false, the following features are disabled:
– Adaptive plans
– SQL plan directives
– Automatic reoptimization
Of course those features impact performance.
I do not see a reason for increasing the frequency of the statistics gathering when optimizer_adaptive_features is set to false.
HTH
Chris
The delay may be attributed to the sampling interval, so the plan probably does switch when you expect it to it’s simply not recorded as a change until the next AWR sample period.
David
for “small” errors (i.e. 1-2 seconds) that would be a possibility. But, in this case, the initial plan is executed for 56 seconds. Hence, I think that there is something else going on.
Best,
Chris
i do see 0 for sql plan hash value until the final plan is chosen.
Hi Raje
Which database version?
Best,
Chris