Using v$session_longops to find long running SQL statements

v$session_longops is a dynamic performance view in which Oracle reports on the status of operations that run for more than 6 (elapsed) seconds. Various operations, including queries are automatically reported in this view. Applications can also mark operations as long running with DBMS_APPLICATION_INFO.SET_SESSION_LONGOPS.

I recently spent a day on a site (not a PeopleSoft system) watching a single update statement that eventually ran for 27 hours. I used this view to predict when the SQL statement would complete.

You can see incomplete long running operations by querying long operations where the work done so far is less than the total amount of work.

SELECT * FROM v$session_longops WHERE sofar < totalwork;

SID        SERIAL#    OPNAME
---------- ---------- -----------------------------------------------------------
TARGET                                                    
----------------------------------------------------------------
TARGET_DESC                           SOFAR  TOTALWORK UNITS                     
-------------------------------- ---------- ---------- --------------------------
START_TIME          LAST_UPDATE_TIME    TIME_REMAINING ELAPSED_SECONDS    CONTEXT
------------------- ------------------- -------------- --------------- ----------
MESSAGE                      
---------------------------------------------------------------------------------
USERNAME                       SQL_ADDRESS      SQL_HASH_VALUE      QCSID
------------------------------ ---------------- -------------- ----------
 24      12722 Table Scan                                                     
R2LLMS.TBL_TMX_REGTRANSACTION                                                                          
                               14407      24935 Blocks                                
01:25:40 28/09/2007 17:35:44 28/09/2007          42533           58204          0
Table Scan:  R2LLMS.TBL_TMX_REGTRANSACTION: 14407 out of 24935 Blocks done
R2LLMS                         C00000012FE2A170      861482451          0

The operations remain in this view long after they have completed, so you can use it to get a feel for what long operations occur on a sytem. But there are a fixed number of slots for v$session_longops, determined by ksulomux_. The entry for a completed operation remains in the view until the slots is reused. They are not reused in order of allocation, instead the array element to be reused is "probably determined by a MOD function" (My thanks to Tanel Poder for his clarification). So v$session_longops contains both current incomplete long operations and an arbitrary sample of completed long operations.

You can use the SQL_ADDRESS and SQL_HASH_VALUE to get the SQL statement from the library cache.

SELECT l.sid, l.sofar, l.totalwork, l.start_time, l.last_update_time, s.sql_text
FROM   v$session_longops l
       LEFT OUTER JOIN v$sql s ON s.hash_value = l.sql_hash_value
AND    s.address = l.sql_address
AND    s.child_number = 0

   SID      SOFAR  TOTALWORK START_TIME          LAST_UPDATE_TIME
------ ---------- ---------- ------------------- -------------------
SQL_TEXT
--------------------------------------------------------------------
    90      19014      26171 17:48:25 28/09/2007 17:48:37 28/09/2007
SELECT DISTINCT (PROCESSID) FROM PSAPMSGPUBHDR WHERE MACHINENAME=:1 
AND PUBSTATUS IN (:"SYS_B_0", :"SYS_B_1") ORDER BY PROCESSID

Aggregate total amount of time spent on SQL statements. But there is a problem, SQL statements can produce multiple long operations that may or may not occur concurrently.

SELECT  l.sql_hash_value
,     SUM(l.last_update_time-l.start_time)*86400 secs
,     COUNT(*) execs
FROM  v$session_longops l
GROUP BY l.sql_hash_value
ORDER BY secs

But what if the statement isn’t in the library cache we can try and get it out of statspack! This SQL function looks up the SQL statement by hash value and assembles the pieces up to 4000 characters

CREATE OR REPLACE FUNCTION perfstat.get_sqltext(p_hash_value NUMBER)
RETURN VARCHAR2 IS
 l_sql_text VARCHAR2(32767) := '';
 l_sql_left NUMBER := 4000;
BEGIN
 FOR i IN(SELECT * FROM perfstat.stats$sqltext 
          WHERE  hash_value = p_hash_value ORDER BY piece
 ) LOOP
  IF l_sql_left > 64 THEN
   l_sql_text := l_sql_text || i.sql_text;
  ELSIF l_sql_left > 0 THEN
   l_sql_text := l_sql_text || SUBSTR(i.sql_text,1,l_sql_left);
  END IF;
 l_sql_left := l_sql_left - LENGTH(i.sql_text);
END LOOP;
RETURN l_sql_text;
END get_sqltext;
/
show errors
GRANT EXECUTE ON perfstat.get_sqltext TO PUBLIC;

This version gets the SQL statement from library cache, and if it isn't there it looks it up from the statspack data.

spool longops
SELECT l.*, NVL(s.sql_text
     , perfstat.get_sqltext(l.sql_hash_value)) sql_text
FROM (
  SELECT l.target, l.operation, l.sql_hash_value
       , SUM(secs) secs, SUM(execs) execs
  FROM (
    SELECT l.sid, l.serial#, l.sql_address, l.sql_hash_value
    , l.target, l.operation
    , MAX(l.last_update_time-l.start_time)*86400 secs
    , COUNT(*) execs
    , SUM(totalwork) totalwork
    FROM (
      SELECT l.*
      , SUBSTR(l.message,1,instr(l.message,':',1,1)-1) operation 
      FROM   v$session_longops l) l
    GROUP BY l.sid, l.serial#, l.sql_address
           , l.sql_hash_value, l.target, l.operation
    ) l
  GROUP BY l.target, l.operation, l.sql_hash_value
  ) l
  LEFT OUTER JOIN v$sql s ON s.hash_value = l.sql_hash_value
--AND s.address = l.sql_address
AND  s.child_number = 0
ORDER BY secs desc
/
spool off

This is some sample output. This particular statement has been submitted by the publication servers 25 times with a cumulative execution time of 878 seconds.

TARGET
----------------------------------------------------------------
OPERATION
------------------------------------------------------------------
SQL_HASH_VALUE       SECS      EXECS
-------------- ---------- ----------
SQL_TEXT
------------------------------------------------------------------
SYSADM.PSAPMSGPUBCON
Table Scan
1297842315        878         25
SELECT :"SYS_B_0", MIN(B.MSGNAME), MIN(A.PUBCONSTATUS), COUNT(*) 
FROM PSAPMSGPUBCON A, PSAPMSGPUBHDR B WHERE A.PUBID = B.PUBID AND 
A.PUBNODE = B.PUBNODE AND A.CHNLNAME = B.CHNLNAME AND A.CHNLNAME 
IN (SELECT S.CHNLNAME FROM PS_AMM_CHNL_SECVW S WHERE S.OPRID = 
:"SYS_B_1") AND A.LASTUPDDTTM >= TO_DATE(SUBSTR(:"SYS_B_2", 
:"SYS_B_3", :"SYS_B_4"), :"SYS_B_5") GROUP BY B.MSGNAME, 
A.PUBCONSTATUS ORDER BY MIN(B.MSGNAME), MIN(A.PUBCONSTATUS)