1 3 4 5 6 7 8 Previous Next 117 Replies Latest reply: May 5, 2008 12:19 PM by 181444 Go to original post RSS
      • 60. Re: query tuning
        599921
        charles,
        Here I am posting total TKPROF output.
        TKPROF: Release 9.2.0.4.0 - Production on Thu Apr 17 10:46:10 2008
        
        Copyright (c) 1982, 2002, Oracle Corporation.  All rights reserved.
        
        Trace file: g_ora_14292.trc
        Sort options: default
        
        ********************************************************************************
        count    = number of times OCI procedure was executed
        cpu      = cpu time in seconds executing 
        elapsed  = elapsed time in seconds executing
        disk     = number of physical reads of buffers from disk
        query    = number of buffers gotten for consistent read
        current  = number of buffers gotten in current mode (usually for update)
        rows     = number of rows processed by the fetch or execute call
        ********************************************************************************
        
        alter SESSION SET EVENTS '10046 trace name context forever, level 12'
        
        
        call     count       cpu    elapsed       disk      query    current        rows
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        Parse        0      0.00       0.00          0          0          0           0
        Execute      1      0.00       0.00          0          0          0           0
        Fetch        0      0.00       0.00          0          0          0           0
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        total        1      0.00       0.00          0          0          0           0
        
        Misses in library cache during parse: 0
        Optimizer goal: CHOOSE
        Parsing user id: 315  (DEVEL)
        
        Elapsed times include waiting on following events:
          Event waited on                             Times   Max. Wait  Total Waited
          ----------------------------------------   Waited  ----------  ------------
          SQL*Net message to client                       1        0.00          0.00
          SQL*Net message from client                     1        0.00          0.00
        ********************************************************************************
        
        alter SESSION SET TIMED_STATISTICS = TRUE
        
        
        call     count       cpu    elapsed       disk      query    current        rows
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        Parse        1      0.00       0.02          0          0          0           0
        Execute      1      0.00       0.00          0          0          0           0
        Fetch        0      0.00       0.00          0          0          0           0
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        total        2      0.00       0.02          0          0          0           0
        
        Misses in library cache during parse: 1
        Optimizer goal: CHOOSE
        Parsing user id: 315  (DEVEL)
        
        Elapsed times include waiting on following events:
          Event waited on                             Times   Max. Wait  Total Waited
          ----------------------------------------   Waited  ----------  ------------
          SQL*Net message to client                       1        0.00          0.00
          SQL*Net message from client                     1        0.00          0.00
        ********************************************************************************
        
        alter SESSION SET NLS_NUMERIC_CHARACTERS = '.,'
        
        
        call     count       cpu    elapsed       disk      query    current        rows
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        Parse        1      0.00       0.00          0          0          0           0
        Execute      1      0.00       0.00          0          0          0           0
        Fetch        0      0.00       0.00          0          0          0           0
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        total        2      0.00       0.00          0          0          0           0
        
        Misses in library cache during parse: 1
        Optimizer goal: CHOOSE
        Parsing user id: 315  (DEVEL)
        
        Elapsed times include waiting on following events:
          Event waited on                             Times   Max. Wait  Total Waited
          ----------------------------------------   Waited  ----------  ------------
          SQL*Net message to client                       1        0.00          0.00
          SQL*Net message from client                     1        0.00          0.00
        ********************************************************************************
        
        alter SESSION SET NLS_DATE_FORMAT = 'YYYYMMDD'
        
        
        call     count       cpu    elapsed       disk      query    current        rows
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        Parse        1      0.01       0.00          0          0          0           0
        Execute      1      0.00       0.00          0          0          0           0
        Fetch        0      0.00       0.00          0          0          0           0
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        total        2      0.01       0.00          0          0          0           0
        
        Misses in library cache during parse: 1
        Optimizer goal: CHOOSE
        Parsing user id: 315  (DEVEL)
        
        Elapsed times include waiting on following events:
          Event waited on                             Times   Max. Wait  Total Waited
          ----------------------------------------   Waited  ----------  ------------
          SQL*Net message to client                       1        0.00          0.00
          SQL*Net message from client                     1        0.00          0.00
          library cache pin                               2        3.00          3.00
        ********************************************************************************
        
        select  /*+  INDEX(rc pk_restart_control)  +*/ process_flag ,driver_name ,
          num_threads ,commit_max_ctr  
        from
         restart_control rc where program_name=LOWER(:b0)           
        
        
        call     count       cpu    elapsed       disk      query    current        rows
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        Parse        1      0.00       3.00          0          0          0           0
        Execute      1      0.00       0.00          0          0          0           0
        Fetch        1      0.00       0.00          0          2          0           1
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        total        3      0.00       3.00          0          2          0           1
        
        Misses in library cache during parse: 0
        Optimizer goal: CHOOSE
        Parsing user id: 315  (DEVEL)
        
        Rows     Row Source Operation
        -------  ---------------------------------------------------
              1  TABLE ACCESS BY INDEX ROWID OBJ#(28470) (cr=2 r=0 w=0 time=14 us)
              1   INDEX UNIQUE SCAN OBJ#(28471) (cr=1 r=0 w=0 time=8 us)(object id 28471)
        
        
        Rows     Execution Plan
        -------  ---------------------------------------------------
              0  SELECT STATEMENT   GOAL: CHOOSE
              1   TABLE ACCESS   GOAL: ANALYZED (BY INDEX ROWID) OF 
                      'RESTART_CONTROL'
              1    INDEX   GOAL: ANALYZED (UNIQUE SCAN) OF 'PK_RESTART_CONTROL' 
                       (UNIQUE)
        
        
        Elapsed times include waiting on following events:
          Event waited on                             Times   Max. Wait  Total Waited
          ----------------------------------------   Waited  ----------  ------------
          SQL*Net message to client                       1        0.00          0.00
          SQL*Net message from client                     1        0.00          0.00
        ********************************************************************************
        
        select sid  
        from
         v$session where process=to_char(:b0)           
        
        
        call     count       cpu    elapsed       disk      query    current        rows
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        Parse        1      0.00       0.00          0          0          0           0
        Execute      1      0.00       0.00          0          0          0           0
        Fetch        1      0.00       0.00          0          0          0           1
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        total        3      0.00       0.00          0          0          0           1
        
        Misses in library cache during parse: 0
        Optimizer goal: CHOOSE
        Parsing user id: 315  (DEVEL)
        
        Rows     Row Source Operation
        -------  ---------------------------------------------------
              1  FIXED TABLE FULL X$KSUSE (cr=0 r=0 w=0 time=71 us)
        
        error during execute of EXPLAIN PLAN statement
        ORA-01039: insufficient privileges on underlying objects of the view
        
        parse error offset: 91
        
        Elapsed times include waiting on following events:
          Event waited on                             Times   Max. Wait  Total Waited
          ----------------------------------------   Waited  ----------  ------------
          SQL*Net message to client                       1        0.00          0.00
          SQL*Net message from client                     1        0.00          0.00
        ********************************************************************************
        
        select p.spid  
        from
         v$session s ,v$process p where (s.audsid=userenv('SESSIONID') and s.paddr=
          p.addr)           
        
        
        call     count       cpu    elapsed       disk      query    current        rows
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        Parse        1      0.00       0.00          0          0          0           0
        Execute      1      0.00       0.00          0          0          0           0
        Fetch        1      0.00       0.00          0          0          0           1
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        total        3      0.00       0.00          0          0          0           1
        
        Misses in library cache during parse: 0
        Optimizer goal: CHOOSE
        Parsing user id: 315  (DEVEL)
        
        Rows     Row Source Operation
        -------  ---------------------------------------------------
              1  MERGE JOIN  (cr=0 r=0 w=0 time=376 us)
             19   FIXED TABLE FULL X$KSUPR (cr=0 r=0 w=0 time=37 us)
              1   SORT JOIN (cr=0 r=0 w=0 time=268 us)
              1    FIXED TABLE FULL X$KSUSE (cr=0 r=0 w=0 time=245 us)
        
        error during execute of EXPLAIN PLAN statement
        ORA-01039: insufficient privileges on underlying objects of the view
        
        parse error offset: 107
        
        Elapsed times include waiting on following events:
          Event waited on                             Times   Max. Wait  Total Waited
          ----------------------------------------   Waited  ----------  ------------
          SQL*Net message to client                       1        0.00          0.00
          SQL*Net message from client                     1        0.00          0.00
        ********************************************************************************
        
        select  /*+  INDEX(rps pk_restart_program_status)  +*/ ROWIDTOCHAR(rowid)  
        from
         restart_program_status rps where (restart_name=LOWER(:b0) and (restart_flag=
          'Y' or program_status='ready for start'))           
        
        
        call     count       cpu    elapsed       disk      query    current        rows
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        Parse        1      0.00       0.00          0          0          0           0
        Execute      1      0.00       0.00          0          0          0           0
        Fetch        5      0.00       0.00          0         12          0           9
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        total        7      0.00       0.00          0         12          0           9
        
        Misses in library cache during parse: 0
        Optimizer goal: CHOOSE
        Parsing user id: 315  (DEVEL)
        
        Rows     Row Source Operation
        -------  ---------------------------------------------------
              9  TABLE ACCESS BY INDEX ROWID OBJ#(28475) (cr=12 r=0 w=0 time=189 us)
             10   INDEX RANGE SCAN OBJ#(28477) (cr=6 r=0 w=0 time=102 us)(object id 28477)
        
        
        Rows     Execution Plan
        -------  ---------------------------------------------------
              0  SELECT STATEMENT   GOAL: CHOOSE
              9   TABLE ACCESS   GOAL: ANALYZED (BY INDEX ROWID) OF 
                      'RESTART_PROGRAM_STATUS'
             10    INDEX   GOAL: ANALYZED (RANGE SCAN) OF 
                       'PK_RESTART_PROGRAM_STATUS' (UNIQUE)
        
        
        Elapsed times include waiting on following events:
          Event waited on                             Times   Max. Wait  Total Waited
          ----------------------------------------   Waited  ----------  ------------
          SQL*Net message to client                       5        0.00          0.00
          SQL*Net message from client                     5        0.00          0.03
        ********************************************************************************
        
        select NVL(restart_flag,'N') ,thread_val  
        from
         restart_program_status where (rowid=CHARTOROWID(:b0) and (restart_flag='Y' 
          or program_status='ready for start')) for update nowait 
        
        
        call     count       cpu    elapsed       disk      query    current        rows
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        Parse        2      0.00       0.00          0          0          0           0
        Execute      9      0.00       0.00          0         11          3           0
        Fetch        8      0.00       0.00          0          0          0           1
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        total       19      0.00       0.00          0         11          3           1
        
        Misses in library cache during parse: 0
        Optimizer goal: CHOOSE
        Parsing user id: 315  (DEVEL)
        
        Rows     Row Source Operation
        -------  ---------------------------------------------------
              0  FOR UPDATE  (cr=0 r=0 w=0 time=0 us)
              1   TABLE ACCESS BY USER ROWID RESTART_PROGRAM_STATUS (cr=2 r=0 w=0 time=66 us)
        
        
        Rows     Execution Plan
        -------  ---------------------------------------------------
              0  SELECT STATEMENT   GOAL: CHOOSE
              0   FOR UPDATE
              1    TABLE ACCESS   GOAL: ANALYZED (BY USER ROWID) OF 
                       'RESTART_PROGRAM_STATUS'
        
        
        Elapsed times include waiting on following events:
          Event waited on                             Times   Max. Wait  Total Waited
          ----------------------------------------   Waited  ----------  ------------
          SQL*Net break/reset to client                   2        0.01          0.01
          SQL*Net message to client                       9        0.00          0.00
          SQL*Net message from client                     9        0.04          0.11
        ********************************************************************************
        
        update restart_program_status  set program_status='started',restart_flag=null 
          ,start_time=DECODE(restart_flag,'Y',start_time,SYSDATE),restart_time=
          DECODE(restart_flag,'Y',SYSDATE,null ),finish_time=null ,current_pid=:b0,
          current_operator_id=:b1,current_oracle_sid=:b2,current_shadow_pid=:b3,
          err_message=null  
        where
         rowid = :x
        
        
        call     count       cpu    elapsed       disk      query    current        rows
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        Parse        1      0.00       0.00          0          0          0           0
        Execute      1      0.00       0.00          0          1          1           1
        Fetch        0      0.00       0.00          0          0          0           0
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        total        2      0.00       0.00          0          1          1           1
        
        Misses in library cache during parse: 0
        Optimizer goal: CHOOSE
        Parsing user id: 315  (DEVEL)
        
        Rows     Row Source Operation
        -------  ---------------------------------------------------
              1  UPDATE  (cr=1 r=0 w=0 time=147 us)
              1   TABLE ACCESS BY USER ROWID OBJ#(28475) (cr=1 r=0 w=0 time=23 us)
        
        
        Rows     Execution Plan
        -------  ---------------------------------------------------
              0  UPDATE STATEMENT   GOAL: CHOOSE
              1   UPDATE OF 'RESTART_PROGRAM_STATUS'
              1    TABLE ACCESS   GOAL: ANALYZED (BY USER ROWID) OF 
                       'RESTART_PROGRAM_STATUS'
        
        
        Elapsed times include waiting on following events:
          Event waited on                             Times   Max. Wait  Total Waited
          ----------------------------------------   Waited  ----------  ------------
          SQL*Net message to client                       1        0.00          0.00
          SQL*Net message from client                     1        0.01          0.01
        ********************************************************************************
        
        insert into restart_bookmark (restart_name,thread_val,bookmark_string,
          application_image,out_file_string,non_fatal_err_flag,num_commits,
          avg_time_btwn_commits) 
        values
         (LOWER(:b0),:b1,null ,null ,null ,DECODE(:b2,1,'Y','N'),0,null )
        
        
        call     count       cpu    elapsed       disk      query    current        rows
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        Parse        1      0.00       0.00          0          0          0           0
        Execute      1      0.00       0.00          0          1          7           1
        Fetch        0      0.00       0.00          0          0          0           0
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        total        2      0.00       0.00          0          1          7           1
        
        Misses in library cache during parse: 0
        Optimizer goal: CHOOSE
        Parsing user id: 315  (DEVEL)
        
        Rows     Execution Plan
        -------  ---------------------------------------------------
              0  INSERT STATEMENT   GOAL: CHOOSE
        
        
        Elapsed times include waiting on following events:
          Event waited on                             Times   Max. Wait  Total Waited
          ----------------------------------------   Waited  ----------  ------------
          SQL*Net message to client                       1        0.00          0.00
          SQL*Net message from client                     1        0.00          0.00
        ********************************************************************************
        
        select TO_CHAR(p.vdate,'YYYYMMDD') ,so.multichannel_ind  
        from
         period p ,system_options so            
        
        
        call     count       cpu    elapsed       disk      query    current        rows
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        Parse        1      0.00       0.00          0          0          0           0
        Execute      1      0.00       0.00          0          0          0           0
        Fetch        1      0.00       0.00          0         19          0           1
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        total        3      0.00       0.00          0         19          0           1
        
        Misses in library cache during parse: 0
        Optimizer goal: CHOOSE
        Parsing user id: 315  (DEVEL)
        
        Rows     Row Source Operation
        -------  ---------------------------------------------------
              1  MERGE JOIN CARTESIAN (cr=19 r=0 w=0 time=233 us)
              1   TABLE ACCESS FULL OBJ#(28207) (cr=4 r=0 w=0 time=65 us)
              1   BUFFER SORT (cr=15 r=0 w=0 time=137 us)
              1    TABLE ACCESS FULL OBJ#(29081) (cr=15 r=0 w=0 time=61 us)
        
        
        Rows     Execution Plan
        -------  ---------------------------------------------------
              0  SELECT STATEMENT   GOAL: CHOOSE
              1   MERGE JOIN (CARTESIAN)
              1    TABLE ACCESS   GOAL: ANALYZED (FULL) OF 'PERIOD'
              1    BUFFER (SORT)
              1     TABLE ACCESS   GOAL: ANALYZED (FULL) OF 'SYSTEM_OPTIONS'
        
        
        Elapsed times include waiting on following events:
          Event waited on                             Times   Max. Wait  Total Waited
          ----------------------------------------   Waited  ----------  ------------
          SQL*Net message to client                       1        0.00          0.00
          SQL*Net message from client                     1        0.56          0.56
        ********************************************************************************
        
        select t.tsf_no ,t.from_loc ,t.from_loc_type ,t.to_loc ,t.to_loc_type ,
          TO_CHAR(t.delivery_date,'YYYYMMDD') ,NVL(t.routing_code,' ') ,
          NVL(t.freight_code,'N') ,t.item ,t.tsf_qty ,NVL(t.supp_pack_size,'-1') ,
          ROWIDTOCHAR(t.rowid )  
        from
         tsf_staging t where ((:b0<>'Y' and t.process_ind is null ) and 
          t.from_loc=:b1) union all select t.tsf_no ,t.from_loc ,t.from_loc_type ,
          t.to_loc ,t.to_loc_type ,TO_CHAR(t.delivery_date,'YYYYMMDD') ,
          NVL(t.routing_code,' ') ,NVL(t.freight_code,'N') ,t.item ,t.tsf_qty ,
          NVL(t.supp_pack_size,'-1') ,ROWIDTOCHAR(t.rowid )  from tsf_staging t 
          where (:b0='Y' and t.process_ind='F') order by from_loc,tsf_no            
        
        
        call     count       cpu    elapsed       disk      query    current        rows
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        Parse        1      0.00       0.00          0          0          0           0
        Execute      1      0.00       0.00          0          0          0           0
        Fetch        9      1.63       6.99        713      64359          4       71859
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        total       11      1.63       6.99        713      64359          4       71859
        
        Misses in library cache during parse: 0
        Optimizer goal: CHOOSE
        Parsing user id: 315  (DEVEL)
        
        Rows     Row Source Operation
        -------  ---------------------------------------------------
          71859  SORT ORDER BY (cr=64359 r=713 w=712 time=6546143 us)
          71859   UNION-ALL  (cr=64359 r=1 w=0 time=3038270 us)
          71859    FILTER  (cr=64359 r=1 w=0 time=2231615 us)
          71859     TABLE ACCESS BY INDEX ROWID OBJ#(83393) (cr=64359 r=1 w=0 time=2089038 us)
          71859      INDEX RANGE SCAN OBJ#(95748) (cr=253 r=1 w=0 time=353042 us)(object id 95748)
              0    FILTER  (cr=0 r=0 w=0 time=2 us)
              0     TABLE ACCESS FULL OBJ#(83393) (cr=0 r=0 w=0 time=0 us)
        
        
        Rows     Execution Plan
        -------  ---------------------------------------------------
              0  SELECT STATEMENT   GOAL: CHOOSE
          71859   SORT (ORDER BY)
          71859    UNION-ALL
          71859     FILTER
          71859      TABLE ACCESS   GOAL: ANALYZED (FULL) OF 'TSF_STAGING'
          71859     FILTER
              0      TABLE ACCESS   GOAL: ANALYZED (FULL) OF 'TSF_STAGING'
        
        
        Elapsed times include waiting on following events:
          Event waited on                             Times   Max. Wait  Total Waited
          ----------------------------------------   Waited  ----------  ------------
          SQL*Net message to client                       9        0.00          0.00
          db file sequential read                         1        0.00          0.00
          latch free                                     12        0.03          0.10
          direct path write                               4        0.01          0.01
          direct path read                               14        0.14          0.28
          SQL*Net message from client                     9        0.11          0.15
          SQL*Net more data to client                  1350        0.02          0.24
        ********************************************************************************
        
        select 'Y'  
        from
         tsfhead where tsf_no=:b0           
        
        
        call     count       cpu    elapsed       disk      query    current        rows
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        Parse        1      0.00       0.00          0          0          0           0
        Execute  71859      8.81       7.90          0          0          0           0
        Fetch    71859      6.90      24.57          0     350082          0           0
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        total   143719     15.71      32.47          0     350082          0           0
        
        Misses in library cache during parse: 0
        Optimizer goal: CHOOSE
        Parsing user id: 315  (DEVEL)
        
        Rows     Row Source Operation
        -------  ---------------------------------------------------
              0  INDEX UNIQUE SCAN OBJ#(29253) (cr=350082 r=0 w=0 time=24105625 us)(object id 29253)
        
        
        Rows     Execution Plan
        -------  ---------------------------------------------------
              0  SELECT STATEMENT   GOAL: CHOOSE
              0   INDEX   GOAL: ANALYZED (UNIQUE SCAN) OF 'PK_TSFHEAD' (UNIQUE)
        
        
        Elapsed times include waiting on following events:
          Event waited on                             Times   Max. Wait  Total Waited
          ----------------------------------------   Waited  ----------  ------------
          SQL*Net message to client                   71859        0.00          0.09
          SQL*Net message from client                 71859        0.59        140.66
          buffer busy waits                              60        0.49          2.73
          latch free                                    172        0.29          1.13
          log buffer space                               89        1.00         15.03
        ********************************************************************************
        
        select wh ,stockholding_ind  
        from
         wh where wh=:b0           
        
        
        call     count       cpu    elapsed       disk      query    current        rows
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        Parse        1      0.00       0.00          0          0          0           0
        Execute  71859      8.96       7.62          0          0          0           0
        Fetch    71859      3.38       2.68          0     143718          0       71859
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        total   143719     12.34      10.30          0     143718          0       71859
        
        Misses in library cache during parse: 0
        Optimizer goal: CHOOSE
        Parsing user id: 315  (DEVEL)
        
        Rows     Row Source Operation
        -------  ---------------------------------------------------
          71859  TABLE ACCESS BY INDEX ROWID OBJ#(29746) (cr=143718 r=0 w=0 time=1219455 us)
          71859   INDEX UNIQUE SCAN OBJ#(29747) (cr=71859 r=0 w=0 time=539987 us)(object id 29747)
        
        
        Rows     Execution Plan
        -------  ---------------------------------------------------
              0  SELECT STATEMENT   GOAL: CHOOSE
          71859   TABLE ACCESS   GOAL: ANALYZED (BY INDEX ROWID) OF 'WH'
          71859    INDEX   GOAL: ANALYZED (UNIQUE SCAN) OF 'PK_WH' (UNIQUE)
        
        
        Elapsed times include waiting on following events:
          Event waited on                             Times   Max. Wait  Total Waited
          ----------------------------------------   Waited  ----------  ------------
          SQL*Net message to client                   71859        0.00          0.06
          SQL*Net message from client                 71859        0.55         90.34
          latch free                                      5        0.01          0.01
        ********************************************************************************
        
        select stockholding_ind  
        from
         store where store=:b0           
        
        
        call     count       cpu    elapsed       disk      query    current        rows
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        Parse        1      0.00       0.00          0          0          0           0
        Execute  71859      8.31       6.54          0          0          0           0
        Fetch    71859      3.93       2.46          0     215577          0       71859
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        total   143719     12.24       9.00          0     215577          0       71859
        
        Misses in library cache during parse: 0
        Optimizer goal: CHOOSE
        Parsing user id: 315  (DEVEL)
        
        Rows     Row Source Operation
        -------  ---------------------------------------------------
          71859  TABLE ACCESS BY INDEX ROWID OBJ#(28943) (cr=215577 r=0 w=0 time=1122924 us)
          71859   INDEX UNIQUE SCAN OBJ#(28955) (cr=143718 r=0 w=0 time=599947 us)(object id 28955)
        
        
        Rows     Execution Plan
        -------  ---------------------------------------------------
              0  SELECT STATEMENT   GOAL: CHOOSE
          71859   TABLE ACCESS   GOAL: ANALYZED (BY INDEX ROWID) OF 'STORE'
          71859    INDEX   GOAL: ANALYZED (UNIQUE SCAN) OF 'PK_STORE' (UNIQUE)
        
        
        Elapsed times include waiting on following events:
          Event waited on                             Times   Max. Wait  Total Waited
          ----------------------------------------   Waited  ----------  ------------
          SQL*Net message to client                   71859        0.00          0.05
          SQL*Net message from client                 71859        0.32         69.30
          latch free                                      2        0.00          0.00
        ********************************************************************************
        
        select TO_CHAR(TO_DATE(:b0,'YYYYMMDDHH24MISS')) into :b1  
        from
         dual 
        
        
        call     count       cpu    elapsed       disk      query    current        rows
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        Parse        1      0.00       0.00          0          0          0           0
        Execute  71859      9.13       5.64          0          0          0           0
        Fetch    71859      8.66       5.00          0     215577          0       71859
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        total   143719     17.79      10.65          0     215577          0       71859
        
        Misses in library cache during parse: 0
        Optimizer goal: CHOOSE
        Parsing user id: 315  (DEVEL)
        
        Rows     Row Source Operation
        -------  ---------------------------------------------------
          71859  TABLE ACCESS FULL OBJ#(222) (cr=215577 r=0 w=0 time=2806595 us)
        
        
        Rows     Execution Plan
        -------  ---------------------------------------------------
              0  SELECT STATEMENT   GOAL: CHOOSE
          71859   TABLE ACCESS   GOAL: ANALYZED (FULL) OF 'DUAL'
        
        
        Elapsed times include waiting on following events:
          Event waited on                             Times   Max. Wait  Total Waited
          ----------------------------------------   Waited  ----------  ------------
          SQL*Net message to client                   71859        0.00          0.05
          SQL*Net message from client                 71859        0.28         80.65
          latch free                                     23        0.01          0.11
        ********************************************************************************
        
        select status ,item_level ,tran_level ,pack_ind ,dept ,class ,subclass ,
          DECODE(waste_type,'SL',1,0) wastage_ind ,DECODE(waste_type,'SL',
          (waste_pct/100),0) waste_pct  
        from
         item_master where item=:b0           
        
        
        call     count       cpu    elapsed       disk      query    current        rows
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        Parse        1      0.00       0.00          0          0          0           0
        Execute  71859     11.08       7.04          0          0          0           0
        Fetch    71859      5.32       3.07          2     215577          0       71859
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        total   143719     16.40      10.12          2     215577          0       71859
        
        Misses in library cache during parse: 0
        Optimizer goal: CHOOSE
        Parsing user id: 315  (DEVEL)
        
        Rows     Row Source Operation
        -------  ---------------------------------------------------
          71859  TABLE ACCESS BY INDEX ROWID OBJ#(27569) (cr=215577 r=2 w=0 time=1502990 us)
          71859   INDEX UNIQUE SCAN OBJ#(27577) (cr=143718 r=0 w=0 time=845782 us)(object id 27577)
        
        
        Rows     Execution Plan
        -------  ---------------------------------------------------
              0  SELECT STATEMENT   GOAL: CHOOSE
          71859   TABLE ACCESS   GOAL: ANALYZED (BY INDEX ROWID) OF 'ITEM_MASTER'
          71859    INDEX   GOAL: ANALYZED (UNIQUE SCAN) OF 'PK_ITEM_MASTER' 
                       (UNIQUE)
        
        
        Elapsed times include waiting on following events:
          Event waited on                             Times   Max. Wait  Total Waited
          ----------------------------------------   Waited  ----------  ------------
          SQL*Net message to client                   71859        0.00          0.05
          SQL*Net message from client                 71859        1.06        974.02
          latch free                                      6        0.01          0.01
          db file sequential read                         2        0.02          0.02
        ********************************************************************************
        
        insert into tsfhead (tsf_no,from_loc_type,from_loc,to_loc_type,to_loc,
          tsf_type,status,freight_code,routing_code,create_date,create_id,
          approval_date,approval_id,delivery_date,repl_tsf_approve_ind) 
        values
         (:b1,:b2,:b3,:b4,:b5,'dep','I',:b6,:b7,get_vdate,'TSFUPLD',TO_DATE(:b8,
          'YYYYMMDD'),'TSFUPLD',TO_DATE(:b8,'YYYYMMDD'),'N')
        
        
        call     count       cpu    elapsed       disk      query    current        rows
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        Parse        1      0.00       0.00          0          0          0           0
        Execute      9      3.79      19.79        990       3631     242374       71859
        Fetch        0      0.00       0.00          0          0          0           0
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        total       10      3.79      19.79        990       3631     242374       71859
        
        Misses in library cache during parse: 0
        Optimizer goal: CHOOSE
        Parsing user id: 315  (DEVEL)
        
        Rows     Execution Plan
        -------  ---------------------------------------------------
              0  INSERT STATEMENT   GOAL: CHOOSE
        
        
        Elapsed times include waiting on following events:
          Event waited on                             Times   Max. Wait  Total Waited
          ----------------------------------------   Waited  ----------  ------------
          SQL*Net more data from client                1537        0.04          0.12
          db file sequential read                       990        0.40         12.39
          log buffer space                               20        0.35          1.81
          log file sync                                   6        0.20          0.46
          buffer busy waits                               8        0.00          0.00
          enqueue                                         3        0.06          0.11
          latch free                                      4        0.01          0.02
          SQL*Net message to client                       9        0.00          0.00
          SQL*Net message from client                     9        0.00          0.03
          buffer deadlock                                 1        0.00          0.00
          log file switch completion                      2        0.02          0.03
        ********************************************************************************
        
        SELECT sysavail,
                     vdate,
                     start_454_half,
                     end_454_half,
                     start_454_month,
                     mid_454_month,
                     end_454_month,
                     half_no,
                     next_half_no,
                     curr_454_day,
                     curr_454_week,
                     curr_454_month,
                     curr_454_year,
                     curr_454_month_in_half,
                     curr_454_week_in_half
                from period
        
        call     count       cpu    elapsed       disk      query    current        rows
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        Parse        1      0.00       0.00          0          0          0           0
        Execute      1      0.00       0.00          0          0          0           0
        Fetch        1      0.00       0.00          0          4          0           1
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        total        3      0.00       0.00          0          4          0           1
        
        Misses in library cache during parse: 0
        Optimizer goal: CHOOSE
        Parsing user id: 433 (PRODUCTION)   (recursive depth: 1)
        
        Rows     Row Source Operation
        -------  ---------------------------------------------------
              1  TABLE ACCESS FULL PERIOD (cr=4 r=0 w=0 time=39 us)
        
        
        Rows     Execution Plan
        -------  ---------------------------------------------------
              0  SELECT STATEMENT   GOAL: CHOOSE
              1   TABLE ACCESS   GOAL: ANALYZED (FULL) OF 'PERIOD'
        
        ********************************************************************************
        
        insert into tsfdetail (tsf_no,tsf_seq_no,item,tsf_qty,supp_pack_size,
          publish_ind) 
        values
         (:b1,:b2,:b3,:b4,:b5,'N')
        
        
        call     count       cpu    elapsed       disk      query    current        rows
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        Parse        1      0.00       0.00          0          0          0           0
        Execute      9      3.05      31.45       1075       7279     372396       71859
        Fetch        0      0.00       0.00          0          0          0           0
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        total       10      3.05      31.45       1075       7279     372396       71859
        
        Misses in library cache during parse: 0
        Optimizer goal: CHOOSE
        Parsing user id: 315  (DEVEL)
        
        Rows     Execution Plan
        -------  ---------------------------------------------------
              0  INSERT STATEMENT   GOAL: CHOOSE
        
        
        Elapsed times include waiting on following events:
          Event waited on                             Times   Max. Wait  Total Waited
          ----------------------------------------   Waited  ----------  ------------
          SQL*Net more data from client                1113        0.00          0.03
          db file sequential read                      1075        0.35         21.91
          buffer busy waits                             103        0.15          1.06
          log file sync                                  18        1.00          2.62
          log buffer space                               14        0.40          1.34
          enqueue                                        21        0.31          0.78
          buffer deadlock                                 2        0.00          0.00
          latch free                                      3        0.01          0.01
          SQL*Net message to client                       9        0.00          0.00
          SQL*Net message from client                     9        0.00          0.01
        ********************************************************************************
        
        delete  from tsf_staging  
        where
         rowid=:b1
        
        
        call     count       cpu    elapsed       disk      query    current        rows
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        Parse        1      0.00       0.00          0          0          0           0
        Execute      9      8.06      18.79          0     175290     294507       71859
        Fetch        0      0.00       0.00          0          0          0           0
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        total       10      8.06      18.79          0     175290     294507       71859
        
        Misses in library cache during parse: 0
        Optimizer goal: CHOOSE
        Parsing user id: 315  (DEVEL)
        
        Rows     Row Source Operation
        -------  ---------------------------------------------------
          71859  DELETE  (cr=175290 r=0 w=0 time=10548624 us)
          71859   TABLE ACCESS BY USER ROWID OBJ#(83393) (cr=175130 r=0 w=0 time=1601247 us)
        
        
        Rows     Execution Plan
        -------  ---------------------------------------------------
              0  DELETE STATEMENT   GOAL: CHOOSE
          71859   DELETE OF 'TSF_STAGING'
          71859    TABLE ACCESS   GOAL: ANALYZED (BY USER ROWID) OF 
                       'TSF_STAGING'
        
        
        Elapsed times include waiting on following events:
          Event waited on                             Times   Max. Wait  Total Waited
          ----------------------------------------   Waited  ----------  ------------
          SQL*Net more data from client                 712        0.00          0.03
          log buffer space                               38        0.43          3.54
          latch free                                      8        0.02          0.05
          buffer busy waits                               7        0.00          0.00
          SQL*Net message to client                       9        0.00          0.00
          SQL*Net message from client                     9        0.01          0.04
        ********************************************************************************
        
        update tsfhead  set status='A' 
        where
         tsf_no=:b1
        
        
        call     count       cpu    elapsed       disk      query    current        rows
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        Parse        1      0.00       0.00          0          0          0           0
        Execute      9     19.25      52.38        308     498917     512356       71859
        Fetch        0      0.00       0.00          0          0          0           0
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        total       10     19.25      52.38        308     498917     512356       71859
        
        Misses in library cache during parse: 0
        Optimizer goal: CHOOSE
        Parsing user id: 315  (DEVEL)
        
        Rows     Row Source Operation
        -------  ---------------------------------------------------
          71859  UPDATE  (cr=498917 r=308 w=0 time=43891595 us)
          71859   INDEX UNIQUE SCAN OBJ#(29253) (cr=497791 r=0 w=0 time=21701628 us)(object id 29253)
        
        
        Rows     Execution Plan
        -------  ---------------------------------------------------
              0  UPDATE STATEMENT   GOAL: CHOOSE
          71859   UPDATE OF 'TSFHEAD'
          71859    INDEX   GOAL: ANALYZED (UNIQUE SCAN) OF 'PK_TSFHEAD' (UNIQUE)
        
        
        Elapsed times include waiting on following events:
          Event waited on                             Times   Max. Wait  Total Waited
          ----------------------------------------   Waited  ----------  ------------
          db file sequential read                       308        0.26          7.97
          latch free                                     74        0.10          0.89
          log buffer space                               42        0.30          4.60
          buffer busy waits                              34        0.04          0.22
          SQL*Net more data from client                 353        0.00          0.03
          log file sync                                   1        0.03          0.03
          SQL*Net message to client                       9        0.00          0.00
          SQL*Net message from client                     9        0.00          0.00
          log file switch completion                      2        0.11          0.15
        ********************************************************************************
        
        update  /*+  INDEX(rb pk_restart_bookmark)  +*/ restart_bookmark rb  set 
          bookmark_string=:b0,application_image=:b1,out_file_string=:b2,
          non_fatal_err_flag=DECODE(:b3,1,'Y','N'),num_commits=(num_commits+1),
          avg_time_btwn_commits=DECODE(num_commits,0,null ,((((num_commits-1)* 
          NVL(avg_time_btwn_commits,0))+:b4)/num_commits)) 
        where
         (restart_name=LOWER(:b5) and thread_val=TO_NUMBER(:b6))
        
        
        call     count       cpu    elapsed       disk      query    current        rows
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        Parse        1      0.00       0.00          0          0          0           0
        Execute      9      0.01       0.00          0         18         11           9
        Fetch        0      0.00       0.00          0          0          0           0
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        total       10      0.01       0.00          0         18         11           9
        
        Misses in library cache during parse: 0
        Optimizer goal: CHOOSE
        Parsing user id: 315  (DEVEL)
        
        Rows     Row Source Operation
        -------  ---------------------------------------------------
              9  UPDATE  (cr=18 r=0 w=0 time=1130 us)
              9   INDEX UNIQUE SCAN OBJ#(28469) (cr=18 r=0 w=0 time=109 us)(object id 28469)
        
        
        Rows     Execution Plan
        -------  ---------------------------------------------------
              0  UPDATE STATEMENT   GOAL: CHOOSE
              9   UPDATE OF 'RESTART_BOOKMARK'
              9    INDEX   GOAL: ANALYZED (UNIQUE SCAN) OF 'PK_RESTART_BOOKMARK' 
                       (UNIQUE)
        
        
        Elapsed times include waiting on following events:
          Event waited on                             Times   Max. Wait  Total Waited
          ----------------------------------------   Waited  ----------  ------------
          SQL*Net message to client                       9        0.00          0.00
          SQL*Net message from client                     9        0.00          0.00
        ********************************************************************************
        
        update  /*+  INDEX(rps pk_restart_program_status)  +*/ restart_program_status 
          rps  set program_status=DECODE(:b0,1,'aborted in process',2,'aborted in 
          init',3,'aborted in final','completed'),restart_flag=null ,finish_time=
          DECODE(:b0,0,SYSDATE,null ),current_pid=null ,current_operator_id=null ,
          current_oracle_sid=null ,current_shadow_pid=null ,err_message=DECODE(:b0,1,
          'Terminated in process',2,'Terminated in init',3,'Terminated in final',null 
          ) 
        where
         (restart_name=LOWER(:b3) and thread_val=TO_NUMBER(:b4))
        
        
        call     count       cpu    elapsed       disk      query    current        rows
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        Parse        1      0.00       0.00          0          0          0           0
        Execute      1      0.00       0.00          0          2          2           1
        Fetch        0      0.00       0.00          0          0          0           0
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        total        2      0.00       0.00          0          2          2           1
        
        Misses in library cache during parse: 0
        Optimizer goal: CHOOSE
        Parsing user id: 315  (DEVEL)
        
        Rows     Row Source Operation
        -------  ---------------------------------------------------
              1  UPDATE  (cr=2 r=0 w=0 time=137 us)
              1   INDEX UNIQUE SCAN OBJ#(28477) (cr=2 r=0 w=0 time=18 us)(object id 28477)
        
        
        Rows     Execution Plan
        -------  ---------------------------------------------------
              0  UPDATE STATEMENT   GOAL: CHOOSE
              1   UPDATE OF 'RESTART_PROGRAM_STATUS'
              1    INDEX   GOAL: ANALYZED (UNIQUE SCAN) OF 
                       'PK_RESTART_PROGRAM_STATUS' (UNIQUE)
        
        
        Elapsed times include waiting on following events:
          Event waited on                             Times   Max. Wait  Total Waited
          ----------------------------------------   Waited  ----------  ------------
          SQL*Net message to client                       1        0.00          0.00
          SQL*Net message from client                     1        0.00          0.00
        ********************************************************************************
        
        insert into restart_program_history (restart_name,thread_val,start_time,
          program_name,commit_max_ctr,restart_time,finish_time,num_threads,shadow_pid,
          success_flag,non_fatal_err_flag,num_commits,avg_time_btwn_commits)(select  
          /*+  INDEX(rps pk_restart_program_status)  +*/ rps.restart_name ,
          rps.thread_val ,rps.start_time ,rps.program_name ,rc.commit_max_ctr ,
          rps.restart_time ,rps.finish_time ,rc.num_threads ,:b0 ,DECODE(:b1,0,'Y',
          'N') ,rb.non_fatal_err_flag ,rb.num_commits ,rb.avg_time_btwn_commits  from 
          restart_program_status rps ,restart_control rc ,restart_bookmark rb where 
          ((((rps.restart_name=LOWER(:b2) and rps.thread_val=TO_NUMBER(:b3)) and 
          rps.program_name=rc.program_name) and rps.restart_name=rb.restart_name) and 
          rps.thread_val=rb.thread_val))
        
        
        
        call     count       cpu    elapsed       disk      query    current        rows
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        Parse        1      0.00       0.00          0          0          0           0
        Execute      1      0.00       0.00          0          9          6           1
        Fetch        0      0.00       0.00          0          0          0           0
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        total        2      0.00       0.00          0          9          6           1
        
        Misses in library cache during parse: 0
        Optimizer goal: CHOOSE
        Parsing user id: 315  (DEVEL)
        
        Rows     Row Source Operation
        -------  ---------------------------------------------------
              1  FILTER  (cr=8 r=0 w=0 time=77 us)
              1   NESTED LOOPS  (cr=8 r=0 w=0 time=72 us)
              1    NESTED LOOPS  (cr=6 r=0 w=0 time=46 us)
              1     TABLE ACCESS BY INDEX ROWID OBJ#(28468) (cr=3 r=0 w=0 time=24 us)
              1      INDEX UNIQUE SCAN OBJ#(28469) (cr=2 r=0 w=0 time=12 us)(object id 28469)
              1     TABLE ACCESS BY INDEX ROWID OBJ#(28475) (cr=3 r=0 w=0 time=14 us)
              1      INDEX UNIQUE SCAN OBJ#(28477) (cr=2 r=0 w=0 time=5 us)(object id 28477)
              1    TABLE ACCESS BY INDEX ROWID OBJ#(28470) (cr=2 r=0 w=0 time=17 us)
              1     INDEX UNIQUE SCAN OBJ#(28471) (cr=1 r=0 w=0 time=12 us)(object id 28471)
        
        
        Rows     Execution Plan
        -------  ---------------------------------------------------
              0  INSERT STATEMENT   GOAL: CHOOSE
              1   FILTER
              1    NESTED LOOPS
              1     NESTED LOOPS
              1      TABLE ACCESS   GOAL: ANALYZED (BY INDEX ROWID) OF 
                         'RESTART_BOOKMARK'
              1       INDEX   GOAL: ANALYZED (UNIQUE SCAN) OF 
                          'PK_RESTART_BOOKMARK' (UNIQUE)
              1      TABLE ACCESS   GOAL: ANALYZED (BY INDEX ROWID) OF 
                         'RESTART_PROGRAM_STATUS'
              1       INDEX   GOAL: ANALYZED (UNIQUE SCAN) OF 
                          'PK_RESTART_PROGRAM_STATUS' (UNIQUE)
              1     TABLE ACCESS   GOAL: ANALYZED (BY INDEX ROWID) OF 
                        'RESTART_CONTROL'
              1      INDEX   GOAL: ANALYZED (UNIQUE SCAN) OF 
                         'PK_RESTART_CONTROL' (UNIQUE)
        
        
        Elapsed times include waiting on following events:
          Event waited on                             Times   Max. Wait  Total Waited
          ----------------------------------------   Waited  ----------  ------------
          SQL*Net message to client                       1        0.00          0.00
          SQL*Net message from client                     1        0.00          0.00
        ********************************************************************************
        
        delete  /*+  INDEX(rb pk_restart_bookmark)  +*/  from restart_bookmark  
        where
         (restart_name=LOWER(:b0) and thread_val=TO_NUMBER(:b1))
        
        
        call     count       cpu    elapsed       disk      query    current        rows
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        Parse        1      0.00       0.00          0          0          0           0
        Execute      1      0.00       0.00          0          2          4           1
        Fetch        0      0.00       0.00          0          0          0           0
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        total        2      0.00       0.00          0          2          4           1
        
        Misses in library cache during parse: 0
        Optimizer goal: CHOOSE
        Parsing user id: 315  (DEVEL)
        
        Rows     Row Source Operation
        -------  ---------------------------------------------------
              1  DELETE  (cr=2 r=0 w=0 time=83 us)
              1   INDEX UNIQUE SCAN OBJ#(28469) (cr=2 r=0 w=0 time=6 us)(object id 28469)
        
        
        Rows     Execution Plan
        -------  ---------------------------------------------------
              0  DELETE STATEMENT   GOAL: CHOOSE
              1   DELETE OF 'RESTART_BOOKMARK'
              1    INDEX   GOAL: ANALYZED (UNIQUE SCAN) OF 'PK_RESTART_BOOKMARK' 
                       (UNIQUE)
        
        
        Elapsed times include waiting on following events:
          Event waited on                             Times   Max. Wait  Total Waited
          ----------------------------------------   Waited  ----------  ------------
          SQL*Net message to client                       1        0.00          0.00
          SQL*Net message from client                     1        0.00          0.00
        ********************************************************************************
        
        update  /*+  INDEX(rps pk_restart_program_status)  +*/ restart_program_status 
          rps  set program_status='ready for start' 
        where
         (restart_name=LOWER(:b0) and thread_val=TO_NUMBER(:b1))
        
        
        call     count       cpu    elapsed       disk      query    current        rows
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        Parse        1      0.00       0.00          0          0          0           0
        Execute      1      0.00       0.00          0          2          2           1
        Fetch        0      0.00       0.00          0          0          0           0
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        total        2      0.00       0.00          0          2          2           1
        
        Misses in library cache during parse: 0
        Optimizer goal: CHOOSE
        Parsing user id: 315  (DEVEL)
        
        Rows     Row Source Operation
        -------  ---------------------------------------------------
              1  UPDATE  (cr=2 r=0 w=0 time=113 us)
              1   INDEX UNIQUE SCAN OBJ#(28477) (cr=2 r=0 w=0 time=12 us)(object id 28477)
        
        
        Rows     Execution Plan
        -------  ---------------------------------------------------
              0  UPDATE STATEMENT   GOAL: CHOOSE
              1   UPDATE OF 'RESTART_PROGRAM_STATUS'
              1    INDEX   GOAL: ANALYZED (UNIQUE SCAN) OF 
                       'PK_RESTART_PROGRAM_STATUS' (UNIQUE)
        
        
        Elapsed times include waiting on following events:
          Event waited on                             Times   Max. Wait  Total Waited
          ----------------------------------------   Waited  ----------  ------------
          SQL*Net message to client                       1        0.00          0.00
          SQL*Net message from client                     1        0.00          0.00
        ********************************************************************************
        
        delete  /*+  INDEX(rb pk_restart_bookmark)  +*/  from restart_bookmark rb  
        where
         (restart_name=LOWER(:b0) and thread_val=TO_NUMBER(:b1))
        
        
        call     count       cpu    elapsed       disk      query    current        rows
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        Parse        1      0.00       0.00          0          0          0           0
        Execute      1      0.00       0.00          0          2          0           0
        Fetch        0      0.00       0.00          0          0          0           0
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        total        2      0.00       0.00          0          2          0           0
        
        Misses in library cache during parse: 0
        Optimizer goal: CHOOSE
        Parsing user id: 315  (DEVEL)
        
        Rows     Row Source Operation
        -------  ---------------------------------------------------
              0  DELETE  (cr=2 r=0 w=0 time=10 us)
              0   INDEX UNIQUE SCAN OBJ#(28469) (cr=2 r=0 w=0 time=8 us)(object id 28469)
        
        
        Rows     Execution Plan
        -------  ---------------------------------------------------
              0  DELETE STATEMENT   GOAL: CHOOSE
              0   DELETE OF 'RESTART_BOOKMARK'
              0    INDEX   GOAL: ANALYZED (UNIQUE SCAN) OF 'PK_RESTART_BOOKMARK' 
                       (UNIQUE)
        
        
        Elapsed times include waiting on following events:
          Event waited on                             Times   Max. Wait  Total Waited
          ----------------------------------------   Waited  ----------  ------------
          SQL*Net message to client                       1        0.00          0.00
          SQL*Net message from client                     1        0.00          0.00
        ********************************************************************************
        
        ALTER SESSION SET EVENTS '10046 TRACE NAME CONTEXT FOREVER, LEVEL 12'
        
        
        call     count       cpu    elapsed       disk      query    current        rows
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        Parse        0      0.00       0.00          0          0          0           0
        Execute      1      0.00       0.02          0          0          0           0
        Fetch        0      0.00       0.00          0          0          0           0
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        total        1      0.00       0.02          0          0          0           0
        
        Misses in library cache during parse: 0
        Optimizer goal: CHOOSE
        Parsing user id: 315  (DEVEL)
        
        Elapsed times include waiting on following events:
          Event waited on                             Times   Max. Wait  Total Waited
          ----------------------------------------   Waited  ----------  ------------
          SQL*Net message to client                       2        0.00          0.00
          SQL*Net message from client                     2      630.51        674.29
          SQL*Net break/reset to client                   2        0.00          0.00
        ********************************************************************************
        
         SELECT /*+leading(vcs)*/itl.loc                        store,
                           itl.item                       rms_sku,
                           vcs.case_size                  order_multiple,
                           itl.onsale_date                onsale_date,
                           itl.offsale_date               offsale_date,
                           iem.status                     status
        FROM  v_case_size       vcs,
              item_loc          itl,
              item_master       iem,
              store             s  
        WHERE    iem.pack_ind                   = 'N'
        AND      iem.item_level                 = iem.tran_level
        AND      iem.status                     = 'A'
        AND      iem.forecast_ind               = 'Y'
        AND      iem.item                       = itl.item
        AND      itl.loc_type                   = 'S'
        AND      iem.item                       = vcs.item
        AND      vcs.primary_supp_ind           = 'Y'
        AND      vcs.primary_country_ind        = 'Y'
        AND      itl.loc=s.store 
        AND      NVL(s.STORE_CLOSE_DATE,'04-APR-4444')>=TO_DATE(20080403, 'YYYYMMDD') 
        
        call     count       cpu    elapsed       disk      query    current        rows
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        Parse        1      0.33       0.48          0        616          0           0
        Execute      1      0.00       0.00          0          0          0           0
        Fetch        1    338.94     677.03    1758266    9612126          5           0
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        total        3    339.27     677.51    1758266    9612742          5           0
        
        Misses in library cache during parse: 1
        Optimizer goal: CHOOSE
        Parsing user id: 315  (DEVEL)
        
        Rows     Row Source Operation
        -------  ---------------------------------------------------
              0  HASH JOIN  (cr=0 r=0 w=0 time=0 us)
        6161725   HASH JOIN  (cr=9612125 r=1758234 w=2408 time=2625092582 us)
          15989    HASH JOIN  (cr=7560001 r=2408 w=2408 time=81619953 us)
         212315     VIEW  (cr=7553336 r=2408 w=2408 time=81058149 us)
         212315      SORT UNIQUE (cr=7553336 r=2408 w=2408 time=80958818 us)
         697081       HASH JOIN  (cr=7553336 r=2408 w=2408 time=76507154 us)
         210609        HASH JOIN  (cr=12485 r=0 w=0 time=2923341 us)
         210649         TABLE ACCESS FULL ITEM_SUPP_COUNTRY (cr=3333 r=0 w=0 time=249455 us)
         232549         HASH JOIN  (cr=9152 r=0 w=0 time=1727673 us)
         210609          MERGE JOIN CARTESIAN (cr=6695 r=0 w=0 time=654287 us)
              1           MERGE JOIN CARTESIAN (cr=30 r=0 w=0 time=355 us)
              1            TABLE ACCESS FULL SYSTEM_OPTIONS (cr=15 r=0 w=0 time=178 us)
              1            BUFFER SORT (cr=15 r=0 w=0 time=140 us)
              1             TABLE ACCESS FULL SYSTEM_OPTIONS (cr=15 r=0 w=0 time=83 us)
         210609           BUFFER SORT (cr=6665 r=0 w=0 time=563221 us)
         210609            TABLE ACCESS FULL ITEM_MASTER (cr=6665 r=0 w=0 time=268814 us)
         232590          TABLE ACCESS FULL ITEM_SUPPLIER (cr=2457 r=0 w=0 time=184676 us)
        1829931        VIEW  (cr=7540851 r=2408 w=2408 time=66339321 us)
        1829931         UNION-ALL  (cr=7540851 r=2408 w=2408 time=64305693 us)
         232590          INDEX FAST FULL SCAN PK_ITEM_SUPP_COUNTRY (cr=1956 r=0 w=0 time=138049 us)(object id 27601)
         232590          TABLE ACCESS FULL ITEM_SUPP_COUNTRY (cr=3333 r=0 w=0 time=173372 us)
         232590          TABLE ACCESS FULL ITEM_SUPP_COUNTRY (cr=3333 r=0 w=0 time=186309 us)
         232590          TABLE ACCESS FULL ITEM_SUPP_COUNTRY (cr=3333 r=0 w=0 time=204421 us)
         299857          VIEW  (cr=9082 r=0 w=0 time=4488596 us)
         299857           SORT UNIQUE (cr=9082 r=0 w=0 time=4332822 us)
        1175224            INDEX FAST FULL SCAN PK_CASE_UPDATES (cr=9082 r=0 w=0 time=657277 us)(object id 64316)
         299857          VIEW  (cr=9082 r=0 w=0 time=4502275 us)
         299857           SORT UNIQUE (cr=9082 r=0 w=0 time=4336513 us)
        1175224            INDEX FAST FULL SCAN PK_CASE_UPDATES (cr=9082 r=0 w=0 time=673263 us)(object id 64316)
         299857          VIEW  (cr=9082 r=2408 w=2408 time=4912354 us)
         299857           SORT UNIQUE (cr=9082 r=2408 w=2408 time=4750923 us)
        1175224            INDEX FAST FULL SCAN PK_CASE_UPDATES (cr=9082 r=0 w=0 time=668371 us)(object id 64316)
          15406     TABLE ACCESS FULL ITEM_MASTER (cr=6665 r=0 w=0 time=276030 us)
        86032675    PARTITION HASH ALL PARTITION: 1 16 (cr=2052125 r=1755858 w=0 time=5678872646 us)
        86032675     TABLE ACCESS FULL ITEM_LOC PARTITION: 1 16 (cr=2052125 r=1755858 w=0 time=3484995974 us)
              0   TABLE ACCESS FULL STORE (cr=0 r=0 w=0 time=0 us)
        
        
        Rows     Execution Plan
        -------  ---------------------------------------------------
              0  SELECT STATEMENT   GOAL: CHOOSE
              0   HASH JOIN
        6161725    HASH JOIN
          15989     HASH JOIN
         212315      VIEW
         212315       SORT (UNIQUE)
         697081        HASH JOIN
         210609         HASH JOIN
         210649          TABLE ACCESS   GOAL: ANALYZED (FULL) OF 
                             'ITEM_SUPP_COUNTRY'
         232549          HASH JOIN
         210609           MERGE JOIN (CARTESIAN)
              1            MERGE JOIN (CARTESIAN)
              1             TABLE ACCESS   GOAL: ANALYZED (FULL) OF 
                                'SYSTEM_OPTIONS'
              1             BUFFER (SORT)
              1              TABLE ACCESS   GOAL: ANALYZED (FULL) OF 
                                 'SYSTEM_OPTIONS'
         210609            BUFFER (SORT)
         210609             TABLE ACCESS   GOAL: ANALYZED (FULL) OF 
                                'ITEM_MASTER'
         232590           TABLE ACCESS   GOAL: ANALYZED (FULL) OF 
                              'ITEM_SUPPLIER'
        1829931         VIEW
        1829931          UNION-ALL
         232590           INDEX   GOAL: ANALYZED (FAST FULL SCAN) OF 
                              'PK_ITEM_SUPP_COUNTRY' (UNIQUE)
         232590           TABLE ACCESS   GOAL: ANALYZED (FULL) OF 
                              'ITEM_SUPP_COUNTRY'
         232590           TABLE ACCESS   GOAL: ANALYZED (FULL) OF 
                              'ITEM_SUPP_COUNTRY'
         232590           TABLE ACCESS   GOAL: ANALYZED (FULL) OF 
                              'ITEM_SUPP_COUNTRY'
         299857           VIEW
         299857            SORT (UNIQUE)
        1175224             INDEX   GOAL: ANALYZED (FAST FULL SCAN) OF 
                                'PK_CASE_UPDATES' (UNIQUE)
         299857           VIEW
         299857            SORT (UNIQUE)
        1175224             INDEX   GOAL: ANALYZED (FAST FULL SCAN) OF 
                                'PK_CASE_UPDATES' (UNIQUE)
         299857           VIEW
         299857            SORT (UNIQUE)
        1175224             INDEX   GOAL: ANALYZED (FAST FULL SCAN) OF 
                                'PK_CASE_UPDATES' (UNIQUE)
          15406      TABLE ACCESS   GOAL: ANALYZED (FULL) OF 'ITEM_MASTER'
        86032675     PARTITION HASH (ALL) PARTITION: START=1 STOP=16
        86032675      TABLE ACCESS   GOAL: ANALYZED (FULL) OF 'ITEM_LOC' 
                         PARTITION: START=1 STOP=16
              0    TABLE ACCESS   GOAL: ANALYZED (FULL) OF 'STORE'
        
        
        Elapsed times include waiting on following events:
          Event waited on                             Times   Max. Wait  Total Waited
          ----------------------------------------   Waited  ----------  ------------
          SQL*Net message to client                       2        0.00          0.00
          direct path write                            5506        0.22          4.39
          direct path read                               42        0.00          0.06
          db file sequential read                     73643        0.32         47.06
          db file scattered read                     123335        0.93        318.67
          latch free                                      3        0.00          0.00
          SQL*Net break/reset to client                   1        0.00          0.00
          SQL*Net message from client                     1      181.03        181.03
        ********************************************************************************
        
        SELECT /*+All_ROWS(vcs)*/ itl.loc                        store,
         itl.item                       rms_sku,
                           vcs.case_size                  order_multiple,
                           itl.onsale_date                onsale_date,
          itl.offsale_date               offsale_date,
        iem.status                     status
         FROM  v_case_size       vcs,
            item_loc          itl,
         item_master       iem,
        store             s  
        WHERE    iem.pack_ind                   = 'N'
         AND      iem.item_level                 = iem.tran_level
        AND      iem.status                     = 'A'
        AND      iem.forecast_ind               = 'Y'
        AND      iem.item                       = itl.item
        AND      itl.loc_type                   = 'S'
        AND      iem.item                       = vcs.item
        AND      vcs.primary_supp_ind           = 'Y'
        AND      vcs.primary_country_ind        = 'Y'
        AND      itl.loc=s.store 
        AND      NVL(s.STORE_CLOSE_DATE,'04-APR-4444')>=TO_DATE(20080403, 'YYYYMMDD')
        
        call     count       cpu    elapsed       disk      query    current        rows
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        Parse        1      0.32       0.29          0        593          0           0
        Execute      1      0.00       0.00          0          0          0           0
        Fetch   819704    874.76    1529.15    3879188   12619996          5    12295541
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        total   819706    875.08    1529.45    3879188   12620589          5    12295541
        
        Misses in library cache during parse: 1
        Optimizer goal: ALL_ROWS
        Parsing user id: 315  (DEVEL)
        
        Rows     Row Source Operation
        -------  ---------------------------------------------------
        12295541  HASH JOIN  (cr=12619996 r=3879188 w=2408 time=1503903336 us)
         212315   VIEW  (cr=7553336 r=2408 w=2408 time=82297538 us)
         212315    SORT UNIQUE (cr=7553336 r=2408 w=2408 time=82196703 us)
         697081     HASH JOIN  (cr=7553336 r=2408 w=2408 time=1611842355 us)
         210609      HASH JOIN  (cr=12485 r=0 w=0 time=3006259 us)
         210649       TABLE ACCESS FULL OBJ#(27596) (cr=3333 r=0 w=0 time=252569 us)
         232549       HASH JOIN  (cr=9152 r=0 w=0 time=1792328 us)
         210609        MERGE JOIN CARTESIAN (cr=6695 r=0 w=0 time=672733 us)
              1         MERGE JOIN CARTESIAN (cr=30 r=0 w=0 time=414 us)
              1          TABLE ACCESS FULL OBJ#(29081) (cr=15 r=0 w=0 time=224 us)
              1          BUFFER SORT (cr=15 r=0 w=0 time=151 us)
              1           TABLE ACCESS FULL OBJ#(29081) (cr=15 r=0 w=0 time=84 us)
         210609         BUFFER SORT (cr=6665 r=0 w=0 time=588521 us)
         210609          TABLE ACCESS FULL OBJ#(27569) (cr=6665 r=0 w=0 time=282828 us)
         232590        TABLE ACCESS FULL OBJ#(27592) (cr=2457 r=0 w=0 time=193494 us)
        1829931      VIEW  (cr=7540851 r=2408 w=2408 time=1601326949 us)
        1829931       UNION-ALL  (cr=7540851 r=2408 w=2408 time=1599477138 us)
         232590        INDEX FAST FULL SCAN OBJ#(27601) (cr=1956 r=0 w=0 time=148965 us)(object id 27601)
         232590        TABLE ACCESS FULL OBJ#(27596) (cr=3333 r=0 w=0 time=182131 us)
         232590        TABLE ACCESS FULL OBJ#(27596) (cr=3333 r=0 w=0 time=196427 us)
         232590        TABLE ACCESS FULL OBJ#(27596) (cr=3333 r=0 w=0 time=208067 us)
         299857        VIEW  (cr=9082 r=0 w=0 time=4366181 us)
         299857         SORT UNIQUE (cr=9082 r=0 w=0 time=4209094 us)
        1175224          INDEX FAST FULL SCAN OBJ#(64316) (cr=9082 r=0 w=0 time=669001 us)(object id 64316)
         299857        VIEW  (cr=9082 r=0 w=0 time=4346393 us)
         299857         SORT UNIQUE (cr=9082 r=0 w=0 time=4186605 us)
        1175224          INDEX FAST FULL SCAN OBJ#(64316) (cr=9082 r=0 w=0 time=649200 us)(object id 64316)
         299857        VIEW  (cr=9082 r=2408 w=2408 time=4992268 us)
         299857         SORT UNIQUE (cr=9082 r=2408 w=2408 time=4829837 us)
        1175224          INDEX FAST FULL SCAN OBJ#(64316) (cr=9082 r=0 w=0 time=669465 us)(object id 64316)
        11847214   HASH JOIN  (cr=5066660 r=3876780 w=0 time=1400482785 us)
          15406    TABLE ACCESS FULL OBJ#(27569) (cr=6665 r=0 w=0 time=288486 us)
        161989081    HASH JOIN  (cr=5059995 r=3876780 w=0 time=5271269810 us)
            769     TABLE ACCESS FULL OBJ#(28943) (cr=62 r=0 w=0 time=1407 us)
        178209054     PARTITION HASH ALL PARTITION: 1 16 (cr=5059933 r=3876780 w=0 time=5045798853 us)
        178209054      TABLE ACCESS FULL OBJ#(27216) PARTITION: 1 16 (cr=5059933 r=3876780 w=0 time=4974317964 us)
        
        
        Rows     Execution Plan
        -------  ---------------------------------------------------
              0  SELECT STATEMENT   GOAL: HINT: ALL_ROWS
        12295541   HASH JOIN
         212315    VIEW
         212315     SORT (UNIQUE)
         697081      HASH JOIN
         210609       HASH JOIN
         210649        TABLE ACCESS   GOAL: ANALYZED (FULL) OF 
                           'ITEM_SUPP_COUNTRY'
         232549        HASH JOIN
         210609         MERGE JOIN (CARTESIAN)
              1          MERGE JOIN (CARTESIAN)
              1           TABLE ACCESS   GOAL: ANALYZED (FULL) OF 
                              'SYSTEM_OPTIONS'
              1           BUFFER (SORT)
              1            TABLE ACCESS   GOAL: ANALYZED (FULL) OF 
                               'SYSTEM_OPTIONS'
         210609          BUFFER (SORT)
         210609           TABLE ACCESS   GOAL: ANALYZED (FULL) OF 
                              'ITEM_MASTER'
         232590         TABLE ACCESS   GOAL: ANALYZED (FULL) OF 
                            'ITEM_SUPPLIER'
        1829931       VIEW
        1829931        UNION-ALL
         232590         INDEX   GOAL: ANALYZED (FAST FULL SCAN) OF 
                            'PK_ITEM_SUPP_COUNTRY' (UNIQUE)
         232590         TABLE ACCESS   GOAL: ANALYZED (FULL) OF 
                            'ITEM_SUPP_COUNTRY'
         232590         TABLE ACCESS   GOAL: ANALYZED (FULL) OF 
                            'ITEM_SUPP_COUNTRY'
         232590         TABLE ACCESS   GOAL: ANALYZED (FULL) OF 
                            'ITEM_SUPP_COUNTRY'
         299857         VIEW
         299857          SORT (UNIQUE)
        1175224           INDEX   GOAL: ANALYZED (FAST FULL SCAN) OF 
                              'PK_CASE_UPDATES' (UNIQUE)
         299857         VIEW
         299857          SORT (UNIQUE)
        1175224           INDEX   GOAL: ANALYZED (FAST FULL SCAN) OF 
                              'PK_CASE_UPDATES' (UNIQUE)
         299857         VIEW
         299857          SORT (UNIQUE)
        1175224           INDEX   GOAL: ANALYZED (FAST FULL SCAN) OF 
                              'PK_CASE_UPDATES' (UNIQUE)
        11847214    HASH JOIN
          15406     TABLE ACCESS   GOAL: ANALYZED (FULL) OF 'ITEM_MASTER'
        161989081     HASH JOIN
            769      TABLE ACCESS   GOAL: ANALYZED (FULL) OF 'STORE'
        178209054      PARTITION HASH (ALL) PARTITION: START=1 STOP=16
        178209054       TABLE ACCESS   GOAL: ANALYZED (FULL) OF 'ITEM_LOC' 
                          PARTITION: START=1 STOP=16
        
        
        Elapsed times include waiting on following events:
          Event waited on                             Times   Max. Wait  Total Waited
          ----------------------------------------   Waited  ----------  ------------
          SQL*Net message to client                  819704        0.00          0.45
          direct path write                               4        0.00          0.00
          direct path read                               51        0.00          0.07
          db file sequential read                     94884        0.41         60.91
          db file scattered read                     222696     2302.70       4675.10
          SQL*Net message from client                819704     3672.87       6299.98
          latch free                                      2        0.00          0.00
        
        
        
        ********************************************************************************
        
        OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS
        
        call     count       cpu    elapsed       disk      query    current        rows
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        Parse       30      0.66       3.81          0       1209          0           0
        Execute 359369     80.45     157.24       2373     685165    1421669      287451
        Fetch   1179026   1243.52    2250.98    5638169   23437045         14    12654850
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        total   1538425   1324.63    2412.03    5640542   24123419    1421683    12942301
        
        Misses in library cache during parse: 5
        
        Elapsed times include waiting on following events:
          Event waited on                             Times   Max. Wait  Total Waited
          ----------------------------------------   Waited  ----------  ------------
          SQL*Net message to client                 1179098        0.00          0.77
          SQL*Net message from client               1179097     3672.87       8511.63
          library cache pin                               2        3.00          3.00
          SQL*Net break/reset to client                   5        0.01          0.01
          log file sync                                  37        1.00          4.11
          db file sequential read                    170903        0.41        150.29
          latch free                                    314        0.29          2.38
          direct path write                            5514        0.22          4.41
          direct path read                              107        0.14          0.43
          SQL*Net more data to client                  1350        0.02          0.24
          buffer busy waits                             212        0.49          4.02
          SQL*Net more data from client                3715        0.04          0.23
          log buffer space                              203        1.00         26.34
          enqueue                                        24        0.31          0.90
          buffer deadlock                                 3        0.00          0.00
          log file switch completion                      4        0.11          0.18
          db file scattered read                     346031     2302.70       4993.78
        
        
        OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS
        
        call     count       cpu    elapsed       disk      query    current        rows
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        Parse      669      0.00       0.01          0          0          0           0
        Execute    676      0.02       0.06          0          4          1           1
        Fetch      947      0.01       0.13          3       1837          0         874
        ------- ------  -------- ---------- ---------- ---------- ----------  ----------
        total     2292      0.03       0.22          3       1841          1         875
        
        Misses in library cache during parse: 5
        
        Elapsed times include waiting on following events:
          Event waited on                             Times   Max. Wait  Total Waited
          ----------------------------------------   Waited  ----------  ------------
          db file sequential read                         3        0.01          0.03
        
           33  user  SQL statements in session.
          668  internal SQL statements in session.
          701  SQL statements in session.
           25  statements EXPLAINed in this session.
        ********************************************************************************
        Trace file: adqora3g_ora_147292.trc
        Trace file compatibility: 9.00.01
        Sort options: default
        
               2  sessions in tracefile.
              63  user  SQL statements in trace file.
             739  internal SQL statements in trace file.
             701  SQL statements in trace file.
              41  unique SQL statements in trace file.
              25  SQL statements EXPLAINed using schema:
                   devel.prof$plan_table
                     Default table was used.
                     Table was created.
                     Table was dropped.
         6446643  lines in trace file.
        Message was edited by:
        User71408
        • 61. Re: query tuning
          620899
          HI,
          You have not done the CASE_SIZE view as inline view as charles told you.

          FROM CASE_SIZE CS,
          ITEM IM,
          MASTER MAS,
          WAREHOUSE WH

          you write the sql statement of the CASE_SIZE view in place of CASE_SIZE mentioned in bold letters like

          from (select .....) cs,
          item im,
          master mas,
          warehouse wh

          Regards
          • 62. Re: query tuning
            Charles Hooper
            Thanks for posting the entire TKPROF output.

            Something odd that I did noticed, you have one SQL statement that begins with
            SELECT /*+leading(vcs)*/
            That appears to be accessing the same tables and views, but returns 0 rows. This SQL statement appears very similar to the SQL statement that begins with
            SELECT /*+All_ROWS(vcs)*/
            However, that SQL statement returned 12,295,541 rows. I am not sure if this is a bug, or if I am not reading something right.

            Another thing that I noticed is this in the WHERE clause:
            AND NVL(s.STORE_CLOSE_DATE,'04-APR-4444')>=TO_DATE(20080403, 'YYYYMMDD')
            You are using TO_DATE on the right of ">=", but not in the NVL function. Also, you are attempting to use a date that is far in the future.

            Try changing this line in the WHERE clause so that it is
            AND NVL(s.STORE_CLOSE_DATE,TO_DATE(20080403, 'YYYYMMDD'))>=TO_DATE(20080403, 'YYYYMMDD')
            In other words, put exactly what is on the right of ">=" inside the NVL function.

            It looks like most of the time, consistent reads, and physical reads are from this part of the row source plan (and most of those rows are thrown away later):
            178,209,054     PARTITION HASH ALL PARTITION: 1 16 (cr=5059933 r=3876780 w=0 time=5045798853 us)
            178,209,054      TABLE ACCESS FULL OBJ#(27216) PARTITION: 1 16 (cr=5059933 r=3876780 w=0 time=4974317964 us)
            That part of the row source plan is for the ITEM_LOC table. A full table scan of partitions 1 through 16 of the ITEM_LOC table is being performed. You may be able to fix this problem by creating a new index on the LOC,LOC_TYPE columns of the ITEM_LOC table.

            It appears that the cardinality estimates (Card=) in your original explain plan are very different from the number of rows reported in the Row Source Operation execution plan. Part of that problem may be caused by the NVL(s.STORE_CLOSE_DATE,'04-APR-4444') line in the WHERE clause, and the plan may change again when you fix that part of the WHERE clause.

            I am still analyzing at the TKPROF output that you provided.

            If Jonathan Lewis is still monitoring this thread, he should be able to provide additional suggestions.

            Charles Hooper
            IT Manager/Oracle DBA
            K&M Machine-Fabricating, Inc.
            • 63. Re: query tuning
              Jonathan Lewis
              There are a couple of irritants with this trace/tkprof file: the strange 2,400 second db file scattered read doesn't help, and the fact that times are always suspects in the row source execution statistics of trace files - and why are there two variants of the same query !

              However, I think you've identified the key point - the tablescan of the ITEM_LOC table is responsible for a huge proportion of the work.

              We can ignore the v_case_size view at the moment - it's inefficient, but small, and it's a non-mergeable view anyway, so not introducing real complications. The only obvious saving seems to be in the hash join ordering:
               12295541  HASH JOIN  (cr=12619996 r=3879188 w=2408 time=1503903336 us)
                 212315   VIEW  (v_case_size) (cr=7553336 r=2408 w=2408 time=82297538 us)
                                 ...
               11847214   HASH JOIN  (cr=5066660 r=3876780 w=0 time=1400482785 us)
                  15406    TABLE ACCESS FULL ITEM_MASTER (cr=6665 r=0 w=0 time=288486 us)
              161989081    HASH JOIN  (cr=5059995 r=3876780 w=0 time=5271269810 us)
                    769     TABLE ACCESS FULL STORE (cr=62 r=0 w=0 time=1407 us)
              178209054     PARTITION HASH ALL PARTITION: 1 16 (cr=5059933 r=3876780 w=0 time=5045798853 us)
              178209054      TABLE ACCESS FULL ITEM_LOC PARTITION: 1 16 (cr=5059933 r=3876780 w=0 time=4974317964 us)
              The first join is between ITEM_LOC and STORE, and eliminates virtually no data, the second join is between that result and ITEM_MASTER and eliminates more than 92% of the result. It looks as if we should get that elimination to occur earlier. The last join is between v_case_size and the 11.8 M rows and grows the result to 12.2M rows.

              It's a big data set, we can't do much with it.

              To get the join order re-arranged (for 9i - which makes it a bit painful), I think you will need to re-arrange the FROM clause, then put in several hash-related hints:
              select
                   /*+ 
                        ordered
                        full(iem)
                        full(itl) use_hash(itl)
                        full(s)     use_hash(s) swap_join_inputs(s)
                        no_merge(vcs)
                        use_hash(vcs) swap_join_inputs(vcs)
                   */
                   ...
              from
                   item_master     iem,
                   item_loc     itl,
                   store          s,
                   v_case_size     vcs
              where
              The aim is to get v_case_size, store and item_master hashed into memory, and then pass item_loc through each in turn - i.e. changing the order of item_master and store in the previous plan.


              I think that will be the best you can do with a serial query, but I don't think it will go much faster.

              Once you've got the best path, you could force it to run parallel, making sure that you get an execution plan that broadcasts the three small "tables" so that the 178M rows from the item_loc table don't have to be distributed between layers of slaves.

              You could also try dirty tricks on the serial path to speed up the scan of item_loc and cut down CPU spent on latching. Check with Oracle support if you can set the parameter serialdirect_read to true for the session before running the query.


              Regards
              Jonathan Lewis
              http://jonathanlewis.wordpress.com
              http://www.jlcomp.demon.co.uk
              • 64. Re: query tuning
                Charles Hooper
                Jonathan,

                Thanks for the follow-up, the modified query with several hints (about 9 more than I would have thought to suggest), and the precise reasoning behind the suggestions.

                User71408, please try the query changes that Jonathan provided with all of the hints and the table/view names in the order that he specified - you will need to add the WHERE clause, and the column names (in place of ...).

                Charles Hooper
                IT Manager/Oracle DBA
                K&M Machine-Fabricating, Inc.
                • 65. Re: query tuning
                  599921
                  Hi Lewis ,
                  I am not a DBA. So please give me some more ideas regarding this.

                  Thank you.
                  • 66. Re: query tuning
                    Jonathan Lewis
                    User71408

                    I'm sorry, but if you can't follow the instructions about how to add hints to the SQL and change the order of the FROM clause, you shouldn't be doing the job you are currently doing.

                    You may not be able to understand how I interpreted the execution plan to understand the work being done - but you SHOULD be in a position to understand the description that I gave of how the tables are being joined, and the volumes of data produced at each stage. This NOT a DBA skill, it's something that everyone who writes any SQL should be able to do.

                    Regards
                    Jonathan Lewis
                    http://jonathanlewis.wordpress.com
                    http://www.jlcomp.demon.co.uk
                    • 67. Re: query tuning
                      181444
                      Just because someone tacks their reply onto your post does not mean that the reply is to you. This is the most common way of adding to a thread. You reply to the last in the string.

                      If the reply is to you it should reference you by name or reference something you posted otherwise the reply is usualy to the OP or just more comments on the points already made.

                      Take a look at most of the thread here on OTN.

                      HTH -- Mark D Powell --
                      • 68. Re: query tuning
                        Aman....
                        Mark,
                        Thanks.I shall remember it in future.There was no hard feeling with Alok.I just mentioned it.Still Ishall be careful next time.
                        Regards
                        Aman....
                        • 69. Re: query tuning
                          599921
                          Hi Lewis,
                          I have done as per your suggestion. Now the query is taking 42 mins. Previously it was taking 45 mins. Just 3 mins was reduced .Is there way to ncrease the
                          the performance .please guide me.and one more is Index is already created on LOC and LO_TYPE in Item_loc table.

                          Thank you.

                          Message was edited by:
                          User71408
                          • 70. Re: query tuning
                            Jonathan Lewis
                            Can you post the execution plan from the tkprof output again (just the one with the heading "row source operation") so that we can confirm that it is doing what I had hoped.

                            Don't forget the "tags" to get the fixed format

                            Regards
                            Jonathan Lewis
                            http://jonathanlewis.wordpress.com
                            http://www.jlcomp.demon.co.uk
                            • 71. Re: query tuning
                              599921
                              Rows     Row Source Operation
                              -------  ---------------------------------------------------
                                    1  TABLE ACCESS BY INDEX ROWID OBJ#(28470) (cr=2 r=0 w=0 time=14 us)
                                    1   INDEX UNIQUE SCAN OBJ#(28471) (cr=1 r=0 w=0 time=8 us)(object id 28471)
                               
                               
                              Rows     Execution Plan
                              -------  ---------------------------------------------------
                                    0  SELECT STATEMENT   GOAL: CHOOSE
                                    1   TABLE ACCESS   GOAL: ANALYZED (BY INDEX ROWID) OF 
                                            'RESTART_CONTROL'
                                    1    INDEX   GOAL: ANALYZED (UNIQUE SCAN) OF 'PK_RESTART_CONTROL' 
                                             (UNIQUE)
                              #################################################################################
                              Rows     Row Source Operation
                              -------  ---------------------------------------------------
                                    1  FIXED TABLE FULL X$KSUSE (cr=0 r=0 w=0 time=71 us)
                               
                              error during execute of EXPLAIN PLAN statement
                              ORA-01039: insufficient privileges on underlying objects of the view
                               
                              parse error offset: 91
                               
                              Elapsed times include waiting on following events:
                                Event waited on                             Times   Max. Wait  Total Waited
                                ----------------------------------------   Waited  ----------  ------------
                                SQL*Net message to client                       1        0.00          0.00
                                SQL*Net message from client                     1        0.00          0.00
                              ********************************************************************************
                              Rows     Row Source Operation
                              -------  ---------------------------------------------------
                                    1  MERGE JOIN  (cr=0 r=0 w=0 time=376 us)
                                   19   FIXED TABLE FULL X$KSUPR (cr=0 r=0 w=0 time=37 us)
                                    1   SORT JOIN (cr=0 r=0 w=0 time=268 us)
                                    1    FIXED TABLE FULL X$KSUSE (cr=0 r=0 w=0 time=245 us)
                               
                              error during execute of EXPLAIN PLAN statement
                              ORA-01039: insufficient privileges on underlying objects of the view
                               
                              parse error offset: 107
                               
                              Elapsed times include waiting on following events:
                                Event waited on                             Times   Max. Wait  Total Waited
                                ----------------------------------------   Waited  ----------  ------------
                                SQL*Net message to client                       1        0.00          0.00
                                SQL*Net message from client                     1        0.00          0.00
                              ********************************************************************************
                              Rows     Row Source Operation
                              -------  ---------------------------------------------------
                                    9  TABLE ACCESS BY INDEX ROWID OBJ#(28475) (cr=12 r=0 w=0 time=189 us)
                                   10   INDEX RANGE SCAN OBJ#(28477) (cr=6 r=0 w=0 time=102 us)(object id 28477)
                               
                               
                              Rows     Execution Plan
                              -------  ---------------------------------------------------
                                    0  SELECT STATEMENT   GOAL: CHOOSE
                                    9   TABLE ACCESS   GOAL: ANALYZED (BY INDEX ROWID) OF 
                                            'RESTART_PROGRAM_STATUS'
                                   10    INDEX   GOAL: ANALYZED (RANGE SCAN) OF 
                                             'PK_RESTART_PROGRAM_STATUS' (UNIQUE)
                               
                               
                              Elapsed times include waiting on following events:
                                Event waited on                             Times   Max. Wait  Total Waited
                                ----------------------------------------   Waited  ----------  ------------
                                SQL*Net message to client                       5        0.00          0.00
                                SQL*Net message from client                     5        0.00          0.03
                              ********************************************************************************
                              Rows     Row Source Operation
                              -------  ---------------------------------------------------
                                    0  FOR UPDATE  (cr=0 r=0 w=0 time=0 us)
                                    1   TABLE ACCESS BY USER ROWID RESTART_PROGRAM_STATUS (cr=2 r=0 w=0 time=66 us)
                               
                               
                              Rows     Execution Plan
                              -------  ---------------------------------------------------
                                    0  SELECT STATEMENT   GOAL: CHOOSE
                                    0   FOR UPDATE
                                    1    TABLE ACCESS   GOAL: ANALYZED (BY USER ROWID) OF 
                                             'RESTART_PROGRAM_STATUS'
                               
                               
                              Elapsed times include waiting on following events:
                                Event waited on                             Times   Max. Wait  Total Waited
                                ----------------------------------------   Waited  ----------  ------------
                                SQL*Net break/reset to client                   2        0.01          0.01
                                SQL*Net message to client                       9        0.00          0.00
                                SQL*Net message from client                     9        0.04          0.11
                              ********************************************************************************Rows     Row Source Operation
                              -------  ---------------------------------------------------
                                    1  UPDATE  (cr=1 r=0 w=0 time=147 us)
                                    1   TABLE ACCESS BY USER ROWID OBJ#(28475) (cr=1 r=0 w=0 time=23 us)
                               
                               
                              Rows     Execution Plan
                              -------  ---------------------------------------------------
                                    0  UPDATE STATEMENT   GOAL: CHOOSE
                                    1   UPDATE OF 'RESTART_PROGRAM_STATUS'
                                    1    TABLE ACCESS   GOAL: ANALYZED (BY USER ROWID) OF 
                                             'RESTART_PROGRAM_STATUS'
                               
                               
                              Elapsed times include waiting on following events:
                                Event waited on                             Times   Max. Wait  Total Waited
                                ----------------------------------------   Waited  ----------  ------------
                                SQL*Net message to client                       1        0.00          0.00
                                SQL*Net message from client                     1        0.01          0.01
                              ********************************************************************************
                              Rows     Row Source Operation
                              -------  ---------------------------------------------------
                                    1  MERGE JOIN CARTESIAN (cr=19 r=0 w=0 time=233 us)
                                    1   TABLE ACCESS FULL OBJ#(28207) (cr=4 r=0 w=0 time=65 us)
                                    1   BUFFER SORT (cr=15 r=0 w=0 time=137 us)
                                    1    TABLE ACCESS FULL OBJ#(29081) (cr=15 r=0 w=0 time=61 us)
                               
                               
                              Rows     Execution Plan
                              -------  ---------------------------------------------------
                                    0  SELECT STATEMENT   GOAL: CHOOSE
                                    1   MERGE JOIN (CARTESIAN)
                                    1    TABLE ACCESS   GOAL: ANALYZED (FULL) OF 'PERIOD'
                                    1    BUFFER (SORT)
                                    1     TABLE ACCESS   GOAL: ANALYZED (FULL) OF 'SYSTEM_OPTIONS'
                               
                               
                              Elapsed times include waiting on following events:
                                Event waited on                             Times   Max. Wait  Total Waited
                                ----------------------------------------   Waited  ----------  ------------
                                SQL*Net message to client                       1        0.00          0.00
                                SQL*Net message from client                     1        0.56          0.56
                              ********************************************************************************Rows     Row Source Operation
                              -------  ---------------------------------------------------
                                71859  SORT ORDER BY (cr=64359 r=713 w=712 time=6546143 us)
                                71859   UNION-ALL  (cr=64359 r=1 w=0 time=3038270 us)
                                71859    FILTER  (cr=64359 r=1 w=0 time=2231615 us)
                                71859     TABLE ACCESS BY INDEX ROWID OBJ#(83393) (cr=64359 r=1 w=0 time=2089038 us)
                                71859      INDEX RANGE SCAN OBJ#(95748) (cr=253 r=1 w=0 time=353042 us)(object id 95748)
                                    0    FILTER  (cr=0 r=0 w=0 time=2 us)
                                    0     TABLE ACCESS FULL OBJ#(83393) (cr=0 r=0 w=0 time=0 us)
                               
                               
                              Rows     Execution Plan
                              -------  ---------------------------------------------------
                                    0  SELECT STATEMENT   GOAL: CHOOSE
                                71859   SORT (ORDER BY)
                                71859    UNION-ALL
                                71859     FILTER
                                71859      TABLE ACCESS   GOAL: ANALYZED (FULL) OF 'TSF_STAGING'
                                71859     FILTER
                                    0      TABLE ACCESS   GOAL: ANALYZED (FULL) OF 'TSF_STAGING'
                               
                               
                              Elapsed times include waiting on following events:
                                Event waited on                             Times   Max. Wait  Total Waited
                                ----------------------------------------   Waited  ----------  ------------
                                SQL*Net message to client                       9        0.00          0.00
                                db file sequential read                         1        0.00          0.00
                                latch free                                     12        0.03          0.10
                                direct path write                               4        0.01          0.01
                                direct path read                               14        0.14          0.28
                                SQL*Net message from client                     9        0.11          0.15
                                SQL*Net more data to client                  1350        0.02          0.24
                              ********************************************************************************Rows     Row Source Operation
                              -------  ---------------------------------------------------
                                    0  INDEX UNIQUE SCAN OBJ#(29253) (cr=350082 r=0 w=0 time=24105625 us)(object id 29253)
                               
                               
                              Rows     Execution Plan
                              -------  ---------------------------------------------------
                                    0  SELECT STATEMENT   GOAL: CHOOSE
                                    0   INDEX   GOAL: ANALYZED (UNIQUE SCAN) OF 'PK_TSFHEAD' (UNIQUE)
                               
                               
                              Elapsed times include waiting on following events:
                                Event waited on                             Times   Max. Wait  Total Waited
                                ----------------------------------------   Waited  ----------  ------------
                                SQL*Net message to client                   71859        0.00          0.09
                                SQL*Net message from client                 71859        0.59        140.66
                                buffer busy waits                              60        0.49          2.73
                                latch free                                    172        0.29          1.13
                                log buffer space                               89        1.00         15.03
                              ********************************************************************************Rows     Row Source Operation
                              -------  ---------------------------------------------------
                                71859  TABLE ACCESS BY INDEX ROWID OBJ#(29746) (cr=143718 r=0 w=0 time=1219455 us)
                                71859   INDEX UNIQUE SCAN OBJ#(29747) (cr=71859 r=0 w=0 time=539987 us)(object id 29747)
                               
                               
                              Rows     Execution Plan
                              -------  ---------------------------------------------------
                                    0  SELECT STATEMENT   GOAL: CHOOSE
                                71859   TABLE ACCESS   GOAL: ANALYZED (BY INDEX ROWID) OF 'WH'
                                71859    INDEX   GOAL: ANALYZED (UNIQUE SCAN) OF 'PK_WH' (UNIQUE)
                               
                               
                              Elapsed times include waiting on following events:
                                Event waited on                             Times   Max. Wait  Total Waited
                                ----------------------------------------   Waited  ----------  ------------
                                SQL*Net message to client                   71859        0.00          0.06
                                SQL*Net message from client                 71859        0.55         90.34
                                latch free                                      5        0.01          0.01
                              ********************************************************************************
                              Rows     Row Source Operation
                              -------  ---------------------------------------------------
                                71859  TABLE ACCESS BY INDEX ROWID OBJ#(28943) (cr=215577 r=0 w=0 time=1122924 us)
                                71859   INDEX UNIQUE SCAN OBJ#(28955) (cr=143718 r=0 w=0 time=599947 us)(object id 28955)
                               
                               
                              Rows     Execution Plan
                              -------  ---------------------------------------------------
                                    0  SELECT STATEMENT   GOAL: CHOOSE
                                71859   TABLE ACCESS   GOAL: ANALYZED (BY INDEX ROWID) OF 'STORE'
                                71859    INDEX   GOAL: ANALYZED (UNIQUE SCAN) OF 'PK_STORE' (UNIQUE)
                               
                               
                              Elapsed times include waiting on following events:
                                Event waited on                             Times   Max. Wait  Total Waited
                                ----------------------------------------   Waited  ----------  ------------
                                SQL*Net message to client                   71859        0.00          0.05
                                SQL*Net message from client                 71859        0.32         69.30
                                latch free                                      2        0.00          0.00
                              ********************************************************************************Rows     Row Source Operation
                              -------  ---------------------------------------------------
                                71859  TABLE ACCESS FULL OBJ#(222) (cr=215577 r=0 w=0 time=2806595 us)
                               
                               
                              Rows     Execution Plan
                              -------  ---------------------------------------------------
                                    0  SELECT STATEMENT   GOAL: CHOOSE
                                71859   TABLE ACCESS   GOAL: ANALYZED (FULL) OF 'DUAL'
                               
                               
                              Elapsed times include waiting on following events:
                                Event waited on                             Times   Max. Wait  Total Waited
                                ----------------------------------------   Waited  ----------  ------------
                                SQL*Net message to client                   71859        0.00          0.05
                                SQL*Net message from client                 71859        0.28         80.65
                                latch free                                     23        0.01          0.11
                              ********************************************************************************
                               
                              Rows     Row Source Operation
                              -------  ---------------------------------------------------
                                71859  TABLE ACCESS BY INDEX ROWID OBJ#(27569) (cr=215577 r=2 w=0 time=1502990 us)
                                71859   INDEX UNIQUE SCAN OBJ#(27577) (cr=143718 r=0 w=0 time=845782 us)(object id 27577)
                               
                               
                              Rows     Execution Plan
                              -------  ---------------------------------------------------
                                    0  SELECT STATEMENT   GOAL: CHOOSE
                                71859   TABLE ACCESS   GOAL: ANALYZED (BY INDEX ROWID) OF 'ITEM_MASTER'
                                71859    INDEX   GOAL: ANALYZED (UNIQUE SCAN) OF 'PK_ITEM_MASTER' 
                                             (UNIQUE)
                               
                               
                              Elapsed times include waiting on following events:
                                Event waited on                             Times   Max. Wait  Total Waited
                                ----------------------------------------   Waited  ----------  ------------
                                SQL*Net message to client                   71859        0.00          0.05
                                SQL*Net message from client                 71859        1.06        974.02
                                latch free                                      6        0.01          0.01
                                db file sequential read                         2        0.02          0.02
                              ********************************************************************************Rows     Row Source Operation
                              -------  ---------------------------------------------------
                                    1  TABLE ACCESS FULL PERIOD (cr=4 r=0 w=0 time=39 us)
                               
                               
                              Rows     Execution Plan
                              -------  ---------------------------------------------------
                                    0  SELECT STATEMENT   GOAL: CHOOSE
                                    1   TABLE ACCESS   GOAL: ANALYZED (FULL) OF 'PERIOD'
                               
                              ********************************************************************************Rows     Row Source Operation
                              -------  ---------------------------------------------------
                                71859  DELETE  (cr=175290 r=0 w=0 time=10548624 us)
                                71859   TABLE ACCESS BY USER ROWID OBJ#(83393) (cr=175130 r=0 w=0 time=1601247 us)
                               
                               
                              Rows     Execution Plan
                              -------  ---------------------------------------------------
                                    0  DELETE STATEMENT   GOAL: CHOOSE
                                71859   DELETE OF 'TSF_STAGING'
                                71859    TABLE ACCESS   GOAL: ANALYZED (BY USER ROWID) OF 
                                             'TSF_STAGING'
                               
                               
                              Elapsed times include waiting on following events:
                                Event waited on                             Times   Max. Wait  Total Waited
                                ----------------------------------------   Waited  ----------  ------------
                                SQL*Net more data from client                 712        0.00          0.03
                                log buffer space                               38        0.43          3.54
                                latch free                                      8        0.02          0.05
                                buffer busy waits                               7        0.00          0.00
                                SQL*Net message to client                       9        0.00          0.00
                                SQL*Net message from client                     9        0.01          0.04
                              ********************************************************************************Rows     Row Source Operation
                              -------  ---------------------------------------------------
                                71859  UPDATE  (cr=498917 r=308 w=0 time=43891595 us)
                                71859   INDEX UNIQUE SCAN OBJ#(29253) (cr=497791 r=0 w=0 time=21701628 us)(object id 29253)
                               
                               
                              Rows     Execution Plan
                              -------  ---------------------------------------------------
                                    0  UPDATE STATEMENT   GOAL: CHOOSE
                                71859   UPDATE OF 'TSFHEAD'
                                71859    INDEX   GOAL: ANALYZED (UNIQUE SCAN) OF 'PK_TSFHEAD' (UNIQUE)
                               
                               
                              Elapsed times include waiting on following events:
                                Event waited on                             Times   Max. Wait  Total Waited
                                ----------------------------------------   Waited  ----------  ------------
                                db file sequential read                       308        0.26          7.97
                                latch free                                     74        0.10          0.89
                                log buffer space                               42        0.30          4.60
                                buffer busy waits                              34        0.04          0.22
                                SQL*Net more data from client                 353        0.00          0.03
                                log file sync                                   1        0.03          0.03
                                SQL*Net message to client                       9        0.00          0.00
                                SQL*Net message from client                     9        0.00          0.00
                                log file switch completion                      2        0.11          0.15
                              ********************************************************************************
                              Rows     Row Source Operation
                              -------  ---------------------------------------------------
                                    9  UPDATE  (cr=18 r=0 w=0 time=1130 us)
                                    9   INDEX UNIQUE SCAN OBJ#(28469) (cr=18 r=0 w=0 time=109 us)(object id 28469)
                               
                               
                              Rows     Execution Plan
                              -------  ---------------------------------------------------
                                    0  UPDATE STATEMENT   GOAL: CHOOSE
                                    9   UPDATE OF 'RESTART_BOOKMARK'
                                    9    INDEX   GOAL: ANALYZED (UNIQUE SCAN) OF 'PK_RESTART_BOOKMARK' 
                                             (UNIQUE)
                               
                               
                              Elapsed times include waiting on following events:
                                Event waited on                             Times   Max. Wait  Total Waited
                                ----------------------------------------   Waited  ----------  ------------
                                SQL*Net message to client                       9        0.00          0.00
                                SQL*Net message from client                     9        0.00          0.00
                              ********************************************************************************
                               
                              Rows     Row Source Operation
                              -------  ---------------------------------------------------
                                    1  UPDATE  (cr=2 r=0 w=0 time=137 us)
                                    1   INDEX UNIQUE SCAN OBJ#(28477) (cr=2 r=0 w=0 time=18 us)(object id 28477)
                               
                               
                              Rows     Execution Plan
                              -------  ---------------------------------------------------
                                    0  UPDATE STATEMENT   GOAL: CHOOSE
                                    1   UPDATE OF 'RESTART_PROGRAM_STATUS'
                                    1    INDEX   GOAL: ANALYZED (UNIQUE SCAN) OF 
                                             'PK_RESTART_PROGRAM_STATUS' (UNIQUE)
                               
                               
                              Elapsed times include waiting on following events:
                                Event waited on                             Times   Max. Wait  Total Waited
                                ----------------------------------------   Waited  ----------  ------------
                                SQL*Net message to client                       1        0.00          0.00
                                SQL*Net message from client                     1        0.00          0.00
                              ********************************************************************************Rows     Row Source Operation
                              -------  ---------------------------------------------------
                                    1  FILTER  (cr=8 r=0 w=0 time=77 us)
                                    1   NESTED LOOPS  (cr=8 r=0 w=0 time=72 us)
                                    1    NESTED LOOPS  (cr=6 r=0 w=0 time=46 us)
                                    1     TABLE ACCESS BY INDEX ROWID OBJ#(28468) (cr=3 r=0 w=0 time=24 us)
                                    1      INDEX UNIQUE SCAN OBJ#(28469) (cr=2 r=0 w=0 time=12 us)(object id 28469)
                                    1     TABLE ACCESS BY INDEX ROWID OBJ#(28475) (cr=3 r=0 w=0 time=14 us)
                                    1      INDEX UNIQUE SCAN OBJ#(28477) (cr=2 r=0 w=0 time=5 us)(object id 28477)
                                    1    TABLE ACCESS BY INDEX ROWID OBJ#(28470) (cr=2 r=0 w=0 time=17 us)
                                    1     INDEX UNIQUE SCAN OBJ#(28471) (cr=1 r=0 w=0 time=12 us)(object id 28471)
                               
                               
                              Rows     Execution Plan
                              -------  ---------------------------------------------------
                                    0  INSERT STATEMENT   GOAL: CHOOSE
                                    1   FILTER
                                    1    NESTED LOOPS
                                    1     NESTED LOOPS
                                    1      TABLE ACCESS   GOAL: ANALYZED (BY INDEX ROWID) OF 
                                               'RESTART_BOOKMARK'
                                    1       INDEX   GOAL: ANALYZED (UNIQUE SCAN) OF 
                                                'PK_RESTART_BOOKMARK' (UNIQUE)
                                    1      TABLE ACCESS   GOAL: ANALYZED (BY INDEX ROWID) OF 
                                               'RESTART_PROGRAM_STATUS'
                                    1       INDEX   GOAL: ANALYZED (UNIQUE SCAN) OF 
                                                'PK_RESTART_PROGRAM_STATUS' (UNIQUE)
                                    1     TABLE ACCESS   GOAL: ANALYZED (BY INDEX ROWID) OF 
                                              'RESTART_CONTROL'
                                    1      INDEX   GOAL: ANALYZED (UNIQUE SCAN) OF 
                                               'PK_RESTART_CONTROL' (UNIQUE)
                               
                               
                              Elapsed times include waiting on following events:
                                Event waited on                             Times   Max. Wait  Total Waited
                                ----------------------------------------   Waited  ----------  ------------
                                SQL*Net message to client                       1        0.00          0.00
                                SQL*Net message from client                     1        0.00          0.00
                              ********************************************************************************
                              Rows     Row Source Operation
                              -------  ---------------------------------------------------
                                    1  DELETE  (cr=2 r=0 w=0 time=83 us)
                                    1   INDEX UNIQUE SCAN OBJ#(28469) (cr=2 r=0 w=0 time=6 us)(object id 28469)
                               
                               
                              Rows     Execution Plan
                              -------  ---------------------------------------------------
                                    0  DELETE STATEMENT   GOAL: CHOOSE
                                    1   DELETE OF 'RESTART_BOOKMARK'
                                    1    INDEX   GOAL: ANALYZED (UNIQUE SCAN) OF 'PK_RESTART_BOOKMARK' 
                                             (UNIQUE)
                               
                               
                              Elapsed times include waiting on following events:
                                Event waited on                             Times   Max. Wait  Total Waited
                                ----------------------------------------   Waited  ----------  ------------
                                SQL*Net message to client                       1        0.00          0.00
                                SQL*Net message from client                     1        0.00          0.00
                              ********************************************************************************
                              Rows     Row Source Operation
                              -------  ---------------------------------------------------
                                    1  UPDATE  (cr=2 r=0 w=0 time=113 us)
                                    1   INDEX UNIQUE SCAN OBJ#(28477) (cr=2 r=0 w=0 time=12 us)(object id 28477)
                               
                               
                              Rows     Execution Plan
                              -------  ---------------------------------------------------
                                    0  UPDATE STATEMENT   GOAL: CHOOSE
                                    1   UPDATE OF 'RESTART_PROGRAM_STATUS'
                                    1    INDEX   GOAL: ANALYZED (UNIQUE SCAN) OF 
                                             'PK_RESTART_PROGRAM_STATUS' (UNIQUE)
                               
                               
                              Elapsed times include waiting on following events:
                                Event waited on                             Times   Max. Wait  Total Waited
                                ----------------------------------------   Waited  ----------  ------------
                                SQL*Net message to client                       1        0.00          0.00
                                SQL*Net message from client                     1        0.00          0.00
                              ********************************************************************************
                              Rows     Row Source Operation
                              -------  ---------------------------------------------------
                                    0  DELETE  (cr=2 r=0 w=0 time=10 us)
                                    0   INDEX UNIQUE SCAN OBJ#(28469) (cr=2 r=0 w=0 time=8 us)(object id 28469)
                               
                               
                              Rows     Execution Plan
                              -------  ---------------------------------------------------
                                    0  DELETE STATEMENT   GOAL: CHOOSE
                                    0   DELETE OF 'RESTART_BOOKMARK'
                                    0    INDEX   GOAL: ANALYZED (UNIQUE SCAN) OF 'PK_RESTART_BOOKMARK' 
                                             (UNIQUE)
                               
                               
                              Elapsed times include waiting on following events:
                                Event waited on                             Times   Max. Wait  Total Waited
                                ----------------------------------------   Waited  ----------  ------------
                                SQL*Net message to client                       1        0.00          0.00
                                SQL*Net message from client                     1        0.00          0.00
                              ********************************************************************************
                               
                              Rows     Row Source Operation
                              -------  ---------------------------------------------------
                                    0  HASH JOIN  (cr=0 r=0 w=0 time=0 us)
                              6161725   HASH JOIN  (cr=9612125 r=1758234 w=2408 time=2625092582 us)
                                15989    HASH JOIN  (cr=7560001 r=2408 w=2408 time=81619953 us)
                               212315     VIEW  (cr=7553336 r=2408 w=2408 time=81058149 us)
                               212315      SORT UNIQUE (cr=7553336 r=2408 w=2408 time=80958818 us)
                               697081       HASH JOIN  (cr=7553336 r=2408 w=2408 time=76507154 us)
                               210609        HASH JOIN  (cr=12485 r=0 w=0 time=2923341 us)
                               210649         TABLE ACCESS FULL ITEM_SUPP_COUNTRY (cr=3333 r=0 w=0 time=249455 us)
                               232549         HASH JOIN  (cr=9152 r=0 w=0 time=1727673 us)
                               210609          MERGE JOIN CARTESIAN (cr=6695 r=0 w=0 time=654287 us)
                                    1           MERGE JOIN CARTESIAN (cr=30 r=0 w=0 time=355 us)
                                    1            TABLE ACCESS FULL SYSTEM_OPTIONS (cr=15 r=0 w=0 time=178 us)
                                    1            BUFFER SORT (cr=15 r=0 w=0 time=140 us)
                                    1             TABLE ACCESS FULL SYSTEM_OPTIONS (cr=15 r=0 w=0 time=83 us)
                               210609           BUFFER SORT (cr=6665 r=0 w=0 time=563221 us)
                               210609            TABLE ACCESS FULL ITEM_MASTER (cr=6665 r=0 w=0 time=268814 us)
                               232590          TABLE ACCESS FULL ITEM_SUPPLIER (cr=2457 r=0 w=0 time=184676 us)
                              1829931        VIEW  (cr=7540851 r=2408 w=2408 time=66339321 us)
                              1829931         UNION-ALL  (cr=7540851 r=2408 w=2408 time=64305693 us)
                               232590          INDEX FAST FULL SCAN PK_ITEM_SUPP_COUNTRY (cr=1956 r=0 w=0 time=138049 us)(object id 27601)
                               232590          TABLE ACCESS FULL ITEM_SUPP_COUNTRY (cr=3333 r=0 w=0 time=173372 us)
                               232590          TABLE ACCESS FULL ITEM_SUPP_COUNTRY (cr=3333 r=0 w=0 time=186309 us)
                               232590          TABLE ACCESS FULL ITEM_SUPP_COUNTRY (cr=3333 r=0 w=0 time=204421 us)
                               299857          VIEW  (cr=9082 r=0 w=0 time=4488596 us)
                               299857           SORT UNIQUE (cr=9082 r=0 w=0 time=4332822 us)
                              1175224            INDEX FAST FULL SCAN PK_CASE_UPDATES (cr=9082 r=0 w=0 time=657277 us)(object id 64316)
                               299857          VIEW  (cr=9082 r=0 w=0 time=4502275 us)
                               299857           SORT UNIQUE (cr=9082 r=0 w=0 time=4336513 us)
                              1175224            INDEX FAST FULL SCAN PK_CASE_UPDATES (cr=9082 r=0 w=0 time=673263 us)(object id 64316)
                               299857          VIEW  (cr=9082 r=2408 w=2408 time=4912354 us)
                               299857           SORT UNIQUE (cr=9082 r=2408 w=2408 time=4750923 us)
                              1175224            INDEX FAST FULL SCAN PK_CASE_UPDATES (cr=9082 r=0 w=0 time=668371 us)(object id 64316)
                                15406     TABLE ACCESS FULL ITEM_MASTER (cr=6665 r=0 w=0 time=276030 us)
                              86032675    PARTITION HASH ALL PARTITION: 1 16 (cr=2052125 r=1755858 w=0 time=5678872646 us)
                              86032675     TABLE ACCESS FULL ITEM_LOC PARTITION: 1 16 (cr=2052125 r=1755858 w=0 time=3484995974 us)
                                    0   TABLE ACCESS FULL STORE (cr=0 r=0 w=0 time=0 us)
                               
                               
                              Rows     Execution Plan
                              -------  ---------------------------------------------------
                                    0  SELECT STATEMENT   GOAL: CHOOSE
                                    0   HASH JOIN
                              6161725    HASH JOIN
                                15989     HASH JOIN
                               212315      VIEW
                               212315       SORT (UNIQUE)
                               697081        HASH JOIN
                               210609         HASH JOIN
                               210649          TABLE ACCESS   GOAL: ANALYZED (FULL) OF 
                                                   'ITEM_SUPP_COUNTRY'
                               232549          HASH JOIN
                               210609           MERGE JOIN (CARTESIAN)
                                    1            MERGE JOIN (CARTESIAN)
                                    1             TABLE ACCESS   GOAL: ANALYZED (FULL) OF 
                                                      'SYSTEM_OPTIONS'
                                    1             BUFFER (SORT)
                                    1              TABLE ACCESS   GOAL: ANALYZED (FULL) OF 
                                                       'SYSTEM_OPTIONS'
                               210609            BUFFER (SORT)
                               210609             TABLE ACCESS   GOAL: ANALYZED (FULL) OF 
                                                      'ITEM_MASTER'
                               232590           TABLE ACCESS   GOAL: ANALYZED (FULL) OF 
                                                    'ITEM_SUPPLIER'
                              1829931         VIEW
                              1829931          UNION-ALL
                               232590           INDEX   GOAL: ANALYZED (FAST FULL SCAN) OF 
                                                    'PK_ITEM_SUPP_COUNTRY' (UNIQUE)
                               232590           TABLE ACCESS   GOAL: ANALYZED (FULL) OF 
                                                    'ITEM_SUPP_COUNTRY'
                               232590           TABLE ACCESS   GOAL: ANALYZED (FULL) OF 
                                                    'ITEM_SUPP_COUNTRY'
                               232590           TABLE ACCESS   GOAL: ANALYZED (FULL) OF 
                                                    'ITEM_SUPP_COUNTRY'
                               299857           VIEW
                               299857            SORT (UNIQUE)
                              1175224             INDEX   GOAL: ANALYZED (FAST FULL SCAN) OF 
                                                      'PK_CASE_UPDATES' (UNIQUE)
                               299857           VIEW
                               299857            SORT (UNIQUE)
                              1175224             INDEX   GOAL: ANALYZED (FAST FULL SCAN) OF 
                                                      'PK_CASE_UPDATES' (UNIQUE)
                               299857           VIEW
                               299857            SORT (UNIQUE)
                              1175224             INDEX   GOAL: ANALYZED (FAST FULL SCAN) OF 
                                                      'PK_CASE_UPDATES' (UNIQUE)
                                15406      TABLE ACCESS   GOAL: ANALYZED (FULL) OF 'ITEM_MASTER'
                              86032675     PARTITION HASH (ALL) PARTITION: START=1 STOP=16
                              86032675      TABLE ACCESS   GOAL: ANALYZED (FULL) OF 'ITEM_LOC' 
                                               PARTITION: START=1 STOP=16
                                    0    TABLE ACCESS   GOAL: ANALYZED (FULL) OF 'STORE'
                               
                               
                              Elapsed times include waiting on following events:
                                Event waited on                             Times   Max. Wait  Total Waited
                                ----------------------------------------   Waited  ----------  ------------
                                SQL*Net message to client                       2        0.00          0.00
                                direct path write                            5506        0.22          4.39
                                direct path read                               42        0.00          0.06
                                db file sequential read                     73643        0.32         47.06
                                db file scattered read                     123335        0.93        318.67
                                latch free                                      3        0.00          0.00
                                SQL*Net break/reset to client                   1        0.00          0.00
                                SQL*Net message from client                     1      181.03        181.03
                              ********************************************************************************
                              • 72. Re: query tuning
                                599921
                                Charles,
                                I have followed as per Lewis and ur suggestion.now it was taking 42 mins time.Previously it was taking 45 mins.So please guide me for the next step to increase the performance.

                                Thank you
                                • 73. Re: query tuning
                                  Jonathan Lewis
                                  The plan shows that the swap_join_inputs() hint was not followed, and at the moment I can't see why not.

                                  In the text you've posted, can you remove all the tkrprof output from the OTHER
                                  sql statements, and the bit titled ''Éxecution P'lan for the critical statement - that will leave just the wait stats and the 'Rowsource Operation' for the one statement.

                                  Then add in the SQL that actually ran and the run stats (the table of parse/execute/fetch figures) for that statement.

                                  One question - why, in this case, did you have zero rows selected from the store ? If the optimizer had followed my desired plan you would have got your result in just a few seconds as the empty store result would have been discovered before the massive table scan.

                                  Regards
                                  Jonathan Lewis.
                                  http://jonathanlewis.wordpress.com
                                  http://www.jlcomp.demon.co.uk
                                  • 74. Re: query tuning
                                    599921
                                    Hi Lewis,
                                    Sorry for posting wrong output of TKPROF. It's previous output.I will post the new o/P.once again sorry for this.

                                    Thank you

                                    Message was edited by:
                                    User71408
                                    1 3 4 5 6 7 8 Previous Next