Drilling into Session Detail from the Operating System – On the Windows Platform

9 01 2010

January 9, 2010

(Forward to the Follow-Up Article)

As you might be aware, Oracle running on Unix/Linux uses a process model, while Oracle running on Windows uses a thread model.  With the process model it is fairly easy to use operating system tools, such as ps or top, to monitor the performance of individual database sessions, and then the DBA can use that information to manually drill back into what the high utilization sessions are doing.  Unfortunately, with the thread model, that procedure is impossible.  Unless, of course, you know a trick.

In one of the two chapters of the Expert Oracle Practices book, Randolf and I stated the following:

“In the case of performance problems caused by Oracle-related processes, consider drilling into the Oracle process activity by using the operating system process identifier (PID) to search V$PROCESS for a matching PID, and then join to V$SESSION on V$PROCESS.ADDR=V$SESSION.PADDR.”

I think that we also stated somewhere in the chapters that WMI queries could be used to drill into the session level activity on the Windows platform.  We did not provide a script to demonstrate the process – the chapters were running long by a couple pages (OK more than a couple if you have seen the chapters), so we did not bother to construct a demonstration.  I played with the idea a little, and then decided that the 10 to 20 pages it would take to describe the process could be better used for something else.

So, let’s play a game of bury the poor Windows box (this happens to be a computer with a dual core CPU).  It would be neat, if we have 20 database instances running on this poor Windows box, to play a game of Whose Got My CPU (R).  So, it would be neat if we could send something like this out to a command line window:

1/8/2010 12:47:18 PM Processes: 73 Threads: 880 C. Switches: 10573606 Q. Length: 7
Instance: c:\oracle\product\10.2.0\db_1\bin\ORACLE.EXE OR10
 User Time: 668.4S Sys  Time: 295.9S Memory: 275.59MB Page File: 0.63MB
  Handle: 1444 User Time: 663.32S Sys  Time: 296.99S ElapsedTime: 3358S Priority: 8 ThreadState: In Run Queue

Instance: c:\oracle\product\11.1.0\db_1\bin\ORACLE.EXE OR11
 User Time: 2959.84S Sys  Time: 11.73S Memory: 539.5MB Page File: 0.67MB
  Handle: 3520 User Time: 1081.91S Sys  Time: 0.92S ElapsedTime: 3238S Priority: 8 ThreadState: Running

The above states that at 12:47 there were 73 processes running on this poor Windows box with 880 process threads.  There were 10,573,606 context switches over some period of time, and the run queue length is currently 7 (could this be a sign of a problem on a computer with a single dual core CPU – no, can’t be – someone on the Internet said that pushing the CPUs to 100% utilization is desirable, and because it is on the Internet, it must be true).

Next, the above output shows that an Oracle 10.2.0.x database instance was found (OR10).  This instance had consumed 668.4 seconds of CPU time in user mode, and 295.9 seconds of CPU time in system (kernel) mode – that system mode time seems to be high compared to the user mode time.  The instance was using about 276MB of memory. A single thread representing a dedicated connection was created 33,585 seconds earlier (that might be a calculation error – looks like I should have divided that number by 10).  That thread has used 663.32 seconds of user mode CPU time, and 296.99 seconds of system (kernel) mode CPU time.  The thread had a scheduling priority of 8 assigned to it and at the time was sitting in the run queue waiting for the CPU to become available.

Next, the above output shows that an Oracle 11.1.0.x database instance was found (OR11).  This instance consumed 2959.84 seconds of CPU time in user mode, and 11.73 second of CPU time in system (kernel) mode.  The instance was using about 540MB of memory.   A single thread representing a dedicated session was created 32,385 seconds earlier.  That thread had used 1081.91 seconds of user mode CPU time (about 1/3 of the total for the instance) and 0.92 seconds of system (kernel) mode CPU time.  The thread had a scheduling priority of 8 assigned to it and at the time was running on the CPU (something else must have been running on the other CPU core – possibly the script that collected this data).

OK, the above is kind of neat, but what are the sessions doing that caused the CPU usage?  I don’t have the SID and SERIAL# for the sessions, so I can’t enable a 10046 trace.  It will take too long to fire up a GUI of some sort to see what is happening.  I wonder if I can do anything with the handle number that was output?  Well, I read the chapters that Randolf and I wrote, and that Handle just so happens to be treated like the PID on Oracle platforms that use a process model.  So, I could do all kinds of interesting things once I resolve the displayed Handle to a SID.  For instance, I could do something like this:

1/8/2010 12:47:18 PM Processes: 73 Threads: 880 C. Switches: 10573606 Q. Length: 7
Instance: c:\oracle\product\10.2.0\db_1\bin\ORACLE.EXE OR10
 User Time: 668.4S Sys  Time: 295.9S Memory: 275.59MB Page File: 0.63MB
  Handle: 1444 User Time: 663.32S Sys  Time: 296.99S ElapsedTime: 3358S Priority: 8 ThreadState: In Run Queue

Instance: c:\oracle\product\11.1.0\db_1\bin\ORACLE.EXE OR11
 User Time: 2959.84S Sys  Time: 11.73S Memory: 539.5MB Page File: 0.67MB
  Handle: 3520 User Time: 1081.91S Sys  Time: 0.92S ElapsedTime: 3238S Priority: 8 ThreadState: Running
   PID:18 SPID:3520 SID:146 SERIAL#:4 USERNAME:TESTUSER MACHINE:HOME.NET\AIRFORCE-3 PROGRAM:sqlplus.exe
   SELECT   TOP_LEVEL_PART_ID, REQ.PURC_PART_ID, REQ.TOTAL_QTY,   REQ.TOTAL_QTY*TPPD.INCREASE "Increase",   REQ.R1_PART_ID, REQ.R2_PART_ID,...

    SQL_ID  3p1v051atxt1z, child number 0
    -------------------------------------
    SELECT   TOP_LEVEL_PART_ID, REQ.PURC_PART_ID, REQ.TOTAL_QTY,  
    REQ.TOTAL_QTY*TPPD.INCREASE "Increase",   REQ.R1_PART_ID,
    REQ.R2_PART_ID, REQ.R3_PART_ID,   REQ.R4_PART_ID, REQ.R5_PART_ID,
    REQ.R6_PART_ID,   REQ.R1_CALC_QTY, REQ.R2_CALC_QTY, REQ.R3_CALC_QTY,  
    REQ.R4_CALC_QTY, REQ.R5_CALC_QTY, REQ.R6_CALC_QTY FROM   (SELECT    
    TOP_LEVEL_PART_ID,     DECODE(R6_PART_ID,NULL,      
    DECODE(R5_PART_ID,NULL,         DECODE(R4_PART_ID,NULL,          
    DECODE(R3_PART_ID,NULL,             DECODE(R2_PART_ID,NULL,            
           R1_PART_ID,R2_PART_ID),                  R3_PART_ID),           
        R4_PART_ID),              R5_PART_ID),            R6_PART_ID)
    PURC_PART_ID,     NVL(R1_CALC_QTY,0)*NVL(R2_CALC_QTY,1)*NVL(R3_CALC_QTY,
    1)*NVL(R4_CALC_QTY,1)*NVL(R5_CALC_QTY,1)*NVL(R6_CALC_QTY,1) TOTAL_QTY, 
       R1_PART_ID, R1_CALC_QTY, R2_PART_ID, R2_CALC_QTY, R3_PART_ID,
    R3_CALC_QTY,     R4_PART_ID, R4_CALC_QTY, R5_PART_ID, R5_CALC_QTY,
    R6_PART_ID, R6_CALC_QTY   FROM     (SELECT       PL.PART_ID TOP_LEVE

    Plan hash value: 3313542492

    ---------------------------------------------------------------------------------------------------------------------------------
    | Id  | Operation                                       | Name                 | Rows  | Bytes | Cost (%CPU)| Time     | Inst   |
    ---------------------------------------------------------------------------------------------------------------------------------
    |   0 | SELECT STATEMENT                                |                      |       |       |   101 (100)|          |        |
    |   1 |  VIEW                                           | VM_NWVW_1            |     1 |   225 |   101   (2)| 00:00:02 |   OR11 |
    |   2 |   HASH UNIQUE                                   |                      |     1 |   498 |   101   (2)| 00:00:02 |        |
    |   3 |    NESTED LOOPS OUTER                           |                      |     1 |   498 |   100   (1)| 00:00:02 |        |
    |*  4 |     FILTER                                      |                      |       |       |            |          |        |
    |   5 |      NESTED LOOPS OUTER                         |                      |     1 |   474 |    99   (2)| 00:00:02 |        |
    |   6 |       NESTED LOOPS OUTER                        |                      |     1 |   435 |    96   (2)| 00:00:02 |        |
    |   7 |        NESTED LOOPS OUTER                       |                      |     1 |   411 |    95   (2)| 00:00:02 |        |
    |*  8 |         FILTER                                  |                      |       |       |            |          |        |
    |   9 |          NESTED LOOPS OUTER                     |                      |     1 |   387 |    94   (2)| 00:00:02 |        |
    |* 10 |           FILTER                                |                      |       |       |            |          |        |
    |  11 |            NESTED LOOPS OUTER                   |                      |     1 |   348 |    91   (2)| 00:00:02 |        |
    |  12 |             NESTED LOOPS OUTER                  |                      |     1 |   309 |    88   (2)| 00:00:02 |        |
    |  13 |              NESTED LOOPS OUTER                 |                      |     1 |   285 |    87   (2)| 00:00:02 |        |
    |  14 |               NESTED LOOPS OUTER                |                      |     1 |   261 |    86   (2)| 00:00:02 |        |
    |* 15 |                FILTER                           |                      |       |       |            |          |        |
    |  16 |                 NESTED LOOPS OUTER              |                      |     1 |   237 |    85   (2)| 00:00:02 |        |
    |* 17 |                  FILTER                         |                      |       |       |            |          |        |
    |  18 |                   NESTED LOOPS OUTER            |                      |     1 |   198 |    82   (2)| 00:00:01 |        |
    |  19 |                    NESTED LOOPS                 |                      |     1 |   159 |    79   (2)| 00:00:01 |        |
    |  20 |                     NESTED LOOPS                |                      |     1 |   118 |    76   (2)| 00:00:01 |        |
    |  21 |                      MERGE JOIN CARTESIAN       |                      |     1 |    94 |    71   (2)| 00:00:01 |        |
    |* 22 |                       TABLE ACCESS FULL         | TEMP_PART_PRICE_DATE |     1 |    85 |     2   (0)| 00:00:01 |   OR11 |
    |  23 |                       BUFFER SORT               |                      |  7016 | 63144 |    69   (2)| 00:00:01 |        |
    |* 24 |                        TABLE ACCESS FULL        | CUSTOMER_ORDER       |  7016 | 63144 |    69   (2)| 00:00:01 |   OR11 |
    |* 25 |                      TABLE ACCESS BY INDEX ROWID| CUST_ORDER_LINE      |     1 |    24 |     5   (0)| 00:00:01 |   OR11 |
    |* 26 |                       INDEX RANGE SCAN          | SYS_C0028623         |     9 |       |     1   (0)| 00:00:01 |   OR11 |
    |  27 |                     TABLE ACCESS BY INDEX ROWID | REQUIREMENT          |     1 |    41 |     3   (0)| 00:00:01 |   OR11 |
    |* 28 |                      INDEX RANGE SCAN           | X_REQUIREMENT_5      |     1 |       |     2   (0)| 00:00:01 |   OR11 |
    |  29 |                    TABLE ACCESS BY INDEX ROWID  | REQUIREMENT          |     1 |    39 |     3   (0)| 00:00:01 |   OR11 |
    |* 30 |                     INDEX RANGE SCAN            | SYS_C0028831         |     1 |       |     2   (0)| 00:00:01 |   OR11 |
    |  31 |                  TABLE ACCESS BY INDEX ROWID    | REQUIREMENT          |     1 |    39 |     3   (0)| 00:00:01 |   OR11 |
    |* 32 |                   INDEX RANGE SCAN              | SYS_C0028831         |     1 |       |     2   (0)| 00:00:01 |   OR11 |
    |* 33 |                TABLE ACCESS BY INDEX ROWID      | PART                 |     1 |    24 |     1   (0)| 00:00:01 |   OR11 |
    |* 34 |                 INDEX UNIQUE SCAN               | SYS_C0028742         |     1 |       |     0   (0)|          |   OR11 |
    |* 35 |               TABLE ACCESS BY INDEX ROWID       | PART                 |     1 |    24 |     1   (0)| 00:00:01 |   OR11 |
    |* 36 |                INDEX UNIQUE SCAN                | SYS_C0028742         |     1 |       |     0   (0)|          |   OR11 |
    |* 37 |              TABLE ACCESS BY INDEX ROWID        | PART                 |     1 |    24 |     1   (0)| 00:00:01 |   OR11 |
    |* 38 |               INDEX UNIQUE SCAN                 | SYS_C0028742         |     1 |       |     0   (0)|          |   OR11 |
    |  39 |             TABLE ACCESS BY INDEX ROWID         | REQUIREMENT          |     1 |    39 |     3   (0)| 00:00:01 |   OR11 |
    |* 40 |              INDEX RANGE SCAN                   | SYS_C0028831         |     1 |       |     2   (0)| 00:00:01 |   OR11 |
    |  41 |           TABLE ACCESS BY INDEX ROWID           | REQUIREMENT          |     1 |    39 |     3   (0)| 00:00:01 |   OR11 |
    |* 42 |            INDEX RANGE SCAN                     | SYS_C0028831         |     1 |       |     2   (0)| 00:00:01 |   OR11 |
    |* 43 |         TABLE ACCESS BY INDEX ROWID             | PART                 |     1 |    24 |     1   (0)| 00:00:01 |   OR11 |
    |* 44 |          INDEX UNIQUE SCAN                      | SYS_C0028742         |     1 |       |     0   (0)|          |   OR11 |
    |* 45 |        TABLE ACCESS BY INDEX ROWID              | PART                 |     1 |    24 |     1   (0)| 00:00:01 |   OR11 |
    |* 46 |         INDEX UNIQUE SCAN                       | SYS_C0028742         |     1 |       |     0   (0)|          |   OR11 |
    |  47 |       TABLE ACCESS BY INDEX ROWID               | REQUIREMENT          |     1 |    39 |     3   (0)| 00:00:01 |   OR11 |
    |* 48 |        INDEX RANGE SCAN                         | SYS_C0028831         |     1 |       |     2   (0)| 00:00:01 |   OR11 |
    |* 49 |     TABLE ACCESS BY INDEX ROWID                 | PART                 |     1 |    24 |     1   (0)| 00:00:01 |   OR11 |
    |* 50 |      INDEX UNIQUE SCAN                          | SYS_C0028742         |     1 |       |     0   (0)|          |   OR11 |
    ---------------------------------------------------------------------------------------------------------------------------------

    Predicate Information (identified by operation id):
    ---------------------------------------------------

       4 - filter(("TPPD"."PART_ID"=DECODE(DECODE(DECODE(DECODE(DECODE(DECODE(NVL("P"."FABRICATED",'NONE'),'Y',"R2"."PART_ID"
                  ,NULL),NULL,NULL,DECODE(NVL("P2"."FABRICATED",'NONE'),'Y',"R3"."PART_ID",NULL)),NULL,NULL,DECODE(NVL("P3"."FABRICATED",'N
                  ONE'),'Y',"R4"."PART_ID",NULL)),NULL,NULL,DECODE(NVL("P4"."FABRICATED",'NONE'),'Y',"R5"."PART_ID",NULL)),NULL,NULL,DECODE
                  (NVL("P5"."FABRICATED",'NONE'),'Y',"R6"."PART_ID",NULL)),NULL,DECODE(DECODE(DECODE(DECODE(DECODE(NVL("P"."FABRICATED",'NO
                  NE'),'Y',"R2"."PART_ID",NULL),NULL,NULL,DECODE(NVL("P2"."FABRICATED",'NONE'),'Y',"R3"."PART_ID",NULL)),NULL,NULL,DECODE(N
                  VL("P3"."FABRICATED",'NONE'),'Y',"R4"."PART_ID",NULL)),NULL,NULL,DECODE(NVL("P4"."FABRICATED",'NONE'),'Y',"R5"."PART_ID",
                  NULL)),NULL,DECODE(DECODE(DECODE(DECODE(NVL("P"."FABRICATED",'NONE'),'Y',"R2"."PART_ID",NULL),NULL,NULL,DECODE(NVL("P2"."
                  FABRICATED",'NONE'),'Y',"R3"."PART_ID",NULL)),NULL,NULL,DECODE(NVL("P3"."FABRICATED",'NONE'),'Y',"R4"."PART_ID",NULL)),NU
                  LL,DECODE(DECODE(DECODE(NVL("P"."FABRICATED",'NONE'),'Y',"R2"."PART_ID",NULL),NULL,NULL,DECODE(NVL("P2"."FABRICATED",'NON
                  E'),'Y',"R3"."PART_ID",NULL)),NULL,DECODE(DECODE(NVL("P"."FABRICATED",'NONE'),'Y',"R2"."PART_ID",NULL),NULL,"R"."PART_ID"
                  ,DECODE(NVL("P"."FABRICATED",'NONE'),'Y',"R2"."PART_ID",NULL)),DECODE(DECODE(NVL("P"."FABRICATED",'NONE'),'Y',"R2"."PART_
                  ID",NULL),NULL,NULL,DECODE(NVL("P2"."FABRICATED",'NONE'),'Y',"R3"."PART_ID",NULL))),DECODE(DECODE(DECODE(NVL("P"."FABRICA
                  TED",'NONE'),'Y',"R2"."PART_ID",NULL),NULL,NULL,DECODE(NVL("P2"."FABRICATED",'NONE'),'Y',"R3"."PART_ID",NULL)),NULL,NULL,
                  DECODE(NVL("P3"."FABRICATED",'NONE'),'Y',"R4"."PART_ID",NULL))),DECODE(DECODE(DECODE(DECODE(NVL("P"."FABRICATED",'NONE'),
                  'Y',"R2"."PART_ID",NULL),NULL,NULL,DECODE(NVL("P2"."FABRICATED",'NONE'),'Y',"R3"."PART_ID",NULL)),NULL,NULL,DECODE(NVL("P
                  3"."FABRICATED",'NONE'),'Y',"R4"."PART_ID",NULL)),NULL,NULL,DECODE(NVL("P4"."FABRICATED",'NONE'),'Y',"R5"."PART_ID",NULL)
                  )),DECODE(DECODE(DECODE(DECODE(DECODE(NVL("P"."FABRICATED",'NONE'),'Y',"R2"."PART_ID",NULL),NULL,NULL,DECODE(NVL("P2"."FA
                  BRICATED",'NONE'),'Y',"R3"."PART_ID",NULL)),NULL,NULL,DECODE(NVL("P3"."FABRICATED",'NONE'),'Y',"R4"."PART_ID",NULL)),NULL
                  ,NULL,DECODE(NVL("P4"."FABRICATED",'NONE'),'Y',"R5"."PART_ID",NULL)),NULL,NULL,DECODE(NVL("P5"."FABRICATED",'NONE'),'Y',"
                  R6"."PART_ID",NULL))) AND "R6"."SUBORD_WO_SUB_ID" IS NULL))
       8 - filter("R5"."SUBORD_WO_SUB_ID" IS NULL)
      10 - filter("R4"."SUBORD_WO_SUB_ID" IS NULL)
      15 - filter("R3"."SUBORD_WO_SUB_ID" IS NULL)
      17 - filter("R2"."SUBORD_WO_SUB_ID" IS NULL)
      22 - filter("TPPD"."INCREASE"<>0)
      24 - filter(("CO"."STATUS"='C' OR "CO"."STATUS"='F' OR "CO"."STATUS"='P' OR "CO"."STATUS"='R' OR "CO"."STATUS"='U'))
      25 - filter("COL"."DESIRED_SHIP_DATE">SYSDATE@!-365)
      26 - access("CO"."ID"="COL"."CUST_ORDER_ID")
      28 - access("R"."WORKORDER_TYPE"='M' AND "COL"."PART_ID"="R"."WORKORDER_BASE_ID" AND "R"."WORKORDER_LOT_ID"='0' AND
                  "R"."WORKORDER_SPLIT_ID"='0' AND "R"."SUBORD_WO_SUB_ID" IS NULL)
      30 - access("R2"."WORKORDER_TYPE"='M' AND "R"."PART_ID"="R2"."WORKORDER_BASE_ID" AND "R2"."WORKORDER_LOT_ID"='0')
      32 - access("R3"."WORKORDER_TYPE"='M' AND "R2"."PART_ID"="R3"."WORKORDER_BASE_ID" AND "R3"."WORKORDER_LOT_ID"='0')
      33 - filter("P3"."FABRICATED"='Y')
      34 - access("R3"."PART_ID"="P3"."ID")
      35 - filter("P"."FABRICATED"='Y')
      36 - access("R"."PART_ID"="P"."ID")
      37 - filter("P2"."FABRICATED"='Y')
      38 - access("R2"."PART_ID"="P2"."ID")
      40 - access("R4"."WORKORDER_TYPE"='M' AND "R3"."PART_ID"="R4"."WORKORDER_BASE_ID" AND "R4"."WORKORDER_LOT_ID"='0')
      42 - access("R5"."WORKORDER_TYPE"='M' AND "R4"."PART_ID"="R5"."WORKORDER_BASE_ID" AND "R5"."WORKORDER_LOT_ID"='0')
      43 - filter("P4"."FABRICATED"='Y')
      44 - access("R4"."PART_ID"="P4"."ID")
      45 - filter("P5"."FABRICATED"='Y')
      46 - access("R5"."PART_ID"="P5"."ID")
      48 - access("R6"."WORKORDER_TYPE"='M' AND "R5"."PART_ID"="R6"."WORKORDER_BASE_ID" AND "R6"."WORKORDER_LOT_ID"='0')
      49 - filter("P6"."FABRICATED"='Y')
      50 - access("R6"."PART_ID"="P6"."ID")

  Handle: 2152 User Time: 983.26S Sys  Time: 2.74S ElapsedTime: 3209S Priority: 8 ThreadState: In Run Queue
   PID:19 SPID:2152 SID:145 SERIAL#:12 USERNAME:TESTUSER MACHINE:HOME.NET\AIRFORCE-3 PROGRAM:sqlplus.exe
   INSERT INTO T1 SELECT   CEIL(ABS(SIN(ROWNUM/9.9999)*10000)),   'This is the long description for this number '|| TO_CHAR(CEIL(ABS(SIN(ROWNUM/9.9999)*10000)))...

    SQL_ID  6hxcgpp1rd1ag, child number 0
    -------------------------------------
    INSERT INTO T1 SELECT   CEIL(ABS(SIN(ROWNUM/9.9999)*10000)),   'This is
    the long description for this number '||
    TO_CHAR(CEIL(ABS(SIN(ROWNUM/9.9999)*10000))) FROM   (SELECT     ROWNUM
    RN   FROM     DUAL   CONNECT BY     LEVEL<=10000),   (SELECT     ROWNUM
    RN   FROM     DUAL   CONNECT BY     LEVEL<=10000)

    Plan hash value: 643243249

    -----------------------------------------------------------------------------------
    | Id  | Operation                          | Name | Rows  | Cost (%CPU)| Time     |
    -----------------------------------------------------------------------------------
    |   0 | INSERT STATEMENT                   |      |       |     4 (100)|          |
    |   1 |  LOAD TABLE CONVENTIONAL           |      |       |            |          |
    |   2 |   COUNT                            |      |       |            |          |
    |   3 |    MERGE JOIN CARTESIAN            |      |     1 |     4   (0)| 00:00:01 |
    |   4 |     VIEW                           |      |     1 |     2   (0)| 00:00:01 |
    |   5 |      COUNT                         |      |       |            |          |
    |   6 |       CONNECT BY WITHOUT FILTERING |      |       |            |          |
    |   7 |        FAST DUAL                   |      |     1 |     2   (0)| 00:00:01 |
    |   8 |     BUFFER SORT                    |      |     1 |     4   (0)| 00:00:01 |
    |   9 |      VIEW                          |      |     1 |     2   (0)| 00:00:01 |
    |  10 |       COUNT                        |      |       |            |          |
    |  11 |        CONNECT BY WITHOUT FILTERING|      |       |            |          |
    |  12 |         FAST DUAL                  |      |     1 |     2   (0)| 00:00:01 |
    -----------------------------------------------------------------------------------

  Handle: 5960 User Time: 532.46S Sys  Time: 0.98S ElapsedTime: 1676S Priority: 8 ThreadState: Idle
   PID:20 SPID:5960 SID:132 SERIAL#:55 USERNAME:TESTUSER MACHINE:HOME.NET\AIRFORCE-3 PROGRAM:sqlplus.exe

Neat, for one of the database instances I am able to see the PID and SPID (in case I want to use SQLPLUS’ ORADEBUG), as well as the SID and SERIAL# (in case I want to enable a 10046 trace).  While I only retrieved the SQL statement being executed and its plan, I could have done a lot of other things also to investigate what is happening in the sessions.  I just need to find a way to log into the database to accomplish the above – note that in the above, I only logged into one database in the script. Having the CPU consumed since the thread started might be helpful, but it would be better to know how much was consumed in a particular time period, for instance the last couple minutes.  With a loop in the script, we can accomplish this task.  The script output continues (something is happening in the 10.2.0.x session, compare the user mode time with the system (kernel) mode time for this time period):

1/8/2010 12:48:31 PM Processes: 73 Threads: 866 C. Switches: 53465 Q. Length: 4
Instance: c:\oracle\product\10.2.0\db_1\bin\ORACLE.EXE OR10
 User Time: 10.75S Sys  Time: 25.27S Memory: 275.59MB Page File: 0.63MB
  Handle: 1444 User Time: 11.37S Sys  Time: 26.88S ElapsedTime: 78S Priority: 8 ThreadState: In Run Queue

Instance: c:\oracle\product\11.1.0\db_1\bin\ORACLE.EXE OR11
 User Time: 107.79S Sys  Time: 0.16S Memory: 543.09MB Page File: 0.67MB
  Handle: 3520 User Time: 74.24S Sys  Time: 0.02S ElapsedTime: 76S Priority: 8 ThreadState: In Run Queue
   PID:18 SPID:3520 SID:146 SERIAL#:4 USERNAME:TESTUSER MACHINE:HOME.NET\AIRFORCE-3 PROGRAM:sqlplus.exe
   SELECT   TOP_LEVEL_PART_ID, REQ.PURC_PART_ID, REQ.TOTAL_QTY,   REQ.TOTAL_QTY*TPPD.INCREASE "Increase",   REQ.R1_PART_ID, REQ.R2_PART_ID, REQ.R3_PART_ID,...

    SQL_ID  3p1v051atxt1z, child number 0
    -------------------------------------
    SELECT   TOP_LEVEL_PART_ID, REQ.PURC_PART_ID, REQ.TOTAL_QTY,  
    REQ.TOTAL_QTY*TPPD.INCREASE "Increase",   REQ.R1_PART_ID,
    REQ.R2_PART_ID, REQ.R3_PART_ID,   REQ.R4_PART_ID, REQ.R5_PART_ID,
    REQ.R6_PART_ID,   REQ.R1_CALC_QTY, REQ.R2_CALC_QTY, REQ.R3_CALC_QTY,  
    REQ.R4_CALC_QTY, REQ.R5_CALC_QTY, REQ.R6_CALC_QTY FROM   (SELECT    
    TOP_LEVEL_PART_ID,     DECODE(R6_PART_ID,NULL,      
    DECODE(R5_PART_ID,NULL,         DECODE(R4_PART_ID,NULL,          
    DECODE(R3_PART_ID,NULL,             DECODE(R2_PART_ID,NULL,            
           R1_PART_ID,R2_PART_ID),                  R3_PART_ID),           
        R4_PART_ID),              R5_PART_ID),            R6_PART_ID)
    PURC_PART_ID,     NVL(R1_CALC_QTY,0)*NVL(R2_CALC_QTY,1)*NVL(R3_CALC_QTY,
    1)*NVL(R4_CALC_QTY,1)*NVL(R5_CALC_QTY,1)*NVL(R6_CALC_QTY,1) TOTAL_QTY, 
       R1_PART_ID, R1_CALC_QTY, R2_PART_ID, R2_CALC_QTY, R3_PART_ID,
    R3_CALC_QTY,     R4_PART_ID, R4_CALC_QTY, R5_PART_ID, R5_CALC_QTY,
    R6_PART_ID, R6_CALC_QTY   FROM     (SELECT       PL.PART_ID TOP_LEVE

    Plan hash value: 3313542492

    ---------------------------------------------------------------------------------------------------------------------------------
    | Id  | Operation                                       | Name                 | Rows  | Bytes | Cost (%CPU)| Time     | Inst   |
    ---------------------------------------------------------------------------------------------------------------------------------
    |   0 | SELECT STATEMENT                                |                      |       |       |   101 (100)|          |        |
    |   1 |  VIEW                                           | VM_NWVW_1            |     1 |   225 |   101   (2)| 00:00:02 |   OR11 |
    |   2 |   HASH UNIQUE                                   |                      |     1 |   498 |   101   (2)| 00:00:02 |        |
    |   3 |    NESTED LOOPS OUTER                           |                      |     1 |   498 |   100   (1)| 00:00:02 |        |
    |*  4 |     FILTER                                      |                      |       |       |            |          |        |
    |   5 |      NESTED LOOPS OUTER                         |                      |     1 |   474 |    99   (2)| 00:00:02 |        |
    |   6 |       NESTED LOOPS OUTER                        |                      |     1 |   435 |    96   (2)| 00:00:02 |        |
    |   7 |        NESTED LOOPS OUTER                       |                      |     1 |   411 |    95   (2)| 00:00:02 |        |
    |*  8 |         FILTER                                  |                      |       |       |            |          |        |
    |   9 |          NESTED LOOPS OUTER                     |                      |     1 |   387 |    94   (2)| 00:00:02 |        |
    |* 10 |           FILTER                                |                      |       |       |            |          |        |
    |  11 |            NESTED LOOPS OUTER                   |                      |     1 |   348 |    91   (2)| 00:00:02 |        |
    |  12 |             NESTED LOOPS OUTER                  |                      |     1 |   309 |    88   (2)| 00:00:02 |        |
    |  13 |              NESTED LOOPS OUTER                 |                      |     1 |   285 |    87   (2)| 00:00:02 |        |
    |  14 |               NESTED LOOPS OUTER                |                      |     1 |   261 |    86   (2)| 00:00:02 |        |
    |* 15 |                FILTER                           |                      |       |       |            |          |        |
    |  16 |                 NESTED LOOPS OUTER              |                      |     1 |   237 |    85   (2)| 00:00:02 |        |
    |* 17 |                  FILTER                         |                      |       |       |            |          |        |
    |  18 |                   NESTED LOOPS OUTER            |                      |     1 |   198 |    82   (2)| 00:00:01 |        |
    |  19 |                    NESTED LOOPS                 |                      |     1 |   159 |    79   (2)| 00:00:01 |        |
    |  20 |                     NESTED LOOPS                |                      |     1 |   118 |    76   (2)| 00:00:01 |        |
    |  21 |                      MERGE JOIN CARTESIAN       |                      |     1 |    94 |    71   (2)| 00:00:01 |        |
    |* 22 |                       TABLE ACCESS FULL         | TEMP_PART_PRICE_DATE |     1 |    85 |     2   (0)| 00:00:01 |   OR11 |
    |  23 |                       BUFFER SORT               |                      |  7016 | 63144 |    69   (2)| 00:00:01 |        |
    |* 24 |                        TABLE ACCESS FULL        | CUSTOMER_ORDER       |  7016 | 63144 |    69   (2)| 00:00:01 |   OR11 |
    |* 25 |                      TABLE ACCESS BY INDEX ROWID| CUST_ORDER_LINE      |     1 |    24 |     5   (0)| 00:00:01 |   OR11 |
    |* 26 |                       INDEX RANGE SCAN          | SYS_C0028623         |     9 |       |     1   (0)| 00:00:01 |   OR11 |
    |  27 |                     TABLE ACCESS BY INDEX ROWID | REQUIREMENT          |     1 |    41 |     3   (0)| 00:00:01 |   OR11 |
    |* 28 |                      INDEX RANGE SCAN           | X_REQUIREMENT_5      |     1 |       |     2   (0)| 00:00:01 |   OR11 |
    |  29 |                    TABLE ACCESS BY INDEX ROWID  | REQUIREMENT          |     1 |    39 |     3   (0)| 00:00:01 |   OR11 |
    |* 30 |                     INDEX RANGE SCAN            | SYS_C0028831         |     1 |       |     2   (0)| 00:00:01 |   OR11 |
    |  31 |                  TABLE ACCESS BY INDEX ROWID    | REQUIREMENT          |     1 |    39 |     3   (0)| 00:00:01 |   OR11 |
    |* 32 |                   INDEX RANGE SCAN              | SYS_C0028831         |     1 |       |     2   (0)| 00:00:01 |   OR11 |
    |* 33 |                TABLE ACCESS BY INDEX ROWID      | PART                 |     1 |    24 |     1   (0)| 00:00:01 |   OR11 |
    |* 34 |                 INDEX UNIQUE SCAN               | SYS_C0028742         |     1 |       |     0   (0)|          |   OR11 |
    |* 35 |               TABLE ACCESS BY INDEX ROWID       | PART                 |     1 |    24 |     1   (0)| 00:00:01 |   OR11 |
    |* 36 |                INDEX UNIQUE SCAN                | SYS_C0028742         |     1 |       |     0   (0)|          |   OR11 |
    |* 37 |              TABLE ACCESS BY INDEX ROWID        | PART                 |     1 |    24 |     1   (0)| 00:00:01 |   OR11 |
    |* 38 |               INDEX UNIQUE SCAN                 | SYS_C0028742         |     1 |       |     0   (0)|          |   OR11 |
    |  39 |             TABLE ACCESS BY INDEX ROWID         | REQUIREMENT          |     1 |    39 |     3   (0)| 00:00:01 |   OR11 |
    |* 40 |              INDEX RANGE SCAN                   | SYS_C0028831         |     1 |       |     2   (0)| 00:00:01 |   OR11 |
    |  41 |           TABLE ACCESS BY INDEX ROWID           | REQUIREMENT          |     1 |    39 |     3   (0)| 00:00:01 |   OR11 |
    |* 42 |            INDEX RANGE SCAN                     | SYS_C0028831         |     1 |       |     2   (0)| 00:00:01 |   OR11 |
    |* 43 |         TABLE ACCESS BY INDEX ROWID             | PART                 |     1 |    24 |     1   (0)| 00:00:01 |   OR11 |
    |* 44 |          INDEX UNIQUE SCAN                      | SYS_C0028742         |     1 |       |     0   (0)|          |   OR11 |
    |* 45 |        TABLE ACCESS BY INDEX ROWID              | PART                 |     1 |    24 |     1   (0)| 00:00:01 |   OR11 |
    |* 46 |         INDEX UNIQUE SCAN                       | SYS_C0028742         |     1 |       |     0   (0)|          |   OR11 |
    |  47 |       TABLE ACCESS BY INDEX ROWID               | REQUIREMENT          |     1 |    39 |     3   (0)| 00:00:01 |   OR11 |
    |* 48 |        INDEX RANGE SCAN                         | SYS_C0028831         |     1 |       |     2   (0)| 00:00:01 |   OR11 |
    |* 49 |     TABLE ACCESS BY INDEX ROWID                 | PART                 |     1 |    24 |     1   (0)| 00:00:01 |   OR11 |
    |* 50 |      INDEX UNIQUE SCAN                          | SYS_C0028742         |     1 |       |     0   (0)|          |   OR11 |
    ---------------------------------------------------------------------------------------------------------------------------------

    Predicate Information (identified by operation id):
    ---------------------------------------------------

       4 - filter(("TPPD"."PART_ID"=DECODE(DECODE(DECODE(DECODE(DECODE(DECODE(NVL("P"."FABRICATED",'NONE'),'Y',"R2"."PART_ID"
                  ,NULL),NULL,NULL,DECODE(NVL("P2"."FABRICATED",'NONE'),'Y',"R3"."PART_ID",NULL)),NULL,NULL,DECODE(NVL("P3"."FABRICATED",'N
                  ONE'),'Y',"R4"."PART_ID",NULL)),NULL,NULL,DECODE(NVL("P4"."FABRICATED",'NONE'),'Y',"R5"."PART_ID",NULL)),NULL,NULL,DECODE
                  (NVL("P5"."FABRICATED",'NONE'),'Y',"R6"."PART_ID",NULL)),NULL,DECODE(DECODE(DECODE(DECODE(DECODE(NVL("P"."FABRICATED",'NO
                  NE'),'Y',"R2"."PART_ID",NULL),NULL,NULL,DECODE(NVL("P2"."FABRICATED",'NONE'),'Y',"R3"."PART_ID",NULL)),NULL,NULL,DECODE(N
                  VL("P3"."FABRICATED",'NONE'),'Y',"R4"."PART_ID",NULL)),NULL,NULL,DECODE(NVL("P4"."FABRICATED",'NONE'),'Y',"R5"."PART_ID",
                  NULL)),NULL,DECODE(DECODE(DECODE(DECODE(NVL("P"."FABRICATED",'NONE'),'Y',"R2"."PART_ID",NULL),NULL,NULL,DECODE(NVL("P2"."
                  FABRICATED",'NONE'),'Y',"R3"."PART_ID",NULL)),NULL,NULL,DECODE(NVL("P3"."FABRICATED",'NONE'),'Y',"R4"."PART_ID",NULL)),NU
                  LL,DECODE(DECODE(DECODE(NVL("P"."FABRICATED",'NONE'),'Y',"R2"."PART_ID",NULL),NULL,NULL,DECODE(NVL("P2"."FABRICATED",'NON
                  E'),'Y',"R3"."PART_ID",NULL)),NULL,DECODE(DECODE(NVL("P"."FABRICATED",'NONE'),'Y',"R2"."PART_ID",NULL),NULL,"R"."PART_ID"
                  ,DECODE(NVL("P"."FABRICATED",'NONE'),'Y',"R2"."PART_ID",NULL)),DECODE(DECODE(NVL("P"."FABRICATED",'NONE'),'Y',"R2"."PART_
                  ID",NULL),NULL,NULL,DECODE(NVL("P2"."FABRICATED",'NONE'),'Y',"R3"."PART_ID",NULL))),DECODE(DECODE(DECODE(NVL("P"."FABRICA
                  TED",'NONE'),'Y',"R2"."PART_ID",NULL),NULL,NULL,DECODE(NVL("P2"."FABRICATED",'NONE'),'Y',"R3"."PART_ID",NULL)),NULL,NULL,
                  DECODE(NVL("P3"."FABRICATED",'NONE'),'Y',"R4"."PART_ID",NULL))),DECODE(DECODE(DECODE(DECODE(NVL("P"."FABRICATED",'NONE'),
                  'Y',"R2"."PART_ID",NULL),NULL,NULL,DECODE(NVL("P2"."FABRICATED",'NONE'),'Y',"R3"."PART_ID",NULL)),NULL,NULL,DECODE(NVL("P
                  3"."FABRICATED",'NONE'),'Y',"R4"."PART_ID",NULL)),NULL,NULL,DECODE(NVL("P4"."FABRICATED",'NONE'),'Y',"R5"."PART_ID",NULL)
                  )),DECODE(DECODE(DECODE(DECODE(DECODE(NVL("P"."FABRICATED",'NONE'),'Y',"R2"."PART_ID",NULL),NULL,NULL,DECODE(NVL("P2"."FA
                  BRICATED",'NONE'),'Y',"R3"."PART_ID",NULL)),NULL,NULL,DECODE(NVL("P3"."FABRICATED",'NONE'),'Y',"R4"."PART_ID",NULL)),NULL
                  ,NULL,DECODE(NVL("P4"."FABRICATED",'NONE'),'Y',"R5"."PART_ID",NULL)),NULL,NULL,DECODE(NVL("P5"."FABRICATED",'NONE'),'Y',"
                  R6"."PART_ID",NULL))) AND "R6"."SUBORD_WO_SUB_ID" IS NULL))
       8 - filter("R5"."SUBORD_WO_SUB_ID" IS NULL)
      10 - filter("R4"."SUBORD_WO_SUB_ID" IS NULL)
      15 - filter("R3"."SUBORD_WO_SUB_ID" IS NULL)
      17 - filter("R2"."SUBORD_WO_SUB_ID" IS NULL)
      22 - filter("TPPD"."INCREASE"<>0)
      24 - filter(("CO"."STATUS"='C' OR "CO"."STATUS"='F' OR "CO"."STATUS"='P' OR "CO"."STATUS"='R' OR "CO"."STATUS"='U'))
      25 - filter("COL"."DESIRED_SHIP_DATE">SYSDATE@!-365)
      26 - access("CO"."ID"="COL"."CUST_ORDER_ID")
      28 - access("R"."WORKORDER_TYPE"='M' AND "COL"."PART_ID"="R"."WORKORDER_BASE_ID" AND "R"."WORKORDER_LOT_ID"='0' AND
                  "R"."WORKORDER_SPLIT_ID"='0' AND "R"."SUBORD_WO_SUB_ID" IS NULL)
      30 - access("R2"."WORKORDER_TYPE"='M' AND "R"."PART_ID"="R2"."WORKORDER_BASE_ID" AND "R2"."WORKORDER_LOT_ID"='0')
      32 - access("R3"."WORKORDER_TYPE"='M' AND "R2"."PART_ID"="R3"."WORKORDER_BASE_ID" AND "R3"."WORKORDER_LOT_ID"='0')
      33 - filter("P3"."FABRICATED"='Y')
      34 - access("R3"."PART_ID"="P3"."ID")
      35 - filter("P"."FABRICATED"='Y')
      36 - access("R"."PART_ID"="P"."ID")
      37 - filter("P2"."FABRICATED"='Y')
      38 - access("R2"."PART_ID"="P2"."ID")
      40 - access("R4"."WORKORDER_TYPE"='M' AND "R3"."PART_ID"="R4"."WORKORDER_BASE_ID" AND "R4"."WORKORDER_LOT_ID"='0')
      42 - access("R5"."WORKORDER_TYPE"='M' AND "R4"."PART_ID"="R5"."WORKORDER_BASE_ID" AND "R5"."WORKORDER_LOT_ID"='0')
      43 - filter("P4"."FABRICATED"='Y')
      44 - access("R4"."PART_ID"="P4"."ID")
      45 - filter("P5"."FABRICATED"='Y')
      46 - access("R5"."PART_ID"="P5"."ID")
      48 - access("R6"."WORKORDER_TYPE"='M' AND "R5"."PART_ID"="R6"."WORKORDER_BASE_ID" AND "R6"."WORKORDER_LOT_ID"='0')
      49 - filter("P6"."FABRICATED"='Y')
      50 - access("R6"."PART_ID"="P6"."ID")

  Handle: 2152 User Time: 37.25S Sys  Time: 0S ElapsedTime: 75S Priority: 8 ThreadState: In Run Queue
   PID:19 SPID:2152 SID:145 SERIAL#:12 USERNAME:TESTUSER MACHINE:HOME.NET\AIRFORCE-3 PROGRAM:sqlplus.exe
   INSERT INTO T1 SELECT   CEIL(ABS(SIN(ROWNUM/9.9999)*10000)),   'This is the long description for this number '|| TO_CHAR(CEIL(ABS(SIN(ROWNUM/9.9999)*10000)))...

    SQL_ID  6hxcgpp1rd1ag, child number 0
    -------------------------------------
    INSERT INTO T1 SELECT   CEIL(ABS(SIN(ROWNUM/9.9999)*10000)),   'This is
    the long description for this number '||
    TO_CHAR(CEIL(ABS(SIN(ROWNUM/9.9999)*10000))) FROM   (SELECT     ROWNUM
    RN   FROM     DUAL   CONNECT BY     LEVEL<=10000),   (SELECT     ROWNUM
    RN   FROM     DUAL   CONNECT BY     LEVEL<=10000)

    Plan hash value: 643243249

    -----------------------------------------------------------------------------------
    | Id  | Operation                          | Name | Rows  | Cost (%CPU)| Time     |
    -----------------------------------------------------------------------------------
    |   0 | INSERT STATEMENT                   |      |       |     4 (100)|          |
    |   1 |  LOAD TABLE CONVENTIONAL           |      |       |            |          |
    |   2 |   COUNT                            |      |       |            |          |
    |   3 |    MERGE JOIN CARTESIAN            |      |     1 |     4   (0)| 00:00:01 |
    |   4 |     VIEW                           |      |     1 |     2   (0)| 00:00:01 |
    |   5 |      COUNT                         |      |       |            |          |
    |   6 |       CONNECT BY WITHOUT FILTERING |      |       |            |          |
    |   7 |        FAST DUAL                   |      |     1 |     2   (0)| 00:00:01 |
    |   8 |     BUFFER SORT                    |      |     1 |     4   (0)| 00:00:01 |
    |   9 |      VIEW                          |      |     1 |     2   (0)| 00:00:01 |
    |  10 |       COUNT                        |      |       |            |          |
    |  11 |        CONNECT BY WITHOUT FILTERING|      |       |            |          |
    |  12 |         FAST DUAL                  |      |     1 |     2   (0)| 00:00:01 |
    -----------------------------------------------------------------------------------

1/8/2010 12:49:51 PM Processes: 73 Threads: 869 C. Switches: 43307 Q. Length: 6
Instance: c:\oracle\product\10.2.0\db_1\bin\ORACLE.EXE OR10
 User Time: 11.9S Sys  Time: 27.29S Memory: 275.59MB Page File: 0.63MB
  Handle: 1444 User Time: 11.54S Sys  Time: 26.1S ElapsedTime: 76S Priority: 8 ThreadState: Running

Instance: c:\oracle\product\11.1.0\db_1\bin\ORACLE.EXE OR11
 User Time: 117.66S Sys  Time: 0.11S Memory: 545.34MB Page File: 0.67MB
  Handle: 3520 User Time: 75.34S Sys  Time: 0.01S ElapsedTime: 76S Priority: 8 ThreadState: In Run Queue
   PID:18 SPID:3520 SID:146 SERIAL#:4 USERNAME:TESTUSER MACHINE:HOME.NET\AIRFORCE-3 PROGRAM:sqlplus.exe
   SELECT   TOP_LEVEL_PART_ID, REQ.PURC_PART_ID, REQ.TOTAL_QTY,   REQ.TOTAL_QTY*TPPD.INCREASE "Increase",   REQ.R1_PART_ID, REQ.R2_PART_ID, REQ.R3_PART_ID,...

    SQL_ID  3p1v051atxt1z, child number 0
    -------------------------------------
    SELECT   TOP_LEVEL_PART_ID, REQ.PURC_PART_ID, REQ.TOTAL_QTY,  
    REQ.TOTAL_QTY*TPPD.INCREASE "Increase",   REQ.R1_PART_ID,
    REQ.R2_PART_ID, REQ.R3_PART_ID,   REQ.R4_PART_ID, REQ.R5_PART_ID,
    REQ.R6_PART_ID,   REQ.R1_CALC_QTY, REQ.R2_CALC_QTY, REQ.R3_CALC_QTY,  
    REQ.R4_CALC_QTY, REQ.R5_CALC_QTY, REQ.R6_CALC_QTY FROM   (SELECT    
    TOP_LEVEL_PART_ID,     DECODE(R6_PART_ID,NULL,      
    DECODE(R5_PART_ID,NULL,         DECODE(R4_PART_ID,NULL,          
    DECODE(R3_PART_ID,NULL,             DECODE(R2_PART_ID,NULL,            
           R1_PART_ID,R2_PART_ID),                  R3_PART_ID),           
        R4_PART_ID),              R5_PART_ID),            R6_PART_ID)
    PURC_PART_ID,     NVL(R1_CALC_QTY,0)*NVL(R2_CALC_QTY,1)*NVL(R3_CALC_QTY,
    1)*NVL(R4_CALC_QTY,1)*NVL(R5_CALC_QTY,1)*NVL(R6_CALC_QTY,1) TOTAL_QTY, 
       R1_PART_ID, R1_CALC_QTY, R2_PART_ID, R2_CALC_QTY, R3_PART_ID,
    R3_CALC_QTY,     R4_PART_ID, R4_CALC_QTY, R5_PART_ID, R5_CALC_QTY,
    R6_PART_ID, R6_CALC_QTY   FROM     (SELECT       PL.PART_ID TOP_LEVE

    Plan hash value: 3313542492

    ---------------------------------------------------------------------------------------------------------------------------------
    | Id  | Operation                                       | Name                 | Rows  | Bytes | Cost (%CPU)| Time     | Inst   |
    ---------------------------------------------------------------------------------------------------------------------------------
    |   0 | SELECT STATEMENT                                |                      |       |       |   101 (100)|          |        |
    |   1 |  VIEW                                           | VM_NWVW_1            |     1 |   225 |   101   (2)| 00:00:02 |   OR11 |
    |   2 |   HASH UNIQUE                                   |                      |     1 |   498 |   101   (2)| 00:00:02 |        |
    |   3 |    NESTED LOOPS OUTER                           |                      |     1 |   498 |   100   (1)| 00:00:02 |        |
    |*  4 |     FILTER                                      |                      |       |       |            |          |        |
    |   5 |      NESTED LOOPS OUTER                         |                      |     1 |   474 |    99   (2)| 00:00:02 |        |
    |   6 |       NESTED LOOPS OUTER                        |                      |     1 |   435 |    96   (2)| 00:00:02 |        |
    |   7 |        NESTED LOOPS OUTER                       |                      |     1 |   411 |    95   (2)| 00:00:02 |        |
    |*  8 |         FILTER                                  |                      |       |       |            |          |        |
    |   9 |          NESTED LOOPS OUTER                     |                      |     1 |   387 |    94   (2)| 00:00:02 |        |
    |* 10 |           FILTER                                |                      |       |       |            |          |        |
    |  11 |            NESTED LOOPS OUTER                   |                      |     1 |   348 |    91   (2)| 00:00:02 |        |
    |  12 |             NESTED LOOPS OUTER                  |                      |     1 |   309 |    88   (2)| 00:00:02 |        |
    |  13 |              NESTED LOOPS OUTER                 |                      |     1 |   285 |    87   (2)| 00:00:02 |        |
    |  14 |               NESTED LOOPS OUTER                |                      |     1 |   261 |    86   (2)| 00:00:02 |        |
    |* 15 |                FILTER                           |                      |       |       |            |          |        |
    |  16 |                 NESTED LOOPS OUTER              |                      |     1 |   237 |    85   (2)| 00:00:02 |        |
    |* 17 |                  FILTER                         |                      |       |       |            |          |        |
    |  18 |                   NESTED LOOPS OUTER            |                      |     1 |   198 |    82   (2)| 00:00:01 |        |
    |  19 |                    NESTED LOOPS                 |                      |     1 |   159 |    79   (2)| 00:00:01 |        |
    |  20 |                     NESTED LOOPS                |                      |     1 |   118 |    76   (2)| 00:00:01 |        |
    |  21 |                      MERGE JOIN CARTESIAN       |                      |     1 |    94 |    71   (2)| 00:00:01 |        |
    |* 22 |                       TABLE ACCESS FULL         | TEMP_PART_PRICE_DATE |     1 |    85 |     2   (0)| 00:00:01 |   OR11 |
    |  23 |                       BUFFER SORT               |                      |  7016 | 63144 |    69   (2)| 00:00:01 |        |
    |* 24 |                        TABLE ACCESS FULL        | CUSTOMER_ORDER       |  7016 | 63144 |    69   (2)| 00:00:01 |   OR11 |
    |* 25 |                      TABLE ACCESS BY INDEX ROWID| CUST_ORDER_LINE      |     1 |    24 |     5   (0)| 00:00:01 |   OR11 |
    |* 26 |                       INDEX RANGE SCAN          | SYS_C0028623         |     9 |       |     1   (0)| 00:00:01 |   OR11 |
    |  27 |                     TABLE ACCESS BY INDEX ROWID | REQUIREMENT          |     1 |    41 |     3   (0)| 00:00:01 |   OR11 |
    |* 28 |                      INDEX RANGE SCAN           | X_REQUIREMENT_5      |     1 |       |     2   (0)| 00:00:01 |   OR11 |
    |  29 |                    TABLE ACCESS BY INDEX ROWID  | REQUIREMENT          |     1 |    39 |     3   (0)| 00:00:01 |   OR11 |
    |* 30 |                     INDEX RANGE SCAN            | SYS_C0028831         |     1 |       |     2   (0)| 00:00:01 |   OR11 |
    |  31 |                  TABLE ACCESS BY INDEX ROWID    | REQUIREMENT          |     1 |    39 |     3   (0)| 00:00:01 |   OR11 |
    |* 32 |                   INDEX RANGE SCAN              | SYS_C0028831         |     1 |       |     2   (0)| 00:00:01 |   OR11 |
    |* 33 |                TABLE ACCESS BY INDEX ROWID      | PART                 |     1 |    24 |     1   (0)| 00:00:01 |   OR11 |
    |* 34 |                 INDEX UNIQUE SCAN               | SYS_C0028742         |     1 |       |     0   (0)|          |   OR11 |
    |* 35 |               TABLE ACCESS BY INDEX ROWID       | PART                 |     1 |    24 |     1   (0)| 00:00:01 |   OR11 |
    |* 36 |                INDEX UNIQUE SCAN                | SYS_C0028742         |     1 |       |     0   (0)|          |   OR11 |
    |* 37 |              TABLE ACCESS BY INDEX ROWID        | PART                 |     1 |    24 |     1   (0)| 00:00:01 |   OR11 |
    |* 38 |               INDEX UNIQUE SCAN                 | SYS_C0028742         |     1 |       |     0   (0)|          |   OR11 |
    |  39 |             TABLE ACCESS BY INDEX ROWID         | REQUIREMENT          |     1 |    39 |     3   (0)| 00:00:01 |   OR11 |
    |* 40 |              INDEX RANGE SCAN                   | SYS_C0028831         |     1 |       |     2   (0)| 00:00:01 |   OR11 |
    |  41 |           TABLE ACCESS BY INDEX ROWID           | REQUIREMENT          |     1 |    39 |     3   (0)| 00:00:01 |   OR11 |
    |* 42 |            INDEX RANGE SCAN                     | SYS_C0028831         |     1 |       |     2   (0)| 00:00:01 |   OR11 |
    |* 43 |         TABLE ACCESS BY INDEX ROWID             | PART                 |     1 |    24 |     1   (0)| 00:00:01 |   OR11 |
    |* 44 |          INDEX UNIQUE SCAN                      | SYS_C0028742         |     1 |       |     0   (0)|          |   OR11 |
    |* 45 |        TABLE ACCESS BY INDEX ROWID              | PART                 |     1 |    24 |     1   (0)| 00:00:01 |   OR11 |
    |* 46 |         INDEX UNIQUE SCAN                       | SYS_C0028742         |     1 |       |     0   (0)|          |   OR11 |
    |  47 |       TABLE ACCESS BY INDEX ROWID               | REQUIREMENT          |     1 |    39 |     3   (0)| 00:00:01 |   OR11 |
    |* 48 |        INDEX RANGE SCAN                         | SYS_C0028831         |     1 |       |     2   (0)| 00:00:01 |   OR11 |
    |* 49 |     TABLE ACCESS BY INDEX ROWID                 | PART                 |     1 |    24 |     1   (0)| 00:00:01 |   OR11 |
    |* 50 |      INDEX UNIQUE SCAN                          | SYS_C0028742         |     1 |       |     0   (0)|          |   OR11 |
    ---------------------------------------------------------------------------------------------------------------------------------

    Predicate Information (identified by operation id):
    ---------------------------------------------------

       4 - filter(("TPPD"."PART_ID"=DECODE(DECODE(DECODE(DECODE(DECODE(DECODE(NVL("P"."FABRICATED",'NONE'),'Y',"R2"."PART_ID"
                  ,NULL),NULL,NULL,DECODE(NVL("P2"."FABRICATED",'NONE'),'Y',"R3"."PART_ID",NULL)),NULL,NULL,DECODE(NVL("P3"."FABRICATED",'N
                  ONE'),'Y',"R4"."PART_ID",NULL)),NULL,NULL,DECODE(NVL("P4"."FABRICATED",'NONE'),'Y',"R5"."PART_ID",NULL)),NULL,NULL,DECODE
                  (NVL("P5"."FABRICATED",'NONE'),'Y',"R6"."PART_ID",NULL)),NULL,DECODE(DECODE(DECODE(DECODE(DECODE(NVL("P"."FABRICATED",'NO
                  NE'),'Y',"R2"."PART_ID",NULL),NULL,NULL,DECODE(NVL("P2"."FABRICATED",'NONE'),'Y',"R3"."PART_ID",NULL)),NULL,NULL,DECODE(N
                  VL("P3"."FABRICATED",'NONE'),'Y',"R4"."PART_ID",NULL)),NULL,NULL,DECODE(NVL("P4"."FABRICATED",'NONE'),'Y',"R5"."PART_ID",
                  NULL)),NULL,DECODE(DECODE(DECODE(DECODE(NVL("P"."FABRICATED",'NONE'),'Y',"R2"."PART_ID",NULL),NULL,NULL,DECODE(NVL("P2"."
                  FABRICATED",'NONE'),'Y',"R3"."PART_ID",NULL)),NULL,NULL,DECODE(NVL("P3"."FABRICATED",'NONE'),'Y',"R4"."PART_ID",NULL)),NU
                  LL,DECODE(DECODE(DECODE(NVL("P"."FABRICATED",'NONE'),'Y',"R2"."PART_ID",NULL),NULL,NULL,DECODE(NVL("P2"."FABRICATED",'NON
                  E'),'Y',"R3"."PART_ID",NULL)),NULL,DECODE(DECODE(NVL("P"."FABRICATED",'NONE'),'Y',"R2"."PART_ID",NULL),NULL,"R"."PART_ID"
                  ,DECODE(NVL("P"."FABRICATED",'NONE'),'Y',"R2"."PART_ID",NULL)),DECODE(DECODE(NVL("P"."FABRICATED",'NONE'),'Y',"R2"."PART_
                  ID",NULL),NULL,NULL,DECODE(NVL("P2"."FABRICATED",'NONE'),'Y',"R3"."PART_ID",NULL))),DECODE(DECODE(DECODE(NVL("P"."FABRICA
                  TED",'NONE'),'Y',"R2"."PART_ID",NULL),NULL,NULL,DECODE(NVL("P2"."FABRICATED",'NONE'),'Y',"R3"."PART_ID",NULL)),NULL,NULL,
                  DECODE(NVL("P3"."FABRICATED",'NONE'),'Y',"R4"."PART_ID",NULL))),DECODE(DECODE(DECODE(DECODE(NVL("P"."FABRICATED",'NONE'),
                  'Y',"R2"."PART_ID",NULL),NULL,NULL,DECODE(NVL("P2"."FABRICATED",'NONE'),'Y',"R3"."PART_ID",NULL)),NULL,NULL,DECODE(NVL("P
                  3"."FABRICATED",'NONE'),'Y',"R4"."PART_ID",NULL)),NULL,NULL,DECODE(NVL("P4"."FABRICATED",'NONE'),'Y',"R5"."PART_ID",NULL)
                  )),DECODE(DECODE(DECODE(DECODE(DECODE(NVL("P"."FABRICATED",'NONE'),'Y',"R2"."PART_ID",NULL),NULL,NULL,DECODE(NVL("P2"."FA
                  BRICATED",'NONE'),'Y',"R3"."PART_ID",NULL)),NULL,NULL,DECODE(NVL("P3"."FABRICATED",'NONE'),'Y',"R4"."PART_ID",NULL)),NULL
                  ,NULL,DECODE(NVL("P4"."FABRICATED",'NONE'),'Y',"R5"."PART_ID",NULL)),NULL,NULL,DECODE(NVL("P5"."FABRICATED",'NONE'),'Y',"
                  R6"."PART_ID",NULL))) AND "R6"."SUBORD_WO_SUB_ID" IS NULL))
       8 - filter("R5"."SUBORD_WO_SUB_ID" IS NULL)
      10 - filter("R4"."SUBORD_WO_SUB_ID" IS NULL)
      15 - filter("R3"."SUBORD_WO_SUB_ID" IS NULL)
      17 - filter("R2"."SUBORD_WO_SUB_ID" IS NULL)
      22 - filter("TPPD"."INCREASE"<>0)
      24 - filter(("CO"."STATUS"='C' OR "CO"."STATUS"='F' OR "CO"."STATUS"='P' OR "CO"."STATUS"='R' OR "CO"."STATUS"='U'))
      25 - filter("COL"."DESIRED_SHIP_DATE">SYSDATE@!-365)
      26 - access("CO"."ID"="COL"."CUST_ORDER_ID")
      28 - access("R"."WORKORDER_TYPE"='M' AND "COL"."PART_ID"="R"."WORKORDER_BASE_ID" AND "R"."WORKORDER_LOT_ID"='0' AND
                  "R"."WORKORDER_SPLIT_ID"='0' AND "R"."SUBORD_WO_SUB_ID" IS NULL)
      30 - access("R2"."WORKORDER_TYPE"='M' AND "R"."PART_ID"="R2"."WORKORDER_BASE_ID" AND "R2"."WORKORDER_LOT_ID"='0')
      32 - access("R3"."WORKORDER_TYPE"='M' AND "R2"."PART_ID"="R3"."WORKORDER_BASE_ID" AND "R3"."WORKORDER_LOT_ID"='0')
      33 - filter("P3"."FABRICATED"='Y')
      34 - access("R3"."PART_ID"="P3"."ID")
      35 - filter("P"."FABRICATED"='Y')
      36 - access("R"."PART_ID"="P"."ID")
      37 - filter("P2"."FABRICATED"='Y')
      38 - access("R2"."PART_ID"="P2"."ID")
      40 - access("R4"."WORKORDER_TYPE"='M' AND "R3"."PART_ID"="R4"."WORKORDER_BASE_ID" AND "R4"."WORKORDER_LOT_ID"='0')
      42 - access("R5"."WORKORDER_TYPE"='M' AND "R4"."PART_ID"="R5"."WORKORDER_BASE_ID" AND "R5"."WORKORDER_LOT_ID"='0')
      43 - filter("P4"."FABRICATED"='Y')
      44 - access("R4"."PART_ID"="P4"."ID")
      45 - filter("P5"."FABRICATED"='Y')
      46 - access("R5"."PART_ID"="P5"."ID")
      48 - access("R6"."WORKORDER_TYPE"='M' AND "R5"."PART_ID"="R6"."WORKORDER_BASE_ID" AND "R6"."WORKORDER_LOT_ID"='0')
      49 - filter("P6"."FABRICATED"='Y')
      50 - access("R6"."PART_ID"="P6"."ID")

  Handle: 2152 User Time: 37.44S Sys  Time: 0S ElapsedTime: 76S Priority: 8 ThreadState: Running
   PID:19 SPID:2152 SID:145 SERIAL#:12 USERNAME:TESTUSER MACHINE:HOME.NET\AIRFORCE-3 PROGRAM:sqlplus.exe
   INSERT INTO T1 SELECT   CEIL(ABS(SIN(ROWNUM/9.9999)*10000)),   'This is the long description for this number '|| TO_CHAR(CEIL(ABS(SIN(ROWNUM/9.9999)*10000)))...

    SQL_ID  6hxcgpp1rd1ag, child number 0
    -------------------------------------
    INSERT INTO T1 SELECT   CEIL(ABS(SIN(ROWNUM/9.9999)*10000)),   'This is
    the long description for this number '||
    TO_CHAR(CEIL(ABS(SIN(ROWNUM/9.9999)*10000))) FROM   (SELECT     ROWNUM
    RN   FROM     DUAL   CONNECT BY     LEVEL<=10000),   (SELECT     ROWNUM
    RN   FROM     DUAL   CONNECT BY     LEVEL<=10000)

    Plan hash value: 643243249

    -----------------------------------------------------------------------------------
    | Id  | Operation                          | Name | Rows  | Cost (%CPU)| Time     |
    -----------------------------------------------------------------------------------
    |   0 | INSERT STATEMENT                   |      |       |     4 (100)|          |
    |   1 |  LOAD TABLE CONVENTIONAL           |      |       |            |          |
    |   2 |   COUNT                            |      |       |            |          |
    |   3 |    MERGE JOIN CARTESIAN            |      |     1 |     4   (0)| 00:00:01 |
    |   4 |     VIEW                           |      |     1 |     2   (0)| 00:00:01 |
    |   5 |      COUNT                         |      |       |            |          |
    |   6 |       CONNECT BY WITHOUT FILTERING |      |       |            |          |
    |   7 |        FAST DUAL                   |      |     1 |     2   (0)| 00:00:01 |
    |   8 |     BUFFER SORT                    |      |     1 |     4   (0)| 00:00:01 |
    |   9 |      VIEW                          |      |     1 |     2   (0)| 00:00:01 |
    |  10 |       COUNT                        |      |       |            |          |
    |  11 |        CONNECT BY WITHOUT FILTERING|      |       |            |          |
    |  12 |         FAST DUAL                  |      |     1 |     2   (0)| 00:00:01 |
    -----------------------------------------------------------------------------------

1/8/2010 12:51:07 PM Processes: 73 Threads: 865 C. Switches: 41992 Q. Length: 7
Instance: c:\oracle\product\10.2.0\db_1\bin\ORACLE.EXE OR10
 User Time: 10.81S Sys  Time: 26.83S Memory: 276.09MB Page File: 0.63MB
  Handle: 1444 User Time: 10.02S Sys  Time: 25.51S ElapsedTime: 71S Priority: 8 ThreadState: Running

Instance: c:\oracle\product\11.1.0\db_1\bin\ORACLE.EXE OR11
 User Time: 112.71S Sys  Time: 0.09S Memory: 545.63MB Page File: 0.67MB
  Handle: 3520 User Time: 72.57S Sys  Time: 0S ElapsedTime: 74S Priority: 10 ThreadState: Idle
   PID:18 SPID:3520 SID:146 SERIAL#:4 USERNAME:TESTUSER MACHINE:HOME.NET\AIRFORCE-3 PROGRAM:sqlplus.exe
   SELECT   TOP_LEVEL_PART_ID, REQ.PURC_PART_ID, REQ.TOTAL_QTY,   REQ.TOTAL_QTY*TPPD.INCREASE "Increase",   REQ.R1_PART_ID, REQ.R2_PART_ID, REQ.R3_PART_ID,...

    SQL_ID  3p1v051atxt1z, child number 0
    -------------------------------------
    SELECT   TOP_LEVEL_PART_ID, REQ.PURC_PART_ID, REQ.TOTAL_QTY,  
    REQ.TOTAL_QTY*TPPD.INCREASE "Increase",   REQ.R1_PART_ID,
    REQ.R2_PART_ID, REQ.R3_PART_ID,   REQ.R4_PART_ID, REQ.R5_PART_ID,
    REQ.R6_PART_ID,   REQ.R1_CALC_QTY, REQ.R2_CALC_QTY, REQ.R3_CALC_QTY,  
    REQ.R4_CALC_QTY, REQ.R5_CALC_QTY, REQ.R6_CALC_QTY FROM   (SELECT    
    TOP_LEVEL_PART_ID,     DECODE(R6_PART_ID,NULL,      
    DECODE(R5_PART_ID,NULL,         DECODE(R4_PART_ID,NULL,          
    DECODE(R3_PART_ID,NULL,             DECODE(R2_PART_ID,NULL,            
           R1_PART_ID,R2_PART_ID),                  R3_PART_ID),           
        R4_PART_ID),              R5_PART_ID),            R6_PART_ID)
    PURC_PART_ID,     NVL(R1_CALC_QTY,0)*NVL(R2_CALC_QTY,1)*NVL(R3_CALC_QTY,
    1)*NVL(R4_CALC_QTY,1)*NVL(R5_CALC_QTY,1)*NVL(R6_CALC_QTY,1) TOTAL_QTY, 
       R1_PART_ID, R1_CALC_QTY, R2_PART_ID, R2_CALC_QTY, R3_PART_ID,
    R3_CALC_QTY,     R4_PART_ID, R4_CALC_QTY, R5_PART_ID, R5_CALC_QTY,
    R6_PART_ID, R6_CALC_QTY   FROM     (SELECT       PL.PART_ID TOP_LEVE

    Plan hash value: 3313542492

    ---------------------------------------------------------------------------------------------------------------------------------
    | Id  | Operation                                       | Name                 | Rows  | Bytes | Cost (%CPU)| Time     | Inst   |
    ---------------------------------------------------------------------------------------------------------------------------------
    |   0 | SELECT STATEMENT                                |                      |       |       |   101 (100)|          |        |
    |   1 |  VIEW                                           | VM_NWVW_1            |     1 |   225 |   101   (2)| 00:00:02 |   OR11 |
    |   2 |   HASH UNIQUE                                   |                      |     1 |   498 |   101   (2)| 00:00:02 |        |
    |   3 |    NESTED LOOPS OUTER                           |                      |     1 |   498 |   100   (1)| 00:00:02 |        |
    |*  4 |     FILTER                                      |                      |       |       |            |          |        |
    |   5 |      NESTED LOOPS OUTER                         |                      |     1 |   474 |    99   (2)| 00:00:02 |        |
    |   6 |       NESTED LOOPS OUTER                        |                      |     1 |   435 |    96   (2)| 00:00:02 |        |
    |   7 |        NESTED LOOPS OUTER                       |                      |     1 |   411 |    95   (2)| 00:00:02 |        |
    |*  8 |         FILTER                                  |                      |       |       |            |          |        |
    |   9 |          NESTED LOOPS OUTER                     |                      |     1 |   387 |    94   (2)| 00:00:02 |        |
    |* 10 |           FILTER                                |                      |       |       |            |          |        |
    |  11 |            NESTED LOOPS OUTER                   |                      |     1 |   348 |    91   (2)| 00:00:02 |        |
    |  12 |             NESTED LOOPS OUTER                  |                      |     1 |   309 |    88   (2)| 00:00:02 |        |
    |  13 |              NESTED LOOPS OUTER                 |                      |     1 |   285 |    87   (2)| 00:00:02 |        |
    |  14 |               NESTED LOOPS OUTER                |                      |     1 |   261 |    86   (2)| 00:00:02 |        |
    |* 15 |                FILTER                           |                      |       |       |            |          |        |
    |  16 |                 NESTED LOOPS OUTER              |                      |     1 |   237 |    85   (2)| 00:00:02 |        |
    |* 17 |                  FILTER                         |                      |       |       |            |          |        |
    |  18 |                   NESTED LOOPS OUTER            |                      |     1 |   198 |    82   (2)| 00:00:01 |        |
    |  19 |                    NESTED LOOPS                 |                      |     1 |   159 |    79   (2)| 00:00:01 |        |
    |  20 |                     NESTED LOOPS                |                      |     1 |   118 |    76   (2)| 00:00:01 |        |
    |  21 |                      MERGE JOIN CARTESIAN       |                      |     1 |    94 |    71   (2)| 00:00:01 |        |
    |* 22 |                       TABLE ACCESS FULL         | TEMP_PART_PRICE_DATE |     1 |    85 |     2   (0)| 00:00:01 |   OR11 |
    |  23 |                       BUFFER SORT               |                      |  7016 | 63144 |    69   (2)| 00:00:01 |        |
    |* 24 |                        TABLE ACCESS FULL        | CUSTOMER_ORDER       |  7016 | 63144 |    69   (2)| 00:00:01 |   OR11 |
    |* 25 |                      TABLE ACCESS BY INDEX ROWID| CUST_ORDER_LINE      |     1 |    24 |     5   (0)| 00:00:01 |   OR11 |
    |* 26 |                       INDEX RANGE SCAN          | SYS_C0028623         |     9 |       |     1   (0)| 00:00:01 |   OR11 |
    |  27 |                     TABLE ACCESS BY INDEX ROWID | REQUIREMENT          |     1 |    41 |     3   (0)| 00:00:01 |   OR11 |
    |* 28 |                      INDEX RANGE SCAN           | X_REQUIREMENT_5      |     1 |       |     2   (0)| 00:00:01 |   OR11 |
    |  29 |                    TABLE ACCESS BY INDEX ROWID  | REQUIREMENT          |     1 |    39 |     3   (0)| 00:00:01 |   OR11 |
    |* 30 |                     INDEX RANGE SCAN            | SYS_C0028831         |     1 |       |     2   (0)| 00:00:01 |   OR11 |
    |  31 |                  TABLE ACCESS BY INDEX ROWID    | REQUIREMENT          |     1 |    39 |     3   (0)| 00:00:01 |   OR11 |
    |* 32 |                   INDEX RANGE SCAN              | SYS_C0028831         |     1 |       |     2   (0)| 00:00:01 |   OR11 |
    |* 33 |                TABLE ACCESS BY INDEX ROWID      | PART                 |     1 |    24 |     1   (0)| 00:00:01 |   OR11 |
    |* 34 |                 INDEX UNIQUE SCAN               | SYS_C0028742         |     1 |       |     0   (0)|          |   OR11 |
    |* 35 |               TABLE ACCESS BY INDEX ROWID       | PART                 |     1 |    24 |     1   (0)| 00:00:01 |   OR11 |
    |* 36 |                INDEX UNIQUE SCAN                | SYS_C0028742         |     1 |       |     0   (0)|          |   OR11 |
    |* 37 |              TABLE ACCESS BY INDEX ROWID        | PART                 |     1 |    24 |     1   (0)| 00:00:01 |   OR11 |
    |* 38 |               INDEX UNIQUE SCAN                 | SYS_C0028742         |     1 |       |     0   (0)|          |   OR11 |
    |  39 |             TABLE ACCESS BY INDEX ROWID         | REQUIREMENT          |     1 |    39 |     3   (0)| 00:00:01 |   OR11 |
    |* 40 |              INDEX RANGE SCAN                   | SYS_C0028831         |     1 |       |     2   (0)| 00:00:01 |   OR11 |
    |  41 |           TABLE ACCESS BY INDEX ROWID           | REQUIREMENT          |     1 |    39 |     3   (0)| 00:00:01 |   OR11 |
    |* 42 |            INDEX RANGE SCAN                     | SYS_C0028831         |     1 |       |     2   (0)| 00:00:01 |   OR11 |
    |* 43 |         TABLE ACCESS BY INDEX ROWID             | PART                 |     1 |    24 |     1   (0)| 00:00:01 |   OR11 |
    |* 44 |          INDEX UNIQUE SCAN                      | SYS_C0028742         |     1 |       |     0   (0)|          |   OR11 |
    |* 45 |        TABLE ACCESS BY INDEX ROWID              | PART                 |     1 |    24 |     1   (0)| 00:00:01 |   OR11 |
    |* 46 |         INDEX UNIQUE SCAN                       | SYS_C0028742         |     1 |       |     0   (0)|          |   OR11 |
    |  47 |       TABLE ACCESS BY INDEX ROWID               | REQUIREMENT          |     1 |    39 |     3   (0)| 00:00:01 |   OR11 |
    |* 48 |        INDEX RANGE SCAN                         | SYS_C0028831         |     1 |       |     2   (0)| 00:00:01 |   OR11 |
    |* 49 |     TABLE ACCESS BY INDEX ROWID                 | PART                 |     1 |    24 |     1   (0)| 00:00:01 |   OR11 |
    |* 50 |      INDEX UNIQUE SCAN                          | SYS_C0028742         |     1 |       |     0   (0)|          |   OR11 |
    ---------------------------------------------------------------------------------------------------------------------------------

    Predicate Information (identified by operation id):
    ---------------------------------------------------

       4 - filter(("TPPD"."PART_ID"=DECODE(DECODE(DECODE(DECODE(DECODE(DECODE(NVL("P"."FABRICATED",'NONE'),'Y',"R2"."PART_ID"
                  ,NULL),NULL,NULL,DECODE(NVL("P2"."FABRICATED",'NONE'),'Y',"R3"."PART_ID",NULL)),NULL,NULL,DECODE(NVL("P3"."FABRICATED",'N
                  ONE'),'Y',"R4"."PART_ID",NULL)),NULL,NULL,DECODE(NVL("P4"."FABRICATED",'NONE'),'Y',"R5"."PART_ID",NULL)),NULL,NULL,DECODE
                  (NVL("P5"."FABRICATED",'NONE'),'Y',"R6"."PART_ID",NULL)),NULL,DECODE(DECODE(DECODE(DECODE(DECODE(NVL("P"."FABRICATED",'NO
                  NE'),'Y',"R2"."PART_ID",NULL),NULL,NULL,DECODE(NVL("P2"."FABRICATED",'NONE'),'Y',"R3"."PART_ID",NULL)),NULL,NULL,DECODE(N
                  VL("P3"."FABRICATED",'NONE'),'Y',"R4"."PART_ID",NULL)),NULL,NULL,DECODE(NVL("P4"."FABRICATED",'NONE'),'Y',"R5"."PART_ID",
                  NULL)),NULL,DECODE(DECODE(DECODE(DECODE(NVL("P"."FABRICATED",'NONE'),'Y',"R2"."PART_ID",NULL),NULL,NULL,DECODE(NVL("P2"."
                  FABRICATED",'NONE'),'Y',"R3"."PART_ID",NULL)),NULL,NULL,DECODE(NVL("P3"."FABRICATED",'NONE'),'Y',"R4"."PART_ID",NULL)),NU
                  LL,DECODE(DECODE(DECODE(NVL("P"."FABRICATED",'NONE'),'Y',"R2"."PART_ID",NULL),NULL,NULL,DECODE(NVL("P2"."FABRICATED",'NON
                  E'),'Y',"R3"."PART_ID",NULL)),NULL,DECODE(DECODE(NVL("P"."FABRICATED",'NONE'),'Y',"R2"."PART_ID",NULL),NULL,"R"."PART_ID"
                  ,DECODE(NVL("P"."FABRICATED",'NONE'),'Y',"R2"."PART_ID",NULL)),DECODE(DECODE(NVL("P"."FABRICATED",'NONE'),'Y',"R2"."PART_
                  ID",NULL),NULL,NULL,DECODE(NVL("P2"."FABRICATED",'NONE'),'Y',"R3"."PART_ID",NULL))),DECODE(DECODE(DECODE(NVL("P"."FABRICA
                  TED",'NONE'),'Y',"R2"."PART_ID",NULL),NULL,NULL,DECODE(NVL("P2"."FABRICATED",'NONE'),'Y',"R3"."PART_ID",NULL)),NULL,NULL,
                  DECODE(NVL("P3"."FABRICATED",'NONE'),'Y',"R4"."PART_ID",NULL))),DECODE(DECODE(DECODE(DECODE(NVL("P"."FABRICATED",'NONE'),
                  'Y',"R2"."PART_ID",NULL),NULL,NULL,DECODE(NVL("P2"."FABRICATED",'NONE'),'Y',"R3"."PART_ID",NULL)),NULL,NULL,DECODE(NVL("P
                  3"."FABRICATED",'NONE'),'Y',"R4"."PART_ID",NULL)),NULL,NULL,DECODE(NVL("P4"."FABRICATED",'NONE'),'Y',"R5"."PART_ID",NULL)
                  )),DECODE(DECODE(DECODE(DECODE(DECODE(NVL("P"."FABRICATED",'NONE'),'Y',"R2"."PART_ID",NULL),NULL,NULL,DECODE(NVL("P2"."FA
                  BRICATED",'NONE'),'Y',"R3"."PART_ID",NULL)),NULL,NULL,DECODE(NVL("P3"."FABRICATED",'NONE'),'Y',"R4"."PART_ID",NULL)),NULL
                  ,NULL,DECODE(NVL("P4"."FABRICATED",'NONE'),'Y',"R5"."PART_ID",NULL)),NULL,NULL,DECODE(NVL("P5"."FABRICATED",'NONE'),'Y',"
                  R6"."PART_ID",NULL))) AND "R6"."SUBORD_WO_SUB_ID" IS NULL))
       8 - filter("R5"."SUBORD_WO_SUB_ID" IS NULL)
      10 - filter("R4"."SUBORD_WO_SUB_ID" IS NULL)
      15 - filter("R3"."SUBORD_WO_SUB_ID" IS NULL)
      17 - filter("R2"."SUBORD_WO_SUB_ID" IS NULL)
      22 - filter("TPPD"."INCREASE"<>0)
      24 - filter(("CO"."STATUS"='C' OR "CO"."STATUS"='F' OR "CO"."STATUS"='P' OR "CO"."STATUS"='R' OR "CO"."STATUS"='U'))
      25 - filter("COL"."DESIRED_SHIP_DATE">SYSDATE@!-365)
      26 - access("CO"."ID"="COL"."CUST_ORDER_ID")
      28 - access("R"."WORKORDER_TYPE"='M' AND "COL"."PART_ID"="R"."WORKORDER_BASE_ID" AND "R"."WORKORDER_LOT_ID"='0' AND
                  "R"."WORKORDER_SPLIT_ID"='0' AND "R"."SUBORD_WO_SUB_ID" IS NULL)
      30 - access("R2"."WORKORDER_TYPE"='M' AND "R"."PART_ID"="R2"."WORKORDER_BASE_ID" AND "R2"."WORKORDER_LOT_ID"='0')
      32 - access("R3"."WORKORDER_TYPE"='M' AND "R2"."PART_ID"="R3"."WORKORDER_BASE_ID" AND "R3"."WORKORDER_LOT_ID"='0')
      33 - filter("P3"."FABRICATED"='Y')
      34 - access("R3"."PART_ID"="P3"."ID")
      35 - filter("P"."FABRICATED"='Y')
      36 - access("R"."PART_ID"="P"."ID")
      37 - filter("P2"."FABRICATED"='Y')
      38 - access("R2"."PART_ID"="P2"."ID")
      40 - access("R4"."WORKORDER_TYPE"='M' AND "R3"."PART_ID"="R4"."WORKORDER_BASE_ID" AND "R4"."WORKORDER_LOT_ID"='0')
      42 - access("R5"."WORKORDER_TYPE"='M' AND "R4"."PART_ID"="R5"."WORKORDER_BASE_ID" AND "R5"."WORKORDER_LOT_ID"='0')
      43 - filter("P4"."FABRICATED"='Y')
      44 - access("R4"."PART_ID"="P4"."ID")
      45 - filter("P5"."FABRICATED"='Y')
      46 - access("R5"."PART_ID"="P5"."ID")
      48 - access("R6"."WORKORDER_TYPE"='M' AND "R5"."PART_ID"="R6"."WORKORDER_BASE_ID" AND "R6"."WORKORDER_LOT_ID"='0')
      49 - filter("P6"."FABRICATED"='Y')
      50 - access("R6"."PART_ID"="P6"."ID")

  Handle: 2152 User Time: 37.07S Sys  Time: 0.05S ElapsedTime: 75S Priority: 8 ThreadState: In Run Queue
   PID:19 SPID:2152 SID:145 SERIAL#:12 USERNAME:TESTUSER MACHINE:HOME.NET\AIRFORCE-3 PROGRAM:sqlplus.exe
   INSERT INTO T1 SELECT   CEIL(ABS(SIN(ROWNUM/9.9999)*10000)),   'This is the long description for this number '|| TO_CHAR(CEIL(ABS(SIN(ROWNUM/9.9999)*10000)))...

    SQL_ID  6hxcgpp1rd1ag, child number 0
    -------------------------------------
    INSERT INTO T1 SELECT   CEIL(ABS(SIN(ROWNUM/9.9999)*10000)),   'This is
    the long description for this number '||
    TO_CHAR(CEIL(ABS(SIN(ROWNUM/9.9999)*10000))) FROM   (SELECT     ROWNUM
    RN   FROM     DUAL   CONNECT BY     LEVEL<=10000),   (SELECT     ROWNUM
    RN   FROM     DUAL   CONNECT BY     LEVEL<=10000)

    Plan hash value: 643243249

    -----------------------------------------------------------------------------------
    | Id  | Operation                          | Name | Rows  | Cost (%CPU)| Time     |
    -----------------------------------------------------------------------------------
    |   0 | INSERT STATEMENT                   |      |       |     4 (100)|          |
    |   1 |  LOAD TABLE CONVENTIONAL           |      |       |            |          |
    |   2 |   COUNT                            |      |       |            |          |
    |   3 |    MERGE JOIN CARTESIAN            |      |     1 |     4   (0)| 00:00:01 |
    |   4 |     VIEW                           |      |     1 |     2   (0)| 00:00:01 |
    |   5 |      COUNT                         |      |       |            |          |
    |   6 |       CONNECT BY WITHOUT FILTERING |      |       |            |          |
    |   7 |        FAST DUAL                   |      |     1 |     2   (0)| 00:00:01 |
    |   8 |     BUFFER SORT                    |      |     1 |     4   (0)| 00:00:01 |
    |   9 |      VIEW                          |      |     1 |     2   (0)| 00:00:01 |
    |  10 |       COUNT                        |      |       |            |          |
    |  11 |        CONNECT BY WITHOUT FILTERING|      |       |            |          |
    |  12 |         FAST DUAL                  |      |     1 |     2   (0)| 00:00:01 |
    -----------------------------------------------------------------------------------

1/8/2010 12:52:17 PM Processes: 73 Threads: 861 C. Switches: 1548363 Q. Length: 5
Instance: c:\oracle\product\10.2.0\db_1\bin\ORACLE.EXE OR10
 User Time: 11.42S Sys  Time: 27.27S Memory: 232MB Page File: 0.63MB
  Handle: 1444 User Time: 11.85S Sys  Time: 27.97S ElapsedTime: 69S Priority: 8 ThreadState: Running

Instance: c:\oracle\product\11.1.0\db_1\bin\ORACLE.EXE OR11
 User Time: 55.19S Sys  Time: 0.78S Memory: 519.81MB Page File: 0.67MB
  Handle: 2152 User Time: 48.79S Sys  Time: 0.66S ElapsedTime: 67S Priority: 8 ThreadState: In Run Queue
   PID:19 SPID:2152 SID:145 SERIAL#:12 USERNAME:TESTUSER MACHINE:HOME.NET\AIRFORCE-3 PROGRAM:sqlplus.exe
   INSERT INTO T1 SELECT   CEIL(ABS(SIN(ROWNUM/9.9999)*10000)),   'This is the long description for this number '|| TO_CHAR(CEIL(ABS(SIN(ROWNUM/9.9999)*10000)))...

    SQL_ID  6hxcgpp1rd1ag, child number 0
    -------------------------------------
    INSERT INTO T1 SELECT   CEIL(ABS(SIN(ROWNUM/9.9999)*10000)),   'This is
    the long description for this number '||
    TO_CHAR(CEIL(ABS(SIN(ROWNUM/9.9999)*10000))) FROM   (SELECT     ROWNUM
    RN   FROM     DUAL   CONNECT BY     LEVEL<=10000),   (SELECT     ROWNUM
    RN   FROM     DUAL   CONNECT BY     LEVEL<=10000)

    Plan hash value: 643243249

    -----------------------------------------------------------------------------------
    | Id  | Operation                          | Name | Rows  | Cost (%CPU)| Time     |
    -----------------------------------------------------------------------------------
    |   0 | INSERT STATEMENT                   |      |       |     4 (100)|          |
    |   1 |  LOAD TABLE CONVENTIONAL           |      |       |            |          |
    |   2 |   COUNT                            |      |       |            |          |
    |   3 |    MERGE JOIN CARTESIAN            |      |     1 |     4   (0)| 00:00:01 |
    |   4 |     VIEW                           |      |     1 |     2   (0)| 00:00:01 |
    |   5 |      COUNT                         |      |       |            |          |
    |   6 |       CONNECT BY WITHOUT FILTERING |      |       |            |          |
    |   7 |        FAST DUAL                   |      |     1 |     2   (0)| 00:00:01 |
    |   8 |     BUFFER SORT                    |      |     1 |     4   (0)| 00:00:01 |
    |   9 |      VIEW                          |      |     1 |     2   (0)| 00:00:01 |
    |  10 |       COUNT                        |      |       |            |          |
    |  11 |        CONNECT BY WITHOUT FILTERING|      |       |            |          |
    |  12 |         FAST DUAL                  |      |     1 |     2   (0)| 00:00:01 |
    -----------------------------------------------------------------------------------

1/8/2010 12:53:24 PM Processes: 73 Threads: 859 C. Switches: 66962 Q. Length: 2
Instance: c:\oracle\product\10.2.0\db_1\bin\ORACLE.EXE OR10
 User Time: 21.67S Sys  Time: 43.91S Memory: 175.28MB Page File: 0.63MB
  Handle: 1444 User Time: 22.11S Sys  Time: 45.18S ElapsedTime: 70S Priority: 8 ThreadState: Running

Instance: c:\oracle\product\11.1.0\db_1\bin\ORACLE.EXE OR11
 User Time: 65.88S Sys  Time: 0.08S Memory: 441.9MB Page File: 0.67MB
  Handle: 2152 User Time: 66.77S Sys  Time: 0.06S ElapsedTime: 68S Priority: 8 ThreadState: Running
   PID:19 SPID:2152 SID:145 SERIAL#:12 USERNAME:TESTUSER MACHINE:HOME.NET\AIRFORCE-3 PROGRAM:sqlplus.exe
   INSERT INTO T1 SELECT   CEIL(ABS(SIN(ROWNUM/9.9999)*10000)),   'This is the long description for this number '|| TO_CHAR(CEIL(ABS(SIN(ROWNUM/9.9999)*10000)))...

    SQL_ID  6hxcgpp1rd1ag, child number 0
    -------------------------------------
    INSERT INTO T1 SELECT   CEIL(ABS(SIN(ROWNUM/9.9999)*10000)),   'This is
    the long description for this number '||
    TO_CHAR(CEIL(ABS(SIN(ROWNUM/9.9999)*10000))) FROM   (SELECT     ROWNUM
    RN   FROM     DUAL   CONNECT BY     LEVEL<=10000),   (SELECT     ROWNUM
    RN   FROM     DUAL   CONNECT BY     LEVEL<=10000)

    Plan hash value: 643243249

    -----------------------------------------------------------------------------------
    | Id  | Operation                          | Name | Rows  | Cost (%CPU)| Time     |
    -----------------------------------------------------------------------------------
    |   0 | INSERT STATEMENT                   |      |       |     4 (100)|          |
    |   1 |  LOAD TABLE CONVENTIONAL           |      |       |            |          |
    |   2 |   COUNT                            |      |       |            |          |
    |   3 |    MERGE JOIN CARTESIAN            |      |     1 |     4   (0)| 00:00:01 |
    |   4 |     VIEW                           |      |     1 |     2   (0)| 00:00:01 |
    |   5 |      COUNT                         |      |       |            |          |
    |   6 |       CONNECT BY WITHOUT FILTERING |      |       |            |          |
    |   7 |        FAST DUAL                   |      |     1 |     2   (0)| 00:00:01 |
    |   8 |     BUFFER SORT                    |      |     1 |     4   (0)| 00:00:01 |
    |   9 |      VIEW                          |      |     1 |     2   (0)| 00:00:01 |
    |  10 |       COUNT                        |      |       |            |          |
    |  11 |        CONNECT BY WITHOUT FILTERING|      |       |            |          |
    |  12 |         FAST DUAL                  |      |     1 |     2   (0)| 00:00:01 |
    -----------------------------------------------------------------------------------

1/8/2010 12:54:35 PM Processes: 73 Threads: 860 C. Switches: 47967 Q. Length: 5
Instance: c:\oracle\product\10.2.0\db_1\bin\ORACLE.EXE OR10
 User Time: 15.63S Sys  Time: 48.93S Memory: 141.9MB Page File: 0.63MB
  Handle: 1444 User Time: 14.4S Sys  Time: 46.38S ElapsedTime: 68S Priority: 8 ThreadState: In Run Queue

Instance: c:\oracle\product\11.1.0\db_1\bin\ORACLE.EXE OR11
 User Time: 75.85S Sys  Time: 0.09S Memory: 438.77MB Page File: 0.67MB
  Handle: 2152 User Time: 64.79S Sys  Time: 0S ElapsedTime: 71S Priority: 8 ThreadState: In Run Queue
   PID:19 SPID:2152 SID:145 SERIAL#:12 USERNAME:TESTUSER MACHINE:HOME.NET\AIRFORCE-3 PROGRAM:sqlplus.exe
   INSERT INTO T1 SELECT   CEIL(ABS(SIN(ROWNUM/9.9999)*10000)),   'This is the long description for this number '|| TO_CHAR(CEIL(ABS(SIN(ROWNUM/9.9999)*10000)))...

    SQL_ID  6hxcgpp1rd1ag, child number 0
    -------------------------------------
    INSERT INTO T1 SELECT   CEIL(ABS(SIN(ROWNUM/9.9999)*10000)),   'This is
    the long description for this number '||
    TO_CHAR(CEIL(ABS(SIN(ROWNUM/9.9999)*10000))) FROM   (SELECT     ROWNUM
    RN   FROM     DUAL   CONNECT BY     LEVEL<=10000),   (SELECT     ROWNUM
    RN   FROM     DUAL   CONNECT BY     LEVEL<=10000)

    Plan hash value: 643243249

    -----------------------------------------------------------------------------------
    | Id  | Operation                          | Name | Rows  | Cost (%CPU)| Time     |
    -----------------------------------------------------------------------------------
    |   0 | INSERT STATEMENT                   |      |       |     4 (100)|          |
    |   1 |  LOAD TABLE CONVENTIONAL           |      |       |            |          |
    |   2 |   COUNT                            |      |       |            |          |
    |   3 |    MERGE JOIN CARTESIAN            |      |     1 |     4   (0)| 00:00:01 |
    |   4 |     VIEW                           |      |     1 |     2   (0)| 00:00:01 |
    |   5 |      COUNT                         |      |       |            |          |
    |   6 |       CONNECT BY WITHOUT FILTERING |      |       |            |          |
    |   7 |        FAST DUAL                   |      |     1 |     2   (0)| 00:00:01 |
    |   8 |     BUFFER SORT                    |      |     1 |     4   (0)| 00:00:01 |
    |   9 |      VIEW                          |      |     1 |     2   (0)| 00:00:01 |
    |  10 |       COUNT                        |      |       |            |          |
    |  11 |        CONNECT BY WITHOUT FILTERING|      |       |            |          |
    |  12 |         FAST DUAL                  |      |     1 |     2   (0)| 00:00:01 |
    -----------------------------------------------------------------------------------

1/8/2010 12:55:42 PM Processes: 73 Threads: 864 C. Switches: 35978 Q. Length: 6
Instance: c:\oracle\product\10.2.0\db_1\bin\ORACLE.EXE OR10
 User Time: 8.83S Sys  Time: 23.93S Memory: 141.25MB Page File: 0.63MB
  Handle: 1444 User Time: 9.08S Sys  Time: 24.16S ElapsedTime: 68S Priority: 8 ThreadState: In Run Queue

Instance: c:\oracle\product\11.1.0\db_1\bin\ORACLE.EXE OR11
 User Time: 98.7S Sys  Time: 0.22S Memory: 445.1MB Page File: 0.67MB
  Handle: 2152 User Time: 32.07S Sys  Time: 0S ElapsedTime: 65S Priority: 8 ThreadState: In Run Queue
   PID:19 SPID:2152 SID:145 SERIAL#:12 USERNAME:TESTUSER MACHINE:HOME.NET\AIRFORCE-3 PROGRAM:sqlplus.exe
   INSERT INTO T1 SELECT   CEIL(ABS(SIN(ROWNUM/9.9999)*10000)),   'This is the long description for this number '|| TO_CHAR(CEIL(ABS(SIN(ROWNUM/9.9999)*10000)))...

    SQL_ID  6hxcgpp1rd1ag, child number 0
    -------------------------------------
    INSERT INTO T1 SELECT   CEIL(ABS(SIN(ROWNUM/9.9999)*10000)),   'This is
    the long description for this number '||
    TO_CHAR(CEIL(ABS(SIN(ROWNUM/9.9999)*10000))) FROM   (SELECT     ROWNUM
    RN   FROM     DUAL   CONNECT BY     LEVEL<=10000),   (SELECT     ROWNUM
    RN   FROM     DUAL   CONNECT BY     LEVEL<=10000)

    Plan hash value: 643243249

    -----------------------------------------------------------------------------------
    | Id  | Operation                          | Name | Rows  | Cost (%CPU)| Time     |
    -----------------------------------------------------------------------------------
    |   0 | INSERT STATEMENT                   |      |       |     4 (100)|          |
    |   1 |  LOAD TABLE CONVENTIONAL           |      |       |            |          |
    |   2 |   COUNT                            |      |       |            |          |
    |   3 |    MERGE JOIN CARTESIAN            |      |     1 |     4   (0)| 00:00:01 |
    |   4 |     VIEW                           |      |     1 |     2   (0)| 00:00:01 |
    |   5 |      COUNT                         |      |       |            |          |
    |   6 |       CONNECT BY WITHOUT FILTERING |      |       |            |          |
    |   7 |        FAST DUAL                   |      |     1 |     2   (0)| 00:00:01 |
    |   8 |     BUFFER SORT                    |      |     1 |     4   (0)| 00:00:01 |
    |   9 |      VIEW                          |      |     1 |     2   (0)| 00:00:01 |
    |  10 |       COUNT                        |      |       |            |          |
    |  11 |        CONNECT BY WITHOUT FILTERING|      |       |            |          |
    |  12 |         FAST DUAL                  |      |     1 |     2   (0)| 00:00:01 |
    -----------------------------------------------------------------------------------

  Handle: 5960 User Time: 65.07S Sys  Time: 0S ElapsedTime: 65S Priority: 8 ThreadState: Running
   PID:20 SPID:5960 SID:132 SERIAL#:55 USERNAME:TESTUSER MACHINE:HOME.NET\AIRFORCE-3 PROGRAM:sqlplus.exe
   DECLARE   i NUMBER := 0;   STime DATE := SYSDATE; BEGIN   WHILE (SYSDATE - STime) < 0.006945 LOOP     i := i + + 0.000001;   End Loop; End;

    SQL_ID  cujkdbu2npk0x, child number 0

    DECLARE   i NUMBER := 0;   STime DATE := SYSDATE; BEGIN   WHILE
    (SYSDATE - STime) < 0.006945 LOOP     i := i + + 0.000001;   End Loop;
    End;

    NOTE: cannot fetch plan for SQL_ID: cujkdbu2npk0x, CHILD_NUMBER: 0
          Please verify value of SQL_ID and CHILD_NUMBER;
          It could also be that the plan is no longer in cursor cache (check v$sql_plan)

1/8/2010 12:56:47 PM Processes: 73 Threads: 856 C. Switches: 59846 Q. Length: 5
Instance: c:\oracle\product\10.2.0\db_1\bin\ORACLE.EXE OR10
 User Time: 9.3S Sys  Time: 22.7S Memory: 141.1MB Page File: 0.63MB
  Handle: 1444 User Time: 9.25S Sys  Time: 22.85S ElapsedTime: 65S Priority: 8 ThreadState: In Run Queue

Instance: c:\oracle\product\11.1.0\db_1\bin\ORACLE.EXE OR11
 User Time: 96.47S Sys  Time: 0.03S Memory: 440.21MB Page File: 0.67MB
  Handle: 2152 User Time: 32.72S Sys  Time: 0S ElapsedTime: 67S Priority: 8 ThreadState: In Run Queue
   PID:19 SPID:2152 SID:145 SERIAL#:12 USERNAME:TESTUSER MACHINE:HOME.NET\AIRFORCE-3 PROGRAM:sqlplus.exe
   INSERT INTO T1 SELECT   CEIL(ABS(SIN(ROWNUM/9.9999)*10000)),   'This is the long description for this number '|| TO_CHAR(CEIL(ABS(SIN(ROWNUM/9.9999)*10000)))...

    SQL_ID  6hxcgpp1rd1ag, child number 0
    -------------------------------------
    INSERT INTO T1 SELECT   CEIL(ABS(SIN(ROWNUM/9.9999)*10000)),   'This is
    the long description for this number '||
    TO_CHAR(CEIL(ABS(SIN(ROWNUM/9.9999)*10000))) FROM   (SELECT     ROWNUM
    RN   FROM     DUAL   CONNECT BY     LEVEL<=10000),   (SELECT     ROWNUM
    RN   FROM     DUAL   CONNECT BY     LEVEL<=10000)

    Plan hash value: 643243249

    -----------------------------------------------------------------------------------
    | Id  | Operation                          | Name | Rows  | Cost (%CPU)| Time     |
    -----------------------------------------------------------------------------------
    |   0 | INSERT STATEMENT                   |      |       |     4 (100)|          |
    |   1 |  LOAD TABLE CONVENTIONAL           |      |       |            |          |
    |   2 |   COUNT                            |      |       |            |          |
    |   3 |    MERGE JOIN CARTESIAN            |      |     1 |     4   (0)| 00:00:01 |
    |   4 |     VIEW                           |      |     1 |     2   (0)| 00:00:01 |
    |   5 |      COUNT                         |      |       |            |          |
    |   6 |       CONNECT BY WITHOUT FILTERING |      |       |            |          |
    |   7 |        FAST DUAL                   |      |     1 |     2   (0)| 00:00:01 |
    |   8 |     BUFFER SORT                    |      |     1 |     4   (0)| 00:00:01 |
    |   9 |      VIEW                          |      |     1 |     2   (0)| 00:00:01 |
    |  10 |       COUNT                        |      |       |            |          |
    |  11 |        CONNECT BY WITHOUT FILTERING|      |       |            |          |
    |  12 |         FAST DUAL                  |      |     1 |     2   (0)| 00:00:01 |
    -----------------------------------------------------------------------------------

  Handle: 5960 User Time: 54.01S Sys  Time: 0S ElapsedTime: 67S Priority: 8 ThreadState: In Run Queue
   PID:20 SPID:5960 SID:132 SERIAL#:55 USERNAME:TESTUSER MACHINE:HOME.NET\AIRFORCE-3 PROGRAM:sqlplus.exe
   DECLARE   i NUMBER := 0;   STime DATE := SYSDATE; BEGIN   WHILE (SYSDATE - STime) < 0.006945 LOOP     i := i + + 0.000001;   End Loop; End;

    SQL_ID  cujkdbu2npk0x, child number 0

    DECLARE   i NUMBER := 0;   STime DATE := SYSDATE; BEGIN   WHILE
    (SYSDATE - STime) < 0.006945 LOOP     i := i + + 0.000001;   End Loop;
    End;

    NOTE: cannot fetch plan for SQL_ID: cujkdbu2npk0x, CHILD_NUMBER: 0
          Please verify value of SQL_ID and CHILD_NUMBER;
          It could also be that the plan is no longer in cursor cache (check v$sql_plan)

1/8/2010 12:57:56 PM Processes: 73 Threads: 861 C. Switches: 35972 Q. Length: 6
Instance: c:\oracle\product\10.2.0\db_1\bin\ORACLE.EXE OR10
 User Time: 9.33S Sys  Time: 25.19S Memory: 141.11MB Page File: 0.63MB
  Handle: 1444 User Time: 9.34S Sys  Time: 25.5S ElapsedTime: 70S Priority: 8 ThreadState: In Run Queue

Instance: c:\oracle\product\11.1.0\db_1\bin\ORACLE.EXE OR11
 User Time: 103.9S Sys  Time: 0.13S Memory: 442.42MB Page File: 0.67MB
  Handle: 3520 User Time: 34.13S Sys  Time: 0.02S ElapsedTime: 69S Priority: 8 ThreadState: Running
   PID:18 SPID:3520 SID:146 SERIAL#:4 USERNAME:TESTUSER MACHINE:HOME.NET\AIRFORCE-3 PROGRAM:sqlplus.exe
   DECLARE   i NUMBER := 0;   STime DATE := SYSDATE; BEGIN   WHILE (SYSDATE - STime) < 0.006945 LOOP     i := i + + 0.000001;   End Loop; End;

    SQL_ID  cujkdbu2npk0x, child number 0

    DECLARE   i NUMBER := 0;   STime DATE := SYSDATE; BEGIN   WHILE
    (SYSDATE - STime) < 0.006945 LOOP     i := i + + 0.000001;   End Loop;
    End;

    NOTE: cannot fetch plan for SQL_ID: cujkdbu2npk0x, CHILD_NUMBER: 0
          Please verify value of SQL_ID and CHILD_NUMBER;
          It could also be that the plan is no longer in cursor cache (check v$sql_plan)

  Handle: 2152 User Time: 34.04S Sys  Time: 0S ElapsedTime: 69S Priority: 8 ThreadState: In Run Queue
   PID:19 SPID:2152 SID:145 SERIAL#:12 USERNAME:TESTUSER MACHINE:HOME.NET\AIRFORCE-3 PROGRAM:sqlplus.exe
   INSERT INTO T1 SELECT   CEIL(ABS(SIN(ROWNUM/9.9999)*10000)),   'This is the long description for this number '|| TO_CHAR(CEIL(ABS(SIN(ROWNUM/9.9999)*10000)))...

    SQL_ID  6hxcgpp1rd1ag, child number 0
    -------------------------------------
    INSERT INTO T1 SELECT   CEIL(ABS(SIN(ROWNUM/9.9999)*10000)),   'This is
    the long description for this number '||
    TO_CHAR(CEIL(ABS(SIN(ROWNUM/9.9999)*10000))) FROM   (SELECT     ROWNUM
    RN   FROM     DUAL   CONNECT BY     LEVEL<=10000),   (SELECT     ROWNUM
    RN   FROM     DUAL   CONNECT BY     LEVEL<=10000)

    Plan hash value: 643243249

    -----------------------------------------------------------------------------------
    | Id  | Operation                          | Name | Rows  | Cost (%CPU)| Time     |
    -----------------------------------------------------------------------------------
    |   0 | INSERT STATEMENT                   |      |       |     4 (100)|          |
    |   1 |  LOAD TABLE CONVENTIONAL           |      |       |            |          |
    |   2 |   COUNT                            |      |       |            |          |
    |   3 |    MERGE JOIN CARTESIAN            |      |     1 |     4   (0)| 00:00:01 |
    |   4 |     VIEW                           |      |     1 |     2   (0)| 00:00:01 |
    |   5 |      COUNT                         |      |       |            |          |
    |   6 |       CONNECT BY WITHOUT FILTERING |      |       |            |          |
    |   7 |        FAST DUAL                   |      |     1 |     2   (0)| 00:00:01 |
    |   8 |     BUFFER SORT                    |      |     1 |     4   (0)| 00:00:01 |
    |   9 |      VIEW                          |      |     1 |     2   (0)| 00:00:01 |
    |  10 |       COUNT                        |      |       |            |          |
    |  11 |        CONNECT BY WITHOUT FILTERING|      |       |            |          |
    |  12 |         FAST DUAL                  |      |     1 |     2   (0)| 00:00:01 |
    -----------------------------------------------------------------------------------

  Handle: 5960 User Time: 34.18S Sys  Time: 0S ElapsedTime: 68S Priority: 8 ThreadState: In Run Queue
   PID:20 SPID:5960 SID:132 SERIAL#:55 USERNAME:TESTUSER MACHINE:HOME.NET\AIRFORCE-3 PROGRAM:sqlplus.exe
   DECLARE   i NUMBER := 0;   STime DATE := SYSDATE; BEGIN   WHILE (SYSDATE - STime) < 0.006945 LOOP     i := i + + 0.000001;   End Loop; End;
    SQL_ID  cujkdbu2npk0x, child number 0

    DECLARE   i NUMBER := 0;   STime DATE := SYSDATE; BEGIN   WHILE
    (SYSDATE - STime) < 0.006945 LOOP     i := i + + 0.000001;   End Loop;
    End;

    NOTE: cannot fetch plan for SQL_ID: cujkdbu2npk0x, CHILD_NUMBER: 0
          Please verify value of SQL_ID and CHILD_NUMBER;
          It could also be that the plan is no longer in cursor cache (check v$sql_plan)

Notice in the above that toward the end two sessions were doing nothing but burning CPU in a PL/SQL loop - the script caught the person trying to soak the computer's dual core CPU.  The CPU queue length jumped significantly as a result of the activity of the two sessions.

Well, the above is neat, but what about the script to create the output?  Sorry, I ran out of space in this blog post - check back in a little while... (Forward to the Follow-Up Article)


Actions

Information

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s




Follow

Get every new post delivered to your Inbox.

Join 143 other followers

%d bloggers like this: