This discussion is archived
1 3 4 5 6 7 8 Previous Next 117 Replies Latest reply: May 5, 2008 10:19 AM by 181444 Go to original post RSS
  • 60. Re: query tuning
    599921 Newbie
    Currently Being Moderated
    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 Newbie
    Currently Being Moderated
    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
    CharlesHooper Expert
    Currently Being Moderated
    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 Oracle ACE Director
    Currently Being Moderated
    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
    CharlesHooper Expert
    Currently Being Moderated
    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 Newbie
    Currently Being Moderated
    Hi Lewis ,
    I am not a DBA. So please give me some more ideas regarding this.

    Thank you.
  • 66. Re: query tuning
    Jonathan Lewis Oracle ACE Director
    Currently Being Moderated
    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 Expert
    Currently Being Moderated
    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.... Oracle ACE
    Currently Being Moderated
    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 Newbie
    Currently Being Moderated
    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 Oracle ACE Director
    Currently Being Moderated
    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 Newbie
    Currently Being Moderated
    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 Newbie
    Currently Being Moderated
    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 Oracle ACE Director
    Currently Being Moderated
    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 Newbie
    Currently Being Moderated
    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