Oracle – Historical SQL Monitoring Techniques

oracle

Is there a built-in Oracle feature that extends Real-Time SQL Monitoring to
historical activity? I am specifically interested in getting wait events aggregated at the SQL operation level, not just per-statement.

Operation level information is available in DBA_HIST_ACTIVE_SESS_HISTORY. Many AWR reports use that table, but do any of them display information at the operation level? Currently I am getting this data by joining DBA_HIST_ACTIVE_SESS_HISTORY and DBMS_XPLAN.DISPLAY_AWR, but it seems like there should be a built-in feature to do this for me. Before I build my own tool I want to ensure someone else hasn't already built it.

This missing feature may sound like a minor inconvenience but using the actual execution statistics, or even a sample of them, makes tuning so much easier. For example, below is a real SQL Monitoring Report for a recent problem, modified to fit here. With operation-level information there was no need to guess which step was slow, or even examine the waits. The problem was quickly found – the indexes were not disabled before a large INSERT.

SQL Monitoring Report


SQL Text
------------------------------
<SQL statement...>


Global Information
------------------------------
<metadata like run status, session, sql_id, duration, etc...>

Parallel Execution Details (DOP=64 , Servers Allocated=128)
...

SQL Plan Monitoring Details (Plan Hash Value=2062479242)

=================================================================================
| Id |     Operation          | Activity |          Activity Detail             |
|    |                        |   (%)    |            (# samples)               |
=================================================================================
...
|  1 |   PX COORDINATOR       |     0.19 | enq: KO - fast object checkpoint (21)|
|  2 |    PX SEND QC (RANDOM) |          |                                      |
|  3 |     INDEX MAINTENANCE  |    84.70 | buffer busy waits (2801)             |
|    |                        |          | enq: HW - contention (29)            |
|    |                        |          | enq: TX - allocate ITL entry (25)    |
|    |                        |          | free buffer waits (61734)            |
|    |                        |          | write complete waits (10365)         |
|    |                        |          | Cpu (341)                            |
|    |                        |          | enq: FB - contention (1632)          |
|    |                        |          | enq: TX - contention (53)            |
|    |                        |          | db file sequential read (3717)       |
|    |                        |          | read by other session (641)          |
|  4 |      PX RECEIVE        |     0.02 | Cpu (18)                             |
|    |                        |          | resmgr:cpu quantum (1)               |
...
=================================================================================

There are some other methods that produce similar information, such as tracing, /*+ gather_plan_statistics */, or alter session set statistics_level=all;. But those methods are only useful in a development environment. I don't have the luxury of being able to re-run statements with different settings.

Best Answer

Oracle 12c has a Performance Hub which includes Monitored SQL in historical mode. Although I haven't tested it, and based on some open bugs I doubt it works 100% of the time.

For 11g, or when the Performance Hub is not available or not working, I have created the open source program Historical SQL Monitoring (hist_sql_mon):

Here's an example of how to use it:

select hist_sql_mon.hist_sql_mon(
    p_sql_id            => '2ssrz4j1m39wx',
    p_start_time_filter => date '2014-09-25',
    p_end_time_filter   => sysdate - interval '1' day)
from dual;

The primary output is a CLOB containing an execution plan with a count and distinct count of events.

-------------------------------------------------------------
|Id  | Operation              | Name   | Rows  | Cost (%CPU)| Event (count|distinct count)
-------------------------------------------------------------
|  0 | SELECT STATEMENT       |        |       | 83031 (100)|
|  1 |  SORT AGGREGATE        |        |     1 |            |
|  2 |   HASH JOIN RIGHT OUTER|        |  8116K| 83031   (4)| Cpu (25|25)
|  3 |    INDEX FULL SCAN     | I_USER2|   155 |     1   (0)|
|  4 |    NESTED LOOPS OUTER  |        |  8116K| 82993   (4)| Cpu (1|1)
|  5 |     NESTED LOOPS OUTER |        |  8116K| 10702  (24)| Cpu (2|2)
...

The functions also print the SQL statement to DBMS_OUTPUT. The bind variables are replaced with hard-coded values so the query can run anywhere. This can help with debugging or creating your own queries.

----------------------------------
--Historical SQL Monitoring Report
----------------------------------
--Execution plans and ASH data, where there are some samples for a plan_hash_value.
select
    --Add execution metadata.
    case
        when plan_table_output like 'Plan hash value: %' then
...
Related Question