Reported SQL Plan Line ID and Adaptive Plans

If no real time SQL monitor report is available I often sample v$session or do aggregations over v$active_session_history or dba_hist_active_sess_history and group by the column sql_plan_line_id to find out where most of the time is spent.

This blog post shows that you should be aware of whether or not an adaptive plan is used when using this data. So, let’s create a small demo.

create table t1 (c1 number(10), c2 varchar2(4000));
create table t2 (c1 number(10), c2 varchar2(4000));

create index i1 on t1(c1);
create index i2 on t2(c1);


insert into t1 
  select trunc(dbms_random.value(0, 1000)), lpad('*', 4000, '*')
  from dual connect by rownum <= 1e5;

insert into t2 
  select trunc(dbms_random.value(1000, 100000)), lpad('*', 4000, '*')
  from dual connect by rownum <= 1e5;

commit;

exec dbms_stats.gather_table_stats(user, 'T1');
exec dbms_stats.gather_table_stats(user, 'T2');

Now let’s display the execution plan of a simple query joining the two tables:

explain plan for select * from t1 join t2 on (t1.c1 = t2.c1);

select * from table(dbms_xplan.display(format =>'BASIC +NOTE'));

This is the plan Oracle came up with:

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 we execute the query:

select * from t1 join t2 on (t1.c1 = t2.c1);

The query returns 0 rows as the generated numbers in the join columns are not overlapping. In my case it ran for about 6 seconds. I then used the following query to get a rough idea where in the execution plan Oracle spent most of the time.

select
  sql_plan_hash_value,
  sql_plan_line_id,
  count(*)
from v$active_session_history
where session_id = sys_context('userenv','sid')
  and sample_time > sysdate - interval '10' second
group by sql_id,
  sql_plan_hash_value,
  sql_plan_line_id;

Here’s the output:

SQL_PLAN_HASH_VALUE SQL_PLAN_LINE_ID   COUNT(*)
------------------- ---------------- ----------
         1838229974                1          4
         1838229974                8          2

Oracle reports two samples where it spent time on plan line id 8, but in the execution plan there is no such plan line id. As the plan is an adaptive plan, it’s pretty obvious that this must be the issue here. So we display the plan with the ADAPTIVE formatting option, which also displays skipped operations.

select * from table(dbms_xplan.display(format =>'BASIC +NOTE +ADAPTIVE'));

Plan hash value: 1838229974

----------------------------------------------
| 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 RANGE SCAN          | I2   |
|-  7 |    TABLE ACCESS BY INDEX ROWID| T2   |
|   8 |   TABLE ACCESS FULL           | T2   |
----------------------------------------------

Note
-----
   - this is an adaptive plan (rows marked '-' are inactive)

Whether or not an operation is skipped in a specific execution plan is stored in the other_xml column of v$sql_plan. Therefore we could extract this information to get a mapping between the reported plan line ids and the plan line ids shown in the execution plan when calling the dbms_xplan.display* functions without the ADAPTIVE formatting option.

with plan_line_ids as ( 
  select extractvalue(value(ops), '/row/@op')  op, 
         extractvalue(value(ops), '/row/@skp') skip 
  from table ( 
    select xmlsequence(extract(xmltype(other_xml), '/*/display_map/row')) 
    from v$sql_plan 
    -- change plan_hash_value and child_number
    where plan_hash_value = 1838229974 and child_number = 0 
    and other_xml is not null
  ) ops
) 
select o.op as plan_line_id_adaptive, 
  o.op - ( 
    select count(*) 
    from plan_line_ids i 
    where i.op <= o.op and i.skip = '1') plan_line_id 
from plan_line_ids o 
where  o.skip = '0';

Output:

PLAN_LINE_ID_ADAPTIVE     PLAN_LINE_ID
------------------------- ------------
1                                    1
5                                    2
8                                    3

Conclusion

This demo showed an example where it was obvious that there’s something wrong, because the reported plan line id simply didn’t exist in the plan. Depending on the reported line ids it is not necessarily obvious at first. So if you’re using the sql_plan_line_id from v$session, v$active_session_history or dba_hist_active_sess_history to determine where in the execution plan Oracle is spending time, always make sure to check whether you’re looking at an adaptive plan or not.