V$SESSION_LONGOPS – Where’s My SQL Statement

9 03 2010

March 9, 2010

A question recently appeared on the OTN forums that stated the following:

I have a query joining 4 tables and it returns 48 million. I have used /+parallel(tablename,4) */ hint with the select clause. I want to the 48 million returned by the query to another table t2.

I do get the select result in 20 minutes. when I am performing insert, I checked gv$session_longops. I usually check like select * from gv$session_longops where time_remaining>0.

It didnt return anything. I removed the where clause and rather gave the sid.(i found the sql_id from gv$session)

select * from gv$session_longops where sql_id=’XXXXXXX';

I got 3 rows but time_remaining column is 0. Could someone explain why this is so.

OS: Linux
DB:11.1.0.6.0 – 11g
Rac- 2 node RAC

So what is happening, why does GV$SESSION_LONGOPS show 3 rows for the SQL statement, all with the TIME_REMAINING column set to 0?  This is a good question, but I do not know if there is a straight-forward answer for the question.  Possibly one of the first questions to ask is: What is the SQL statement, and what does its execution plan look like?

It probably makes sense to check the documentation for the GV$SESSION_LONGOPS view (or more accurately, the documentation for the single instance V$SESSION_LONGOPS view):

“V$SESSION_LONGOPS displays the status of various operations that run for longer than 6 seconds (in absolute time). These operations currently include many backup and recovery functions, statistics gathering, and query execution, and more operations are added for every Oracle release.

To monitor query execution progress, you must be using the cost-based optimizer and you must:

  • Set the TIMED_STATISTICS or SQL_TRACE parameters to true
  • Gather statistics for your objects with the ANALYZE statement or the DBMS_STATS package”

From the above, having the TIMED_STATISTICS parameter set to FALSE or failing to gather the statistics for the objects using DBMS_STATS are two possible reasons for the TIME_REMAINING column being set to 0.  Any other ideas?  Where is that SQL statement and execution plan when you need it?  Why ask for the execution plan?  From the documentation link you will notice that the view definition includes the SQL_PLAN_LINE_ID column, which refers to a specific line in the execution plan for the query.  From this bit of information, we just need to define what is considered an operation (and does it have to be an uninterrupted operation) – without parallel query we might be able to perform a couple of tests.  The definition of an operation and the 6 second rule might be very important.

We will use tables T3 and T4 from yesterday’s blog article since the original poster did not provide a SQL statement to reproduce the problem.  Consider the following query:

SELECT
  T3.C1,
  T3.C2,
  T4.C3
FROM
  T3,
  T4
WHERE
  TRUNC(T3.C2) BETWEEN TO_DATE('08-MAR-2009','DD-MON-YYYY')
    AND TO_DATE('01-JUL-2009','DD-MON-YYYY')
  AND T3.C2=T4.C2;

If we set the STATISTICS_LEVEL parameter to ALL at the session level, run the SQL statement, and then generate the DBMS_XPLAN for the last execution, we may see an execution plan that looks something like this:

SQL_ID  2d4f5x92axqgn, child number 0
-------------------------------------
SELECT    T3.C1,    T3.C2,    T4.C3  FROM    T3,    T4  WHERE   
TRUNC(T3.C2) BETWEEN TO_DATE('08-MAR-2009','DD-MON-YYYY')      AND
TO_DATE('01-JUL-2009','DD-MON-YYYY')    AND T3.C2=T4.C2

Plan hash value: 1396201636

-------------------------------------------------------------------------------------------------------------------------
| Id  | Operation          | Name | Starts | E-Rows | A-Rows |   A-Time   | Buffers | Reads  |  OMem |  1Mem | Used-Mem |
-------------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT   |      |      1 |        |    874K|00:03:31.20 |    3771K|   3763K|       |       |          |
|*  1 |  HASH JOIN         |      |      1 |    849K|    874K|00:03:31.20 |    3771K|   3763K|    33M|  5591K|   50M (0)|
|*  2 |   TABLE ACCESS FULL| T3   |      1 |    802K|    795K|00:02:32.69 |    2743K|   2743K|       |       |          |
|   3 |   TABLE ACCESS FULL| T4   |      1 |     25M|     25M|00:00:35.93 |    1028K|   1020K|       |       |          |
-------------------------------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   1 - access("T3"."C2"="T4"."C2")
   2 - filter((TRUNC(INTERNAL_FUNCTION("C2"))>=TO_DATE(' 2009-03-08 00:00:00', 'syyyy-mm-dd hh24:mi:ss') AND
              TRUNC(INTERNAL_FUNCTION("C2"))<=TO_DATE(' 2009-07-01 00:00:00', 'syyyy-mm-dd hh24:mi:ss')))

From the above, we are able to see that Oracle is reporting that the full table scan of table T3 required roughly 152.69 seconds and the full table scan of table T4 required roughly 35.93 seconds.  Assume that in another session we executed the following SQL statement roughly every 6 seconds while the above SQL statement was in the process of being executed:

SELECT
  SQL_ID,
  SQL_PLAN_HASH_VALUE HASH_VALUE,
  SQL_PLAN_LINE_ID LINE_ID,
  OPNAME,
  TARGET,
  TARGET_DESC,
  TIME_REMAINING,
  ELAPSED_SECONDS,
  SID,
  SERIAL#,
  USERNAME
FROM
  V$SESSION_LONGOPS
WHERE
  TIME_REMAINING>0;

The output of the above SQL statement might look something like the following:

SQL_ID        HASH_VALUE    LINE_ID OPNAME          TARGET          TARGET_DESC  TIME_REMAINING ELAPSED_SECONDS        SID    SERIAL#  USERNAME
------------- ---------- ---------- --------------- --------------- ------------ -------------- --------------- ---------- ----------  --------
2d4f5x92axqgn 1396201636          2 Table Scan      TESTUSER.T3                             104              53        159        909  TESTUSER

2d4f5x92axqgn 1396201636          2 Table Scan      TESTUSER.T3                              92              62        159        909  TESTUSER

2d4f5x92axqgn 1396201636          2 Table Scan      TESTUSER.T3                              82              73        159        909  TESTUSER

2d4f5x92axqgn 1396201636          2 Table Scan      TESTUSER.T3                              74              81        159        909  TESTUSER

2d4f5x92axqgn 1396201636          2 Table Scan      TESTUSER.T3                              59              95        159        909  TESTUSER

2d4f5x92axqgn 1396201636          2 Table Scan      TESTUSER.T3                              52             101        159        909  TESTUSER

2d4f5x92axqgn 1396201636          2 Table Scan      TESTUSER.T3                              41             112        159        909  TESTUSER

2d4f5x92axqgn 1396201636          2 Table Scan      TESTUSER.T3                              33             120        159        909  TESTUSER

2d4f5x92axqgn 1396201636          2 Table Scan      TESTUSER.T3                              23             131        159        909  TESTUSER

2d4f5x92axqgn 1396201636          2 Table Scan      TESTUSER.T3                              14             140        159        909  TESTUSER

2d4f5x92axqgn 1396201636          2 Table Scan      TESTUSER.T3                               5             148        159        909  TESTUSER

no rows selected

2d4f5x92axqgn 1396201636          3 Table Scan      TESTUSER.T4                              57              10        159        909  TESTUSER

2d4f5x92axqgn 1396201636          3 Table Scan      TESTUSER.T4                              42              18        159        909  TESTUSER

2d4f5x92axqgn 1396201636          3 Table Scan      TESTUSER.T4                              27              31        159        909  TESTUSER

2d4f5x92axqgn 1396201636          3 Table Scan      TESTUSER.T4                              18              41        159        909  TESTUSER

2d4f5x92axqgn 1396201636          3 Table Scan      TESTUSER.T4                               6              53        159        909  TESTUSER

2d4f5x92axqgn 1396201636          3 Table Scan      TESTUSER.T4                               6              57        159        909  TESTUSER

2d4f5x92axqgn 1396201636          3 Table Scan      TESTUSER.T4                               6              63        159        909  TESTUSER

2d4f5x92axqgn 1396201636          3 Table Scan      TESTUSER.T4                               6              70        159        909  TESTUSER

2d4f5x92axqgn 1396201636          3 Table Scan      TESTUSER.T4                               6              75        159        909  TESTUSER

2d4f5x92axqgn 1396201636          3 Table Scan      TESTUSER.T4                               6              81        159        909  TESTUSER

2d4f5x92axqgn 1396201636          3 Table Scan      TESTUSER.T4                               6              86        159        909  TESTUSER

no rows selected

From the above output it appears that the full table scan of table T3 required between 148 and 154 seconds.  At the point where the full table scan of T3 completed and the first couple of seconds (probably 6) of the full table scan of T4, the SQL statement executed in the second session returned no rows – after roughly 6 seconds of reading table T4, the query of V$SESSION_LONGOPS started reporting that table T4 was being read.  From the above it appears that the read of table T4 required between 86 and 94 seconds, yet that does not agree with the DBMS_XPLAN output – it appears that in the V$SESSION_LONGOPS output the hash join operation’s time is being reported as part of this elapsed time for reading table T4.

So, we have found a third possible reason for the rows in V$SESSION_LONGOPS appearing as 0 for the OP’s SQL statement – the line in the plan had not yet consumed 6 seconds of time, or the operation had already completed.

Let’s look at one of the other SQL statements from yesterday’s blog article:

SELECT
  T3.C1,
  T3.C2,
  T4.C3
FROM
  T3,
  T4
WHERE
  T3.C2 BETWEEN TO_DATE('08-MAR-2009','DD-MON-YYYY')
    AND TO_DATE('01-JUL-2009','DD-MON-YYYY') + (1-1/24/60/60)
  AND T3.C2=T4.C2;

This statement is equivalent to the previous SQL statement, except that it is able to use the index that exists on table T3.  The execution plan follows:

SQL_ID  539d93k50ruz3, child number 0
-------------------------------------
SELECT    T3.C1,    T3.C2,    T4.C3  FROM    T3,    T4  WHERE    T3.C2
BETWEEN TO_DATE('08-MAR-2009','DD-MON-YYYY')      AND
TO_DATE('01-JUL-2009','DD-MON-YYYY') + (1-1/24/60/60)    AND T3.C2=T4.C2

Plan hash value: 1243183227

--------------------------------------------------------------------------------------------------------------------------------
| Id  | Operation                     | Name      | Starts | E-Rows | A-Rows |   A-Time   | Buffers |  OMem |  1Mem | Used-Mem |
--------------------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT              |           |      1 |        |    874K|00:00:05.19 |   85051 |       |       |          |
|   1 |  MERGE JOIN                   |           |      1 |    795K|    874K|00:00:05.19 |   85051 |       |       |          |
|   2 |   TABLE ACCESS BY INDEX ROWID | T4        |      1 |    795K|    795K|00:00:01.69 |   51097 |       |       |          |
|*  3 |    INDEX RANGE SCAN           | IND_T4_C2 |      1 |    795K|    795K|00:00:00.42 |   10841 |       |       |          |
|*  4 |   SORT JOIN                   |           |    795K|    795K|    874K|00:00:02.11 |   33954 |    30M|  1977K|   26M (0)|
|   5 |    TABLE ACCESS BY INDEX ROWID| T3        |      1 |    795K|    795K|00:00:00.58 |   33954 |       |       |          |
|*  6 |     INDEX RANGE SCAN          | IND_T3_C2 |      1 |    795K|    795K|00:00:00.18 |    2114 |       |       |          |
--------------------------------------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   3 - access("T4"."C2">=TO_DATE(' 2009-03-08 00:00:00', 'syyyy-mm-dd hh24:mi:ss') AND "T4"."C2"<=TO_DATE(' 2009-07-01
              23:59:59', 'syyyy-mm-dd hh24:mi:ss'))
   4 - access("T3"."C2"="T4"."C2")
       filter("T3"."C2"="T4"."C2")
   6 - access("T3"."C2">=TO_DATE(' 2009-03-08 00:00:00', 'syyyy-mm-dd hh24:mi:ss') AND "T3"."C2"<=TO_DATE(' 2009-07-01
              23:59:59', 'syyyy-mm-dd hh24:mi:ss'))

The above SQL statement completed too quickly to report any time in the V$SESSION_LONGOPS view, so let’s set the ’08-MAR-2009′ date to ’08-MAR-2007′ and re-run the SQL statement.  For quite a bit of time the query of V$SESSION_LONGOPS only returned the following:

no rows selected

But the SQL statement was executing, why did it not appear in V$SESSION_LONGOPS – where is that link for reporting a bug on Metalink?  :-)  Or maybe, just maybe, Oracle is not performing any single operation in the execution plan continuously for more than 6 seconds (reading the index at ID 3 followed by the corresponding rows at ID 2, and then back to the index at ID 3 again).

Eventually, the following appeared after what must have been a minute or two:

SQL_ID        HASH_VALUE    LINE_ID OPNAME          TARGET          TARGET_DESC  TIME_REMAINING ELAPSED_SECONDS        SID    SERIAL# USERNAME
------------- ---------- ---------- --------------- --------------- ------------ -------------- --------------- ---------- ---------- --------
f3scvt222bu0t 1243183227          4 Sort Output                                            1194              12        159        909 TESTUSER

f3scvt222bu0t 1243183227          4 Sort Output                                            2115              22        159        909 TESTUSER

f3scvt222bu0t 1243183227          4 Sort Output                                            2115              22        159        909 TESTUSER
...
(in the above the last row continued to repeat with ELAPSED_SECONDS displayed as 22 for a minute or two)

Ready, aim,… hey – what is the TARGET.  The LINE_ID column (the SQL_PLAN_LINE_ID column in V$SESSION_LONGOPS) reported that Oracle is executing ID 4 of the execution plan.  I can’t explain why the last line remained in the V$SESSION_LONGOPS output for a minute or two (maybe someone else knows why).

So, we have found a fourth possible reason for the rows in V$SESSION_LONGOPS appearing as 0 for the OP’s SQL statement – it could be that Oracle was alternating between an index range scan and the retrieval of the matching rows from the corresponding table.

Let’s try executing the first query with a parallel hint to see what happens to the V$SESSION_LONGOPS output:

SELECT /*+ PARALLEL (T3, 4) PARALLEL (T4, 4) */
  T3.C1,
  T3.C2,
  T4.C3
FROM
  T3,
  T4
WHERE
  TRUNC(T3.C2) BETWEEN TO_DATE('08-MAR-2009','DD-MON-YYYY')
    AND TO_DATE('01-JUL-2009','DD-MON-YYYY')
  AND T3.C2=T4.C2;

The DBMS_XPLAN output for the query follows:

SQL_ID  dywt9v0xuvgyv, child number 0
-------------------------------------
SELECT /*+ PARALLEL (T3, 4) PARALLEL (T4, 4) */    T3.C1,    T3.C2,   
T4.C3  FROM    T3,    T4  WHERE    TRUNC(T3.C2) BETWEEN
TO_DATE('08-MAR-2009','DD-MON-YYYY')      AND
TO_DATE('01-JUL-2009','DD-MON-YYYY')    AND T3.C2=T4.C2

Plan hash value: 1800244878

-------------------------------------------------------------------------------------------------------------------------
| Id  | Operation               | Name     | Starts | E-Rows | A-Rows |   A-Time   | Buffers |  OMem |  1Mem | Used-Mem |
-------------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT        |          |      1 |        |    874K|00:03:49.60 |      14 |       |       |          |
|   1 |  PX COORDINATOR         |          |      1 |        |    874K|00:03:49.60 |      14 |       |       |          |
|   2 |   PX SEND QC (RANDOM)   | :TQ10001 |      0 |    849K|      0 |00:00:00.01 |       0 |       |       |          |
|*  3 |    HASH JOIN            |          |      0 |    849K|      0 |00:00:00.01 |       0 |   126M|    10M|   49M (0)|
|   4 |     PX RECEIVE          |          |      0 |    802K|      0 |00:00:00.01 |       0 |       |       |          |
|   5 |      PX SEND BROADCAST  | :TQ10000 |      0 |    802K|      0 |00:00:00.01 |       0 |       |       |          |
|   6 |       PX BLOCK ITERATOR |          |      0 |    802K|      0 |00:00:00.01 |       0 |       |       |          |
|*  7 |        TABLE ACCESS FULL| T3       |      0 |    802K|      0 |00:00:00.01 |       0 |       |       |          |
|   8 |     PX BLOCK ITERATOR   |          |      0 |     25M|      0 |00:00:00.01 |       0 |       |       |          |
|*  9 |      TABLE ACCESS FULL  | T4       |      0 |     25M|      0 |00:00:00.01 |       0 |       |       |          |
-------------------------------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   3 - access("T3"."C2"="T4"."C2")
   7 - access(:Z>=:Z AND :Z<=:Z)
       filter((TRUNC(INTERNAL_FUNCTION("C2"))>=TO_DATE(' 2009-03-08 00:00:00', 'syyyy-mm-dd hh24:mi:ss') AND
              TRUNC(INTERNAL_FUNCTION("C2"))<=TO_DATE(' 2009-07-01 00:00:00', 'syyyy-mm-dd hh24:mi:ss')))
   9 - access(:Z>=:Z AND :Z<=:Z)
       filter(SYS_OP_BLOOM_FILTER(:BF0000,"T4"."C2"))

A bloom filter, just in time for Spring (it must be true, it is in the Predicate Information section of the actual execution plan).

After roughly a 6 second delay, V$SESSION_LONGOPS was queried roughly every 6 seconds.  The output of the V$SESSION_LONGOPS query follows:

SQL_ID        HASH_VALUE    LINE_ID OPNAME           TARGET          TARGET_DESC TIME_REMAINING ELAPSED_SECONDS        SID    SERIAL# USERNAME
------------- ---------- ---------- ---------------- --------------- ----------- -------------- --------------- ---------- ---------- --------
dywt9v0xuvgyv 1800244878          7 Rowid Range Scan TESTUSER.T3                              8               7        553        243 TESTUSER
dywt9v0xuvgyv 1800244878          7 Rowid Range Scan TESTUSER.T3                              4               7         80        544 TESTUSER
dywt9v0xuvgyv 1800244878          7 Rowid Range Scan TESTUSER.T3                            114               7          7        251 TESTUSER
dywt9v0xuvgyv 1800244878          7 Rowid Range Scan TESTUSER.T3                             14               7        159        982 TESTUSER

SQL> /

SQL_ID        HASH_VALUE    LINE_ID OPNAME           TARGET          TARGET_DESC TIME_REMAINING ELAPSED_SECONDS        SID    SERIAL# USERNAME
------------- ---------- ---------- ---------------- --------------- ----------- -------------- --------------- ---------- ---------- --------
dywt9v0xuvgyv 1800244878          7 Rowid Range Scan TESTUSER.T3                              2              16        159        982 TESTUSER

SQL> /

SQL_ID        HASH_VALUE    LINE_ID OPNAME           TARGET          TARGET_DESC TIME_REMAINING ELAPSED_SECONDS        SID    SERIAL# USERNAME
------------- ---------- ---------- ---------------- --------------- ----------- -------------- --------------- ---------- ---------- --------
dywt9v0xuvgyv 1800244878          7 Rowid Range Scan TESTUSER.T3                              4               9        553        243 TESTUSER
dywt9v0xuvgyv 1800244878          7 Rowid Range Scan TESTUSER.T3                              1              13         80        544 TESTUSER
dywt9v0xuvgyv 1800244878          7 Rowid Range Scan TESTUSER.T3                              7               9          7        251 TESTUSER

SQL> /

SQL_ID        HASH_VALUE    LINE_ID OPNAME           TARGET          TARGET_DESC TIME_REMAINING ELAPSED_SECONDS        SID    SERIAL# USERNAME
------------- ---------- ---------- ---------------- --------------- ----------- -------------- --------------- ---------- ---------- --------
dywt9v0xuvgyv 1800244878          7 Rowid Range Scan TESTUSER.T3                             13               9         80        544 TESTUSER

SQL> /

SQL_ID        HASH_VALUE    LINE_ID OPNAME           TARGET          TARGET_DESC TIME_REMAINING ELAPSED_SECONDS        SID    SERIAL# USERNAME
------------- ---------- ---------- ---------------- --------------- ----------- -------------- --------------- ---------- ---------- --------
dywt9v0xuvgyv 1800244878          7 Rowid Range Scan TESTUSER.T3                              2              12        553        243 TESTUSER
dywt9v0xuvgyv 1800244878          7 Rowid Range Scan TESTUSER.T3                              7              10          7        251 TESTUSER
dywt9v0xuvgyv 1800244878          7 Rowid Range Scan TESTUSER.T3                              6               7        159        982 TESTUSER

SQL> /

SQL_ID        HASH_VALUE    LINE_ID OPNAME           TARGET          TARGET_DESC TIME_REMAINING ELAPSED_SECONDS        SID    SERIAL# USERNAME
------------- ---------- ---------- ---------------- --------------- ----------- -------------- --------------- ---------- ---------- --------
dywt9v0xuvgyv 1800244878          7 Rowid Range Scan TESTUSER.T3                              7               7        553        243 TESTUSER
dywt9v0xuvgyv 1800244878          7 Rowid Range Scan TESTUSER.T3                              4              10         80        544 TESTUSER

SQL> /

SQL_ID        HASH_VALUE    LINE_ID OPNAME           TARGET          TARGET_DESC TIME_REMAINING ELAPSED_SECONDS        SID    SERIAL# USERNAME
------------- ---------- ---------- ---------------- --------------- ----------- -------------- --------------- ---------- ---------- --------
dywt9v0xuvgyv 1800244878          7 Rowid Range Scan TESTUSER.T3                              2              13        159        982 TESTUSER

SQL> /

SQL_ID        HASH_VALUE    LINE_ID OPNAME           TARGET          TARGET_DESC TIME_REMAINING ELAPSED_SECONDS        SID    SERIAL# USERNAME
------------- ---------- ---------- ---------------- --------------- ----------- -------------- --------------- ---------- ---------- --------
dywt9v0xuvgyv 1800244878          7 Rowid Range Scan TESTUSER.T3                              4               9        553        243 TESTUSER
dywt9v0xuvgyv 1800244878          7 Rowid Range Scan TESTUSER.T3                              6              10          7        251 TESTUSER

SQL> /

SQL_ID        HASH_VALUE    LINE_ID OPNAME           TARGET          TARGET_DESC TIME_REMAINING ELAPSED_SECONDS        SID    SERIAL# USERNAME
------------- ---------- ---------- ---------------- --------------- ----------- -------------- --------------- ---------- ---------- --------
dywt9v0xuvgyv 1800244878          7 Rowid Range Scan TESTUSER.T3                             10               8         80        544 TESTUSER

SQL> /

SQL_ID        HASH_VALUE    LINE_ID OPNAME           TARGET          TARGET_DESC TIME_REMAINING ELAPSED_SECONDS        SID    SERIAL# USERNAME
------------- ---------- ---------- ---------------- --------------- ----------- -------------- --------------- ---------- ---------- --------
dywt9v0xuvgyv 1800244878          7 Rowid Range Scan TESTUSER.T3                              2              12        553        243 TESTUSER
dywt9v0xuvgyv 1800244878          7 Rowid Range Scan TESTUSER.T3                              1              16         80        544 TESTUSER
dywt9v0xuvgyv 1800244878          7 Rowid Range Scan TESTUSER.T3                              3              10          7        251 TESTUSER
dywt9v0xuvgyv 1800244878          7 Rowid Range Scan TESTUSER.T3                              6              10        159        982 TESTUSER

SQL> /

SQL_ID        HASH_VALUE    LINE_ID OPNAME           TARGET          TARGET_DESC TIME_REMAINING ELAPSED_SECONDS        SID    SERIAL# USERNAME
------------- ---------- ---------- ---------------- --------------- ----------- -------------- --------------- ---------- ---------- --------
dywt9v0xuvgyv 1800244878          7 Rowid Range Scan TESTUSER.T3                              6               8        553        243 TESTUSER
dywt9v0xuvgyv 1800244878          7 Rowid Range Scan TESTUSER.T3                              8               8         80        544 TESTUSER

SQL> /

SQL_ID        HASH_VALUE    LINE_ID OPNAME           TARGET          TARGET_DESC TIME_REMAINING ELAPSED_SECONDS        SID    SERIAL# USERNAME
------------- ---------- ---------- ---------------- --------------- ----------- -------------- --------------- ---------- ---------- --------
dywt9v0xuvgyv 1800244878          7 Rowid Range Scan TESTUSER.T3                              3              12        159        982 TESTUSER

SQL> /

SQL_ID        HASH_VALUE    LINE_ID OPNAME           TARGET          TARGET_DESC TIME_REMAINING ELAPSED_SECONDS        SID    SERIAL# USERNAME
------------- ---------- ---------- ---------------- --------------- ----------- -------------- --------------- ---------- ---------- --------
dywt9v0xuvgyv 1800244878          7 Rowid Range Scan TESTUSER.T3                              4              10        553        243 TESTUSER
dywt9v0xuvgyv 1800244878          7 Rowid Range Scan TESTUSER.T3                              5              10         80        544 TESTUSER
dywt9v0xuvgyv 1800244878          7 Rowid Range Scan TESTUSER.T3                              5               8          7        251 TESTUSER

SQL> /

SQL_ID        HASH_VALUE    LINE_ID OPNAME           TARGET          TARGET_DESC TIME_REMAINING ELAPSED_SECONDS        SID    SERIAL# USERNAME
------------- ---------- ---------- ---------------- --------------- ----------- -------------- --------------- ---------- ---------- --------
dywt9v0xuvgyv 1800244878          7 Rowid Range Scan TESTUSER.T3                              7               9        159        982 TESTUSER

SQL> /

SQL_ID        HASH_VALUE    LINE_ID OPNAME           TARGET          TARGET_DESC TIME_REMAINING ELAPSED_SECONDS        SID    SERIAL# USERNAME
------------- ---------- ---------- ---------------- --------------- ----------- -------------- --------------- ---------- ---------- --------
dywt9v0xuvgyv 1800244878          7 Rowid Range Scan TESTUSER.T3                              7               9        159        982 TESTUSER

SQL> /

SQL_ID        HASH_VALUE    LINE_ID OPNAME           TARGET          TARGET_DESC TIME_REMAINING ELAPSED_SECONDS        SID    SERIAL# USERNAME
------------- ---------- ---------- ---------------- --------------- ----------- -------------- --------------- ---------- ---------- --------
dywt9v0xuvgyv 1800244878          7 Rowid Range Scan TESTUSER.T3                              7               9        159        982 TESTUSER

SQL> /

SQL_ID        HASH_VALUE    LINE_ID OPNAME           TARGET          TARGET_DESC TIME_REMAINING ELAPSED_SECONDS        SID    SERIAL# USERNAME
------------- ---------- ---------- ---------------- --------------- ----------- -------------- --------------- ---------- ---------- --------
dywt9v0xuvgyv 1800244878          7 Rowid Range Scan TESTUSER.T3                              7               9        159        982 TESTUSER

SQL> /

SQL_ID        HASH_VALUE    LINE_ID OPNAME           TARGET          TARGET_DESC TIME_REMAINING ELAPSED_SECONDS        SID    SERIAL# USERNAME
------------- ---------- ---------- ---------------- --------------- ----------- -------------- --------------- ---------- ---------- --------
dywt9v0xuvgyv 1800244878          7 Rowid Range Scan TESTUSER.T3                              7               9        159        982 TESTUSER

SQL> /

SQL_ID        HASH_VALUE    LINE_ID OPNAME           TARGET          TARGET_DESC TIME_REMAINING ELAPSED_SECONDS        SID    SERIAL# USERNAME
------------- ---------- ---------- ---------------- --------------- ----------- -------------- --------------- ---------- ---------- --------
dywt9v0xuvgyv 1800244878          7 Rowid Range Scan TESTUSER.T3                              7               9        159        982 TESTUSER

SQL> /

SQL_ID        HASH_VALUE    LINE_ID OPNAME           TARGET          TARGET_DESC TIME_REMAINING ELAPSED_SECONDS        SID    SERIAL# USERNAME
------------- ---------- ---------- ---------------- --------------- ----------- -------------- --------------- ---------- ---------- --------
dywt9v0xuvgyv 1800244878          7 Rowid Range Scan TESTUSER.T3                              7               9        159        982 TESTUSER

SQL> /

SQL_ID        HASH_VALUE    LINE_ID OPNAME           TARGET          TARGET_DESC TIME_REMAINING ELAPSED_SECONDS        SID    SERIAL# USERNAME
------------- ---------- ---------- ---------------- --------------- ----------- -------------- --------------- ---------- ---------- --------
dywt9v0xuvgyv 1800244878          7 Rowid Range Scan TESTUSER.T3                              2              57         80        544 TESTUSER
dywt9v0xuvgyv 1800244878          7 Rowid Range Scan TESTUSER.T3                             20              66        159        982 TESTUSER

SQL> /

no rows selected

SQL> /

no rows selected

SQL> /

no rows selected

SQL> /

no rows selected

SQL> /

no rows selected

SQL> /

no rows selected

SQL> /

no rows selected

SQL> /

SQL_ID        HASH_VALUE    LINE_ID OPNAME           TARGET          TARGET_DESC TIME_REMAINING ELAPSED_SECONDS        SID    SERIAL# USERNAME
------------- ---------- ---------- ---------------- --------------- ----------- -------------- --------------- ---------- ---------- --------
dywt9v0xuvgyv 1800244878          9 Rowid Range Scan TESTUSER.T4                              9               8         81       1204 TESTUSER
dywt9v0xuvgyv 1800244878          9 Rowid Range Scan TESTUSER.T4                              4               7        395        631 TESTUSER

SQL> /

SQL_ID        HASH_VALUE    LINE_ID OPNAME           TARGET          TARGET_DESC TIME_REMAINING ELAPSED_SECONDS        SID    SERIAL# USERNAME
------------- ---------- ---------- ---------------- --------------- ----------- -------------- --------------- ---------- ---------- --------
dywt9v0xuvgyv 1800244878          9 Rowid Range Scan TESTUSER.T4                             69              13        160         32 TESTUSER
dywt9v0xuvgyv 1800244878          9 Rowid Range Scan TESTUSER.T4                             12              16         81       1204 TESTUSER
dywt9v0xuvgyv 1800244878          9 Rowid Range Scan TESTUSER.T4                              5              15        395        631 TESTUSER
dywt9v0xuvgyv 1800244878          9 Rowid Range Scan TESTUSER.T4                             71              13        238         31 TESTUSER

SQL> /

SQL_ID        HASH_VALUE    LINE_ID OPNAME           TARGET          TARGET_DESC TIME_REMAINING ELAPSED_SECONDS        SID    SERIAL# USERNAME
------------- ---------- ---------- ---------------- --------------- ----------- -------------- --------------- ---------- ---------- --------
dywt9v0xuvgyv 1800244878          9 Rowid Range Scan TESTUSER.T4                             11              25         81       1204 TESTUSER
dywt9v0xuvgyv 1800244878          9 Rowid Range Scan TESTUSER.T4                              4              24        395        631 TESTUSER
dywt9v0xuvgyv 1800244878          9 Rowid Range Scan TESTUSER.T4                             58              22        238         31 TESTUSER

SQL> /

SQL_ID        HASH_VALUE    LINE_ID OPNAME           TARGET          TARGET_DESC TIME_REMAINING ELAPSED_SECONDS        SID    SERIAL# USERNAME
------------- ---------- ---------- ---------------- --------------- ----------- -------------- --------------- ---------- ---------- --------
dywt9v0xuvgyv 1800244878          9 Rowid Range Scan TESTUSER.T4                              7              33         81       1204 TESTUSER

SQL> /

no rows selected

As you can see from the above, the parallel query processes (each with a different SID) appear, and disappear from the V$SESSION_LONGOPS output as the query executes.  The output shows a roughly 40 to 50 second time period during the execution of the query in the first session where nothing appeared in the V$SESSION_LONGOPS output.

So, we have found a fifth possible reason for the rows in V$SESSION_LONGOPS appearing as 0 for the OP’s SQL statement – the OP may have just queried V$SESSION_LONGOPS at the wrong time.

Any other possible reasons why the OP would see 0 for the TIME_REMAINING column when querying V$SESSION_LONGOPS during the execution of a SQL statement that is expected to require 20 minutes to complete?








Follow

Get every new post delivered to your Inbox.

Join 144 other followers