Forum Stats

  • 3,825,165 Users
  • 2,260,474 Discussions
  • 7,896,430 Comments

Discussions

High version count for INSERTS due to HASH_MATCH_FAILED with cursor_sharing = force

Vsevolod Afanassiev
Vsevolod Afanassiev Member Posts: 359 Bronze Badge
edited May 15, 2016 9:56AM in General Database Discussions

12.1.0.2 on Linux, standalone instance

We are testing new -3-rd party application, it isn't using bind variables. During the first test cursor_sharing was set to default value EXACT, the rate of hard parses reaches 800 per second, and we saw events indicating issues with shared pool (library cache: mutex X, latch: shared pool, cursor: pin S wait on X). However the percentage of these waits was small, less than 3% of total waits.

During the second test we set cursor_sharing to FORCE. Waits on shared pool-related events were high:

37% of total waits for 'cursor: pin S wait on X'

21% for 'library cache lock'

V$SQL shows several statements with hundreds of child cursors, mostly single-row INSERTS:

INSERT INTO schema.tableName (column1,columns2,..)

VALUES (:"SYS_B_0",:"SYS_B_1",:"SYS_B_2",:"SYS_B_3",:"SYS_B_4",:"SYS_B_5",:"SYS_B_6",timestamp:"SYS_B_7",SYSTIMESTAMP,:"SYS_B_8")

These cursors aren't being shared, every execution created new child cursor.


V$SQL_SHARED_CURSOR has 'Y' for HASH_MATCH_FAILED.This is the definition: No existing child cursors have the unsafe literal bind hash values required by the current cursor.

What does it mean?

There is nothing special about these tables, they have VARCHAR2, NUMBER, and DATE columns, no triggers.


Best Answer

  • Jonathan Lewis
    Jonathan Lewis Member Posts: 9,974 Blue Diamond
    edited May 14, 2016 3:51PM Answer ✓

    I don't think that can be correct.

    You have created an SQL Plan Baseline - the baseline doesn't know that it came from a stattement with a different SQL_ID, that information isn't stored in the SMB.

    To understand the meaning of the explanation No existing child cursors have the unsafe literal bind hash values required by the current cursor

    "unsafe literal bind" refers to the fact that Oracle recognises that extended cursor sharing may be needed when different bind values may require different execution plans.  Bind VARIABLES that are recognised as unsafe are (at least) dictated by:

        partition_key = :bind

        column_with_histogram = :bind

        column between :bind1 and :bind2

    I'm fairly sure there's one more condition, but I can't remember what it is at present.

    So the message appears when the optimizer says: I can see that this is a statement with unsafe bind variables but there are currently no child cursors which were generated by an exact match of the current bind VALUES (which I can check by checking a hashkey on the unsage bind values). I think in your example this appears because the parent cursor still existed at parse time (only the child was flushed because of the SMB activity) but there was (as the message says) no suitable child.

    In the case of the OP I think the message is appearing because the use of timestamp in timestamp:"SYS_B_7" is considered to make :sys_b_7 unsafe and he keeps getting different values for it.


    Regards

    Jonathan Lewis

Answers

  • John Thorton
    John Thorton Member Posts: 14,493 Silver Crown
    edited May 14, 2016 8:58AM

    >What does it mean?

    It means that you suffer from Compulsive Tuning Disorder.

    > However the percentage of these waits was small, less than 3% of total waits.

    If you drive the percentage to ZERO, could you measure the improvement at the application level?

  • AndrewSayer
    AndrewSayer Member Posts: 13,007 Gold Crown
    edited May 14, 2016 11:33AM

    I wouldn't expect this when using insert values only.

    Can you post full results from v$sql_shared_cursor (for all child cursors.

    Do histograms exist on the tables (should only be relevant when selecting them)

  • Jonathan Lewis
    Jonathan Lewis Member Posts: 9,974 Blue Diamond
    edited May 15, 2016 2:53AM

    To get a handle on the relative cost of the two options, you should also look at the parse time CPU as well as the throughput.

    A quick test suggests that the use of the ANSI feature for literal date and timestamp conversion cause the problem.

    Regards

    Jonathan Lewis

  • Jonathan Lewis
    Jonathan Lewis Member Posts: 9,974 Blue Diamond
    edited May 14, 2016 11:50AM

    I've just checked MoS and found a slightly related "not a bug" bug:

    Bug 13407937 : HIGH VERSION COUNT FOR INSERT WITH CURSOR_SHARING=FORCE AND TIMESTAMP COLUMN

    Regards

    Jonathan Lewis

  • Mohamed Houri
    Mohamed Houri Member Posts: 1,247 Bronze Trophy
    edited May 14, 2016 1:28PM

    I am trying to write a series of articles about  a couple of 64 cursors non shareable reasons. Coincidentally in the first article I have investigated the HASH_MATCH_FAILED reason as you can read in the following article

    https://www.toadworld.com/platforms/oracle/b/weblog/archive/2016/04/30/why-my-execution-plan-has-not-been-shared-part-i

    I come up, at least with my reproducible model, to the following conclusion about the HASH_MATCH_FAILED reason:

    The HASH_MATCH_FAILED reason means: when a parent cursor is forced to run via an execution plan coming from a different or modified sql_id


    But I have a clear tendency to think that there exist other situations for which Oracle will hard parse a new execution plan and will signal that it has done this due to HASH_MATCH_FAILED reason


    Best regards

    Mohamed Houri

  • Jonathan Lewis
    Jonathan Lewis Member Posts: 9,974 Blue Diamond
    edited May 14, 2016 3:51PM Answer ✓

    I don't think that can be correct.

    You have created an SQL Plan Baseline - the baseline doesn't know that it came from a stattement with a different SQL_ID, that information isn't stored in the SMB.

    To understand the meaning of the explanation No existing child cursors have the unsafe literal bind hash values required by the current cursor

    "unsafe literal bind" refers to the fact that Oracle recognises that extended cursor sharing may be needed when different bind values may require different execution plans.  Bind VARIABLES that are recognised as unsafe are (at least) dictated by:

        partition_key = :bind

        column_with_histogram = :bind

        column between :bind1 and :bind2

    I'm fairly sure there's one more condition, but I can't remember what it is at present.

    So the message appears when the optimizer says: I can see that this is a statement with unsafe bind variables but there are currently no child cursors which were generated by an exact match of the current bind VALUES (which I can check by checking a hashkey on the unsage bind values). I think in your example this appears because the parent cursor still existed at parse time (only the child was flushed because of the SMB activity) but there was (as the message says) no suitable child.

    In the case of the OP I think the message is appearing because the use of timestamp in timestamp:"SYS_B_7" is considered to make :sys_b_7 unsafe and he keeps getting different values for it.


    Regards

    Jonathan Lewis

  • Vsevolod Afanassiev
    Vsevolod Afanassiev Member Posts: 359 Bronze Badge
    edited May 14, 2016 7:33PM

    Yes, it is the use of timestamp. Simple test:

    - create table with column TIMESTAMP

    - insert values using TO_TIMESTAMP. INSERTS are shared

    - repeat insert using TIMESTAMP as above (timestamp:"SYS_B_7). INSERTS aren't shared

    Initially I thought that the issue is cased by the datatype mismatch: the columns have type DATE while the application is trying to insert TIMESTAMP.

    However INSERTS aren't shared even when there is no mismatch.

    SQL> create table test06 (n number, d timestamp);

    Table created.

    SQL>

    SQL> insert /* test678*/ into test06 values (1,to_timestamp('2016-05-15 00:00:00','YYYY-MM-DD HH24:MI:SS'));

    1 row created.

    SQL> insert /* test678*/ into test06 values (1,to_timestamp('2016-05-16 01:00:00','YYYY-MM-DD HH24:MI:SS'));

    1 row created.

    SQL> insert /* test678*/ into test06 values (1,to_timestamp('2016-05-17 02:00:00','YYYY-MM-DD HH24:MI:SS'));

    1 row created.

    SQL> insert /* test678*/ into test06 values (1,to_timestamp('2016-05-18 02:50:00','YYYY-MM-DD HH24:MI:SS'));

    1 row created.

    SQL> insert /* test678*/ into test06 values (1,to_timestamp('2016-05-17 02:40:00','YYYY-MM-DD HH24:MI:SS'));

    1 row created.

    SQL> insert /* test678*/ into test06 values (2,timestamp'2016-05-12 20:44:33.000');

    1 row created.

    SQL> insert /* test678*/ into test06 values (2,timestamp'2016-05-16 20:45:33.000');

    1 row created.

    SQL> insert /* test678*/ into test06 values (2,timestamp'2016-05-17 20:46:33.000');

    1 row created.

    SQL> insert /* test678*/ into test06 values (2,timestamp'2016-05-18 20:56:33.000');

    1 row created.

    SQL> insert /* test678*/ into test06 values (2,timestamp'2016-05-19 20:36:33.000');

    1 row created.

    SQL>

    SQL> select

      2 child_number,

      3 executions,

      4 sql_text

      5  from

      6 v$sql

      7 where

      8 sql_text like '%test6' || '78%';

      n  exe SQL_TEXT

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

      0    5 insert /* test678*/ into test06 values (:"SYS_B_0",to_timestamp(:"SYS_B_1",:"SYS_B_2"))

      0    1 insert /* test678*/ into test06 values (:"SYS_B_0",timestamp:"SYS_B_1")

      1    1 insert /* test678*/ into test06 values (:"SYS_B_0",timestamp:"SYS_B_1")

      2    1 insert /* test678*/ into test06 values (:"SYS_B_0",timestamp:"SYS_B_1")

      3    1 insert /* test678*/ into test06 values (:"SYS_B_0",timestamp:"SYS_B_1")

      4    1 insert /* test678*/ into test06 values (:"SYS_B_0",timestamp:"SYS_B_1")

    6 rows selected.

  • Jonathan Lewis
    Jonathan Lewis Member Posts: 9,974 Blue Diamond
    edited May 15, 2016 2:55AM

    I'd just about finished a blog note before you posted this - now you've spoiled the surprise

    The same is true for the date'yyyy-mm-dd ANSI literal - it's a pity really given the convenience.

    Regards

    Jonathan Lewis

  • Mohamed Houri
    Mohamed Houri Member Posts: 1,247 Bronze Trophy
    edited May 15, 2016 9:56AM

    Jonathan,

    Thanks for your answer.

    What you are referring to "unsafe literal bind" in your answer seems to be those bind variable cases where the cursor is said to be "bind sensitive"

    which a is a mandatory transient state for the "adaptive and extended cursor sharing" feature.

    If so then, as far as there is no bind sensitiveness with dynamic sampling, I just flushed out shared pool memory , dropped existing SPM and deleted table statistics

    SQL> alter system flush shared_pool;

    System altered.

    SQL> exec dbms_stats.delete_table_stats(user ,'t1');

    PL/SQL procedure successfully completed.

    SQL> @dropallspm

    PL/SQL procedure successfully completed.

    SQL> select count(1) from t1 where v1 = :v1;

      COUNT(1)

    ----------

          100

     

    SQL> select * from table(dbms_xplan.display_cursor);

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

    SQL_ID  d2h2phry5d881, child number 0

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

    select count(1) from t1 where v1 = :v1

    Plan hash value: 2603166377

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

    | Id  | Operation        | Name  | Rows  | Bytes | Cost (%CPU)| Time    |

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

    |  0 | SELECT STATEMENT  |        |      |      |    1 (100)|           |

    |  1 |  SORT AGGREGATE   |        |    1 |    7 |           |           |

    |*  2 |  INDEX RANGE SCAN| T1_IND |  100 |  700 |    1  (0) | 00:00:01  |

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

    Predicate Information (identified by operation id):

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

      2 - access("V1"=:V1)

    Note

    -----

      - dynamic statistics used: dynamic sampling (level=2)

    SQL> select sql_id, child_number, is_bind_sensitive from gv$sql where sql_id = 'd2h2phry5d881';

    SQL_ID        CHILD_NUMBER I

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

    d2h2phry5d881            0 N

    SQL> @Transferspm

    Enter value for original_sql_id: d2h2phry5d881

    Enter value for modified_sql_id: 34z8wv6bsyu6u

    Enter value for plan_hash_value: 3724264953

    PL/SQL procedure successfully completed.

    SQL> select * from table(dbms_xplan.display_cursor);

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

    SQL_ID  d2h2phry5d881, child number 0

    An uncaught error happened in prepare_sql_statement : ORA-01403: no data found

    NOTE: cannot fetch plan for SQL_ID: d2h2phry5d881, CHILD_NUMBER: 0

          Please verify value of SQL_ID and CHILD_NUMBER;

          It could also be that the plan is no longer in cursor cache (check v$sql_plan)

    This error message represents the proof of what you wrote above (only the child was flushed because of the SMB activity)

    SQL> @nonshared d2h2phry5d881

    Show why existing SQL child cursors were not reused (V$SQL_SHARED_CURSOR)...

    SQL_ID                        : d2h2phry5d881

    ADDRESS                      : 00007FFFBC1D4350

    CHILD_ADDRESS                : 00007FFFC2FD17C8

    CHILD_NUMBER                  : 0

    HASH_MATCH_FAILED            : Y

    REASON                        :

    CON_ID                        : 1

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

    So I am inclined to understand this reason(in this case) as  to be the collateral effect of, as you have pointed it, the SMB activity which flushed out the child cursor n°0

    and not the effect of a cursor being sensitive to the bind variable value. That's my opinion and I might be wrong of course.

    Best regards

    Mohamed Houri

This discussion has been closed.