Re: child cursor with bind mismatch, implicit conversion of timestamp to date

From: anthony Sanchez <anthonycsanchez_at_gmail.com>
Date: Fri, 7 Mar 2014 13:33:13 -0700
Message-ID: <CAEwv4fExVVFxekJnm8_46z8m=8M7EkYVrMedS5_3q+EzwCAPpA_at_mail.gmail.com>



Thank you Martin.

I concur that the developers should either be casting correctly or using the correct data types from the start. Since posting this question I've found 12 other sql's causing thousands of child cursors due to bind mismatch. More ammo for my forthcoming attack on their practices :).

I would have liked to exactly how oracle calculated the "tipping point" and understand how to decipher the reason xml column data in v$sql_shared_cursor.   One of these days...

thanks again,

Anthony

On Thu, Mar 6, 2014 at 7:19 AM, Martin Berger <martin.a.berger_at_gmail.com>wrote:

> Anthony,
>
> You hit a nasty problem with implicit type conversion. For whatever reason
> the RDBMS decides to convert date to timestamp in your 2nd plan. (my pure
> guesswork: some internal rule states, a timestamp without secondsis precise
> enough to cast to date for a comparison, whereas a timestamp with seconds
> is more precise (?) and therefore the date must be converted to timestamp).
> Even it might be interesting "why", it's of little help and might change
> without notification at any time.
>
> The proper way is to write explicit casts:
>
> UTC_INTERVAL_TIME > to_date(:2) AND UTC_INTERVAL_TIME <=
> to_date(:3)
>
>
> I fear everything else might fail at random reasons.
>
> Martin
>
>
>
> On Wed, Mar 5, 2014 at 7:21 PM, anthony Sanchez <anthonycsanchez_at_gmail.com
> > wrote:
>
>> Hi Folks,
>>
>> I've got a child cursor with nasty performance against a ranged
>> partitioned table (EMAPP.LP_INTERVALS) by date.
>>
>> Oracle 11.2.0.3
>> RHEL 5.9
>>
>> The application is passing in bind values of type timestamp to filter
>> against a date column (UTC_INTERVAL_TIME,partition key). Sometimes this
>> results in an implicit from conversion from timestamp to date to date and
>> terrible performance. According to the oracle data warehousing guide this
>> is a construct to avoid. What I find interesting is that it only does the
>> implicit conversion some of the time and not always.
>>
>> SELECT INSERT_TIME INSERT_TIME,
>> UTC_INTERVAL_TIME END_DATE,
>> LP_VALUE VALUE,
>> LP_INTERVAL_LENGTH INTERVAL_LENGTH
>> FROM LP_INTERVALS
>> WHERE CHANNEL_ID = :1 AND UTC_INTERVAL_TIME > :2 AND UTC_INTERVAL_TIME
>> <= :3
>> ORDER BY END_DATE ASC
>>
>>
>> below you'll see dbms_xplan.display_cursor for both the good and the bad
>> cursors with peeked_binds enabled. Timestamp values won't display but I
>> used the handy script to convert hex to timestamp for display -
>> http://oaktable.net/content/convert-rawhex-timestamp
>>
>>
>> GOOD cursor:
>>
>>
>> PLAN_TABLE_OUTPUT
>>
>>
>>
>> --------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
>> SQL_ID br5s8sn8hbhtb, child number 1
>>
>>
>> -------------------------------------
>>
>>
>> SELECT INSERT_TIME INSERT_TIME,
>>
>>
>> UTC_INTERVAL_TIME END_DATE, LP_VALUE VALUE,
>>
>>
>> LP_INTERVAL_LENGTH INTERVAL_LENGTH FROM
>>
>>
>> LP_INTERVALS WHERE CHANNEL_ID = :1 AND
>>
>>
>> UTC_INTERVAL_TIME > :2 AND UTC_INTERVAL_TIME <= :3
>>
>>
>> ORDER BY END_DATE ASC
>>
>>
>>
>>
>>
>> Plan hash value: 687203500
>>
>>
>>
>>
>>
>> -----------------------------------------------------------------------------------------------------------------------
>>
>>
>> | Id | Operation | Name | Rows |
>> Bytes | Cost (%CPU)| Time | Pstart| Pstop |
>>
>> -----------------------------------------------------------------------------------------------------------------------
>>
>>
>> | 0 | SELECT STATEMENT | | |
>> | 101 (100)| | | |
>>
>> |* 1 | FILTER | | |
>> | | | | |
>>
>> | 2 | PARTITION RANGE ITERATOR | | 1221 |
>> 36630 | 100 (0)| 00:00:02 | KEY | KEY |
>>
>> | 3 | TABLE ACCESS BY LOCAL INDEX ROWID| LP_INTERVALS | 1221 |
>> 36630 | 100 (0)| 00:00:02 | KEY | KEY |
>>
>> |* 4 | INDEX RANGE SCAN | PK_LP_INTERVALS | 1221 |
>> | 11 (0)| 00:00:01 | KEY | KEY |
>>
>> -----------------------------------------------------------------------------------------------------------------------
>>
>>
>>
>>
>>
>>
>> PLAN_TABLE_OUTPUT
>>
>>
>>
>> --------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
>> Peeked Binds (identified by position):
>>
>>
>> --------------------------------------
>>
>>
>>
>>
>>
>> 1 - :1 (VARCHAR2(30), CSID=873): '1-3ML6O'
>>
>>
>> 2 - :2 (TIMESTAMP): [Not Printable] (2/26/2014 7:00:00.000000000 AM)
>>
>>
>>
>> 3 - :3 (TIMESTAMP): [Not Printable] (3/26/2014 6:00:00.000000000 AM)
>>
>>
>>
>>
>>
>>
>> Predicate Information (identified by operation id):
>>
>>
>> ---------------------------------------------------
>>
>>
>>
>>
>>
>> 1 - filter(:2<:3)
>>
>>
>> 4 - access("CHANNEL_ID"=:1 AND "UTC_INTERVAL_TIME">:2 AND
>> "UTC_INTERVAL_TIME"<=:3)
>>
>>
>>
>>
>>
>> BAD Cursor (see predicate information section):
>>
>>
>> PLAN_TABLE_OUTPUT
>>
>>
>>
>> --------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
>> SQL_ID br5s8sn8hbhtb, child number 24
>>
>>
>> --------------------------------------
>>
>>
>> SELECT INSERT_TIME INSERT_TIME,
>>
>>
>> UTC_INTERVAL_TIME END_DATE, LP_VALUE VALUE,
>>
>>
>> LP_INTERVAL_LENGTH INTERVAL_LENGTH FROM
>>
>>
>> LP_INTERVALS WHERE CHANNEL_ID = :1 AND
>>
>>
>> UTC_INTERVAL_TIME > :2 AND UTC_INTERVAL_TIME <= :3
>>
>>
>> ORDER BY END_DATE ASC
>>
>>
>>
>>
>>
>> Plan hash value: 2873790348
>>
>>
>>
>>
>>
>> ----------------------------------------------------------------------------------------------------------------------
>>
>>
>> | Id | Operation | Name | Rows |
>> Bytes | Cost (%CPU)| Time | Pstart| Pstop |
>>
>> ----------------------------------------------------------------------------------------------------------------------
>>
>>
>> | 0 | SELECT STATEMENT | | |
>> | 12 (100)| | | |
>>
>> | 1 | PARTITION RANGE ITERATOR | | 1 |
>> 30 | 11 (0)| 00:00:01 | KEY | 78 |
>>
>> | 2 | TABLE ACCESS BY LOCAL INDEX ROWID| LP_INTERVALS | 1 |
>> 30 | 11 (0)| 00:00:01 | KEY | 78 |
>>
>> |* 3 | INDEX RANGE SCAN | PK_LP_INTERVALS | 1 |
>> | 10 (0)| 00:00:01 | KEY | 78 |
>>
>> ----------------------------------------------------------------------------------------------------------------------
>>
>>
>>
>>
>>
>> Peeked Binds (identified by position):
>>
>>
>>
>> PLAN_TABLE_OUTPUT
>>
>>
>>
>> --------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
>> --------------------------------------
>>
>>
>>
>>
>>
>> 1 - :1 (VARCHAR2(30), CSID=873): '1-4J5PW'
>>
>>
>> 2 - :2 (TIMESTAMP): [Not Printable] (3/4/2014 7:00:00.000000000 AM)
>>
>>
>>
>> 3 - :3 (TIMESTAMP): [Not Printable] (3/4/2014 11:04:13.000000000 PM)
>> --interesting that this is the only one with seconds greater than zero.
>>
>>
>>
>>
>>
>> Predicate Information (identified by operation id):
>>
>>
>> ---------------------------------------------------
>>
>>
>>
>>
>>
>> 3 - access("CHANNEL_ID"=:1 AND "UTC_INTERVAL_TIME">:2)
>>
>>
>> filter(INTERNAL_FUNCTION("UTC_INTERVAL_TIME")<=:3) ***THIS IS
>> NASTY***
>>
>> In v$sql_shared_cursor, cursor 24 is listed as having a bind_mismatch=Y.
>> The reason column XML states the following that I'm not sure how to
>> interpret:
>>
>> *<ChildNode><ChildNumber>24</ChildNumber><ID>34</ID><reason>Rolling
>> Invalidate Window
>> Exceeded(2)</reason><size>0x0</size><details>already_processed</details></ChildNode><ChildNode><ChildNumber>24</ChildNumber><ID>34</ID><reason>Rolling
>> Invalidate Window
>> Exceeded(3)</reason><size>2x4</size><invalidation_window>1394035130</invalidation_window><ksugctm>1394038111</ksugctm></ChildNode><ChildNode><ChildNumber>24</ChildNumber><ID>40</ID><reason>Bind
>> mismatch(14)</reason><size>4x4</size><bind_position>2</bind_position><original_oacflg>3</original_oacflg><original_oacscl>9</original_oacscl><new_oacscl>0</new_oacscl></ChildNode> *
>>
>>
>> Does anyone know how to interpret the reason xml above? Any ideas as to
>> why the implicit conversion happens some of the time but not all of the
>> time?
>>
>> thanks in advance,
>>
>> Anthony
>>
>
>

--
http://www.freelists.org/webpage/oracle-l
Received on Fri Mar 07 2014 - 21:33:13 CET

Original text of this message