Oracle Real-Time SQL Monitoring cheat sheet: V$SQL_MONITOR, plan-line actuals, reports and history

#When to use this

A batch job is "still running", a report takes 40 minutes instead of 4, or a parallel query is not getting its servers. AWR and ASH tell you the SQL ID. Real-Time SQL Monitoring tells you which line of the plan is taking the time, how many rows each line really produced, and how much memory and TEMP each work area used, while the statement is still running.

Caution

SQL Monitoring is part of the Oracle Tuning Pack, which needs the Diagnostics Pack. Querying V$SQL_MONITOR, V$SQL_PLAN_MONITOR or calling DBMS_SQLTUNE.REPORT_SQL_MONITOR counts as use. Check your licence before running anything here, and check CONTROL_MANAGEMENT_PACK_ACCESS.

SHOW PARAMETER control_management_pack_access   -- needs DIAGNOSTIC+TUNING
SHOW PARAMETER statistics_level                 -- TYPICAL or ALL

#What gets monitored

A statement is monitored automatically when it runs in parallel, or when it has used at least 5 seconds of combined CPU and I/O time in one execution. You can force it on or off with hints:

SELECT /*+ MONITOR */ ...        -- always monitor
SELECT /*+ NO_MONITOR */ ...     -- never monitor

Very large plans (hundreds of lines) are not monitored by default. The limit is controlled by a hidden parameter; change it only on advice from Oracle Support.

Each execution is identified by SQL_ID + SQL_EXEC_START + SQL_EXEC_ID. The same SQL ID can have many monitored executions.

#Find monitored executions

#Running now, slowest first

SET LINESIZE 250
COL username FORMAT a14
COL module   FORMAT a25
SELECT sql_id, sql_exec_id, status, username, module,
       TO_CHAR(sql_exec_start,'YYYY-MM-DD HH24:MI:SS') AS started,
       ROUND(elapsed_time/1e6)        AS ela_s,
       ROUND(cpu_time/1e6)            AS cpu_s,
       ROUND(user_io_wait_time/1e6)   AS io_s,
       ROUND(concurrency_wait_time/1e6) AS conc_s,
       buffer_gets, disk_reads,
       px_servers_requested, px_servers_allocated
FROM   v$sql_monitor
WHERE  status = 'EXECUTING'
ORDER  BY elapsed_time DESC
FETCH FIRST 20 ROWS ONLY;

#Recently finished or failed

SELECT sql_id, sql_exec_id, status, username,
       TO_CHAR(sql_exec_start,'HH24:MI:SS') AS started,
       ROUND(elapsed_time/1e6) AS ela_s, error_message
FROM   v$sql_monitor
WHERE  sql_exec_start > SYSDATE - 1/24
AND    status <> 'EXECUTING'
ORDER  BY sql_exec_start DESC;

STATUS values include EXECUTING, DONE, DONE (ALL ROWS), DONE (FIRST N ROWS), DONE (ERROR) and QUEUED.

#Downgraded parallel queries

SELECT sql_id, sql_exec_id, username,
       px_servers_requested, px_servers_allocated,
       ROUND(elapsed_time/1e6) AS ela_s
FROM   v$sql_monitor
WHERE  px_servers_requested > px_servers_allocated
ORDER  BY sql_exec_start DESC;

QUEUED status means the statement is waiting in the parallel statement queue (resmgr:pq queued in ASH).

#Generate the report

#Text report for one SQL ID (latest execution)

SET LONG 10000000 LONGCHUNKSIZE 10000000 LINESIZE 400 PAGESIZE 0 TRIMSPOOL ON
SELECT DBMS_SQLTUNE.REPORT_SQL_MONITOR(
         sql_id       => '9babjv8yq8ru3',
         type         => 'TEXT',
         report_level => 'ALL')
FROM   dual;

#A specific execution

SELECT DBMS_SQLTUNE.REPORT_SQL_MONITOR(
         sql_id      => '9babjv8yq8ru3',
         sql_exec_id => 16777217,
         type        => 'TEXT')
FROM   dual;

#By session

SELECT DBMS_SQLTUNE.REPORT_SQL_MONITOR(
         session_id     => 1234,
         session_serial => 56789,
         type           => 'TEXT')
FROM   dual;

#Active HTML report to send to someone

SET TERMOUT OFF
SPOOL sqlmon_9babjv8yq8ru3.html
SELECT DBMS_SQLTUNE.REPORT_SQL_MONITOR(
         sql_id => '9babjv8yq8ru3', type => 'ACTIVE', report_level => 'ALL')
FROM   dual;
SPOOL OFF
SET TERMOUT ON

ACTIVE reports are interactive and load their viewer from Oracle's website when opened. On an isolated network use type => 'HTML'.

#Summary list of everything monitored

SELECT DBMS_SQLTUNE.REPORT_SQL_MONITOR_LIST(type => 'TEXT') FROM dual;

#Read the plan lines directly

The report is built from V$SQL_PLAN_MONITOR. Querying it directly is faster when you want one answer.

#Estimates against actuals, per line

SELECT plan_line_id AS id,
       LPAD(' ', plan_depth) || plan_operation || ' ' || plan_options AS operation,
       plan_object_name AS object,
       starts,
       plan_cardinality AS est_rows_per_start,
       output_rows      AS actual_rows,
       ROUND(output_rows / NULLIF(starts,0) / NULLIF(plan_cardinality,0), 1) AS ratio,
       ROUND(physical_read_bytes/1048576) AS read_mb,
       ROUND(workarea_max_mem/1048576)    AS max_mem_mb,
       ROUND(workarea_max_tempseg/1048576) AS max_temp_mb
FROM   v$sql_plan_monitor
WHERE  sql_id = '9babjv8yq8ru3'
AND    sql_exec_id = 16777217
ORDER  BY plan_line_id;

A ratio far from 1 (say below 0.1 or above 10) on a line feeding a join is usually where the plan went wrong. PLAN_CARDINALITY is the estimate per start, so compare it with OUTPUT_ROWS / STARTS, not with OUTPUT_ROWS alone. Column names can differ slightly between releases; DESC v$sql_plan_monitor if one is missing.

#Which line is active right now

SELECT plan_line_id, plan_operation, plan_options, plan_object_name,
       output_rows,
       TO_CHAR(last_change_time,'HH24:MI:SS') AS last_change
FROM   v$sql_plan_monitor
WHERE  sql_id = '9babjv8yq8ru3' AND status = 'EXECUTING'
ORDER  BY last_change_time DESC NULLS LAST
FETCH FIRST 5 ROWS ONLY;

#Where time went, from ASH, by plan line

SELECT sql_plan_line_id,
       NVL(event, 'ON CPU') AS event,
       COUNT(*)             AS samples
FROM   v$active_session_history
WHERE  sql_id = '9babjv8yq8ru3'
AND    sql_exec_id = 16777217
GROUP  BY sql_plan_line_id, NVL(event, 'ON CPU')
ORDER  BY samples DESC;

Each sample is about one second of DB time for one session (parallel servers each contribute samples).

#Symptom → what to look at

#History after it ages out

Monitored executions stay in memory only for a limited time. From 12c, completed reports are captured automatically into the AWR repository:

SELECT report_id, key1 AS sql_id, key2 AS sql_exec_id,
       TO_CHAR(period_start_time,'YYYY-MM-DD HH24:MI') AS started,
       TO_CHAR(period_end_time,'YYYY-MM-DD HH24:MI')   AS ended
FROM   dba_hist_reports
WHERE  component_name = 'sqlmonitor'
AND    key1 = '9babjv8yq8ru3'
ORDER  BY period_start_time DESC;

SELECT DBMS_AUTO_REPORT.REPORT_REPOSITORY_DETAIL(
         rid => 4711, type => 'TEXT')
FROM   dual;

Not every execution is captured; the automatic capture is sampled. Save the report yourself while the statement is still in V$SQL_MONITOR if you need it for a post-incident review.

#Monitor a whole batch, not one statement

Composite database operations group many statements under one name:

VARIABLE eid NUMBER
EXEC :eid := DBMS_SQL_MONITOR.BEGIN_OPERATION(dbop_name => 'NIGHTLY_LOAD', forced_tracking => DBMS_SQL_MONITOR.FORCE_TRACKING);
-- run the batch in this session
EXEC DBMS_SQL_MONITOR.END_OPERATION(dbop_name => 'NIGHTLY_LOAD', dbop_eid => :eid);

SELECT DBMS_SQL_MONITOR.REPORT_SQL_MONITOR(
         dbop_name => 'NIGHTLY_LOAD', type => 'TEXT')
FROM   dual;

#Habits worth keeping

• Grab the text report as soon as a long job is reported slow. It is the single most useful artifact for a plan problem.
• Always note SQL_EXEC_ID. Comparing two executions of the same SQL ID (good night against bad night) usually shows the regression immediately.
• Pair the report with the plan hash value from V$SQL and check whether a baseline or profile is in use before changing anything.