Querying the Top 5 Timed Events

Querying the Top 5 Timed Events

In a previous life, I spent the better part of two years digesting other people's AWR reports.  Text, HTML, Statspack etc., all in an effort to show how slow their storage was an how much better their databases would perform on our all-flash storage array.

One of the frustrations of this job was that every problem generally only had one solution (a flash storage array, if you hadn't guessed) and along the way I encountered some pretty horribly tuned databases but of course could do nothing about that.

I did get to work with some excellent and talented people though, including the English duo of Chris Buckel and Ash Ubhi who have produced some sterling work in the field of AWR analysis - and parsing AWR reports and transforming them into lovely Excel charts...  All very useful sales stuff and actually quite essential for in-house DBA's for reporting purposes.  Most management like a pretty chart.

Writing my own AWR scripts to circumvent having to run a thousand reports led me down various rat holes - I was really looking for the top 5 timed events in query form.... and then I stumbled across the blog of my fellow Enkitecian, Alex Fatkulin.  In his blog entry (that's where the link goes), he provides a script to do just what I wanted.   Here's Alex's original script.

	select case wait_rank when 1 then inst_id end "Inst Num",
	case wait_rank when 1 then snap_id end "Snap Id",
	case wait_rank when 1 then begin_snap end "Begin Snap",
	case wait_rank when 1 then end_snap end "End Snap",
	event_name "Event",
	total_waits "Waits",
	time_waited "Time(s)",
	round((time_waited/total_waits)*1000) "Avg wait(ms)",
	round((time_waited/db_time)*100, 2) "% DB time",
	substr(wait_class, 1, 15) "Wait Class"
	from (
	select
	inst_id,
	snap_id, to_char(begin_snap, 'DD-MM-YY hh24:mi:ss') begin_snap,
	to_char(end_snap, 'hh24:mi:ss') end_snap,
	event_name,
	wait_class,
	total_waits,
	time_waited,
	dense_rank() over (partition by inst_id, snap_id order by time_waited desc)-1 wait_rank,
	max(time_waited) over (partition by inst_id, snap_id) db_time
	from (
	select
	s.instance_number inst_id,
	s.snap_id,
	s.begin_interval_time begin_snap,
	s.end_interval_time end_snap,
	event_name,
	wait_class,
	total_waits-lag(total_waits, 1, total_waits) over
	(partition by s.startup_time, s.instance_number, stats.event_name order by s.snap_id) total_waits,
	time_waited-lag(time_waited, 1, time_waited) over
	(partition by s.startup_time, s.instance_number, stats.event_name order by s.snap_id) time_waited,
	min(s.snap_id) over (partition by s.startup_time, s.instance_number, stats.event_name) min_snap_id
	from (
	select dbid, instance_number, snap_id, event_name, wait_class, total_waits_fg total_waits, round(time_waited_micro_fg/1000000, 2) time_waited
	from dba_hist_system_event
	where wait_class not in ('Idle', 'System I/O')
	union all
	select dbid, instance_number, snap_id, stat_name event_name, null wait_class, null total_waits, round(value/1000000, 2) time_waited
	from dba_hist_sys_time_model
	where stat_name in ('DB CPU', 'DB time')
	) stats, dba_hist_snapshot s
	where stats.instance_number=s.instance_number
	and stats.snap_id=s.snap_id
	and stats.dbid=s.dbid
	and s.dbid=3552404819
	and s.instance_number=2
	and stats.snap_id between 17720 and 17729
	) where snap_id > min_snap_id and nvl(total_waits,1) > 0
	) where event_name!='DB time' and wait_rank <= 5
	order by inst_id, snap_id;

view raw gistfile1.sql hosted with ❤ by GitHub

As you can see, it will give a nicely formatted output....

Top 5 Wait Events

Great for various purposes so utilizing the work Alex already did, I modified it slightly to give me statistics that I could turn into useful presentation materials.  Here's a snippet of the data I extracted:

More Top 5 Wait Events

In general, I only care about a few events - I/O or contention related for my purposes on this client engagement.  

Graphical wait event data

Not rocket science but it makes my life easier.  My code modifications to the original are minimal.

	select inst_id "Inst Num",
	snap_id "Snap Id",
	begin_snap "Begin Snap",
	end_snap "End Snap",
	sum(case when event_name='DB CPU' then time_waited end) "DB CPU",
	sum(case when event_name='db file sequential read' then time_waited end) "db file sequential read",
	sum(case when event_name='direct path read' then time_waited end) "direct path read",
	sum(case when event_name='direct path write' then time_waited end) "direct path write",
	sum(case when event_name='direct path read temp' then time_waited end) "direct path read temp",
	sum(case when event_name='enq: TX - index contention' then time_waited end) "enq: TX - index contention",
	sum(case when event_name='gc buffer busy acquire' then time_waited end) "gc buffer busy acquire",
	sum(case when event_name='gc buffer busy release' then time_waited end) "gc buffer busy release",
	sum(case when event_name='db file scattered read' then time_waited end) "db file scattered read",
	sum(case when event_name='log gile sync' then time_waited end) "log file sync"
	-- event_name "Event",
	-- total_waits "Waits",
	-- time_waited "Time(s)",
	-- round((time_waited/total_waits)*1000) "Avg wait(ms)",
	-- round((time_waited/db_time)*100, 2) "% DB time",
	-- substr(wait_class, 1, 15) "Wait Class"
	from (
	select
	inst_id,
	snap_id, to_char(begin_snap, 'DD-MM-YY hh24:mi:ss') begin_snap,
	to_char(end_snap, 'hh24:mi:ss') end_snap,
	event_name,
	wait_class,
	total_waits,
	time_waited,
	dense_rank() over (partition by inst_id, snap_id order by time_waited desc)-1 wait_rank,
	max(time_waited) over (partition by inst_id, snap_id) db_time
	from (
	select
	s.instance_number inst_id,
	s.snap_id,
	s.begin_interval_time begin_snap,
	s.end_interval_time end_snap,
	event_name,
	wait_class,
	total_waits-lag(total_waits, 1, total_waits) over
	(partition by s.startup_time, s.instance_number, stats.event_name order by s.snap_id) total_waits,
	time_waited-lag(time_waited, 1, time_waited) over
	(partition by s.startup_time, s.instance_number, stats.event_name order by s.snap_id) time_waited,
	min(s.snap_id) over (partition by s.startup_time, s.instance_number, stats.event_name) min_snap_id
	from (
	select dbid, instance_number, snap_id, event_name, wait_class, total_waits_fg total_waits, round(time_waited_micro_fg/1000000, 2) time_waited
	from dba_hist_system_event
	where wait_class not in ('Idle', 'System I/O')
	union all
	select dbid, instance_number, snap_id, stat_name event_name, null wait_class, null total_waits, round(value/1000000, 2) time_waited
	from dba_hist_sys_time_model
	where stat_name in ('DB CPU', 'DB time')
	) stats, dba_hist_snapshot s
	where stats.instance_number=s.instance_number
	and stats.snap_id=s.snap_id
	and stats.dbid=s.dbid
	and s.dbid=3552404819
	and s.instance_number=2
	and stats.snap_id between 17720 and 17790
	) where snap_id > min_snap_id and nvl(total_waits,1) > 0
	) where event_name!='DB time' and wait_rank <= 5
	group by inst_id, snap_id, begin_snap, end_snap
	order by inst_id, snap_id

view raw gistfile1.txt hosted with ❤ by GitHub

Have fun with your own AWR analysis.