Script to show change in query execution

Click here for a simple but useful script that shows how the execution of a given query has changed over time.

This script just queries DBA_HIST_SQLSTAT for a given sql_id. A sql_id corresponds to a single SQL query.  I’ve changed the units to milliseconds because I think in terms of disk reads which take a few milliseconds each.

Here is the text of the query:

select ss.sql_id,
sn.END_INTERVAL_TIME,
ss.executions_delta,
ELAPSED_TIME_DELTA/(executions_delta*1000) "Elapsed Average ms",
CPU_TIME_DELTA/(executions_delta*1000) "CPU Average ms",
IOWAIT_DELTA/(executions_delta*1000) "IO Average ms",
BUFFER_GETS_DELTA/executions_delta "Average buffer gets",
DISK_READS_DELTA/executions_delta "Average disk reads"
from DBA_HIST_SQLSTAT ss,DBA_HIST_SNAPSHOT sn
where ss.sql_id = '7gnz0zx8070n9'
and ss.snap_id=sn.snap_id
and executions_delta > 0
order by ss.snap_id,ss.sql_id;

I’ve hard coded the sql_id as 7gnz0zx8070n9 but you would change that to the sql_id of the query you want to investigate.  You can get the sql_id from an AWR report.

Typical output:

SQL_ID        END_INTERVAL_TIME         EXECUTIONS_DELTA Elapsed Average ms CPU Average ms IO Average ms Average buffer gets Average disk reads
------------- ------------------------- ---------------- ------------------ -------------- ------------- ------------------- ------------------
7gnz0zx8070n9 14-MAY-12 12.00.04.795 PM               11         84726.4826     29198.7186    1606.64882          37011.7273         2950.72727
7gnz0zx8070n9 14-MAY-12 01.00.31.734 PM               18         176928.853     40828.9464    11324.6743          288660.056         15410.1111
7gnz0zx8070n9 14-MAY-12 02.00.05.723 PM               11         213522.486      58663.698    16163.4455          576307.545         24678.5455
7gnz0zx8070n9 14-MAY-12 03.00.43.561 PM               27         224199.385     61645.2061    7544.87026              898836         4479.62963
7gnz0zx8070n9 14-MAY-12 04.00.04.411 PM                5         104387.372     60219.0786     7351.9572           1546004.2             4287.6
7gnz0zx8070n9 21-MAY-12 12.28.46.943 PM               15         72550.5727     28886.7986     3299.5736               67194         5001.86667
7gnz0zx8070n9 21-MAY-12 01.09.43.427 PM                9         166778.289     47970.0616    12468.9748          266338.111               7342
7gnz0zx8070n9 21-MAY-12 02.00.54.605 PM                7         335266.608     68207.2234    15403.1189          457152.143         17968.8571
7gnz0zx8070n9 21-MAY-12 03.00.42.256 PM               12         395749.327     57734.2631    25077.6642            701764.5              19920
7gnz0zx8070n9 21-MAY-12 04.01.00.514 PM               23         271734.101     66244.0698    7713.01161          2645183.43         3724.08696
7gnz0zx8070n9 21-MAY-12 05.00.30.643 PM                6         93118.3805     58891.7195      8212.002          1142748.67               3662

In this example we compare the May 14 run to the May 21 run of the same query.  The output shows two things:

1 – The query ran about the same number of times both weeks

2 – The run time, CPU and disk I/O per execution were about the same

If the number of executions for one week over the next were different that would indicate a change in query volume.  If the per execution times were different that would indicate a change in the way each query ran.

Pretty simple, but helpful when tracking down whether a query is behaving the same today as the last time it ran.

– Bobby

About Bobby

I live in Chandler, Arizona with my wife and three daughters. I work for US Foods, the second largest food distribution company in the United States. I've been working as an Oracle database administrator and PeopleSoft administrator since 1994. I'm very interested in Oracle performance tuning.
This entry was posted in Uncategorized. Bookmark the permalink.

Leave a Reply