1 2 3 4 Previous Next 46 Replies Latest reply: Mar 23, 2010 7:39 PM by Iggy Fernandez RSS

    Tuning a sql using tkprof

    AleC
      The most important query in our application is:
      SELECT           
            COUNT ( * )
        FROM            I_JOURNAL m
                     INNER JOIN
                        LIU_TYPES lt
                     ON (m.LIU_TYPE = lt.LIU_TYPE)
                  INNER JOIN
                     LAWFUL_I li
                  ON (m.LIID = li.LIID)
               LEFT OUTER JOIN
                  PHONE_BOOK pb
               ON (    m.NORM_CIN = pb.NORM_CIN
                   AND pb.DELETION_DATE IS NULL
                   AND pb.OPERATOR_ID = :"SYS_B_00")
       WHERE   LIU_PRIORITY >= :"SYS_B_01"
               AND (li.ID IN
                          (:"SYS_B_02",
                           :"SYS_B_03",
                           :"SYS_B_04",
                           :"SYS_B_05",
                           :"SYS_B_06",
                           :"SYS_B_07",
                           :"SYS_B_08",
                           :"SYS_B_09",
      [...]
                           :"SYS_B_59",
                           :"SYS_B_60",
                           :"SYS_B_61",
                           :"SYS_B_62"))
               AND (li.END_VALID_DATE IS NULL
                    OR m.DISPLAY_DATE <= li.END_VALID_DATE)
               AND li.OPERATOR_ID = :"SYS_B_63"
      It should be fast: response time less than 5 seconds.
      But in some sites, the number of records of the tables is big:
      - I_JOURNAL: 5000000 rows
      - LAWFUL_I: 1000 rows
      - phone_book: 78000 rows

      The worst case we have is when the operator_id is related to a lot of rows in I_JOURNAL, for example 800000.
      In that case the response time is 20 seconds.

      I've traced the query and the output of tkprof is:
      call     count       cpu    elapsed       disk      query    current        rows
      ------- ------  -------- ---------- ---------- ---------- ----------  ----------
      Parse        1      0.00       0.00          0          0          0           0
      Execute      1      0.05       0.04          0          0          0           0
      Fetch        2    105.00     102.69     283093     652774          0           1
      ------- ------  -------- ---------- ---------- ---------- ----------  ----------
      total        4    105.05     102.73     283093     652774          0           1
      
      Misses in library cache during parse: 1
      Misses in library cache during execute: 1
      Optimizer mode: ALL_ROWS
      Parsing user id: 50  
      
      Rows     Row Source Operation
      -------  ---------------------------------------------------
            1  SORT AGGREGATE (cr=652774 pr=283093 pw=0 time=102690302 us)
       888030   HASH JOIN RIGHT OUTER (cr=652774 pr=283093 pw=0 time=99929786 us)
        28488    INDEX RANGE SCAN OBJ#(45035) (cr=130 pr=0 pw=0 time=142564 us)(object id 45035)
       888030    HASH JOIN  (cr=652644 pr=283093 pw=0 time=85254971 us)
           15     TABLE ACCESS FULL OBJ#(44893) (cr=7 pr=0 pw=0 time=320 us)
       888117     TABLE ACCESS BY INDEX ROWID OBJ#(47625) (cr=652637 pr=283093 pw=0 time=63945559 us)
       888179      NESTED LOOPS  (cr=5389 pr=4986 pw=0 time=23801052 us)
           61       INLIST ITERATOR  (cr=213 pr=1 pw=0 time=8299 us)
           61        TABLE ACCESS BY INDEX ROWID OBJ#(44860) (cr=213 pr=1 pw=0 time=7235 us)
           61         INDEX RANGE SCAN OBJ#(45023) (cr=122 pr=0 pw=0 time=2454 us)(object id 45023)
       888117       INDEX RANGE SCAN OBJ#(52001) (cr=5176 pr=4985 pw=0 time=9904545 us)(object id 52001)
      
      
      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
        db file sequential read                    283093        0.02          8.51
        SQL*Net message from client                     2        0.00          0.00
      ********************************************************************************
      First question: I cannot understand why the fetch count is *2*.

      Second question: could you give me any suggestions to reduce the response time?

      Another question: the cardinality seems wrong:
      SELECT STATEMENT  ALL_ROWSCost: 28,44  Bytes: 130  Cardinality: 1                                          
           11 SORT AGGREGATE  Bytes: 130  Cardinality: 1                                     
                10 HASH JOIN RIGHT OUTER  Cost: 28,44  Bytes: 3.878.940  Cardinality: 29,838                                
                     1 INDEX RANGE SCAN INDEX (UNIQUE) PBK_GET_NORM_CIN_UK Cost: 131  Bytes: 585,051  Cardinality: 25,437                           
                     9 HASH JOIN  Cost: 28,4  Bytes: 3.192.666  Cardinality: 29,838                           
                          2 TABLE ACCESS FULL TABLE LIU_TYPES Cost: 3  Bytes: 160  Cardinality: 16                      
                          8 TABLE ACCESS BY INDEX ROWID TABLE I_JOURNAL Cost: 1,092  Bytes: 58,6  Cardinality: 1,172                      
                               7 NESTED LOOPS  Cost: 28,396  Bytes: 2.973.923  Cardinality: 30,659                 
                                    5 INLIST ITERATOR            
                                         4 TABLE ACCESS BY INDEX ROWID TABLE LAWFUL_I Cost: 11  Bytes: 1,222  Cardinality: 26       
                                              3 INDEX RANGE SCAN INDEX (UNIQUE) MITO.LIN_ID_UK Cost: 2  Cardinality: 61  
                                    6 INDEX RANGE SCAN INDEX IJL_LIN_FK_IX Cost: 30  Cardinality: 5,318  
      The result of the query is 890403 and in the explain plan you can see *"Cardinality: 29,838"*

      Edited by: user600979 on 11-mar-2010 2.27
        • 1. Re: Tuning a sql using tkprof
          475839
          Much clarity required to understand your query.
          • 2. Re: Tuning a sql using tkprof
            AleC
            Table explanation:

            - LAWFUL_I contains the description the jobs descriptions.
            - I_JOURNAL contains the activities for each job.
            - PHONE_BOOK contains the telephone numbers

            Each customer (operator_id) should see the job activities for his jobs: he could have a lot of jobs (ie: 500 jobs) and each job could have a lot of activities (i.e. 2000).
            The worst case customer (operator_id) could see 800000 activities.

            The li.id is the id (PK) of each job).
            • 3. Re: Tuning a sql using tkprof
              Timur Akhmadeev
              user600979 wrote:
              The worst case customer (operator_id) could see 800000 activities.
              could you give me any suggestions to reduce the response time?
              Well, your query is not to see the data, but count it. That is a very popular case when the app does what it shouldn't. Don't count the activities, just show 20-100 of them and/or supply additional filtering conditions for more precise data display. And of course, don't count it - just display what is necessary to show to a user.
              I cannot understand why the fetch count is 2.
              This is most likely your client side tool side-effect. For example, SQL*Plus Re: Value for FETCH in TKPROF is 2, though I executed the SQL only once.
              • 4. Re: Tuning a sql using tkprof
                SatishKandi
                Rows Row Source Operation
                ------- ---------------------------------------------------
                1 SORT AGGREGATE (cr=652774 pr=283093 pw=0 time=102690302 us)
                888030 HASH JOIN RIGHT OUTER (cr=652774 pr=283093 pw=0 time=99929786 us)
                28488 INDEX RANGE SCAN OBJ#(45035) (cr=130 pr=0 pw=0 time=142564 us)(object id 45035)
                888030 HASH JOIN (cr=652644 pr=283093 pw=0 time=85254971 us)
                15 TABLE ACCESS FULL OBJ#(44893) (cr=7 pr=0 pw=0 time=320 us)
                888117 TABLE ACCESS BY INDEX ROWID OBJ#(47625) (cr=652637 pr=283093 pw=0 time=63945559 us)
                888179 NESTED LOOPS (cr=5389 pr=4986 pw=0 time=23801052 us)
                61 INLIST ITERATOR (cr=213 pr=1 pw=0 time=8299 us)
                61 TABLE ACCESS BY INDEX ROWID OBJ#(44860) (cr=213 pr=1 pw=0 time=7235 us)
                61 INDEX RANGE SCAN OBJ#(45023) (cr=122 pr=0 pw=0 time=2454 us)(object id 45023)
                888117 INDEX RANGE SCAN OBJ#(52001) (cr=5176 pr=4985 pw=0 time=9904545 us)(object id 52001)
                The "Row source operation" in TKPROF output posted here does not tally with your SQL query. Have you posted a wrong output?
                • 5. Re: Tuning a sql using tkprof
                  AleC
                  It's the right one: why do you write it's wrong?
                  • 6. Re: Tuning a sql using tkprof
                    SatishKandi
                    user600979 wrote:
                    It's the right one: why do you write it's wrong?
                    Since none of the table names listed in the SQL and the Row source operation are matching - that's why.
                    • 7. Re: Tuning a sql using tkprof
                      AleC
                      You are right, our application runs two queries: the first one count the activities and the second one shows the all the activities.
                      But the queries have the same tables and the same where conditions.
                      • 8. Re: Tuning a sql using tkprof
                        AleC
                        Because there the OBJ# not the OBJ name.
                        • 9. Re: Tuning a sql using tkprof
                          adnanKaysar
                          call count cpu elapsed disk query current rows
                          ------- ------ -------- ---------- ---------- ---------- ---------- ----------
                          Parse 1 0.00 0.00 0 0 0 0
                          Execute 1 0.05 0.04 0 0 0 0
                          Fetch 2 105.00 102.69 *283093* 652774 0 1
                          ------- ------ -------- ---------- ---------- ---------- ---------- ----------
                          total 4 105.05 102.73 283093 652774 0 1

                          This showing that you have many disk reads that is physical I/O.

                          Event waited on Times Max. Wait Total Waited
                          ---------------------------------------- Waited ---------- ------------
                          SQL*Net message to client 2 0.00 0.00
                          db file sequential read 283093 0.02 8.51
                          SQL*Net message from client 2 0.00 0.00
                          ********************************************************************************
                          db file sequential read noticed Poorly tuned SQL or Slow I/O system
                          Cross-check I/O system and V$FILESTAT for poor read time.

                          Try to increase the initialization parameter DB_FILE_MULTIBLOCK_READ_COUNT as there are db file sequential read and high disk reads.

                          For table join the goal is to drive from the table that has the most selective filter.
                          This means that there are fewer rows passed to the next step.If the next step is a join, then this means that fewer rows are joined.
                          This will drive by your condition, try to join the less vol. data tables first then to the high vol. data tables,although less and high volume tables can have less output.

                          Try to use EXISTS rather than IN, will be helpfull.
                          • 10. Re: Tuning a sql using tkprof
                            user503699
                            user600979 wrote:
                            Because there the OBJ# not the OBJ name.
                            Not sure what that means but TkProf should be able to show object names.
                            You might want to read following and post additional details as described there
                            When your query takes too long ...
                            HOW TO: Post a SQL statement tuning request - template posting

                            But I would agree with Timur's suggestion above. The best solution here might be not to execute the query at all and you might want to look into that possibility.
                            • 11. Re: Tuning a sql using tkprof
                              Charles Hooper
                              There is something very strange with the output you posted. All of your physical disk reads were single block read, which in itself is not strange based on the execution plan. The TKPROF output shows that there were 283,093 waits on the 'db file sequential read' wait event for a total of 8.51 seconds, meaning that the average wait time was 0.000030 seconds per single block physical read (about 133 times faster than the typical seek time of a 15,000 RPM hard drive). That means that those blocks were most likely sitting in some form of cache, whether at the operating system level, the RAID controller level, the SAN level, or in the cache of the physical hard drives. OK, this is not the really strange part. Let's take a look at a line in the plan that was output by TKPROF:
                               888117       INDEX RANGE SCAN OBJ#(52001) (cr=5176 pr=4985 pw=0 time=9904545 us)(object id 52001)  IJL_LIN_FK_IX
                              There were a total of 283,093 single block reads, with 1.76% of those single block reads appearing in the above line. If the total single block read time for the SQL statement is 8.51 seconds, that suggests that the above line in the plan might have consumed about 0.15 seconds performing the physical block reads. The time= entry for that plan line indicates that the line required about 9.90 seconds, which would suggest that Oracle accumulated roughly 9.75 seconds of CPU time performing the 5,176 consistent gets, which would suggest that reading a block from Oracle's buffer cache (in RAM) is significantly slower than reading the block from disk. Considering that all of the other wait events were essentially non-existent, I do not know if this is a sign of exceeding the physical memory of the server, or if it is another problem such as overloading the server's CPUs, or problems with implicit data type conversions (you would see if this is the case by generating a DBMS_XPLAN for the SQL statement when the statement is actually executed - see the examples here: http://hoopercharles.wordpress.com/2010/01/30/execution-plans-what-is-the-plan-and-where-do-i-find-it/ ).

                              The differences in the cardinality estimates and the actual number of rows could be a contributing problem - it might explain, for instance, why a nested loop join was used in the plan. What happens if you force a full table scan of the I_JOURNAL table? Even if there are 5,000,000 rows in the table, each roughly 100 bytes, if we assume that each block is 80% used, that is only about 596MB to be read from disk. I would assume with your I/O system this would require somewhere between 0.5 and 4 seconds. If you want to test this as a possibility, begin the SQL statement like this:
                              SELECT /*+ FULL(M) */
                              Charles Hooper
                              Co-author of "Expert Oracle Practices: Oracle Database Administration from the Oak Table"
                              http://hoopercharles.wordpress.com/
                              IT Manager/Oracle DBA
                              K&M Machine-Fabricating, Inc.
                              • 12. Re: Tuning a sql using tkprof
                                AleC
                                The explain plan without the hint FULL is
                                15:08:15 SQL> 15:08:15 SQL> select plan_table_output from TABLE(DBMS_XPLAN.DISPLAY_CURSOR(NULL,NULL,'TYPICAL'));
                                
                                PLAN_TABLE_OUTPUT
                                --------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
                                SQL_ID  ffyv1wufuu12v, child number 0
                                -------------------------------------
                                User has no SELECT privileges on V$SQL
                                
                                Plan hash value: 4183643102
                                
                                -----------------------------------------------------------------------------------------------------------
                                | Id  | Operation                         | Name                  | Rows  | Bytes | Cost (%CPU)| Time     |
                                -----------------------------------------------------------------------------------------------------------
                                |   0 | SELECT STATEMENT                  |                       |       |       | 28440 (100)|          |
                                |   1 |  SORT AGGREGATE                   |                       |     1 |   130 |            |          |
                                
                                PLAN_TABLE_OUTPUT
                                --------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
                                |*  2 |   HASH JOIN RIGHT OUTER           |                       | 29838 |  3788K| 28440   (1)| 00:05:42 |
                                |*  3 |    INDEX RANGE SCAN               | PBK_GET_NORM_CIN_UK   | 25437 |   571K|   130   (0)| 00:00:02 |
                                |*  4 |    HASH JOIN                      |                       | 29838 |  3117K| 28399   (1)| 00:05:41 |
                                |*  5 |     TABLE ACCESS FULL             | LIU_TYPES             |    16 |   160 |     3   (0)| 00:00:01 |
                                |*  6 |     TABLE ACCESS BY INDEX ROWID   | I_JOURNAL             |  1172 | 58600 |  1091   (0)| 00:00:14 |
                                |   7 |      NESTED LOOPS                 |                       | 30659 |  2904K| 28396   (1)| 00:05:41 |
                                |   8 |       INLIST ITERATOR             |                       |       |       |            |          |
                                |*  9 |        TABLE ACCESS BY INDEX ROWID| LAWFUL_I              |    26 |  1222 |    10   (0)| 00:00:01 |
                                |* 10 |         INDEX RANGE SCAN          | LIN_ID_UK             |    61 |       |     2   (0)| 00:00:01 |
                                |* 11 |       INDEX RANGE SCAN            | IJL_LIN_FK_IX         |  5318 |       |    30   (0)| 00:00:01 |
                                -----------------------------------------------------------------------------------------------------------
                                
                                PLAN_TABLE_OUTPUT
                                --------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
                                
                                Predicate Information (identified by operation id):
                                ---------------------------------------------------
                                
                                   2 - access("M"."NORM_CIN"="PB"."NORM_CIN")
                                   3 - access("PB"."OPERATOR_ID"=:SYS_B_00 AND "PB"."DELETION_DATE" IS NULL)
                                       filter("PB"."DELETION_DATE" IS NULL)
                                   4 - access("M"."LIU_TYPE"="LT"."LIU_TYPE")
                                   5 - filter("LT"."LIU_PRIORITY">=:SYS_B_01)
                                   6 - filter(("LI"."END_VALID_DATE" IS NULL OR "M"."DISPLAY_DATE"<="LI"."END_VALID_DATE"))
                                   9 - filter("LI"."OPERATOR_ID"=:SYS_B_63)
                                
                                PLAN_TABLE_OUTPUT
                                --------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
                                  10 - access(("LI"."ID"=:SYS_B_02 OR "LI"."ID"=:SYS_B_03 OR "LI"."ID"=:SYS_B_04 OR
                                              "LI"."ID"=:SYS_B_05 OR "LI"."ID"=:SYS_B_06 OR "LI"."ID"=:SYS_B_07 OR "LI"."ID"=:SYS_B_08 OR
                                              "LI"."ID"=:SYS_B_09 OR "LI"."ID"=:SYS_B_10 OR "LI"."ID"=:SYS_B_11 OR "LI"."ID"=:SYS_B_12 OR
                                              "LI"."ID"=:SYS_B_13 OR "LI"."ID"=:SYS_B_14 OR "LI"."ID"=:SYS_B_15 OR "LI"."ID"=:SYS_B_16 OR
                                              "LI"."ID"=:SYS_B_17 OR "LI"."ID"=:SYS_B_18 OR "LI"."ID"=:SYS_B_19 OR "LI"."ID"=:SYS_B_20 OR
                                              "LI"."ID"=:SYS_B_21 OR "LI"."ID"=:SYS_B_22 OR "LI"."ID"=:SYS_B_23 OR "LI"."ID"=:SYS_B_24 OR
                                              "LI"."ID"=:SYS_B_25 OR "LI"."ID"=:SYS_B_26 OR "LI"."ID"=:SYS_B_27 OR "LI"."ID"=:SYS_B_28 OR
                                              "LI"."ID"=:SYS_B_29 OR "LI"."ID"=:SYS_B_30 OR "LI"."ID"=:SYS_B_31 OR "LI"."ID"=:SYS_B_32 OR
                                              "LI"."ID"=:SYS_B_33 OR "LI"."ID"=:SYS_B_34 OR "LI"."ID"=:SYS_B_35 OR "LI"."ID"=:SYS_B_36 OR
                                              "LI"."ID"=:SYS_B_37 OR "LI"."ID"=:SYS_B_38 OR "LI"."ID"=:SYS_B_39 OR "LI"."ID"=:SYS_B_40 OR
                                              "LI"."ID"=:SYS_B_41 OR "LI"."ID"=:SYS_B_42 OR "LI"."ID"=:SYS_B_43 OR "LI"."ID"=:SYS_B_44 OR
                                
                                PLAN_TABLE_OUTPUT
                                --------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
                                              "LI"."ID"=:SYS_B_45 OR "LI"."ID"=:SYS_B_46 OR "LI"."ID"=:SYS_B_47 OR "LI"."ID"=:SYS_B_48 OR
                                              "LI"."ID"=:SYS_B_49 OR "LI"."ID"=:SYS_B_50 OR "LI"."ID"=:SYS_B_51 OR "LI"."ID"=:SYS_B_52 OR
                                              "LI"."ID"=:SYS_B_53 OR "LI"."ID"=:SYS_B_54 OR "LI"."ID"=:SYS_B_55 OR "LI"."ID"=:SYS_B_56 OR
                                              "LI"."ID"=:SYS_B_57 OR "LI"."ID"=:SYS_B_58 OR "LI"."ID"=:SYS_B_59 OR "LI"."ID"=:SYS_B_60 OR
                                              "LI"."ID"=:SYS_B_61 OR "LI"."ID"=:SYS_B_62))
                                  11 - access("M"."LIID"="LI"."LIID")
                                ----
                                The outpout with the FULL hint is:

                                PLAN_TABLE_OUTPUT
                                --------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
                                SQL_ID  5ksz9j3cdqnjc, child number 0
                                -------------------------------------
                                User has no SELECT privileges on V$SQL
                                
                                Plan hash value: 3482366683
                                
                                ----------------------------------------------------------------------------------------------------------
                                | Id  | Operation                        | Name                  | Rows  | Bytes | Cost (%CPU)| Time     |
                                ----------------------------------------------------------------------------------------------------------
                                |   0 | SELECT STATEMENT                 |                       |       |       | 57737 (100)|          |
                                |   1 |  SORT AGGREGATE                  |                       |     1 |   130 |            |          |
                                
                                PLAN_TABLE_OUTPUT
                                --------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
                                |*  2 |   HASH JOIN RIGHT OUTER          |                       | 29838 |  3788K| 57737   (1)| 00:11:33 |
                                |*  3 |    INDEX RANGE SCAN              | PBK_GET_NORM_CIN_UK   | 25437 |   571K|   130   (0)| 00:00:02 |
                                |*  4 |    HASH JOIN                     |                       | 29838 |  3117K| 57697   (1)| 00:11:33 |
                                |*  5 |     TABLE ACCESS FULL            | LIU_TYPES             |    16 |   160 |     3   (0)| 00:00:01 |
                                |*  6 |     HASH JOIN                    |                       | 30659 |  2904K| 57693   (1)| 00:11:33 |
                                |   7 |      INLIST ITERATOR             |                       |       |       |            |          |
                                |*  8 |       TABLE ACCESS BY INDEX ROWID| LAWFUL_I              |    26 |  1222 |    10   (0)| 00:00:01 |
                                |*  9 |        INDEX RANGE SCAN          | LIN_ID_UK             |    61 |       |     2   (0)| 00:00:01 |
                                |  10 |      TABLE ACCESS FULL           | I_JOURNAL             |  4998K|   238M| 57640   (1)| 00:11:32 |
                                ----------------------------------------------------------------------------------------------------------
                                
                                
                                PLAN_TABLE_OUTPUT
                                --------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
                                Predicate Information (identified by operation id):
                                ---------------------------------------------------
                                
                                   2 - access("M"."NORM_CIN"="PB"."NORM_CIN")
                                   3 - access("PB"."OPERATOR_ID"=:SYS_B_00 AND "PB"."DELETION_DATE" IS NULL)
                                       filter("PB"."DELETION_DATE" IS NULL)
                                   4 - access("M"."LIU_TYPE"="LT"."LIU_TYPE")
                                   5 - filter("LT"."LIU_PRIORITY">=:SYS_B_01)
                                   6 - access("M"."LIID"="LI"."LIID")
                                       filter(("LI"."END_VALID_DATE" IS NULL OR "M"."DISPLAY_DATE"<="LI"."END_VALID_DATE"))
                                   8 - filter("LI"."OPERATOR_ID"=:SYS_B_63)
                                
                                PLAN_TABLE_OUTPUT
                                --------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
                                   9 - access(("LI"."ID"=:SYS_B_02 OR "LI"."ID"=:SYS_B_03 OR "LI"."ID"=:SYS_B_04 OR
                                              "LI"."ID"=:SYS_B_05 OR "LI"."ID"=:SYS_B_06 OR "LI"."ID"=:SYS_B_07 OR "LI"."ID"=:SYS_B_08 OR
                                              "LI"."ID"=:SYS_B_09 OR "LI"."ID"=:SYS_B_10 OR "LI"."ID"=:SYS_B_11 OR "LI"."ID"=:SYS_B_12 OR
                                              "LI"."ID"=:SYS_B_13 OR "LI"."ID"=:SYS_B_14 OR "LI"."ID"=:SYS_B_15 OR "LI"."ID"=:SYS_B_16 OR
                                              "LI"."ID"=:SYS_B_17 OR "LI"."ID"=:SYS_B_18 OR "LI"."ID"=:SYS_B_19 OR "LI"."ID"=:SYS_B_20 OR
                                              "LI"."ID"=:SYS_B_21 OR "LI"."ID"=:SYS_B_22 OR "LI"."ID"=:SYS_B_23 OR "LI"."ID"=:SYS_B_24 OR
                                              "LI"."ID"=:SYS_B_25 OR "LI"."ID"=:SYS_B_26 OR "LI"."ID"=:SYS_B_27 OR "LI"."ID"=:SYS_B_28 OR
                                              "LI"."ID"=:SYS_B_29 OR "LI"."ID"=:SYS_B_30 OR "LI"."ID"=:SYS_B_31 OR "LI"."ID"=:SYS_B_32 OR
                                              "LI"."ID"=:SYS_B_33 OR "LI"."ID"=:SYS_B_34 OR "LI"."ID"=:SYS_B_35 OR "LI"."ID"=:SYS_B_36 OR
                                              "LI"."ID"=:SYS_B_37 OR "LI"."ID"=:SYS_B_38 OR "LI"."ID"=:SYS_B_39 OR "LI"."ID"=:SYS_B_40 OR
                                              "LI"."ID"=:SYS_B_41 OR "LI"."ID"=:SYS_B_42 OR "LI"."ID"=:SYS_B_43 OR "LI"."ID"=:SYS_B_44 OR
                                
                                PLAN_TABLE_OUTPUT
                                --------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
                                              "LI"."ID"=:SYS_B_45 OR "LI"."ID"=:SYS_B_46 OR "LI"."ID"=:SYS_B_47 OR "LI"."ID"=:SYS_B_48 OR
                                              "LI"."ID"=:SYS_B_49 OR "LI"."ID"=:SYS_B_50 OR "LI"."ID"=:SYS_B_51 OR "LI"."ID"=:SYS_B_52 OR
                                              "LI"."ID"=:SYS_B_53 OR "LI"."ID"=:SYS_B_54 OR "LI"."ID"=:SYS_B_55 OR "LI"."ID"=:SYS_B_56 OR
                                              "LI"."ID"=:SYS_B_57 OR "LI"."ID"=:SYS_B_58 OR "LI"."ID"=:SYS_B_59 OR "LI"."ID"=:SYS_B_60 OR
                                              "LI"."ID"=:SYS_B_61 OR "LI"."ID"=:SYS_B_62))
                                • 13. Re: Tuning a sql using tkprof
                                  Charles Hooper
                                  Thanks for posting the output of DBMS_XPLAN. It appears that DBMS_XPLAN is complaining that your user account does not have access to query V$SQL. The documentation:
                                  http://download.oracle.com/docs/cd/B13789_01/appdev.101/b10802/d_xplan.htm#999118

                                  Indicates that you need to have select permissions on V$SQL_PLAN, V$SESSION and V$SQL_PLAN_STATISTICS_ALL for DBMS_XPLAN to work fully.

                                  The DBMS_XPLAN output does not indicate any problems with implicit data type conversions. The optimizer is estimating that I_JOURNAL contains roughly 5,000,000 rows and is 238MB in size (about 50% of the size that I estimated). How quickly did the query execute compared to the original version?

                                  Please either generate a 10046 trace at level 8 and process that file with TKPROF with the FULL hint in place (post the output), or do the following once you adjust the permissions on the three views (post the output):
                                  ALTER SESSION SET STATISTICS_LEVEL='ALL';
                                   
                                  (run the SQL statement with the full hint)
                                   
                                  select plan_table_output from TABLE(DBMS_XPLAN.DISPLAY_CURSOR(NULL,NULL,'ALLSTATS LAST'));
                                   
                                  ALTER SESSION SET STATISTICS_LEVEL='TYPICAL';
                                  The ALLSTATS LAST version of the DBMS_XPLAN output with STATISTICS_LEVEL='ALL' specified will show you roughly how much time each operation in the plan actually required, along with the estimated cardinality (E-ROWS) and actual cardinality (A-ROWS) for each operation in the plan.

                                  If it still takes a long time to execute, I suggest sampling V$OSSTAT and V$SYS_TIME_MODEL to see if that provides a clue why the physical reads are so fast and the logical reads appear to be so slow. If you do not have an easy way to do that, you can use the VBS script on my blog that collects the delta values from these views as well as monitors the session-level contributors to the V$SYS_TIME_MODEL view and the session level waits:
                                  http://hoopercharles.wordpress.com/2010/02/09/working-with-oracle%e2%80%99s-time-model-data-3/

                                  There is also another VBS script on my blog for generating 10046 traces while simultaneuosly generating a DBMS_XPLAN output for a SQL statement, if that helps.

                                  Charles Hooper
                                  Co-author of "Expert Oracle Practices: Oracle Database Administration from the Oak Table"
                                  http://hoopercharles.wordpress.com/
                                  IT Manager/Oracle DBA
                                  K&M Machine-Fabricating, Inc.
                                  • 14. Re: Tuning a sql using tkprof
                                    AleC
                                    I've an error:


                                    Error: format 'ALLSTATS LAST' not valid for DBMS_XPAN.DISPLAY_CURSOR()

                                    I'm going to use:

                                    select * from table(dbms_xplan.display_cursor(null,null,'RUNSTATS_LAST'));

                                    Edited by: user600979 on 11-mar-2010 7.32
                                    1 2 3 4 Previous Next