Posts Tagged ‘Plan Hash Value’
Finding SQL with Performance changing over time
I upgraded my database a couple of weeks ago and now my users complain their application is slower. They do not provide specifics but they “feel” it is running slower. Sounds familiar?
Every once in a while I get a request that goes like this: “how can I find if some SQL on my database is performing worse over time?”
It is very hard to deal with the ambiguities of some problems like “finding SQL that performs worse or better over time”. But if you simplify the problem and consider for example “Elapsed Time per Execution”, then you can easily produce a script like the one below, which returns a small list of SQL statements that seem to experience either a regression or an improvement over time. It uses linear regression on the ratio between “Elapsed Time per Execution” and its Median per SQL.
Then, If you are suspecting you have some SQL that may have regressed and need a hand to identify them, you can try this script below. It is now part of a small collection of scripts that you can download and use for free out of the cscripts link on the right hand side of this page, under “Downloads”.
----------------------------------------------------------------------------------------
--
-- File name: sql_performance_changed.sql
--
-- Purpose: Lists SQL Statements with Elapsed Time per Execution changing over time
--
-- Author: Carlos Sierra
--
-- Version: 2014/10/31
--
-- Usage: Lists statements that have changed their elapsed time per execution over
-- some history.
-- Uses the ration between "elapsed time per execution" and the median of
-- this metric for SQL statements within the sampled history, and using
-- linear regression identifies those that have changed the most. In other
-- words where the slope of the linear regression is larger. Positive slopes
-- are considered "improving" while negative are "regressing".
--
-- Example: @sql_performance_changed.sql
--
-- Notes: Developed and tested on 11.2.0.3.
--
-- Requires an Oracle Diagnostics Pack License since AWR data is accessed.
--
-- To further investigate poorly performing SQL use sqltxplain.sql or sqlhc
-- (or planx.sql or sqlmon.sql or sqlash.sql).
--
---------------------------------------------------------------------------------------
--
SPO sql_performance_changed.txt;
DEF days_of_history_accessed = '31';
DEF captured_at_least_x_times = '10';
DEF captured_at_least_x_days_apart = '5';
DEF med_elap_microsecs_threshold = '1e4';
DEF min_slope_threshold = '0.1';
DEF max_num_rows = '20';
SET lin 200 ver OFF;
COL row_n FOR A2 HEA '#';
COL med_secs_per_exec HEA 'Median Secs|Per Exec';
COL std_secs_per_exec HEA 'Std Dev Secs|Per Exec';
COL avg_secs_per_exec HEA 'Avg Secs|Per Exec';
COL min_secs_per_exec HEA 'Min Secs|Per Exec';
COL max_secs_per_exec HEA 'Max Secs|Per Exec';
COL plans FOR 9999;
COL sql_text_80 FOR A80;
PRO SQL Statements with "Elapsed Time per Execution" changing over time
WITH
per_time AS (
SELECT h.dbid,
h.sql_id,
SYSDATE - CAST(s.end_interval_time AS DATE) days_ago,
SUM(h.elapsed_time_total) / SUM(h.executions_total) time_per_exec
FROM dba_hist_sqlstat h,
dba_hist_snapshot s
WHERE h.executions_total > 0
AND s.snap_id = h.snap_id
AND s.dbid = h.dbid
AND s.instance_number = h.instance_number
AND CAST(s.end_interval_time AS DATE) > SYSDATE - &&days_of_history_accessed.
GROUP BY
h.dbid,
h.sql_id,
SYSDATE - CAST(s.end_interval_time AS DATE)
),
avg_time AS (
SELECT dbid,
sql_id,
MEDIAN(time_per_exec) med_time_per_exec,
STDDEV(time_per_exec) std_time_per_exec,
AVG(time_per_exec) avg_time_per_exec,
MIN(time_per_exec) min_time_per_exec,
MAX(time_per_exec) max_time_per_exec
FROM per_time
GROUP BY
dbid,
sql_id
HAVING COUNT(*) >= &&captured_at_least_x_times.
AND MAX(days_ago) - MIN(days_ago) >= &&captured_at_least_x_days_apart.
AND MEDIAN(time_per_exec) > &&med_elap_microsecs_threshold.
),
time_over_median AS (
SELECT h.dbid,
h.sql_id,
h.days_ago,
(h.time_per_exec / a.med_time_per_exec) time_per_exec_over_med,
a.med_time_per_exec,
a.std_time_per_exec,
a.avg_time_per_exec,
a.min_time_per_exec,
a.max_time_per_exec
FROM per_time h, avg_time a
WHERE a.sql_id = h.sql_id
),
ranked AS (
SELECT RANK () OVER (ORDER BY ABS(REGR_SLOPE(t.time_per_exec_over_med, t.days_ago)) DESC) rank_num,
t.dbid,
t.sql_id,
CASE WHEN REGR_SLOPE(t.time_per_exec_over_med, t.days_ago) > 0 THEN 'IMPROVING' ELSE 'REGRESSING' END change,
ROUND(REGR_SLOPE(t.time_per_exec_over_med, t.days_ago), 3) slope,
ROUND(AVG(t.med_time_per_exec)/1e6, 3) med_secs_per_exec,
ROUND(AVG(t.std_time_per_exec)/1e6, 3) std_secs_per_exec,
ROUND(AVG(t.avg_time_per_exec)/1e6, 3) avg_secs_per_exec,
ROUND(MIN(t.min_time_per_exec)/1e6, 3) min_secs_per_exec,
ROUND(MAX(t.max_time_per_exec)/1e6, 3) max_secs_per_exec
FROM time_over_median t
GROUP BY
t.dbid,
t.sql_id
HAVING ABS(REGR_SLOPE(t.time_per_exec_over_med, t.days_ago)) > &&min_slope_threshold.
)
SELECT LPAD(ROWNUM, 2) row_n,
r.sql_id,
r.change,
TO_CHAR(r.slope, '990.000MI') slope,
TO_CHAR(r.med_secs_per_exec, '999,990.000') med_secs_per_exec,
TO_CHAR(r.std_secs_per_exec, '999,990.000') std_secs_per_exec,
TO_CHAR(r.avg_secs_per_exec, '999,990.000') avg_secs_per_exec,
TO_CHAR(r.min_secs_per_exec, '999,990.000') min_secs_per_exec,
TO_CHAR(r.max_secs_per_exec, '999,990.000') max_secs_per_exec,
(SELECT COUNT(DISTINCT p.plan_hash_value) FROM dba_hist_sql_plan p WHERE p.dbid = r.dbid AND p.sql_id = r.sql_id) plans,
REPLACE((SELECT DBMS_LOB.SUBSTR(s.sql_text, 80) FROM dba_hist_sqltext s WHERE s.dbid = r.dbid AND s.sql_id = r.sql_id), CHR(10)) sql_text_80
FROM ranked r
WHERE r.rank_num <= &&max_num_rows.
ORDER BY
r.rank_num
/
SPO OFF;
Once you get the output of this script above, you can use the one below to actually list the time series for one of the SQL statements of interest:
----------------------------------------------------------------------------------------
--
-- File name: one_sql_time_series.sql
--
-- Purpose: Performance History for one SQL
--
-- Author: Carlos Sierra
--
-- Version: 2014/10/31
--
-- Usage: Script sql_performance_changed.sql lists SQL Statements with performance
-- improvement or regressed over some History.
-- This script one_sql_time_series.sql lists the Performance Time Series for
-- one SQL.
--
-- Parameters: SQL_ID
--
-- Example: @one_sql_time_series.sql
--
-- Notes: Developed and tested on 11.2.0.3.
--
-- Requires an Oracle Diagnostics Pack License since AWR data is accessed.
--
-- To further investigate poorly performing SQL use sqltxplain.sql or sqlhc
-- (or planx.sql or sqlmon.sql or sqlash.sql).
--
---------------------------------------------------------------------------------------
--
SPO one_sql_time_series.txt;
SET lin 200 ver OFF;
COL instance_number FOR 9999 HEA 'Inst';
COL end_time HEA 'End Time';
COL plan_hash_value HEA 'Plan|Hash Value';
COL executions_total FOR 999,999 HEA 'Execs|Total';
COL rows_per_exec HEA 'Rows Per Exec';
COL et_secs_per_exec HEA 'Elap Secs|Per Exec';
COL cpu_secs_per_exec HEA 'CPU Secs|Per Exec';
COL io_secs_per_exec HEA 'IO Secs|Per Exec';
COL cl_secs_per_exec HEA 'Clus Secs|Per Exec';
COL ap_secs_per_exec HEA 'App Secs|Per Exec';
COL cc_secs_per_exec HEA 'Conc Secs|Per Exec';
COL pl_secs_per_exec HEA 'PLSQL Secs|Per Exec';
COL ja_secs_per_exec HEA 'Java Secs|Per Exec';
SELECT h.instance_number,
TO_CHAR(CAST(s.end_interval_time AS DATE), 'YYYY-MM-DD HH24:MI') end_time,
h.plan_hash_value,
h.executions_total,
TO_CHAR(ROUND(h.rows_processed_total / h.executions_total), '999,999,999,999') rows_per_exec,
TO_CHAR(ROUND(h.elapsed_time_total / h.executions_total / 1e6, 3), '999,990.000') et_secs_per_exec,
TO_CHAR(ROUND(h.cpu_time_total / h.executions_total / 1e6, 3), '999,990.000') cpu_secs_per_exec,
TO_CHAR(ROUND(h.iowait_total / h.executions_total / 1e6, 3), '999,990.000') io_secs_per_exec,
TO_CHAR(ROUND(h.clwait_total / h.executions_total / 1e6, 3), '999,990.000') cl_secs_per_exec,
TO_CHAR(ROUND(h.apwait_total / h.executions_total / 1e6, 3), '999,990.000') ap_secs_per_exec,
TO_CHAR(ROUND(h.ccwait_total / h.executions_total / 1e6, 3), '999,990.000') cc_secs_per_exec,
TO_CHAR(ROUND(h.plsexec_time_total / h.executions_total / 1e6, 3), '999,990.000') pl_secs_per_exec,
TO_CHAR(ROUND(h.javexec_time_total / h.executions_total / 1e6, 3), '999,990.000') ja_secs_per_exec
FROM dba_hist_sqlstat h,
dba_hist_snapshot s
WHERE h.sql_id = '&sql_id.'
AND h.executions_total > 0
AND s.snap_id = h.snap_id
AND s.dbid = h.dbid
AND s.instance_number = h.instance_number
ORDER BY
h.sql_id,
h.instance_number,
s.end_interval_time,
h.plan_hash_value
/
SPO OFF;
Has my Plan changed or not?
We have learned from Kerry Osborne’s recent post on SQL Gone Bad – But Plan Not Changed?, and a prior post from Randolf Geist on PLAN_HASH_VALUE – How equal (and stable?) are your execution plans – part 1, that having the same Plan Hash Value (PHV) it is not guarantee that we actually have the same Execution Plan if you were to consider Access and Filter Predicates for Plan Operations. So, what does it mean? It means that if you have inconsistent performance out of the same Execution Plan (same PHV) it is not enough to just check if you have or not the same PHV. You need to be aware of the Predicates as well. Of course there are other possible explanations for having inconsistent performance out of the same PHV, like skewed data combined with the use of binds, but that is another story.
Same Plan but different PHV
The opposite to “Same PHV but different Plan” is also possible. So, after we understood we can have the same PHV but not quite the same Plan if we include in the compare the Predicates, the question became: Can we also have cases having the same Plan (including Predicates) but get a different PHV? And the answer is YES.
Discard the keyword STORAGE, which we can consider not strong enough to determine a Plan Operation is different. Of course this is questionable, but as of today the PHV is blind to the STORAGE keyword, so a Plan with or without this keyword would render the same PHV.
What about system-generated names like ‘SYS_TEMP%’, ‘index$_join$_%’ and ‘VW_ST%’? In all these 3 cases the PHV will be different but the Plan is actually the same, with the exception of the system-generated names. So, if you just look at the PHV and see that is different then it is also possible that actually you have the same Plan.
What if in the case of having the same index name, the set of columns or their order is different? In these cases you may look at the PHV and see the same value, and indeed it is the same Plan, but if the columns on a referenced index have changed, is it really the same Plan? In my opinion it is not! You could be spinning on an issue where you have same Plan, different Performance, but an Index changed its columns.
SQLT to the rescue
Since we have the two cases: “Same PHV but different Plan” and “Same Plan but different PHV”, reviewing and ruling out these two possible cases on a complex Execution Plan can be cumbersome and time consuming. That is WHY SQLT incorporated the concept of SQLT Plan Hash Value (SQLT_PHV) since version 11.4.0.5 (from May 20, 2010). First came SQLT_PHV1, then SQLT_PHV2 (on SQLT 11.4.2.4 on February 18, 2011). So we have now PHV, SQLT_PHV1 and SQLT_PHV2, as you can see below.
As you can see in Table foot note: SQLT_PHV1 considers id, parent_id, operation, options, index_columns and object_name. SQLT PHV2 includes also access and filter predicates. So when comparing Plans the values of PHV, SQLT_PHV1 and SQLT_PHV2 can give you a better idea if your Plan is actually the same or not. SQLT COMPARE also uses the 3 values to determine if your Plan is the same or not, and in cases like the PHV is the same but a Predicate on a Plan Operation is different, it highlights in red the specific Plan Operation that has a different Predicate. Pretty cool right? I guess I will have to blog about SQLT COMPARE some time soon then…
Oh, be also aware that AWR does not store Plan Predicates, so if your Plan only exists on AWR you may be blind to these Predicates, but if the EXPLAIN PLAN FOR renders the same Plan as seen in lines 4 and 5 above, then you can see the predicates for 657302870 out the “XPL” Plan instead of “AWR”. A little trick that becomes handy…
Conclusion
When it comes to Execution Plans and their Plan Hash Value, it is possible that two Plans with same PHV are actually different if you consider the Predicates, and also possible you get a different PHV even if the Plan is the same if your Plan has system-generated names. So, during your analysis just looking at the PHV to determine if two Plans are the same or not is not enough. If you are already using SQLT, pay attention to the “Execution Plans” section, and to the SQLT PHV1 and PHV2 columns.
Carlos Sierra's Tools and Tips 