Analysing Statspack (4)

[Further Reading on Statspack]

One of the ways to use statspack is to extract trending information from the data. I published some sample SQL on my website a couple of years ago to show how this could be done – but there are alternatives.

One possibility is simply to run the spreport.sql script as soon as you’ve taken a snapshot, and then use grep (Unix) or find (Windows) to extract some of the data from a series of the output files. Imagine, for example, that I have a problem with excessive I/O and spiking CPU, I might consider checking what’s been going on with tablescans or scatttered reads. If I have accumulated an archive of statspack reports, I could get a trend report very easily with the command:

grep "table scan rows gotten" sp*.txt

                Statistic                      Total  per Second  per Trans
sp_17011430.txt:table scan rows gotten    67,522,182    75,024.7      166.0
sp_17011445.txt:table scan rows gotten    60,288,793    66,987.6      168.3
sp_17011500.txt:table scan rows gotten    68,181,066    75,672.7      154.8
sp_17011515.txt:table scan rows gotten    68,845,922    76,580.6      207.2
sp_17011530.txt:table scan rows gotten   132,836,448   147,432.2      422.4
sp_17011545.txt:table scan rows gotten   134,103,072   149,003.4      430.5
sp_17011600.txt:table scan rows gotten   454,254,201   504,726.9    1,381.8
sp_17011615.txt:table scan rows gotten   218,650,324   243,215.0      577.1
sp_17011630.txt:table scan rows gotten    76,841,570    85,379.5      208.6
sp_17011645.txt:table scan rows gotten    66,468,544    73,853.9      199.4

I’ve inserted the header line on this report just to remind you what the numbers mean – obviously the titles wouldn’t appear when you used that particular call to grep.

I’ve set up this system to report the filename as month/day/hour/minute, and you can see that the output comes fromo a set of 15 minute snapshots. With my file-naming convention, the grep command has automatically reported the results in the right order to be easily readable.

In this example, you can see that something nasty has happened for about an hour from about 3:15 pm to 4:15 pm, peaking around 4:00 pm. It seems that, on average, the volume of tablescan activity per transaction has escalated sharply. We can now ask ourselves if this is consistent with other parts of the statspack information, and investigate the full statspack report for 4:00 pm (particularly) to see if it will tell us where the extra work came from.

To automate the runs of spreport.sql and get suitable file names for the outputs, you could start with a script something like the following.

execute statspack.snap(5)

column	begin_snap	new_value	begin_snap
column	end_snap	new_value	end_snap
column	report_name	new_value	report_name

column	instance_number	new_value	instance_number
column	dbid		new_value	dbid

select dbid from v$database;
select instance_number from v$instance;

select	begin_snap, end_snap, 'sp_' || snap_time || '.txt' report_name
from	(
	 select
		lag(snap_id,1) over(order by snap_id)	begin_snap,
		snap_id					end_snap,
		lead(snap_id,1) over(order by snap_id)	next_snap,
		to_char(snap_time,'mmddhh24mi')		snap_time
	 from	stats$snapshot
	 where	dbid		= &dbid
	 and	instance_number	= &instance_number
	)
where
	next_snap is null
;

start ?/rdbms/admin/spreport

This script executes a snapshot, then finds the snapshot ids of the two most recent snapshots for the database and instance, builds a suitable report name based on the timestamp of the last snapshot, and calls spreport.sql.

Obviously you can’t run this script from dbms_job, so you’ll need another mechanism for automating it – and that could be the dbms_scheduler if you are running 10g.

[Further Reading on Statspack]

Footnote: Any advice about reading Statspack reports is almost always relevant when reading AWR reports (and vice versa).