Re: Multiple SQL_IDs....why?
From: Guy Peleg <makleeengineering_at_gmail.com>
Date: Thu, 25 Feb 2010 10:27:32 -0800 (PST)
Message-ID: <60207466-971f-428c-8b17-c3fad119617f_at_y17g2000yqd.googlegroups.com>
On Feb 25, 12:00 pm, joel garry <joel-ga..._at_home.com> wrote:
> On Feb 24, 11:43 pm, Guy Peleg <makleeengineer..._at_gmail.com> wrote:
>
>
>
>
>
> > On Feb 24, 4:45 pm, joel garry <joel-ga..._at_home.com> wrote:
>
> > > On Feb 24, 10:52 am, Guy Peleg <makleeengineer..._at_gmail.com> wrote:
>
> > > > On Feb 23, 12:14 pm, "Michel Cadot" <micadot{at}altern{dot}org> wrote:
>
> > > > > "Guy Peleg" <makleeengineer..._at_gmail.com> a crit dans le message de news:
> > > > > 513e35ea-858b-4b3f-bc51-270b2e6bb..._at_j6g2000vbd.googlegroups.com...
> > > > > On Feb 23, 4:15 pm, "Michel Cadot" <micadot{at}altern{dot}org> wrote:
>
> > > > > > "Guy Peleg" <makleeengineer..._at_gmail.com> a crit dans le message de news:
> > > > > > e7b40657-4e16-4079-936b-7be353697..._at_s17g2000vbs.googlegroups.com...
> > > > > > | Oracle 10.2.0.3 on solaris, running a select query on a test machine
> > > > > > | takes one second, execution
> > > > > > | plan shows that index range scan is used. On the production node same
> > > > > > | statement takes more than
> > > > > > | a minute and execution plan shows full table scan.
> > > > > > |
> > > > > > | On the production node, looking at V$SQL I can see that I have two
> > > > > > | execution plans for the query, one
> > > > > > | seems fast fast with index range scan and the slow one with full table
> > > > > > | scan.
> > > > > > |
> > > > > > | I'm trying to understand why I have multiple versions of the same
> > > > > > | statement.
> > > > > > |
> > > > > > | Any ideas?
> > > > > > |
> > > > > > |
> > > > > > | SQL> select
> > > > > > | sql_id,child_number,executions,optimizer_cost,optimizer_mode from v
> > > > > > | $sql where sql_id='79tg4h3uhwncc';
> > > > > > |
> > > > > > | SQL_ID CHILD_NUMBER EXECUTIONS OPTIMIZER_COST OPTIMIZER_
> > > > > > | ------------- ------------ ---------- -------------- ----------
> > > > > > | 79tg4h3uhwncc 0 94 49 ALL_ROWS
> > > > > > | 79tg4h3uhwncc 1 60 4716 ALL_ROWS
> > > > > > |
> > > > > > | SQL> select child_number, bind_mismatch B, optimizer_mode_mismatch O
> > > > > > | from v$sql_shared_cursor
> > > > > > | 2 where sql_id='79tg4h3uhwncc';
> > > > > > |
> > > > > > | CHILD_NUMBER B O
> > > > > > | ------------ - -
> > > > > > | 0 N N
> > > > > > | 1 N N
> > > > > > |
> > > > > > |
> > > > > > | Not shown here but BIND_DATA, PARSING_SCHEMA_NAME are the same.
> > > > > > |
> > > > > > | Regards,
> > > > > > |
> > > > > > | Guy Peleg
> > > > > > | Maklee Engineering
>
> > > > > > There are about 40 mismatch columns, you queried only 2,
> > > > > > have a look at the other ones.
>
> > > > > > Regards
> > > > > > Michel
>
> > > > > ROLL_INVALIDATE_MISMATCH is set to Y, is it possible to determine why
> > > > > the execution plan
> > > > > has changed?
>
> > > > > SQL> select * from v$sql_shared_cursor where sql_id='79tg4h3uhwncc';
>
> > > > > SQL_ID ADDRESS CHILD_ADDRESS CHILD_NUMBER U S O O S
> > > > > L S E B P I S T A B D L T R I I R L I O S M U T N F A I T D L
>
> > > > > ------------- ---------------- ---------------- ------------ - - - - -
> > > > > - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - -
>
> > > > > D B P C S R P T M B M R O P M F L
> > > > > - - - - - - - - - - - - - - - - -
> > > > > 79tg4h3uhwncc 0000000532754E90 0000000532753F60 0 N N N N N
> > > > > N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N
>
> > > > > N N N N N N N N N N N N N N N N N
>
> > > > > 79tg4h3uhwncc 0000000532754E90 000000051BDF2DC0 1 N N N N N
> > > > > N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N
>
> > > > > N N N N N N N N N N N Y N N N N N
>
> > > > > ----------------------------------------------------------------------------------------------
>
> > > > > Read the following thread, abovie last but one Dion Cho's post.http://forums.oracle.com/forums/thread.jspa?threadID=592771
>
> > > > > Regards
> > > > > Michel- Hide quoted text -
>
> > > > > - Show quoted text -
>
> > > > Something still does not make sense to me. I understand that the
> > > > execution plan was being invalidated,
> > > > most probably after statistics was collected at 10pm.
>
> > > > The database was started Monday morning. Throughout Monday, it was
> > > > using the fast execution plan, Tuesday it
> > > > switched to the slow execution plan and today it switched back to the
> > > > fast version. The table this query operate against
> > > > has 700K rows and it may grow by ~10,000 per day. So why would we
> > > > switch back and forth between these plans?
>
> > > That sounds like classic ol' bind peeking. Seehttp://www.pythian.com/news/867/stabilize-oracle-10gs-bind-peeking-be...
>
> > > Perhaps your data distribution is such that you are near a
> > > discontinuity with a slight change in query? How exactly are you
> > > gathering statistics?
>
> > > jg
> > > --
> > > _at_home.com is bogus.http://news.bbc.co.uk/2/hi/technology/8533641.stm-Hidequoted text -
>
> > > - Show quoted text -
>
> > jg - thanks for the excellent pointer.
>
> > The query in question does not use bind variables but I have strong
> > feeling that stats collection is the key to solving this mystery. I
> > will investigate
> > further.
>
> Are you sure about those bind variables?http://asktom.oracle.com/pls/asktom/f?p=100:11:0::::P11_QUESTION_ID:2...
>
> Apologies if you've gone through plans and traces already to check, I
> don't know what experience level you are at with these things, or your
> query and access methods.
>
> jg
> --
> _at_home.com is bogus.http://www.signonsandiego.com/news/2010/feb/25/city-computer-pact-mig...- Hide quoted text -
>
> - Show quoted text -
Date: Thu, 25 Feb 2010 10:27:32 -0800 (PST)
Message-ID: <60207466-971f-428c-8b17-c3fad119617f_at_y17g2000yqd.googlegroups.com>
On Feb 25, 12:00 pm, joel garry <joel-ga..._at_home.com> wrote:
> On Feb 24, 11:43 pm, Guy Peleg <makleeengineer..._at_gmail.com> wrote:
>
>
>
>
>
> > On Feb 24, 4:45 pm, joel garry <joel-ga..._at_home.com> wrote:
>
> > > On Feb 24, 10:52 am, Guy Peleg <makleeengineer..._at_gmail.com> wrote:
>
> > > > On Feb 23, 12:14 pm, "Michel Cadot" <micadot{at}altern{dot}org> wrote:
>
> > > > > "Guy Peleg" <makleeengineer..._at_gmail.com> a crit dans le message de news:
> > > > > 513e35ea-858b-4b3f-bc51-270b2e6bb..._at_j6g2000vbd.googlegroups.com...
> > > > > On Feb 23, 4:15 pm, "Michel Cadot" <micadot{at}altern{dot}org> wrote:
>
> > > > > > "Guy Peleg" <makleeengineer..._at_gmail.com> a crit dans le message de news:
> > > > > > e7b40657-4e16-4079-936b-7be353697..._at_s17g2000vbs.googlegroups.com...
> > > > > > | Oracle 10.2.0.3 on solaris, running a select query on a test machine
> > > > > > | takes one second, execution
> > > > > > | plan shows that index range scan is used. On the production node same
> > > > > > | statement takes more than
> > > > > > | a minute and execution plan shows full table scan.
> > > > > > |
> > > > > > | On the production node, looking at V$SQL I can see that I have two
> > > > > > | execution plans for the query, one
> > > > > > | seems fast fast with index range scan and the slow one with full table
> > > > > > | scan.
> > > > > > |
> > > > > > | I'm trying to understand why I have multiple versions of the same
> > > > > > | statement.
> > > > > > |
> > > > > > | Any ideas?
> > > > > > |
> > > > > > |
> > > > > > | SQL> select
> > > > > > | sql_id,child_number,executions,optimizer_cost,optimizer_mode from v
> > > > > > | $sql where sql_id='79tg4h3uhwncc';
> > > > > > |
> > > > > > | SQL_ID CHILD_NUMBER EXECUTIONS OPTIMIZER_COST OPTIMIZER_
> > > > > > | ------------- ------------ ---------- -------------- ----------
> > > > > > | 79tg4h3uhwncc 0 94 49 ALL_ROWS
> > > > > > | 79tg4h3uhwncc 1 60 4716 ALL_ROWS
> > > > > > |
> > > > > > | SQL> select child_number, bind_mismatch B, optimizer_mode_mismatch O
> > > > > > | from v$sql_shared_cursor
> > > > > > | 2 where sql_id='79tg4h3uhwncc';
> > > > > > |
> > > > > > | CHILD_NUMBER B O
> > > > > > | ------------ - -
> > > > > > | 0 N N
> > > > > > | 1 N N
> > > > > > |
> > > > > > |
> > > > > > | Not shown here but BIND_DATA, PARSING_SCHEMA_NAME are the same.
> > > > > > |
> > > > > > | Regards,
> > > > > > |
> > > > > > | Guy Peleg
> > > > > > | Maklee Engineering
>
> > > > > > There are about 40 mismatch columns, you queried only 2,
> > > > > > have a look at the other ones.
>
> > > > > > Regards
> > > > > > Michel
>
> > > > > ROLL_INVALIDATE_MISMATCH is set to Y, is it possible to determine why
> > > > > the execution plan
> > > > > has changed?
>
> > > > > SQL> select * from v$sql_shared_cursor where sql_id='79tg4h3uhwncc';
>
> > > > > SQL_ID ADDRESS CHILD_ADDRESS CHILD_NUMBER U S O O S
> > > > > L S E B P I S T A B D L T R I I R L I O S M U T N F A I T D L
>
> > > > > ------------- ---------------- ---------------- ------------ - - - - -
> > > > > - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - -
>
> > > > > D B P C S R P T M B M R O P M F L
> > > > > - - - - - - - - - - - - - - - - -
> > > > > 79tg4h3uhwncc 0000000532754E90 0000000532753F60 0 N N N N N
> > > > > N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N
>
> > > > > N N N N N N N N N N N N N N N N N
>
> > > > > 79tg4h3uhwncc 0000000532754E90 000000051BDF2DC0 1 N N N N N
> > > > > N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N
>
> > > > > N N N N N N N N N N N Y N N N N N
>
> > > > > ----------------------------------------------------------------------------------------------
>
> > > > > Read the following thread, abovie last but one Dion Cho's post.http://forums.oracle.com/forums/thread.jspa?threadID=592771
>
> > > > > Regards
> > > > > Michel- Hide quoted text -
>
> > > > > - Show quoted text -
>
> > > > Something still does not make sense to me. I understand that the
> > > > execution plan was being invalidated,
> > > > most probably after statistics was collected at 10pm.
>
> > > > The database was started Monday morning. Throughout Monday, it was
> > > > using the fast execution plan, Tuesday it
> > > > switched to the slow execution plan and today it switched back to the
> > > > fast version. The table this query operate against
> > > > has 700K rows and it may grow by ~10,000 per day. So why would we
> > > > switch back and forth between these plans?
>
> > > That sounds like classic ol' bind peeking. Seehttp://www.pythian.com/news/867/stabilize-oracle-10gs-bind-peeking-be...
>
> > > Perhaps your data distribution is such that you are near a
> > > discontinuity with a slight change in query? How exactly are you
> > > gathering statistics?
>
> > > jg
> > > --
> > > _at_home.com is bogus.http://news.bbc.co.uk/2/hi/technology/8533641.stm-Hidequoted text -
>
> > > - Show quoted text -
>
> > jg - thanks for the excellent pointer.
>
> > The query in question does not use bind variables but I have strong
> > feeling that stats collection is the key to solving this mystery. I
> > will investigate
> > further.
>
> Are you sure about those bind variables?http://asktom.oracle.com/pls/asktom/f?p=100:11:0::::P11_QUESTION_ID:2...
>
> Apologies if you've gone through plans and traces already to check, I
> don't know what experience level you are at with these things, or your
> query and access methods.
>
> jg
> --
> _at_home.com is bogus.http://www.signonsandiego.com/news/2010/feb/25/city-computer-pact-mig...- Hide quoted text -
>
> - Show quoted text -
Bind variables are not involved....I have verified it. Unfortunately,
I can't post the query, but
here partial output returned from display_cursor:
SQL> select * from table (dbms_xplan.display_cursor('79tg4h3uhwncc', 1));
PLAN_TABLE_OUTPUT
SQL_ID 79tg4h3uhwncc, child number 1
...SQL STATEMENT removed
Predicate Information (identified by operation id):
1 - access("A"."A_1"="AC"."NAME" AND "A"."O_2"="AC"."TABLE3")
3 - filter("AC"."TABLE4"<>24)
4 - access("AC"."TABLE5"="CAR".TABLE6)
5 - filter(("A"."O_2"<>24 AND "A"."TABLE7"=1))
6 - access("A"."O_TABLE8"=TRUNC(SYSDATE_at_!))
Received on Thu Feb 25 2010 - 12:27:32 CST