Search

Top 60 Oracle Blogs

Recent comments

Profiling Execution Plans

In my previous blog post, I demonstrated how to identify the active lines in an adaptive execution plan on DBA_HIST_SQL_PLAN so that I could profile behaviour. This post demonstrates a practical application of that technique. This statement comes out of the PeopleSoft Financials Multi-currency Processing. A process extracts groups of rows in elimination sets into a working storage table and joins that table to the ledger table for further processing. The number of rows extracted from the elimination set selector table (PS_ELIM_CF_SEL2001 in this case) can vary in a single process from a few to a few thousand. However, the process does regather optimizer statistics each time.

#eeeeee; border: 0px solid #000000; font-family: courier new; font-size: 100%; overflow: auto; padding-left: 4px; padding-right: 4px; width: 95%;">SQL_ID fwcdxjy41j23n
--------------------
SELECT L.BUSINESS_UNIT,L.ACCOUNT,L.DEPTID,L.PRODUCT,L.BUDGET_REF,L.AFFIL
IATE,L.CHARTFIELD1,L.BOOK_CODE,L.GL_ADJUST_TYPE,L.DATE_CODE,SUM(L.POSTED
_TOTAL_AMT) FROM PS_ELIM_CF_SEL2001 S, PS_LEDGER L WHERE
S.ELIMINATION_SET='UK_OTHER' AND S.TREE_NODE_NUM=1234567890 AND
S.PROCESS_INSTANCE=0001234567 AND L.FISCAL_YEAR=2018 AND
L.LEDGER=S.LEDGER AND L.BUSINESS_UNIT=S.BUSINESS_UNIT AND
L.AFFILIATE=S.AFFILIATE AND L.ACCOUNT=S.ACCOUNT AND L.CURRENCY_CD='GBP'
AND L.STATISTICS_CODE=' ' AND (L.ACCOUNTING_PERIOD<=001 AND
((L.ACCOUNTING_PERIOD>=0 AND S.BALANCE_FWD_SW='Y') OR
L.ACCOUNTING_PERIOD>=1 AND S.BALANCE_FWD_SW='N')) GROUP BY
L.BUSINESS_UNIT,L.ACCOUNT,L.DEPTID,L.PRODUCT,L.BUDGET_REF,L.AFFILIATE,L.
CHARTFIELD1,L.BOOK_CODE,L.GL_ADJUST_TYPE,L.DATE_CODE

The changing literal values mean that every SQL statement has a different SQL_ID. SQL Baselines are not viable here. No one plan produces optimal performance, so a traditional SQL profile proscribing a particular plan is not the answer. Oracle moves between three adaptive plans depending at least partially upon the number of rows in the elimination table.

#eeeeee; border: 0px solid #000000; font-family: courier new; font-size: 90%; overflow: auto; padding-left: 4px; padding-right: 4px; width: 95%;">Plan hash value: 42743070
-----------------------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time | Pstart| Pstop |
-----------------------------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | | | 237K(100)| | | |
| 1 | SORT GROUP BY | | 13 | 1716 | 237K (1)| 00:00:10 | | |
|- 2 | HASH JOIN | | 13 | 1716 | 237K (1)| 00:00:10 | | |
| 3 | NESTED LOOPS | | 13 | 1716 | 237K (1)| 00:00:10 | | |
|- 4 | STATISTICS COLLECTOR | | | | | | | |
| 5 | TABLE ACCESS STORAGE FULL | PS_ELIM_CF_SEL2001 | 13 | 728 | 138 (2)| 00:00:01 | | |
| 6 | PARTITION RANGE OR | | 1 | 76 | 18249 (1)| 00:00:01 |KEY(OR)|KEY(OR)|
| 7 | PARTITION LIST ITERATOR | | 1 | 76 | 18249 (1)| 00:00:01 | KEY | KEY |
| 8 | TABLE ACCESS BY LOCAL INDEX ROWID| PS_LEDGER | 1 | 76 | 18249 (1)| 00:00:01 | KEY | KEY |
| 9 | INDEX RANGE SCAN | PSCLEDGER | 1 | | 18228 (1)| 00:00:01 | KEY | KEY |
|- 10 | PARTITION RANGE OR | | 1 | 76 | 18249 (1)| 00:00:01 |KEY(OR)|KEY(OR)|
|- 11 | PARTITION LIST JOIN-FILTER | | 1 | 76 | 18249 (1)| 00:00:01 |:BF0000|:BF0000|
|- 12 | TABLE ACCESS STORAGE FULL | PS_LEDGER | 1 | 76 | 18249 (1)| 00:00:01 | KEY | KEY |
-----------------------------------------------------------------------------------------------------------------------------

Plan hash value: 3968216348
-----------------------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time | Pstart| Pstop |
-----------------------------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | | | 1679K(100)| | | |
| 1 | SORT GROUP BY | | 92 | 12236 | 1679K (1)| 00:01:06 | | |
| 2 | HASH JOIN | | 92 | 12236 | 1679K (1)| 00:01:06 | | |
|- 3 | NESTED LOOPS | | 92 | 12236 | 1679K (1)| 00:01:06 | | |
|- 4 | STATISTICS COLLECTOR | | | | | | | |
| 5 | TABLE ACCESS STORAGE FULL | PS_ELIM_CF_SEL2001 | 92 | 5244 | 138 (2)| 00:00:01 | | |
|- 6 | PARTITION RANGE OR | | 1 | 76 | 18249 (1)| 00:00:01 |KEY(OR)|KEY(OR)|
|- 7 | PARTITION LIST ITERATOR | | 1 | 76 | 18249 (1)| 00:00:01 | KEY | KEY |
|- 8 | TABLE ACCESS BY LOCAL INDEX ROWID| PS_LEDGER | 1 | 76 | 18249 (1)| 00:00:01 | KEY | KEY |
|- 9 | INDEX RANGE SCAN | PSCLEDGER | 1 | | 18228 (1)| 00:00:01 | KEY | KEY |
| 10 | PARTITION RANGE OR | | 1 | 76 | 18249 (1)| 00:00:01 |KEY(OR)|KEY(OR)|
| 11 | PARTITION LIST JOIN-FILTER | | 1 | 76 | 18249 (1)| 00:00:01 |:BF0000|:BF0000|
| 12 | TABLE ACCESS STORAGE FULL | PS_LEDGER | 1 | 76 | 18249 (1)| 00:00:01 | KEY | KEY |
-----------------------------------------------------------------------------------------------------------------------------

Plan hash value: 386495123
------------------------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time | Pstart| Pstop |
------------------------------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | | | 1763K(100)| | | |
| 1 | SORT GROUP BY | | 1 | 132 | 1763K (2)| 00:01:09 | | |
| 2 | HASH JOIN | | 2105 | 271K| 1763K (2)| 00:01:09 | | |
| 3 | PART JOIN FILTER CREATE | :BF0000 | 2105 | 271K| 1763K (2)| 00:01:09 | | |
|- 4 | NESTED LOOPS | | 2105 | 271K| 1763K (2)| 00:01:09 | | |
|- 5 | STATISTICS COLLECTOR | | | | | | | |
| 6 | TABLE ACCESS STORAGE FULL | PS_ELIM_CF_SEL2001 | 2113 | 115K| 138 (2)| 00:00:01 | | |
|- 7 | PARTITION RANGE OR | | 1 | 76 | 1763K (2)| 00:01:09 |KEY(OR)|KEY(OR)|
|- 8 | PARTITION LIST ITERATOR | | 1 | 76 | 1763K (2)| 00:01:09 | KEY | KEY |
|- 9 | TABLE ACCESS BY LOCAL INDEX ROWID| PS_LEDGER | 1 | 76 | 1763K (2)| 00:01:09 | KEY | KEY |
|- 10 | INDEX RANGE SCAN | PSCLEDGER | | | | | KEY | KEY |
| 11 | PARTITION RANGE OR | | 24M| 1743M| 1763K (2)| 00:01:09 |KEY(OR)|KEY(OR)|
| 12 | PARTITION LIST JOIN-FILTER | | 24M| 1743M| 1763K (2)| 00:01:09 |:BF0000|:BF0000|
| 13 | TABLE ACCESS STORAGE FULL | PS_LEDGER | 24M| 1743M| 1763K (2)| 00:01:09 | KEY | KEY |
------------------------------------------------------------------------------------------------------------------------------

Only a small proportion of statements run by the process are captured during AWR snapshots. With PeopleSoft, because there is so much dynamically generated non-sharable SQL, I generally recommend reducing the snapshot interval to 15 minutes and collecting the top 100 statements (the default is hourly and the top 30 statements), and even so we only have a limited number of samples with the larger statements more likely to be sampled.
We are already using SQL Profiles to apply optimizer parameters to this statement so I can identify entries in DBA_HIST_SQLSTAT by the matched profile, though I could also use the FORCE_MATCHING_SIGNATURE. I will start by extracting the SQL statistics for all matching statements into a temporary working storage table, including the OTHER_XML from the SQL Plan

#eeeeee; border: 0px solid #000000; font-family: courier new; font-size: 100%; overflow: auto; padding-left: 4px; padding-right: 4px; width: 95%;">drop table my_stats purge;
create table my_stats as
with s as (
select s.dbid, s.sql_id, s.plan_hash_value, s.sql_profile, s.action
, max(s.optimizer_cost) optimizer_cost
, max(s.PX_SERVERS_EXECS_DELTA) px_servers
, sum(ELAPSED_TIME_DELTA)/1e6 elapsed_time
from dba_hist_snapshot x
, dba_hist_sqlstat s
WHERE s.SNAP_id = X.SNAP_id
AND s.dbid = x.dbid
AND s.instance_number = x.instance_number
AND s.module = 'GLPOCONS'
and s.sql_profile LIKE 'GLPOCONS_AD%B2%'
and s.plan_hash_value > 0
group by s.dbid, s.sql_id, s.plan_hash_value, s.sql_profile, s.action
)
SELECT s.*
, xmltype(other_xml) other_xml
FROM s, dba_hist_sql_plan p
WHERE p.dbid = s.dbid
and p.sql_id = s.sql_id
and p.plan_hash_value = s.plan_hash_value
and p.other_xml IS NOT NULL
and p.id = 1
/
select count(*) from my_stats
/

I found it was necessary to break this up into two stages.  Otherwise, I got ORA-32036: unsupported case for inlining of query name in WITH clause. This could be a manifestation of Bug 19684504 - ORA-32036 executing WITH statement with XML (Doc ID 19684504.8)

#eeeeee; border: 0px solid #000000; font-family: courier new; font-size: 100%; overflow: auto; padding-left: 4px; padding-right: 4px; width: 95%;">set pages 99 long 10
break on sql_profile skip 1
column sql_profile format a17
column op format 999
column dis format 999
column par format 999
column dep format 999
column skp format 999
column plan_hash_value format 9999999999 heading 'PHV'
column px_servers format 9999 heading 'PX|Serv'
column ecost format 9999 heading 'Elim|Cost'
column lcost format 99999999 heading 'Ledger|Cost'
column ecard format 99999 heading 'Elim|Card'
column lcard format 99999999 heading 'Ledger|Card'
column optimizer_cost format 99999999 heading 'Opt|Cost'
column elapsed_time format 9999.99 heading 'Elapsed|Time'
column object_name format a18
column elim_obj format a7 heading 'Bloom?'
column epoptions format a14 heading 'Join|Options'
column epoperation format a16 heading 'Join|Operation'
column eoptions format a14 heading 'Elim|Options'
column loptions format a20 heading 'Ledger|Options'
column options format a20
spool dmk
with y as (
select /*+MATERIALIZE*/ x.*
, xt.*
, p.object_type, p.object_name
, p.operation, p.options, p.cost, p.cardinality
from my_stats x
, xmltable('/other_xml/display_map/row' PASSING x.other_xml
COLUMNS "OP" NUMBER path '@op',
"DIS" NUMBER path '@dis',
"PAR" NUMBER path '@par',
"DEP" NUMBER path '@dep',
"SKP" NUMBER path '@skp'
) xt
, dba_hist_sql_plan p
where xt.skp = 0
and p.dbid = x.dbid
and p.sql_id = x.sql_id
and p.plan_hash_Value = x.plan_hash_value
and p.id = xt.op
)
select x.sql_profile, x.sql_id, x.plan_hash_value, x.px_servers
, e.object_name, e.options eoptions, e.cardinality ecard, e.cost ecost
, l.options loptions, l.cardinality lcard, l.cost lcost
, ep.operation epoperation, ep.object_name elim_obj
, x.optimizer_cost, x.elapsed_time
From my_stats x
, y e
, y l
, y ep
WHERE e.dbid = x.dbid
And e.sql_id = x.sql_id
And e.plan_hash_Value = x.plan_hash_value
And e.object_name like 'PS_ELIM_CF_SEL%'
And e.object_type = 'TABLE'
AND l.dbid = x.dbid
And l.sql_id = x.sql_id
And l.plan_hash_Value = x.plan_hash_value
And l.object_name = 'PS_LEDGER'
And l.object_type = 'TABLE'
And ep.dbid = x.dbid
And ep.sql_id = x.sql_id
And ep.plan_hash_Value = x.plan_hash_value
And ep.dis = e.par /*parent of display line*/
ORDER by x.sql_profile, e.cardinality, x.optimizer_cost, x.elapsed_time
/
spool off

The SQL query to profile the plan will be different for each set of plans that I want to investigate. The query showing in this blog was developed for the plan I am investigating here. I am interested in three aspects of the execution plan, the access method for each of the two tables, and the method by which they are joined. So, I have to join each SQL stats sub-query (X) back to the execution plan sub-query (Y) three times, selecting a different row from the plan each time.

  • E: table access of PS_ELIM_CF_SEL% table, either by a FULL scan or it might be by ROWID if an index was used.
  • L: table access of PS_LEDGER table. This will either be a FULL scan or by ROWID if an index was used.
  • EP: parent of table access of PS_ELIM_CF_SEL%. This will either be a HASH JOIN or the creation of the Bloom Filter (:BF000). If I order the result by the cardinality of the PS_ELIM_CF_SEL% I can see how and when the plan changes as the number of rows retrieved from it (the cardinality) change.
#eeeeee; border: 0px solid #000000; font-family: courier new; font-size: 60%; overflow: auto; padding-left: 4px; padding-right: 4px; width: 95%;">                                               PX                    Elim             Elim  Elim Ledger                  Ledger    Ledger Join                           Opt Elapsed
SQL_PROFILE SQL_ID PHV Serv OBJECT_NAME Options Card Cost Options Card Cost Operation Bloom? Cost Time
----------------- ------------- ----------- ----- ------------------ -------------- ------ ----- -------------------- --------- --------- ---------------- ------- --------- -------
GLPOCONS_ADPB2001 b7hy0jfppdvn2 42743070 0 PS_ELIM_CF_SEL2001 STORAGE FULL 13 138 BY LOCAL INDEX ROWID 1 18249 NESTED LOOPS 237379 .40

9yz896xyn5aky 42743070 0 PS_ELIM_CF_SEL2001 STORAGE FULL 51 138 BY LOCAL INDEX ROWID 1 18249 NESTED LOOPS 930851 2.62
cbnz1jumm0x23 42743070 0 PS_ELIM_CF_SEL2001 STORAGE FULL 52 138 BY LOCAL INDEX ROWID 1 18249 NESTED LOOPS 949101 .66

cmajgmuyc3hc3 42743070 0 PS_ELIM_CF_SEL2001 STORAGE FULL 92 138 BY LOCAL INDEX ROWID 1 18249 NESTED LOOPS 1679071 21.89
3sbkyfwy6xk02 3968216348 0 PS_ELIM_CF_SEL2001 STORAGE FULL 92 138 STORAGE FULL 1 18249 HASH JOIN 1679071 51.95
27pxj6qu49zzr 3968216348 0 PS_ELIM_CF_SEL2001 STORAGE FULL 92 138 STORAGE FULL 1 18249 HASH JOIN 1679071 52.49
8nfbzan3hbzdg 3968216348 0 PS_ELIM_CF_SEL2001 STORAGE FULL 92 138 STORAGE FULL 1 18249 HASH JOIN 1679071 67.49
827sykfucq01t 3968216348 0 PS_ELIM_CF_SEL2001 STORAGE FULL 93 138 STORAGE FULL 1 18249 HASH JOIN 1697321 87.65
fmd3r4848nypk 3968216348 0 PS_ELIM_CF_SEL2001 STORAGE FULL 93 138 STORAGE FULL 1 18249 HASH JOIN 1697321 89.39
34h7j9rqf8y73 2660510816 0 PS_ELIM_CF_SEL2001 STORAGE FULL 97 138 BY LOCAL INDEX ROWID 1 1763685 NESTED LOOPS 1763970 1.54
0cfqyuz79qd09 386495123 0 PS_ELIM_CF_SEL2001 STORAGE FULL 98 138 STORAGE FULL 24054654 1763685 PART JOIN FILTER :BF0000 1763970 21.32
ff5hf8zpwhmd2 386495123 0 PS_ELIM_CF_SEL2001 STORAGE FULL 98 138 STORAGE FULL 24054654 1763685 PART JOIN FILTER :BF0000 1763970 26.64
9j0m5gq5aqssz 386495123 0 PS_ELIM_CF_SEL2001 STORAGE FULL 99 138 STORAGE FULL 24054654 1763685 PART JOIN FILTER :BF0000 1763970 34.28
bzbqrc7bw768q 42743070 0 PS_ELIM_CF_SEL2001 STORAGE FULL 102 138 BY LOCAL INDEX ROWID 1 18249 NESTED LOOPS 1861564 .76
bjjx0fxmtqzzt 42743070 0 PS_ELIM_CF_SEL2001 STORAGE FULL 102 138 BY LOCAL INDEX ROWID 1 18249 NESTED LOOPS 1861564 3.66
aqcxt7par2a22 2660510816 0 PS_ELIM_CF_SEL2001 STORAGE FULL 104 138 BY LOCAL INDEX ROWID 1 1763685 NESTED LOOPS 1763970 9.57
4cfsq52xzftpz 386495123 0 PS_ELIM_CF_SEL2001 STORAGE FULL 104 138 STORAGE FULL 24054654 1763685 PART JOIN FILTER :BF0000 1763970 25.39
76hq9zbfrm599 386495123 0 PS_ELIM_CF_SEL2001 STORAGE FULL 104 138 STORAGE FULL 24054654 1763685 PART JOIN FILTER :BF0000 1763970 26.11
2b8ck8kpyrvhg 386495123 0 PS_ELIM_CF_SEL2001 STORAGE FULL 104 138 STORAGE FULL 24054654 1763685 PART JOIN FILTER :BF0000 1763970 35.71
6gtu9tauhp55y 386495123 0 PS_ELIM_CF_SEL2001 STORAGE FULL 104 138 STORAGE FULL 24054654 1763685 PART JOIN FILTER :BF0000 1763970 39.77

88kyxqx2qbjxg 386495123 0 PS_ELIM_CF_SEL2001 STORAGE FULL 1021 138 STORAGE FULL 24054654 1763685 PART JOIN FILTER :BF0000 1763970 21.73

dh39mtw8rga5s 386495123 0 PS_ELIM_CF_SEL2001 STORAGE FULL 2113 138 STORAGE FULL 24054654 1763685 PART JOIN FILTER :BF0000 1763970 40.26

I can see that the optimizer goes backwards and forwards between different plans at different times as the cardinality increases. Nevertheless, I can make some informed decisions about how to adjust the optimizer parameters for this statement with hints introduced by a SQL Profile.

  • I can change the point where the optimizer switches from to the full scan and bloom filter to a lower cardinality by increasing the cost of the index with a higher value optimizer_index_cost_adj.
  • I can enable automatic parallelism with parallel_degree_policy, scale the calculated degree of parallelism with parallel_degree_level, but limit the degree of parallelism with parallel_degree_limit. The threshold for parallelism can be set with parallel_min_time_threshold. The parallelism threshold can be set at a slightly lower cardinality than the switch to the full scan.
  • The settings can be tested using EXPLAIN PLAN FOR with the cardinality hint to set the number of rows returned from the PS_ELIM_CF_SEL% table
#eeeeee; border: 0px solid #000000; font-family: courier new; font-size: 100%; overflow: auto; padding-left: 4px; padding-right: 4px; width: 95%;">explain plan for
SELECT /*+cardinality(s 300)
NO_EXPAND
OPT_PARAM('parallel_degree_policy','AUTO')
OPT_PARAM('parallel_min_time_threshold',220)
OPT_PARAM('parallel_degree_limit',40)
OPT_PARAM('optimizer_index_cost_adj',10912)
*/
L.BUSINESS_UNIT,L.ACCOUNT,L.DEPTID,L.PRODUCT,L.BUDGET_REF

/
set echo off trimspool on pages 999 lines 200 autotrace off
select * from table(dbms_xplan.display(null,null,'ADVANCED +ADAPTIVE -PROJECTION -PREDICATE -OUTLINE'));

When satisfactory values have been determined, they can be passed back into the SQL Profile.

#eeeeee; border: 0px solid #000000; font-family: courier new; font-size: 100%; overflow: auto; padding-left: 4px; padding-right: 4px; width: 95%;">
h := SYS.SQLPROF_ATTR(
q'[BEGIN_OUTLINE_DATA]',
q'[OPT_PARAM('parallel_degree_policy','AUTO')]',
q'[OPT_PARAM('parallel_min_time_threshold',60)]',
q'[OPT_PARAM('parallel_degree_limit',40)]',
q'[OPT_PARAM('optimizer_index_cost_adj',10912)]',
q'[NO_EXPAND]',

q'[END_OUTLINE_DATA]');

DBMS_SQLTUNE.IMPORT_SQL_PROFILE (
sql_text => sql_txt,
profile => h,
name => 'GLPOCONS_'||i.id,

replace => TRUE,
force_match => TRUE /* TRUE:FORCE (match even when different literals in SQL). FALSE:EXACT (similar to CURSOR_SHARING) */
);