Calculating Elapsed Time For Queries In Oracle

There may be times when a query is taking longer to execute than expected. With Oracle, the Automatic Workload Repository collects statistics on a regular schedule to report on how the system is performing, including elapsed time for queries. Since a full AWR report may not be necessary a script using some of the AWR data can generate elapsed time reports by sql_id. Let’s look at a script that does that and see how it can report longer elapsed times.

Looking at the code there is nothing unusual:


set linesize 200 trimspool on pagesize 60 verify off
column begin_interval_time format a35
column end_interval_time format a35

break on sql_id skip 1 on instance_number

column sdate new_value sdt noprint

select to_char(sysdate, 'YYYYMMDDHHMI') sdate from dual;

spool &sdt._elapsed_time_report.log

prompt 
prompt  Historic
prompt 
prompt  Elapsed by exec
prompt 

select distinct x.instance_number, x.sql_id, x.time_per_exec, x.elapsed_time_total, s.begin_interval_time, s.end_interval_time
from
(select instance_number, sql_id, snap_id,
       round((elapsed_time_total/1000000)/(case when elapseds_total = 0 then 1 else elapseds_total end),4) time_per_exec,
       round(elapsed_time_total/1000000, 4) elapsed_time_total
from dba_hist_sqlstat) x, (select snap_id, 
                                  max(begin_interval_time) begin_interval_time, 
                                  max(end_interval_time) end_interval_time
                           from dba_hist_snapshot 
                           group by snap_id) s
where s.snap_id = x.snap_id 
and x.time_per_exec > &&1
and x.time_per_exec <> x.elapsed_time_total
order by 2 asc, 3 desc, 6 desc
/

clear breaks

prompt 
prompt  Elapsed time total, current statements
prompt 

select inst_id,
       sql_id,
       elapseds,
       round(elapsed_time/1000000, 6) elapsed_sec,
       round((elapsed_time/1000000)/(case when elapseds = 0 then 1 else elapseds end), 6) elapsed_per_exec,
       last_active_time
from gv$sqlstats
where elapsed_time/1000000 > &&1
order by 4 desc
/

prompt 
prompt  Elapsed per exec, current statements
prompt 

select inst_id,
       sql_id,
       elapseds,
       round(elapsed_time/1000000, 6) elapsed_sec,
       round((elapsed_time/1000000)/(case when elapseds = 0 then 1 else elapseds end), 6) elapsed_per_exec,
       last_active_time
from gv$sqlstats
where elapsed_time/1000000 > &&1
order by 5 desc
/

set linesize 80 trimspool off

spool off

The main report, of the overall elapsed times by sql_id, is generated using a standard group by expression; since a number of readings are taken for each snap_id this is necessary to provide the overall elapsed time. One item to notice is the target time is entered when the script is called, which eliminates any statements executing in less time than the supplied lower limit. The next sections return the elapsed times for current queries and statements as total elapsed time across all executions and as elapsed time by execution; this can be helpful in determining if a total elapsed time for a given statement indicates a problem.

Let’s look at a report (that’s been abbreviated) that was generated by this script:



Historic

Elapsed by exec


INSTANCE_NUMBER SQL_ID        TIME_PER_EXEC ELAPSED_TIME_TOTAL BEGIN_INTERVAL_TIME                 END_INTERVAL_TIME
--------------- ------------- ------------- ------------------ ----------------------------------- -----------------------------------
              1 59bmb7cm4nt4f      224.5749          1122.8747 08-JUN-12 12.15.08.732 AM           08-JUN-12 12.30.24.296 AM
                                   212.7979          1063.9894 08-JUN-12 12.01.00.685 AM           08-JUN-12 12.15.08.732 AM
                                   216.1208           864.4831 07-JUN-12 11.45.49.310 PM           08-JUN-12 12.01.00.685 AM
                                   203.1346           609.4037 07-JUN-12 11.30.36.654 PM           07-JUN-12 11.45.49.310 PM

              1 5zruc4v6y32f9      182.2784           1822.784 31-MAY-12 10.00.50.731 PM           31-MAY-12 10.15.51.379 PM
                                    192.264          1730.3759 31-MAY-12 09.45.21.072 PM           31-MAY-12 10.00.50.731 PM
                                    186.032          1674.2882 30-MAY-12 10.00.46.052 PM           30-MAY-12 10.15.43.051 PM
                                    193.738          1549.9039 30-MAY-12 09.45.19.524 PM           30-MAY-12 10.00.46.052 PM
                                   187.7805          1502.2439 29-MAY-12 10.00.42.597 PM           29-MAY-12 10.15.24.997 PM
                                   196.9061          1378.3427 29-MAY-12 09.45.10.158 PM           29-MAY-12 10.00.42.597 PM
                                   190.0967          1330.6767 28-MAY-12 10.00.29.482 PM           28-MAY-12 10.15.26.294 PM
                                   196.9987          1181.9921 28-MAY-12 09.45.54.019 PM           28-MAY-12 10.00.29.482 PM
                                    191.655          1149.9302 27-MAY-12 06.00.15.294 AM           27-MAY-12 06.15.51.136 AM
                                   167.3931           836.9655 27-MAY-12 05.45.29.554 AM           27-MAY-12 06.00.15.294 AM
                                    161.164             805.82 26-MAY-12 06.00.30.744 AM           26-MAY-12 06.15.10.325 AM
                                   188.5593           754.2373 26-MAY-12 05.45.03.717 AM           26-MAY-12 06.00.30.744 AM
                                   178.5737            714.295 25-MAY-12 10.00.02.791 PM           25-MAY-12 10.26.24.823 PM
                                   164.9698           494.9094 25-MAY-12 09.45.32.561 PM           25-MAY-12 10.00.02.791 PM
                                   143.5624          1292.0617 21-MAY-12 10.00.46.343 PM           21-MAY-12 10.15.46.594 PM
                                   147.4573          1179.6585 21-MAY-12 09.45.24.175 PM           21-MAY-12 10.00.46.343 PM
                                   142.1139          1136.9116 20-MAY-12 06.00.52.551 AM           20-MAY-12 06.15.25.398 AM
                                   153.6895          1075.8264 20-MAY-12 05.48.57.140 AM           20-MAY-12 06.00.52.551 AM
                                   145.2897          1017.0279 19-MAY-12 06.00.26.527 AM           19-MAY-12 06.15.06.182 AM
                                   161.3405           968.0428 19-MAY-12 05.45.03.089 AM           19-MAY-12 06.00.26.527 AM
                                   155.9836           935.9015 18-MAY-12 10.00.17.672 PM           18-MAY-12 10.15.41.592 PM
                                   160.2133           801.0666 18-MAY-12 09.45.07.899 PM           18-MAY-12 10.00.17.672 PM
                                   155.0522           775.2609 17-MAY-12 10.00.13.715 PM           17-MAY-12 10.15.05.760 PM
                                   160.3245           641.2979 17-MAY-12 09.45.37.003 PM           17-MAY-12 10.00.13.715 PM
                                    156.017            624.068 16-MAY-12 10.00.26.261 PM           16-MAY-12 10.15.38.548 PM
                                   165.4983           496.4949 16-MAY-12 09.45.46.786 PM           16-MAY-12 10.00.26.261 PM
                                    154.449           463.3471 15-MAY-12 10.00.07.816 PM           15-MAY-12 10.15.30.184 PM
                                   125.2814           250.5627 15-MAY-12 09.45.40.159 PM           15-MAY-12 10.00.07.816 PM
                                   120.0409           240.0817 14-MAY-12 10.00.25.046 PM           14-MAY-12 10.15.53.999 PM
                                    82.0499           410.2493 11-MAY-12 10.00.37.022 PM           11-MAY-12 10.15.38.163 PM
                                    99.9666           399.8664 11-MAY-12 09.46.56.027 PM           11-MAY-12 10.00.37.022 PM
                                    87.7092           350.8368 10-MAY-12 10.05.18.932 PM           10-MAY-12 10.15.20.504 PM
                                    99.8229           299.4686 10-MAY-12 09.45.19.954 PM           10-MAY-12 10.05.18.932 PM
                                    79.4074           238.2222 09-MAY-12 10.00.55.529 PM           09-MAY-12 10.15.27.534 PM
                                   115.4541           230.9081 09-MAY-12 09.45.31.049 PM           09-MAY-12 10.00.55.529 PM

              1 6bh95z369zn4h      251.6948           503.3896 08-JUN-12 12.15.08.732 AM           08-JUN-12 12.30.24.296 AM
                                   262.0461           524.0922 08-JUN-12 12.01.00.685 AM           08-JUN-12 12.15.08.732 AM
                                    254.088           508.1759 07-JUN-12 11.45.49.310 PM           08-JUN-12 12.01.00.685 AM

              1 6mcpb06rctk0x      127.3666          1018.9332 03-JUN-12 10.00.02.086 PM           03-JUN-12 10.15.05.223 PM
                                   144.8615          1014.0306 03-JUN-12 06.00.17.500 PM           03-JUN-12 06.15.21.261 PM
                                   168.0681          1008.4086 03-JUN-12 02.00.21.570 PM           03-JUN-12 02.15.33.540 PM
                                    200.658          1003.2902 03-JUN-12 10.00.03.080 AM           03-JUN-12 10.15.14.467 AM
                                   249.6134           998.4535 03-JUN-12 06.00.00.701 AM           03-JUN-12 06.15.37.615 AM
                                   330.9043           992.7128 02-JUN-12 10.45.44.377 PM           02-JUN-12 11.00.47.236 PM
                                   493.3585           986.7171 02-JUN-12 06.45.21.749 PM           02-JUN-12 07.00.48.438 PM
                                   150.1094          2551.8605 01-JUN-12 10.30.49.857 PM           01-JUN-12 10.45.56.692 PM
                                   145.4944          2327.9102 01-JUN-12 10.15.27.924 PM           01-JUN-12 10.30.49.857 PM
                                    89.1964          1427.1429 01-JUN-12 10.00.05.680 PM           01-JUN-12 10.15.27.924 PM
                                    67.0364           268.1455 26-MAY-12 05.45.03.717 AM           26-MAY-12 06.00.30.744 AM


INSTANCE_NUMBER SQL_ID        TIME_PER_EXEC ELAPSED_TIME_TOTAL BEGIN_INTERVAL_TIME                 END_INTERVAL_TIME
--------------- ------------- ------------- ------------------ ----------------------------------- -----------------------------------
              1 7wgks43wrjtrz       68.0912           204.2735 02-JUN-12 02.33.55.172 PM           02-JUN-12 03.12.27.853 PM
                                   128.7025           643.5127 01-JUN-12 10.30.49.857 PM           01-JUN-12 10.45.56.692 PM
                                   170.5982           511.7945 01-JUN-12 10.15.27.924 PM           01-JUN-12 10.30.49.857 PM

              1 8szmwam7fysa3       69.6299           557.0392 03-JUN-12 06.00.17.500 PM           03-JUN-12 06.15.21.261 PM
                                   111.3491           556.7456 02-JUN-12 06.45.21.749 PM           02-JUN-12 07.00.48.438 PM
                                    175.859           527.5769 02-JUN-12 02.33.55.172 PM           02-JUN-12 03.12.27.853 PM
                                   249.2256           1246.128 01-JUN-12 10.30.49.857 PM           01-JUN-12 10.45.56.692 PM
                                   385.0097          1155.0291 01-JUN-12 10.15.27.924 PM           01-JUN-12 10.30.49.857 PM

              1 b6usrg82hwsa3        62.596           250.3841 03-JUN-12 06.00.00.701 AM           03-JUN-12 06.15.37.615 AM
                                    76.1965           152.3929 02-JUN-12 06.45.21.749 PM           02-JUN-12 07.00.48.438 PM
                                    547.373          9305.3416 01-JUN-12 11.15.49.205 PM           01-JUN-12 11.30.02.603 PM
                                    577.289          9236.6238 01-JUN-12 11.00.23.388 PM           01-JUN-12 11.15.49.205 PM
                                   519.4568          8311.3093 01-JUN-12 10.45.56.692 PM           01-JUN-12 11.00.23.388 PM
                                   466.1027          7457.6429 01-JUN-12 10.30.49.857 PM           01-JUN-12 10.45.56.692 PM
                                   408.6935          6539.0959 01-JUN-12 10.15.27.924 PM           01-JUN-12 10.30.49.857 PM
                                   352.4655          5639.4475 01-JUN-12 10.00.05.680 PM           01-JUN-12 10.15.27.924 PM
                                   295.0185          4720.2965 01-JUN-12 09.45.43.999 PM           01-JUN-12 10.00.05.680 PM
                                   320.5267          5769.4813 31-MAY-12 10.00.50.731 PM           31-MAY-12 10.15.51.379 PM
                                   300.4537          5107.7137 31-MAY-12 09.45.21.072 PM           31-MAY-12 10.00.50.731 PM
                                   297.1011          5050.7182 30-MAY-12 10.00.46.052 PM           30-MAY-12 10.15.43.051 PM
                                   297.7186          4763.4975 30-MAY-12 09.45.19.524 PM           30-MAY-12 10.00.46.052 PM
                                   294.7439          4715.9018 29-MAY-12 10.00.42.597 PM           29-MAY-12 10.15.24.997 PM
                                   305.9663          4589.4941 29-MAY-12 09.45.10.158 PM           29-MAY-12 10.00.42.597 PM
                                   302.7239          4540.8588 28-MAY-12 10.00.29.482 PM           28-MAY-12 10.15.26.294 PM
                                   278.9246           3904.945 28-MAY-12 09.45.54.019 PM           28-MAY-12 10.00.29.482 PM
                                   276.5938          3872.3134 27-MAY-12 10.00.09.604 PM           27-MAY-12 10.15.38.268 PM
                                    295.956          3847.4278 27-MAY-12 06.00.39.242 PM           27-MAY-12 06.17.59.163 PM
                                   318.6127          3823.3525 27-MAY-12 02.00.03.891 PM           27-MAY-12 02.15.34.334 PM
                                   336.8525           3705.378 27-MAY-12 10.00.09.981 AM           27-MAY-12 10.15.40.494 AM
                                   333.4742           3334.742 27-MAY-12 06.00.15.294 AM           27-MAY-12 06.15.51.136 AM
                                   350.1827          3151.6441 27-MAY-12 05.45.29.554 AM           27-MAY-12 06.00.15.294 AM
                                   346.6326          3119.6936 26-MAY-12 10.15.05.305 PM           26-MAY-12 10.30.28.949 PM
                                   383.8398          3070.7187 26-MAY-12 06.15.33.018 PM           26-MAY-12 06.30.08.951 PM
                                   435.6125          3049.2876 26-MAY-12 02.00.14.742 PM           26-MAY-12 02.15.48.394 PM
                                   504.5246          3027.1478 26-MAY-12 10.15.43.954 AM           26-MAY-12 10.30.41.367 AM
                                   531.6921          2658.4606 26-MAY-12 10.00.47.065 AM           26-MAY-12 10.15.43.954 AM
                                   440.6089          2203.0445 26-MAY-12 05.45.03.717 AM           26-MAY-12 06.00.30.744 AM
                                   542.7188          2170.8754 25-MAY-12 10.00.02.791 PM           25-MAY-12 10.26.24.823 PM
                                   631.6046          1894.8139 25-MAY-12 09.45.32.561 PM           25-MAY-12 10.00.02.791 PM
                                   218.6943          4373.8855 21-MAY-12 10.00.46.343 PM           21-MAY-12 10.15.46.594 PM
                                   222.8837          4234.7896 21-MAY-12 09.45.24.175 PM           21-MAY-12 10.00.46.343 PM
                                   220.6253          4191.8809 20-MAY-12 10.15.16.796 PM           20-MAY-12 10.30.41.147 PM
                                   230.2027          4143.6478 20-MAY-12 06.00.41.507 PM           20-MAY-12 06.15.52.794 PM
                                   242.2801          4118.7619 20-MAY-12 02.00.45.447 PM           20-MAY-12 02.15.17.316 PM
                                   253.4033          4054.4528 20-MAY-12 10.01.10.728 AM           20-MAY-12 10.15.43.591 AM
                                   266.7002          4000.5028 20-MAY-12 09.45.21.591 AM           20-MAY-12 10.01.10.728 AM
                                   265.0442          3975.6628 20-MAY-12 06.00.52.551 AM           20-MAY-12 06.15.25.398 AM
                                   228.6042          3200.4584 20-MAY-12 05.48.57.140 AM           20-MAY-12 06.00.52.551 AM
                                   224.4085           3141.719 19-MAY-12 10.00.46.858 PM           19-MAY-12 10.15.02.318 PM
                                   240.7072          3129.1935 19-MAY-12 06.00.28.187 PM           19-MAY-12 06.15.50.486 PM
                                   258.7556          3105.0674 19-MAY-12 02.00.45.094 PM           19-MAY-12 02.16.41.078 PM
                                   277.0242           3047.266 19-MAY-12 10.00.28.691 AM           19-MAY-12 10.15.17.200 AM
                                   300.6173          3006.1726 19-MAY-12 06.00.26.527 AM           19-MAY-12 06.15.06.182 AM
                                   326.0777          2934.6995 19-MAY-12 05.45.03.089 AM           19-MAY-12 06.00.26.527 AM
                                   322.3945          2901.5506 18-MAY-12 10.00.17.672 PM           18-MAY-12 10.15.41.592 PM

INSTANCE_NUMBER SQL_ID        TIME_PER_EXEC ELAPSED_TIME_TOTAL BEGIN_INTERVAL_TIME                 END_INTERVAL_TIME
--------------- ------------- ------------- ------------------ ----------------------------------- -----------------------------------
              1 b6usrg82hwsa3      345.0926          2760.7408 18-MAY-12 09.45.07.899 PM           18-MAY-12 10.00.17.672 PM
                                   209.2946          2930.1247 17-MAY-12 10.15.05.760 PM           17-MAY-12 10.30.32.705 PM
                                   224.6041          2919.8535 17-MAY-12 10.00.13.715 PM           17-MAY-12 10.15.05.760 PM
                                   151.4518          1968.8734 17-MAY-12 09.45.37.003 PM           17-MAY-12 10.00.13.715 PM
                                    150.119          1951.5471 16-MAY-12 10.00.26.261 PM           16-MAY-12 10.15.38.548 PM
                                   135.5454          1626.5453 16-MAY-12 09.45.46.786 PM           16-MAY-12 10.00.26.261 PM
                                   132.6097          1591.3166 15-MAY-12 10.00.07.816 PM           15-MAY-12 10.15.30.184 PM
                                   124.6115           1370.727 15-MAY-12 09.45.40.159 PM           15-MAY-12 10.00.07.816 PM
                                    123.495          1358.4449 14-MAY-12 10.15.53.999 PM           14-MAY-12 10.30.41.744 PM
                                   129.2864          1292.8642 14-MAY-12 10.00.25.046 PM           14-MAY-12 10.15.53.999 PM
                                   355.2154          1776.0768 11-MAY-12 10.00.37.022 PM           11-MAY-12 10.15.38.163 PM
                                    304.275          1217.1002 11-MAY-12 09.46.56.027 PM           11-MAY-12 10.00.37.022 PM
                                   291.9494          1167.7975 10-MAY-12 10.05.18.932 PM           10-MAY-12 10.15.20.504 PM
                                   384.0056          1152.0167 10-MAY-12 09.45.19.954 PM           10-MAY-12 10.05.18.932 PM
                                   363.1818          1089.5454 09-MAY-12 10.00.55.529 PM           09-MAY-12 10.15.27.534 PM
                                   154.9747           309.9494 09-MAY-12 09.45.31.049 PM           09-MAY-12 10.00.55.529 PM

              1 ffrxyztt4415k       69.1093           138.2187 02-JUN-12 06.45.21.749 PM           02-JUN-12 07.00.48.438 PM
                                    63.9713           127.9426 26-MAY-12 06.00.30.744 AM           26-MAY-12 06.15.10.325 AM

              1 g5m0bnvyy37b1       77.0377           154.0755 02-JUN-12 06.00.24.646 AM           02-JUN-12 06.15.35.899 AM
                                   152.2235           304.4469 01-JUN-12 10.00.05.680 PM           01-JUN-12 10.15.27.924 PM
                                    76.5734           153.1468 29-MAY-12 09.45.10.158 PM           29-MAY-12 10.00.42.597 PM
                                   146.9746           293.9493 27-MAY-12 06.00.15.294 AM           27-MAY-12 06.15.51.136 AM
                                    86.2456           172.4912 26-MAY-12 05.45.03.717 AM           26-MAY-12 06.00.30.744 AM
                                    67.1096           134.2193 25-MAY-12 10.00.02.791 PM           25-MAY-12 10.26.24.823 PM


132 rows selected.


Elapsed time total


   INST_ID SQL_ID        EXECUTIONS ELAPSED_SEC ELAPSED_PER_EXEC LAST_ACTI
---------- ------------- ---------- ----------- ---------------- ---------
         1 c2p32r5mzv8hb          2   42.261945        21.130973 08-JUN-12
         1 g0jvz8csyrtcf          2    30.61629        15.308145 08-JUN-12
         1 f6cz4n8y72xdc          1   30.135064        30.135064 08-JUN-12
         1 ajymgnp1qnruw          1    24.38731         24.38731 08-JUN-12
         1 12a2xbmwn5v6z          1   22.693804        22.693804 08-JUN-12
         1 cvn54b7yz0s8u        123   17.256723          .140299 08-JUN-12
         1 bxywuzvtp6wjg          1   14.619797        14.619797 08-JUN-12
         1 db78fxqxwxt7r       1362   12.842434          .009429 08-JUN-12
         1 39m4sx9k63ba2        123   11.588453          .094215 08-JUN-12
         1 3ktacv9r56b51        207    9.451088          .045657 08-JUN-12
         1 7t7spt2vnhfu2          1    8.877334         8.877334 08-JUN-12
         1 2nszajb0qbyvp         11    8.464223          .769475 08-JUN-12
         1 49s332uhbnsma        192    8.160414          .042502 08-JUN-12
         1 3wrrjm9qtr2my          1    7.658871         7.658871 08-JUN-12
         1 b3abwkm67yg8r          2    6.885733         3.442867 08-JUN-12
         1 96g93hntrzjtr       4272    6.340086          .001484 08-JUN-12
         1 6z9uusgaz5z9q          1     6.17565          6.17565 08-JUN-12
         1 d1m8g1r0jntpj          8    5.919787          .739973 08-JUN-12
         1 9s0xa5dgvuq55          3     5.35587          1.78529 08-JUN-12
         1 0nazp4jx2k26t          2    4.931885         2.465943 08-JUN-12
         1 3nkd3g3ju5ph1       1145    4.739167          .004139 08-JUN-12
         1 6ajkhukk78nsr          7    4.532631          .647519 08-JUN-12
         1 02577v815yp77          1    4.441737         4.441737 08-JUN-12
         1 ga9j9xk5cy9s0        123    4.268745          .034705 08-JUN-12
         1 8swypbbr0m372        207    4.163114          .020112 08-JUN-12
         1 dayq182sk41ks          7     3.32712          .475303 08-JUN-12
         1 cnq31548hb8un          1    3.287435         3.287435 08-JUN-12
         1 0b6cmw1158fdg          1    3.217673         3.217673 08-JUN-12
         1 bm2pwrpcr8ru6          8    3.153184          .394148 08-JUN-12
         1 bunssq950snhf          7    3.025152          .432165 08-JUN-12
         1 f99a23s9aba0z          1    2.902161         2.902161 08-JUN-12
         1 c6awqs517jpj0        123     2.78192          .022617 08-JUN-12
         1 8mz0wa11tacp0          1    2.761721         2.761721 08-JUN-12
         1 2crngsbggkkzv          1    2.699521         2.699521 08-JUN-12
         1 aq1vwa734ww0j          7    2.414087           .34487 08-JUN-12
         1 7ng34ruy5awxq        363    2.399479           .00661 08-JUN-12
         1 8rpn8jtjnuu73          1    2.102807         2.102807 08-JUN-12
         1 aukfj0ur6962z         22    2.077201          .094418 08-JUN-12
         1 1gu8t96d0bdmu        366    1.955032          .005342 08-JUN-12
         1 32hbap2vtmf53        325    1.857706          .005716 08-JUN-12
         1 bn4b3vjw2mj3u         25    1.740084          .069603 08-JUN-12
         1 dp2c6pq28u5jr          1    1.692286         1.692286 08-JUN-12
         1 4x2cynvsuuddu         13    1.683365           .12949 08-JUN-12
         1 83taa7kaw59c1        390    1.449783          .003717 08-JUN-12
         1 9dhn1b8d88dpf          5    1.397411          .279482 08-JUN-12
         1 9s0phgvjjnz0k          1      1.3721           1.3721 08-JUN-12
         1 b1wc53ddd6h3p         83    1.363302          .016425 08-JUN-12
         1 836b98xx998x3          1    1.317414         1.317414 08-JUN-12
         1 acc988uzvjmmt          1    1.228041         1.228041 08-JUN-12
         1 fnk7155mk2jq6         27    1.189632           .04406 08-JUN-12
         1 7xa8wfych4mad          1    1.181227         1.181227 08-JUN-12
         1 8yu1fmd6pm6y2          1    1.165524         1.165524 08-JUN-12
         1 3w4qs0tbpmxr6        277    1.161499          .004193 08-JUN-12
         1 6v0cyda83r2qf          1    1.158488         1.158488 08-JUN-12
         1 9ctt1scmwbmbg          2    1.121567          .560784 08-JUN-12
         1 g3wrkmxkxzhf2         27    1.095239          .040564 08-JUN-12
         1 2prbzh4qfms7u          7    1.090865          .155838 08-JUN-12
...

   INST_ID SQL_ID        EXECUTIONS ELAPSED_SEC ELAPSED_PER_EXEC LAST_ACTI
---------- ------------- ---------- ----------- ---------------- ---------
         1 01srqknh66jbn          0           0                0 31-DEC-69
         1 2ajy4zgqrakrx          0           0                0 31-DEC-69
         1 8tdy251ry2npr          0           0                0 31-DEC-69
         1 aq19zrtmdanug          0           0                0 31-DEC-69
         1 1fa6m97mnaq58          0           0                0 31-DEC-69
         1 fj16zvcuykr1z          0           0                0 31-DEC-69

975 rows selected.


Elapsed per exec


   INST_ID SQL_ID        EXECUTIONS ELAPSED_SEC ELAPSED_PER_EXEC LAST_ACTI
---------- ------------- ---------- ----------- ---------------- ---------
         1 f6cz4n8y72xdc          1   30.135064        30.135064 08-JUN-12
         1 ajymgnp1qnruw          1    24.38731         24.38731 08-JUN-12
         1 12a2xbmwn5v6z          1   22.693804        22.693804 08-JUN-12
         1 c2p32r5mzv8hb          2   42.261945        21.130973 08-JUN-12
         1 g0jvz8csyrtcf          2    30.61629        15.308145 08-JUN-12
         1 bxywuzvtp6wjg          1   14.619797        14.619797 08-JUN-12
         1 7t7spt2vnhfu2          1    8.877334         8.877334 08-JUN-12
         1 3wrrjm9qtr2my          1    7.658871         7.658871 08-JUN-12
         1 6z9uusgaz5z9q          1     6.17565          6.17565 08-JUN-12
         1 02577v815yp77          1    4.441737         4.441737 08-JUN-12
         1 b3abwkm67yg8r          2    6.885733         3.442867 08-JUN-12
         1 cnq31548hb8un          1    3.287435         3.287435 08-JUN-12
         1 0b6cmw1158fdg          1    3.217673         3.217673 08-JUN-12
         1 f99a23s9aba0z          1    2.902161         2.902161 08-JUN-12
         1 8mz0wa11tacp0          1    2.761721         2.761721 08-JUN-12
         1 2crngsbggkkzv          1    2.699521         2.699521 08-JUN-12
         1 0nazp4jx2k26t          2    4.931885         2.465943 08-JUN-12
         1 8rpn8jtjnuu73          1    2.102807         2.102807 08-JUN-12
         1 9s0xa5dgvuq55          3     5.35587          1.78529 08-JUN-12
         1 dp2c6pq28u5jr          1    1.692286         1.692286 08-JUN-12
         1 9s0phgvjjnz0k          1      1.3721           1.3721 08-JUN-12
         1 836b98xx998x3          1    1.317414         1.317414 08-JUN-12
         1 acc988uzvjmmt          1    1.228041         1.228041 08-JUN-12
         1 7xa8wfych4mad          1    1.181227         1.181227 08-JUN-12
         1 8yu1fmd6pm6y2          1    1.165524         1.165524 08-JUN-12
         1 6v0cyda83r2qf          1    1.158488         1.158488 08-JUN-12
         1 fdqrbmmvu0fpm          1     1.06258          1.06258 08-JUN-12
         1 01uy9sb7w8a9g          1      .95805           .95805 08-JUN-12
         1 1gnyr2xx1sxzd          1     .919123          .919123 08-JUN-12
         1 0sfsrf0qzvsjv          1     .850743          .850743 08-JUN-12
         1 832kkz790r75k          1     .835987          .835987 08-JUN-12
         1 4y3yvmbav7uwb          1      .82599           .82599 08-JUN-12
         1 2whm2vvjb98k7          1     .808338          .808338 08-JUN-12
         1 2nszajb0qbyvp         11    8.464223          .769475 08-JUN-12
         1 9pvbjqqt222b4          1     .749151          .749151 08-JUN-12
         1 d1m8g1r0jntpj          8    5.919787          .739973 08-JUN-12
         1 70q7c42056upw          1     .691399          .691399 08-JUN-12
         1 1k4n9zzsk1vc4          1     .690879          .690879 08-JUN-12
         1 6ajkhukk78nsr          7    4.532631          .647519 08-JUN-12
         1 3t34b9dnz3s0g          1     .640974          .640974 08-JUN-12
         1 96w2cbx7ntmtv          1     .637091          .637091 08-JUN-12
         1 3hgxzypxz2xpg          1     .616795          .616795 08-JUN-12
         1 27crjkm60uua8          1     .560949          .560949 08-JUN-12
         1 9ctt1scmwbmbg          2    1.121567          .560784 08-JUN-12
         1 38hpmnhjywkz4          1     .556394          .556394 08-JUN-12
         1 bzscyq07w79ab          1     .549535          .549535 08-JUN-12
         1 3qsmy8ybvwt3n          1     .536236          .536236 08-JUN-12
         1 86cq99yvqpjx9          1     .498675          .498675 08-JUN-12
         1 dayq182sk41ks          7     3.32712          .475303 08-JUN-12
         1 1xcngwj6ypnkx          1     .465468          .465468 08-JUN-12
         1 1h7zt6jks80pa          1     .457338          .457338 08-JUN-12
         1 4zmbcythh0m13          1     .442322          .442322 08-JUN-12
         1 bunssq950snhf          7    3.025152          .432165 08-JUN-12
         1 3r3gdz8627kmk          1     .426671          .426671 08-JUN-12
         1 0tdm5skk57ukp          2     .836501          .418251 08-JUN-12
         1 32ss2fd6p2m4g          1     .411469          .411469 08-JUN-12
         1 56rfc4v7g9j25          1     .406445          .406445 08-JUN-12
...

   INST_ID SQL_ID        EXECUTIONS ELAPSED_SEC ELAPSED_PER_EXEC LAST_ACTI
---------- ------------- ---------- ----------- ---------------- ---------
         1 d4m7ss0gdqhw9          0           0                0 31-DEC-69
         1 01srqknh66jbn          0           0                0 31-DEC-69
         1 2ajy4zgqrakrx          0           0                0 31-DEC-69
         1 8tdy251ry2npr          0           0                0 31-DEC-69
         1 aq19zrtmdanug          0           0                0 31-DEC-69
         1 1fa6m97mnaq58          0           0                0 31-DEC-69
         1 fj16zvcuykr1z          0           0                0 31-DEC-69

976 rows selected.

The 0-count execution lines indicate the statement hasn’t completed as of the time the report is run; the latter two sections are reported from data in the GV$SQLSTATS view, which won’t be updated until an execution completes.

Having such a script handy can save time and effort in troubleshooting long elapsed query times by revealing whether or not multiple executions of a statement occurred during the snapshot window and can provide a total elapsed time across snapshots so an accurate time can be obtained. And such a report can be much easier to use than a full AWR or ASH report as it isolates the elapsed time data from the rest of the repository statistics.

See all articles by David Fitzjarrell

David Fitzjarrell
David Fitzjarrell
David Fitzjarrell has more than 20 years of administration experience with various releases of the Oracle DBMS. He has installed the Oracle software on many platforms, including UNIX, Windows and Linux, and monitored and tuned performance in those environments. He is knowledgeable in the traditional tools for performance tuning – the Oracle Wait Interface, Statspack, event 10046 and 10053 traces, tkprof, explain plan and autotrace – and has used these to great advantage at the U.S. Postal Service, American Airlines/SABRE, ConocoPhilips and SiriusXM Radio, among others, to increase throughput and improve the quality of the production system. He has also set up scripts to regularly monitor available space and set thresholds to notify DBAs of impending space shortages before they affect the production environment. These scripts generate data which can also used to trend database growth over time, aiding in capacity planning. He has used RMAN, Streams, RAC and Data Guard in Oracle installations to ensure full recoverability and failover capabilities as well as high availability, and has configured a 'cascading' set of DR databases using the primary DR databases as the source, managing the archivelog transfers manually and montoring, through scripts, the health of these secondary DR databases. He has also used ASM, ASMM and ASSM to improve performance and manage storage and shared memory.

Get the Free Newsletter!

Subscribe to Cloud Insider for top news, trends & analysis

Latest Articles