6 Replies Latest reply: Jan 27, 2011 4:50 PM by Randolf Geist RSS

    Execution plan change for same query.

    Yasu
      Hi All,

      This issue was raised before also, but still not able to find actual cause of this.

      Thread1:
      Re: Finding table fragmentation in Oracle 8.1.6.3.0

      Thread2:
      CBC Latch and Buffer Busy wait on same table.

      Issue is, sometimes server CPU hammers 100% usage with latch free and buffer busy wait events.

      We found one query is consuming high CPU usage which is executed by different sessions.

      This query have two type of execution plans, where one is precise and other is not(Means its hitting Primary Key index not suitable index present on table)

      Because its hitting Primary key index repeatedly from different sessions....some sessions are performing db file sequential read and some sessions are waiting for buffer busy waits event.Also during this time some sessions waits for Latch free event.

      My doubt is how come same sql with different literal values execution plan changes and causes prob.
      select count(*),event from v$session_wait group by event;
        COUNT(*) EVENT
      ---------- ----------------------------------------------------------------
             165 SQL*Net message from client
               1 SQL*Net message to client
               3 buffer busy waits
               2 db file parallel read
              18 db file sequential read
              10 latch free
               5 log file sync
               1 pmon timer
               6 rdbms ipc message
               1 smon timer
      
      SQL> select sid from v$session_wait where event='db file sequential read';
             SID
      ----------
              26
              58
              82
             107
             116
             223
             212
             203
             192
             173
             161
             157
             150
             147
             254
             238
             229
             112
             101
              81
              68
      
      SQL> select spid, sid, s.serial#, p.program from v$session s, v$process p where paddr=addr and sid=&SID;
      Enter value for sid: 161
      old   1: select spid, sid, s.serial#, p.program from v$session s, v$process p where paddr=addr and sid=&SID
      new   1: select spid, sid, s.serial#, p.program from v$session s, v$process p where paddr=addr and sid=161
      
      SPID             SID    SERIAL# PROGRAM
      --------- ---------- ---------- ------------------------------------------------
      4231             161      49569 oracle@tfrdb3 (TNS V1-V3)
      
      
      SQL> select sql_text
      from v$process a,
           v$session b,  2    3
           v$sql c
      where a.addr = b.paddr and
           b.sql_hash_value = c.hash_value and
          a.spid = &PID;  4    5    6    7
      Enter value for pid: 4231
      old   7:     a.spid = &PID
      new   7:     a.spid = 4231
      
      SQL_TEXT
      --------------------------------------------------------------------------------
      SELECT ERROR,TIME_STAMP,O_RESOURCE,QUEUE,NEW_QUEUE FROM LOG WHERE ID = '09292AMR
      10B41FE' AND TYPE IN (11, 28, 25, 18, 60, 13) AND (LOG_SEQ>'234225222' OR TYPE =
       18 AND LOG_SEQ='234225222') ORDER BY TIME_STAMP ASC
      
      SQL> set autotrace traceonly exp
      SQL> SELECT ERROR,TIME_STAMP,O_RESOURCE,QUEUE,NEW_QUEUE FROM amrwf1.LOG WHERE ID = '09292AMR10B41FE' AND TYPE IN (11, 28, 25, 18, 60, 13) AND (LOG_SEQ>'234225222' OR TYPE =18 AND LOG_SEQ='234225222') ORDER BY TIME_STAMP ASC;
      
      Execution Plan
      ----------------------------------------------------------
         0      SELECT STATEMENT Optimizer=CHOOSE (Cost=11 Card=2 Bytes=126)
         1    0   SORT (ORDER BY) (Cost=11 Card=2 Bytes=126)
         2    1     CONCATENATION
         3    2       TABLE ACCESS (BY INDEX ROWID) OF 'LOG' (Cost=4 Card=1
                Bytes=63)
      
         4    3         INDEX (UNIQUE SCAN) OF 'PK_LOG_LOG_SEQ' (UNIQUE) (Co
                st=3 Card=1)
      
         5    2       TABLE ACCESS (BY INDEX ROWID) OF 'LOG' (Cost=4 Card=1
                Bytes=63)
      
         6    5         INDEX (RANGE SCAN) OF 'PK_LOG_LOG_SEQ' (UNIQUE) (Cos
                t=3 Card=1)
      
      
      SQL> select spid, sid, s.serial#, p.program from v$session s, v$process p where paddr=addr and sid=&SID;
      Enter value for sid: 147
      old   1: select spid, sid, s.serial#, p.program from v$session s, v$process p where paddr=addr and sid=&SID
      new   1: select spid, sid, s.serial#, p.program from v$session s, v$process p where paddr=addr and sid=147
      
      SPID             SID    SERIAL# PROGRAM
      --------- ---------- ---------- ------------------------------------------------
      6255             147      38306 oracle@tfrdb3 (TNS V1-V3)
      
      SQL> select sql_text
      from v$process a,
           v$session b,
           v$sql c  2    3
      where a.addr = b.paddr and
           b.sql_hash_value = c.hash_value and
          a.spid = &PID;  4    5    6    7
      Enter value for pid: 6255
      old   7:     a.spid = &PID
      new   7:     a.spid = 6255
      
      SQL_TEXT
      --------------------------------------------------------------------------------
      SELECT ERROR,TIME_STAMP,O_RESOURCE,QUEUE,NEW_QUEUE FROM LOG WHERE ID = '09273AMR
      62B4894' AND TYPE IN (11, 28, 25, 18, 60, 13) AND (LOG_SEQ>'223324996' OR TYPE =
       18 AND LOG_SEQ='223324996') ORDER BY TIME_STAMP ASC
      
      
      SQL> set autotrace traceonly exp
      SQL> SELECT ERROR,TIME_STAMP,O_RESOURCE,QUEUE,NEW_QUEUE FROM amrwf1.LOG WHERE ID = '09273AMR62B4894' AND TYPE IN (11, 28, 25, 18, 60, 13) AND (LOG_SEQ>'223324996' OR TYPE =18 AND LOG_SEQ='223324996') ORDER BY TIME_STAMP ASC;
      
      Execution Plan
      ----------------------------------------------------------
         0      SELECT STATEMENT Optimizer=CHOOSE (Cost=1538 Card=736 Bytes=
                46368)
      
         1    0   SORT (ORDER BY) (Cost=1538 Card=736 Bytes=46368)
         2    1     TABLE ACCESS (BY INDEX ROWID) OF 'LOG' (Cost=1527 Card=7
                36 Bytes=46368)
      
         3    2       INDEX (RANGE SCAN) OF 'LOG_ID' (NON-UNIQUE) (Cost=32 C
                ard=736)
      
      
      
      SQL> select spid, sid, s.serial#, p.program from v$session s, v$process p where paddr=addr and sid=&SID;
      Enter value for sid: 82
      old   1: select spid, sid, s.serial#, p.program from v$session s, v$process p where paddr=addr and sid=&SID
      new   1: select spid, sid, s.serial#, p.program from v$session s, v$process p where paddr=addr and sid=82
      
      SPID             SID    SERIAL# PROGRAM
      --------- ---------- ---------- ------------------------------------------------
      6172              82      45378 oracle@tfrdb3 (TNS V1-V3)
      
      
      SQL> select sql_text
      from v$process a,
           v$session b,
           v$sql c
      where a.addr = b.paddr and
           b.sql_hash_value = c.hash_value and  2
        3      a.spid = &PID;  4    5    6    7
      Enter value for pid: 6172
      old   7:     a.spid = &PID
      new   7:     a.spid = 6172
      
      SQL_TEXT
      --------------------------------------------------------------------------------
      INSERT INTO LOG (ID,TIME_STAMP,TYPE,ERROR,INSTANCE,RULE_NUM,RULE_TYPE,PRIORITY,F
      LAGS,NAME,BATCH,O_RESOURCE,QUEUE,NEW_QUEUE,SERVER,FORM,WORKSET) VALUES (:V001,:V
      002,11,0,0,3,1,0,1,:V003,:V004,:V005,:V006,:V007,:V008,:V009,:V010)
      
      INSERT INTO LOG (ID,TIME_STAMP,TYPE,ERROR,INSTANCE,RULE_NUM,RULE_TYPE,PRIORITY,F
      LAGS,NAME,BATCH,O_RESOURCE,QUEUE,NEW_QUEUE,SERVER,FORM,WORKSET) VALUES (:V001,:V
      002,11,0,0,3,1,0,1,:V003,:V004,:V005,:V006,:V007,:V008,:V009,:V010)
      
      INSERT INTO LOG (ID,TIME_STAMP,TYPE,ERROR,INSTANCE,RULE_NUM,RULE_TYPE,PRIORITY,F
      LAGS,NAME,BATCH,O_RESOURCE,QUEUE,NEW_QUEUE,SERVER,FORM,WORKSET) VALUES (:V001,:V
      002,11,0,0,3,1,0,1,:V003,:V004,:V005,:V006,:V007,:V008,:V009,:V010)
      
      SQL_TEXT
      --------------------------------------------------------------------------------
      
      INSERT INTO LOG (ID,TIME_STAMP,TYPE,ERROR,INSTANCE,RULE_NUM,RULE_TYPE,PRIORITY,F
      LAGS,NAME,BATCH,O_RESOURCE,QUEUE,NEW_QUEUE,SERVER,FORM,WORKSET) VALUES (:V001,:V
      002,11,0,0,3,1,0,1,:V003,:V004,:V005,:V006,:V007,:V008,:V009,:V010)
      
      INSERT INTO LOG (ID,TIME_STAMP,TYPE,ERROR,INSTANCE,RULE_NUM,RULE_TYPE,PRIORITY,F
      LAGS,NAME,BATCH,O_RESOURCE,QUEUE,NEW_QUEUE,SERVER,FORM,WORKSET) VALUES (:V001,:V
      002,11,0,0,3,1,0,1,:V003,:V004,:V005,:V006,:V007,:V008,:V009,:V010)
      
      INSERT INTO LOG (ID,TIME_STAMP,TYPE,ERROR,INSTANCE,RULE_NUM,RULE_TYPE,PRIORITY,F
      LAGS,NAME,BATCH,O_RESOURCE,QUEUE,NEW_QUEUE,SERVER,FORM,WORKSET) VALUES (:V001,:V
      
      SQL_TEXT
      --------------------------------------------------------------------------------
      002,11,0,0,3,1,0,1,:V003,:V004,:V005,:V006,:V007,:V008,:V009,:V010)
      
      INSERT INTO LOG (ID,TIME_STAMP,TYPE,ERROR,INSTANCE,RULE_NUM,RULE_TYPE,PRIORITY,F
      LAGS,NAME,BATCH,O_RESOURCE,QUEUE,NEW_QUEUE,SERVER,FORM,WORKSET) VALUES (:V001,:V
      002,11,0,0,3,1,0,1,:V003,:V004,:V005,:V006,:V007,:V008,:V009,:V010)
      How to avoid this....why its using different execution plan(I mean wrong PK index)

      Is there any way to avoid this?

      If required any details please refer some of my earlier post on this(Given URL above)

      -Yasser
        • 1. Re: Execution plan change for same query.
          Dom Brooks
          My doubt is how come same sql with different literal values execution plan changes and causes prob.
          Different literal values cause hard parse.
          Hard parse includes re-evaluation of best access path.
          Literal value is included in evaluation of selectivity for range scan (log_seq > ....)

          See
          http://www.centrexcc.com/A%20Look%20under%20the%20Hood%20of%20CBO%20-%20the%2010053%20Event.ppt.pdf
          http://www.centrexcc.com/Fallacies%20of%20the%20Cost%20Based%20Optimizer.pdf
          plus Jonathan Lewis's book which, from other threads, I believe you already have.


          You need to get your CPU down.
          From previous threads, if the situation is still the same, it sounded like hard parsing particularly with this SELECT against LOG is playing a significant role in that.

          How to avoid this....why its using different execution plan(I mean wrong PK index)
          The points made in previous threads remain valid.
          - Do you have access to this SQL to change it?
          e.g use bind variables and/or hint it if necessary due to problems caused by data as discussed in previous thread.
          - Or could you repoint it at a view and hint the view?
          - If a particular connecting user issues this sql, could you set cursor_sharing just for that user. If not, you might consider setting it database-wide.

          This is Oracle 8.1.6 still?
          • 2. Re: Execution plan change for same query.
            riedelme
            My doubt is how come same sql with different literal values execution plan changes and causes prob.
            Do you have histograms created on the index?

            Histograms are database objects that record data distribution. Their purpose is to help the optimizer decide if an indexed lookup will benefit or hurt query execution. As such, their presence can influence query plans used based on data values.

            You can see histograms in the user/all/dba_histograms data dictionary views.
            • 3. Re: Execution plan change for same query.
              731548
              Can you please send discription of table and all index created on that table.
              • 4. Re: Execution plan change for same query.
                834885
                HOW TO TRANSPORT A SQL TUNING SET [ID 456019.1]

                --------------------------------------------------------------------------------

                Modified 08-SEP-2008 Type HOWTO Status PUBLISHED

                In this Document
                Goal
                Solution



                --------------------------------------------------------------------------------



                Applies to:
                Oracle Server - Enterprise Edition - Version: 10.2.0.1 to 11.1.0.6
                Information in this document applies to any platform.
                10.2.X,11.1.X
                Goal
                The Purpose of This Note is to Show the Steps needed to Transport a Sql Tuning Set from

                One Database server to another Database Server.

                Solution

                The Sql Tuning Set name is small_sh_sts_4.It is on 10.2.0.2.0 Database server.
                It has 4 sqls .


                select sql_id, substr(sql_text,1, 15) text
                from dba_sqlset_statements
                where sqlset_name = 'small_sh_sts_4'
                order by sql_id;

                SQL_ID TEXT
                ------------- -------------------------
                4qdz7j26mdwzb SELECT /*+ my_q
                6y289t15dqj9r SELECT /*+ my_q
                ckm14c67njf0q SELECT /*+ my_q
                g37muqb81wjau SELECT /*+ my_q


                1) Create the Staging Table ON THE SOURCE SYSTEM ( IN this case 10.2.0.2.0 ) .

                execute DBMS_SQLTUNE.CREATE_STGTAB_SQLSET(table_name =>'TEST');

                PL/SQL procedure successfully completed.

                SQL> select count(*) from test;

                COUNT(*)
                ----------
                0

                2) Popluate the table TEST using DBMS_SQLTUNE.PACK_STGTAB_SQLSET THE SOURCE SYSTEM (IN this case 10.2.0.2.0 )

                execute DBMS_SQLTUNE.PACK_STGTAB_SQLSET(sqlset_name => 'small_sh_sts_4',staging_table_name => 'TEST');

                PL/SQL procedure successfully completed.


                select count(*) from test;

                SQL> select count(*) from test;

                COUNT(*)
                ----------
                4


                3) Export the table table test on THE SOURCE SYSTEM ( IN this case 10.2.0.2.0 )
                and move the table to the Destination Server
                and Import it . The staging table TEST can also be moved using
                the mechanism of choice such as datapump or database link.


                While exporting the table you will see something like

                About to export specified tables via Conventional Path ...
                Table(T) or Partition(T:P) to be exported: (RETURN to quit) > TEST

                . . exporting table TEST 4 rows exported
                . . exporting table TEST_CBINDS 0 rows exported
                . . exporting table TEST_CPLANS 34 rows exported

                Import on the Destination system ( IN this CASE it was 11.1.0.6.0 )

                While Importing the table you will see something like

                . importing SH's objects into SH
                . importing SH's objects into SH
                . . importing table "TEST" 4 rows imported
                . . importing table "TEST_CBINDS" 0 rows imported
                . . importing table "TEST_CPLANS" 34 rows imported
                Import terminated successfully without warnings.


                SQL> select count(*) from test;

                COUNT(*)
                ----------
                4

                Verify the contents of DBA_SQLSET or USER_SQLSET on the Destination system

                Select NAME,CREATED,STATEMENT_COUNT FROM DBA_SQLSET;


                4) Unpack the table using DBMS_SQLTUNE.UNPACK_STGTAB_SQLSET on the Destination system ( IN this CASE it was 11.1.0.6.0 )

                execute DBMS_SQLTUNE.UNPACK_STGTAB_SQLSET( sqlset_name => '%',-
                replace => TRUE,-
                staging_table_name => 'TEST');

                Select NAME,OWNER,CREATED,STATEMENT_COUNT FROM DBA_SQLSET;

                NAME CREATED STATEMENT_COUNT
                ------------------------------ --------- ---------------
                small_sh_sts_4 24-AUG-07 4



                --------------------------------------------------------------------------------


                Related



                --------------------------------------------------------------------------------
                Products
                --------------------------------------------------------------------------------

                •Oracle Database Products > Oracle Database > Oracle Database > Oracle Server - Enterprise Edition
                • 5. Re: Execution plan change for same query.
                  JustinCave
                  I would be very careful about posting the content of a Metalink note to a public forum. It's a violation of Oracle's copyright and can potentially cause legal problems for the company you work for or lead to you losing Metalink access.

                  Justin
                  • 6. Re: Execution plan change for same query.
                    Randolf Geist
                    Yasu wrote:
                    This issue was raised before also, but still not able to find actual cause of this.

                    Thread1:
                    Re: Finding table fragmentation in Oracle 8.1.6.3.0

                    Thread2:
                    CBC Latch and Buffer Busy wait on same table.

                    Issue is, sometimes server CPU hammers 100% usage with latch free and buffer busy wait events.

                    We found one query is consuming high CPU usage which is executed by different sessions.

                    This query have two type of execution plans, where one is precise and other is not(Means its hitting Primary Key index not suitable index present on table)

                    Because its hitting Primary key index repeatedly from different sessions....some sessions are performing db file sequential read and some sessions are waiting for buffer busy waits event.Also during this time some sessions waits for Latch free event.

                    My doubt is how come same sql with different literal values execution plan changes and causes prob.
                    Have you followed up Jonathan's suggestion in the previous thread regarding the histogram on LOG_ID?

                    Can you confirm there is a histogram on LOG_ID? See the previous thread for a query on DBA/ALL/USER_TAB_HISTOGRAMS how to check this. Can you show us the output from the query?

                    This fix would be the most straightforward solution if it worked.

                    If you've already removed the histogram or confirmed that there is no histogram then you can think about the following choices:

                    - Manipulate the statistics so that the index on LOG_ID will be favoured by the CBO in all cases

                    - Switch to CURSOR_SHARING = FORCE and create a Stored Outline for this query so that the plan gets fixed. Note that this is probably a change that you would need to test thoroughly since it is a major change and potentially has serious side effects on the remaining part of your application

                    Regards,
                    Randolf

                    Oracle related stuff blog:
                    http://oracle-randolf.blogspot.com/

                    Co-author of the "OakTable Expert Oracle Practices" book:
                    http://www.apress.com/book/view/1430226684
                    http://www.amazon.com/Expert-Oracle-Practices-Database-Administration/dp/1430226684