Re: Optimizer Instability on 10.2.0.2

From: Jonathan Lewis <jonathan_at_jlcomp.demon.co.uk>
Date: Fri, 20 Apr 2007 16:00:03 +0100
Message-ID: <W8WdneBgXbl-SLXbnZ2dnUVZ8vidnZ2d@bt.com>

<mccmx_at_hotmail.com> wrote in message
news:1177075617.332730.257450_at_l77g2000hsb.googlegroups.com...
> >
>> This could be sufficient to switch the optimizer
>> from a nested loop join to a hash join. That being
>> the case, you just need to have a sufficiently busy
>> system that the plan get aged out from time to time,
>> and you get this type of switch on the re-optimisation.
>>
>
> I agree with all of you points and I was investigating along those
> lines yesterday afternoon. However what I couldn't work out was that
> the slow process found the query in the cache (zero misses) at 13:00
> and the fast process didn't find the query in the cache (1 miss) at
> 13:30 but I could see the SQL cached in the shared pool at 15:00 with
> a first_load_time of 06:00. So I cant explain how one run would find
> it and the other wouldn't. Any thoughts..?
>
> Thanks for your time...
>
> Matt
>

Demonstration:

I've created a table and queried it. Check the first_load_time, last_load_time, and invalidation_count on the child cursor.

Then invalidate the cursor (truncate the table is good enough) and query again. We get a reparse, but the FIRST_load_time does not change, even though the last_load_time shows the time of the re-optimise.

15:54:02 SQL> select count(*) from t1;

COUNT(*)

1 row selected.

15:54:10 SQL> select first_load_time, last_load_time, child_number, invalidations, sql_text from v$sql where sql_id = '5bc0v4my7dvr5';

FIRST_LOAD_TIME LAST_LOAD_TIME CHILD_NUMBER INVALIDATIONS

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

SQL_TEXT

2007-04-20/15:51:09 2007-04-20/15:51:09 0 0 select count(*) from t1

1 row selected.

15:54:19 SQL> truncate table t1;

Table truncated.

15:54:34 SQL> select count(*) from t1;

COUNT(*)

1 row selected.

15:54:37 SQL> select first_load_time, last_load_time, child_number, invalidations, sql_text from v$sql where sql_id = '5bc0v4my7dvr5';

/*                                                    */
/*    First load time NOT changed    */
/*    Last load time HAS changed     */
/*                                                    */

FIRST_LOAD_TIME     LAST_LOAD_TIME      CHILD_NUMBER INVALIDATIONS
------------------- ------------------- ------------ -------------

SQL_TEXT

2007-04-20/15:51:09 2007-04-20/15:54:36 0 1 select count(*) from t1

1 row selected.

15:54:40 SQL> spool off

So in your case,

You had a 'slow cursor' in existence at 13:00, so you re-used it.

The cursor got invalidated - or maybe the plan simply got flushed (you can also check the LOADS column on v$sql) - before 13:30.

At 13:30 you reloaded and got a new LAST_load_time, but the first_load_time was still 6:00.

-- 
Regards

Jonathan Lewis
http://jonathanlewis.wordpress.com

Author: Cost Based Oracle: Fundamentals
http://www.jlcomp.demon.co.uk/cbo_book/ind_book.html

The Co-operative Oracle Users' FAQ
http://www.jlcomp.demon.co.uk/faq/ind_faq.html

Received on Fri Apr 20 2007 - 10:00:03 CDT