SQL execution times from ASH
- http://dboptimizer.com/2011/05/04/sql-execution-times-from-ash/
- http://dboptimizer.com/2011/05/06/sql-timings-for-ash-ii/
- http://dboptimizer.com/2011/05/06/sql-ash-timings-iii/
Update: Check out Tanel Poder’s blog entry on SQL_EXEC_ID for more details, especially for the RAC world: Tanel Poder’s blog on SQL_EXEC_ID
Something I’ve been looking forward to exploiting for a while is the SQL_EXEC_ID field in ASH. Thanks to Karl Arao for pushing me to look into this. Karl sent me an example query he had written using SQL_EXEC_ID and then we started discussing how to harness SQL_EXEC_ID. (see Karl’s blog here http://karlarao.wordpress.com/ and some good examples of SQL_EXEC_ID here http://karlarao.tiddlyspot.com/#Elapsed-AvgMinMax)
One of the several cool things about ASH in Oracle 11g is there is now a SQL_EXEC_ID column. What good is the SQL_EXEC_ID column? Well without it , like in Oracle 10g there was no way to look at ASH data and distinguish between a SQL statement that had been re-executed multiple times in a row and showed up in consecutive ASH samples and a SQL statement that was running for a long time and showing up in consecutive ASH samples. Now in 11g with SQL_EXEC_ID we can now make the distinction. (the distinction can actually be done since Oracle version 7 with SASH – simulated ASH). Now with SQL_EXEC_ID not only can we distinguish long running queries from re-executed queries we can start looking at average execution times and maximum execution times and start seeing variation. These timings though are only accurate for longer running queries as fast running queries running faster than 1 second will only appear once per execute in ASH thus no deltas can be calculated.
Here is an example SQL execution timing data mining query (ashsqlt.sql):
col mx for 999999
col mn for 999999
col av for 999999.9
select
sql_id,
count(*),
max(tm) mx,
avg(tm) av,
min(tm) min
from (
select
sql_id,
sql_exec_id,
max(tm) tm
from ( select
sql_id,
sql_exec_id,
((cast(sample_time as date)) -
(cast(sql_exec_start as date))) * (3600*24) tm
from
dba_hist_active_sess_history
where sql_exec_id is not null
)
group by sql_id,sql_exec_id
)
group by sql_id
having count(*) > 10
order by mx,av
/
|
and the output looks like
SQL_ID COUNT(*) MX AV MIN ------------- ---------- ------- --------- ---------- 2h83mk46003q4 18 1 .2 0 77m98gu3uzb59 15 1 .2 0 6dnvpqs0zdxhv 30 1 .3 0 40r79s5rxabwr 18 1 .3 0 26ugyh75gmnt4 35 1 .3 0 1sjkhrtg3qa48 14 1 .3 0 4h6kn70hsgz9u 20 1 .3 0 b6s2h63d07t91 13 1 .3 0 a18wua1f703xh 29 1 .3 0 6az55y9y8u86c 12 1 .3 0 7ujfmgb1j83a3 21 1 .3 0 |
above is the beginning and times below is the end of output
SQL_ID COUNT(*) MX AV MIN ------------- ---------- ------- --------- ---------- 0fvrpk7476b7y 26 3068 133.1 0 1pjp66rxcj6tg 15 3106 767.7 57 8r5wuxk1dprhr 39 3510 841.0 24 0w5uu5kngyyty 21 3652 442.3 0 0hbv80w9ypy0n 161 4089 1183.9 0 71fwb4n6a92fv 49 4481 676.9 30 0bujgc94rg3fj 604 4929 24.7 0 64dqhdkkw63fd 1083 7147 7.2 0 990m08w8xav7s 591 7681 51.8 0 2n5369dsuvn5a 16 10472 5726.8 303 2spgk3k0f7quz 251 29607 546.1 0 36pd759xym9tc 12 37934 23861.9 1391 497wh6n7hu14f 49 69438 5498.2 0 |
Oracle L
Trackbacks
Comments
Modified the above query after talking with Karl Arao who pointed out that there was no need to self join dba_active_sess_history, so above it’s all done in one query.
If you use SASH you can do similar queries using fixed_table_sequence:
This shows the top twolongest running queries every 15 minute period. The higher the count the longer
they have been running (you can’t do this with 10g ASH)
break on start_time clear breaks column f_secs new_value v_secs column f_mins new_value v_mins select 900 f_secs from dual; select &v_secs/60 f_mins from dual; select * from ( select to_char(trunc(sample_time,'HH')+ (trunc((sample_time-trunc(sample_time,'HH'))*24/(&v_mins/60))+1)/(60/&v_mins)/24 ,'MON-DD HH:MI') start_time, count(*), sql_id, fixed_table_sequence, rank() over ( partition by trunc(sample_time,'HH')+ (trunc((sample_time-trunc(sample_time,'HH'))*24/(&v_mins/60))+1)/(60/&v_mins)/24 order by count(*) desc ) topn from sash where sql_id > 0 and sql_id is not null and sample_time > sysdate - (30)/(24*60) group by sql_id, fixed_table_sequence, trunc(sample_time,'HH')+ (trunc((sample_time-trunc(sample_time,'HH'))*24/(&v_mins/60))+1)/(60/&v_mins)/24 ) where topn < 3 / clear breaksHi Kyle,
Script is very useful and sql_exec_id is very wise to use.
One thing to bear in mind, I don’t know if it is a bug on our 11.2.0.1 DB but I can see a sql which runs 2 seconds has got sql_exec_start_date back in 15 days ago which can cause misleading conclusions with the sql you shared.
@coskan gundogar
Hi Coskan,
Do you have any example output? Or better yet an export of the AWR that I could import and run queries on?
THanks
Kyle
@Kyle Hailey
SOmething like this should work with SASH for queries over 5 minutes:
select * from ( select count(*), sql_id, fixed_table_sequence from sash where sql_id > 0 and sql_id is not null group by sql_id, fixed_table_sequence, having count(*) > 300 /Hi Kyle,
Do MX AV MIN mean in seconds?
THanks
lmwang
MX AV and MIN are the maximum, average and minimum execution times for the SQL statements in seconds, but seconds based on ASH sampling, so it’s not exact but statistically sufficient for queries that take more than a second.