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 have worked in the Information Technology field since 1989. I have a passion for Oracle database performance tuning because I enjoy challenging technical problems that require an understanding of computer science. I enjoy communicating with people about my work.
This entry was posted in Uncategorized. Bookmark the permalink.

Leave a Reply