Oracle Support – Grrr

Is this an appropriate response?

Others have raised this before – in fact I think I’ve raised the question before – but my initial search on Oracle Support did not turn up an answer so I thought I would raise a question again.

Problem Summary
—————————————————
Question only: Null predicates in DBA_HIST_SQL_PLAN

Problem Description
—————————————————
Everyone knows that the FILTER_PREDICATES and ACCESS_PREDICATES columns in DBA_HIST_SQL_PLAN are not populated.
If I remember correctly, this was originally a bug in 9i and statspack and has been carried forward into AWR.
As a result, any execution plan fetched using DBMS_XPLAN.DISPLAY_AWR has no predicate information
The statement which populates the underlying data has hardcoded NULLS.
Why do these continue to be null through all versions?
Is there any plan to address this?

I even provided the AWR statement with the hardcoded NULLS:

INSERT INTO wrh$_sql_plan sp (snap_id, dbid, sql_id, plan_hash_value, id, operation, options, object_node, object#, object_owner, object_name, object_alias, object_type, optimizer, parent_id, depth, position, search_columns, cost, cardinality, bytes, other_tag, partition_start, partition_stop, partition_id, other, distribution, cpu_cost, io_cost, temp_space, access_predicates, filter_predicates, projection, time, qblock_name, remarks, timestamp, other_xml) SELECT /*+ ordered use_nl(p) PARAM(‘_flush_plan_in_awr_sql’, 1) PARAM(‘_cursor_plan_unparse_enabled’, ‘FALSE’) */ :lah_snap_id lsnid, :dbid dbid, p.sql_id, p.plan_hash_value, p.id, p.operation, p.options, p.object_node, p.object#, p.object_owner, p.object_name, p.object_alias, p.object_type, p.optimizer, p.parent_id, p.depth, p.position, p.search_columns, p.cost, p.cardinality, p.bytes, p.other_tag, p.partition_start, p.partition_stop, p.partition_id, p.other, p.distribution, p.cpu_cost, p.io_cost, p.temp_space, NULL access_predicates, NULL filter_predicates, NULL projection, p.time, p.qblock_name, p.remarks, p.timestamp, p.other_xml FROM x$kewrattrnew atn, x$kewrtsqlplan spn, v$sql_plan p WHERE atn.str1_kewrattr = spn.sqlid_kewrspe AND atn.num1_kewrattr = spn.planhash_kewrspe AND spn.sqlid_kewrspe = p.sql_id AND spn.planhash_kewrspe = p.plan_hash_value AND spn.childaddr_kewrspe = p.child_address

Response:

Please provide 10046 showing the issue
…
blah, blah, blah
instructions for doing a trace
blah, blah, blah

Might as well have been an automated response or “did you try turning it off and on again?”
RTFQ…

AWR: Was a baselined plan used?

Sometimes a simple question turns out to be harder than expected.

“Can we see if a particular SQL execution in AWR used a baselined plan?”

Initial thoughts might be:

Q: Does DBMS_XPLAN.DISPLAY_AWR tell us this?
A: Apparently not. See below. This question could also be rephrased as two other possible questions:

Q:Isn’t there a column on DBA_HIST_SQLSTAT which tell us this?
A: No. You’d think there should be. There is a SQL_PROFILE column. There isn’t a SQL_PLAN_BASELINE column.
There also isn’t an EXACT_MATCHING_SIGNATURE although there is a FORCE_MATCHING_SIGNATURE.

Q: Is it in DBA_HIST_SQL_PLAN.OTHER_XML?
A. No although this is where DBMS_XPLAN.DISPLAY_AWR gets it’s notes about cardinality feedback and dynamic sampling from.

First of all, Let’s see that it’s not shown in DBMS_XPLAN.DISPLAY_AWR.
Let’s get a sql statement baselined, in AWR and not in memory.

The usual setup

SQL> create table t1
  2  (col1  number
  3  ,col2  varchar2(50)
  4  ,flag  varchar2(2));

Table created.

SQL> insert into t1
  2  select rownum
  3  ,      lpad('X',50,'X')
  4  ,      case when rownum = 1
  5              then 'Y1'
  6              when rownum = 2
  7              then 'Y2'
  8              when mod(rownum,2) = 0
  9              then 'N1'
 10              else 'N2'
 11         end
 12  from   dual
 13* connect by rownum <= 100000
SQL> /

100000 rows created.

SQL> commit;

Commit complete.

Get a plan and put it in a baseline:

SQL> var n varchar2(2);
SQL> exec :n := 'N1';

PL/SQL procedure successfully completed.

SQL> select count(*), max(col2) from t1 where flag = :n;
select * from table(dbms_xplan.display_cursor);
  COUNT(*) MAX(COL2)
---------- --------------------------------------------------
     49999 XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX

SQL> select * from table(dbms_xplan.display_cursor);


PLAN_TABLE_OUTPUT
--------------------------------------------------------------------------------
SQL_ID  731b98a8u0knf, child number 0
-------------------------------------
select count(*), max(col2) from t1 where flag = :n

Plan hash value: 3724264953

---------------------------------------------------------------------------
| Id  | Operation          | Name | Rows  | Bytes | Cost (%CPU)| Time     |
---------------------------------------------------------------------------
|   0 | SELECT STATEMENT   |      |       |       |   221 (100)|          |
|   1 |  SORT AGGREGATE    |      |     1 |    30 |            |          |
|*  2 |   TABLE ACCESS FULL| T1   | 50254 |  1472K|   221   (1)| 00:00:03 |
---------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------

   2 - filter("FLAG"=:N)

Note
-----
   - dynamic sampling used for this statement (level=2)

SQL> declare
  2   l_op pls_integer;
  3  begin
  4    l_op :=
  5    dbms_spm.load_plans_from_cursor_cache('731b98a8u0knf');
  6* end;
SQL> /

PL/SQL procedure successfully completed.

Verify that DBMS_XPLAN.DISPLAY_CURSOR reports baseline usage:

SQL> select count(*), max(col2) from t1 where flag = :n;

  COUNT(*) MAX(COL2)
---------- --------------------------------------------------
     49999 XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX

SQL> select * from table(dbms_xplan.display_cursor);

PLAN_TABLE_OUTPUT
--------------------------------------------------------------------------------
SQL_ID  731b98a8u0knf, child number 0
-------------------------------------
select count(*), max(col2) from t1 where flag = :n

Plan hash value: 3724264953

---------------------------------------------------------------------------
| Id  | Operation          | Name | Rows  | Bytes | Cost (%CPU)| Time     |
---------------------------------------------------------------------------
|   0 | SELECT STATEMENT   |      |       |       |   221 (100)|          |
|   1 |  SORT AGGREGATE    |      |     1 |    30 |            |          |
|*  2 |   TABLE ACCESS FULL| T1   | 50254 |  1472K|   221   (1)| 00:00:03 |
---------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------

   2 - filter("FLAG"=:N)

Note
-----
   - dynamic sampling used for this statement (level=2)
   - SQL plan baseline SQL_PLAN_13w748wknkcwd616acf47 used for this statement

See that dynamic_sampling note most likely comes from OTHER_XML and Baseline note doesn’t, it comes from V$SQL:

SQL>select sql_id
  2  ,      to_char(exact_matching_signature) sig
  3  ,      plan_hash_value
  4  ,      sql_plan_baseline
  5  from   v$sql
  6* where  sql_id = '731b98a8u0knf'
SQL> /

SQL_ID        SIG                                      PLAN_HASH_VALUE SQL_PLAN_BASELINE
------------- ---------------------------------------- --------------- ------------------------------
731b98a8u0knf 1292784087274697613                           3724264953 SQL_PLAN_13w748wknkcwd616acf47

SQL> set long 10000
SQL> select other_xml
  2  from   v$sql_plan
  3  where  sql_id = '731b98a8u0knf'
  4* and    other_xml is not null
SQL> /

OTHER_XML
--------------------------------------------------------------------------------
<other_xml><info type="db_version">11.2.0.3</info><info type="parse_schema"><![C
DATA["E668983_DBA"]]></info><info type="dynamic_sampling">2</info><info type="pl
an_hash">3724264953</info><info type="plan_hash_2">1634389831</info><peeked_bind
s><bind nam=":N" pos="1" dty="1" csi="178" frm="1" mxl="32">4e31</bind></peeked_
binds><outline_data><hint><![CDATA[IGNORE_OPTIM_EMBEDDED_HINTS]]></hint><hint><!
[CDATA[OPTIMIZER_FEATURES_ENABLE('11.2.0.3')]]></hint><hint><![CDATA[DB_VERSION(
'11.2.0.3')]]></hint><hint><![CDATA[OPT_PARAM('query_rewrite_enabled' 'false')]]
></hint><hint><![CDATA[ALL_ROWS]]></hint><hint><![CDATA[OUTLINE_LEAF(@"SEL$1")]]
></hint><hint><![CDATA[FULL(@"SEL$1" "T1"@"SEL$1")]]></hint></outline_data></oth
er_xml>

Now, let’s add statement to AWR, do an AWR snap and flush the SP:

SQL> exec dbms_workload_repository.add_colored_sql('731b98a8u0knf');

PL/SQL procedure successfully completed.

SQL> exec dbms_workload_repository.create_snapshot;

PL/SQL procedure successfully completed.

SQL> alter system flush shared_pool;

System altered.

Now if we look back at the plan in memory, there’s nothing there.

SQL> select * from v$sql where sql_id = '731b98a8u0knf';

no rows selected

SQL> select * from table(dbms_xplan.display_cursor('731b98a8u0knf'));

PLAN_TABLE_OUTPUT
------------------------------------------------------------
SQL_ID: 731b98a8u0knf, child number: 0 cannot be found

But the SQL is in AWR and let’s see that DBMS_XPLAN.DISPLAY_AWR does not tells us that a baseline is used:

SQL> select * from table(dbms_xplan.display_awr('731b98a8u0knf'));

PLAN_TABLE_OUTPUT
---------------------------------------------------------------
SQL_ID 731b98a8u0knf
--------------------
select count(*), max(col2) from t1 where flag = :n

Plan hash value: 3724264953

---------------------------------------------------------------------------
| Id  | Operation          | Name | Rows  | Bytes | Cost (%CPU)| Time     |
---------------------------------------------------------------------------
|   0 | SELECT STATEMENT   |      |       |       |   221 (100)|          |
|   1 |  SORT AGGREGATE    |      |     1 |    30 |            |          |
|   2 |   TABLE ACCESS FULL| T1   | 50238 |  1471K|   221   (1)| 00:00:03 |
---------------------------------------------------------------------------

Note
-----
   - dynamic sampling used for this statement (level=2)

But it will tell us if a sql profile is used because it can via DBA_HIST_SQLSTAT.SQL_PROFILE – I leave that exercise to the reader.

So, back to the original question:

“Can we see if a particular SQL execution in AWR used a baselined plan?”

I’ve never needed to do this but as an exercise we can infer this connection by the presence of a baselined plan with the same phv2 but it’s convoluted.

It may be that there are simpler ways but it seems to me that we need to:

1. Get the exact_matching_signature from the sql text
2. Get the phv2 out of DBA_HIST_SQL_PLAN.OTHER_XML
3. Match that phv2 with planid which is not exposed in DBA_SQL_PLAN_BASELINES but is in the underlying SYS.SQLOBJ$ tables

SQL> with subq_mysql as
  2  (select sql_id
  3   ,      (select dbms_sqltune.sqltext_to_signature(ht.sql_text)
  4           from dual) sig
  5   from   dba_hist_sqltext       ht
  6   where  sql_id = '731b98a8u0knf')
  7  ,    subq_baselines as
  8  (select b.signature
  9   ,      b.plan_name
 10   ,      b.accepted
 11   ,      b.created
 12   ,      o.plan_id
 13   from   subq_mysql             ms
 14   ,      dba_sql_plan_baselines b
 15   ,      sys.sqlobj$            o
 16   where  b.signature   = ms.sig
 17   and    o.signature   = b.signature
 18   and    o.name        = b.plan_name)
 19  ,    subq_awr_plans as
 20  (select  sn.snap_id
 21   ,       to_char(sn.end_interval_time,'DD-MON-YYYY HH24:MI') dt
 22   ,       hs.sql_id
 23   ,       hs.plan_hash_value
 24   ,       t.phv2
 25   ,       ms.sig
 26   from    subq_mysql        ms
 27   ,       dba_hist_sqlstat  hs
 28   ,       dba_hist_snapshot sn
 29   ,       dba_hist_sql_plan hp
 30   ,       xmltable('for $i in /other_xml/info
 31                     where $i/@type eq "plan_hash_2"
 32                     return $i'
 33                    passing xmltype(hp.other_xml)
 34                    columns phv2 number path '/') t
 35   where   hs.sql_id          = ms.sql_id
 36   and     sn.snap_id         = hs.snap_id
 37   and     sn.instance_number = hs.instance_number
 38   and     hp.sql_id          = hs.sql_id
 39   and     hp.plan_hash_value = hs.plan_hash_value
 40   and     hp.other_xml      is not null)
 41  select awr.*
 42  ,       nvl((select max('Y')
 43               from   subq_baselines b
 44               where  b.signature = awr.sig
 45               and    b.accepted  = 'YES'),'N') does_baseline_exist
 46  ,      nvl2(b.plan_id,'Y','N') is_baselined_plan
 47  ,      to_char(b.created,'DD-MON-YYYY HH24:MI')  when_baseline_created
 48  from   subq_awr_plans awr
 49  ,      subq_baselines b
 50  where  b.signature (+) = awr.sig
 51  and    b.plan_id   (+) = awr.phv2
 52* order by awr.snap_id
SQL> /

   SNAP_ID DT                SQL_ID        PLAN_HASH_VALUE       PHV2        SIG D I WHEN_BASELINE_CRE
---------- ----------------- ------------- --------------- ---------- ---------- - - -----------------
      8703 05-FEB-2014 15:18 731b98a8u0knf      3724264953 1634389831 1.2928E+18 Y Y 05-FEB-2014 15:08

SQL>

Surprising.
Unless, of course, I’ve overlooked something bleeding obvious.

Problem plans

I was looking at a performance problem a week or so before Christmas which I touched on in previous posts recently.

These are big plans and I had trouble uploading them in a decent format for this blog.

The format isn’t great but I’ve finally put them up on on one of these pastebin things for now:

• Good Plan
• Bad Plan

As to how long they remain available, we’ll see.

These are probably of limited interest to anyone.

But they do illustrate a couple of things.

1. There are a lot of distractions in a big plan.

These are big plans at around 2800 lines.

You can see a lot of the deadly duo – MERGE JOIN CARTESIAN and BUFFER SORT operations- but these themselves are not the cause of the performance degradation (see point 2 about relative goodness).

It’s not until you get to lines six to seven hundred that you start to see any symptom of the performance difference.

The main performance problems stem from the full table scans of POSITIONS (e.g. See Id 717 in Bad Plan) and the HASH JOIN (Id 605) rather than the INDEX ACCESS (Id 719 in Good plan) and NESTED LOOP (605/6) operations, operations which are repeated throughout the rest of the plan

2. Good can be relative

I don’t think anyone would look at the “good” plan and be comfortable with it.

Then again could you could ever look at that sort of length of plan and think “Yes!” ?

The point is that the business were happy with the report performance that this plan provided and in the current business environment there’s rarely appetite to change things just because they’re not good technically.

3. It’s difficult to hint adequately

There are a handful of hints in the source code which are presumably intended to offer some sort of plan stability.

However, with a plan of this size, a couple of USE_NL hints are not going to be adequate.

As Jonathan Lewis points out, it’s very difficult to hint well/completely.

There are other ways to achieve plan stability if that’s what you want.

In this case, those handful of hints have probably contributed as much to plan instability as anything else.

4. Reusability is not always a good thing

These plans come from a reporting system which is doing too much calculation dynamically.

There is a core of Views on Views on Pipelined Table Functions on top of more Views which aims to provide a reusable interface to all the information being reported on and the various reports on top.

It’s not unusual to get performance problems from that sort of setup and probably one of the reasons that a handful of hints were used in the first place.

I would nearly always favour performance over reusability.

P.S. These plans also show the wrapping issue mentioned previously. At the time of writing, I still have an open Oracle SR for that. They had asked for full dumps of tables, statistics, etc. However I reproduced it with a standalone query joining dba_objects 50 times.

DBMS_XPLAN display issues

DBMS_XPLAN is a great little tool for getting formatted SQL execution plans and associated information. Good enough to make my revised top 3 yesterday.

Whether following an explain plan:

EXPLAIN PLAN FOR 
SELECT ... FORM ...;

SELECT * 
FROM TABLE(DBMS_XPLAN.DISPLAY);

Or pulling a plan from memory using:

SELECT * 
FROM TABLE(DBMS_XPLAN.DISPLAY_CURSOR(<sql_id>,<child_cursor>,<format>));

Typically used with the gather_plan_statistics hint like this:

SELECT /*+ gather_plan_statistics */ .... 
FROM ... 
WHERE...;

SELECT * 
FROM TABLE(DBMS_XPLAN.DISPLAY_CURSOR(NULL,NULL,'ALLSTATS LAST'));

Or pulling a plan still in memory by specifying the sql_id and, optionally, the child cursor.

For further information on the options for the third format parameter, here is a nice post on Rob van Wijk’s blog.

Jonathan Lewis also has some articles on dbms_xplan here and here.

Another handy option which I’ve been using recently is the ability to pull plans which are no longer in memory from the AWR repository using:

SELECT * 
FROM TABLE(DBMS_XPLAN.DISPLAY_AWR(<sql_id>,<child_cursor>,<db_id>,<format>));

Whilst troubleshooting a recent performance problem where a good (all things are relative) plan had gone bad, the bad plan was no longer in memory. However, I was able to pull the bad plan from the AWR repository and also a number of variations on the good plan.

However, this was a big plan – some 3000 lines – and illustrates some display issues which you can get.

See this excerpt:

| 316 | E JOIN CARTESIAN                                        MERG |                                |    790 |                                                                                                                                                                                             
| 317 | IST ITERATOR                                             INL |                                |        |                                                                                                                                                                                             
| 318 | BLE ACCESS BY INDEX ROWID                                 TA | CLASSIFICATIONS                |      5 |                                                                                                                                                                                             
| 319 | NDEX RANGE SCAN                                            I | CLASSIFICATIONS_IX1            |      5 |                                                                                                                                                                                             
| 320 | FER SORT                                                 BUF |                                |    158 |                                                                                                                                                                                             
| 321 | RT UNIQUE                                                 SO |                                |    158 |                                                                                                                                                                                             
| 322 | NDEX FAST FULL SCAN                                        I | PK_ELEMENT_AGGREGATES          |    158 |                                                                                                                                                                                             
| 323 | E ACCESS FULL                                           TABL | PERFORMANCE_ELEMENTS           |   1863 |                                                                                                                                                                                             
| 324 |  UNIQUE SCAN                                           INDEX | PK_CLASSIFICATION_ELEMENTS     |      1 |                                                                                                                                                                                             
| 325 |  SCAN                                            INDEX RANGE | VEHICLE_METRICS_PK             |      1 |                                                                                                                                                                                             
| 326 | S BY INDEX ROWID                                 TABLE ACCES | POSITIONS                      |      1 |                                                                                                                                                                                             
| 327 | E SCAN                                            INDEX RANG | POSITIONS_UK                   |      1 |                                                                                                                                                                                             
| 328 |  INDEX ROWID                                 TABLE ACCESS BY | PRR_MAPPINGS                   |      1 |                                                                                                                                                                                             
| 329 | AN                                            INDEX RANGE SC | PRR_MAPPINGS_UX1               |      1 | 

The OUTPUT column is wrapped and does not make such investigations and interpretations any easier.
Note that this is NOT a SQL*Plus display issue as far as I can work out. It’s not the whole line which is wrapping.

As far as I know, there is no solution to this.
I have an Oracle SR open for confirmation but after 4 days I’ve yet to even receive confirmation of my ticket…

If there’s a solution, let me know.