High Parse Time Elapsed And High Cursor : Pin S Wait On X Wait Event With Parallelism (Doc ID 1675659.1)

Last updated on JANUARY 27, 2017

Applies to:

Oracle Database - Enterprise Edition - Version 11.2.0.3 and later
Information in this document applies to any platform.

Symptoms

PROBLEM:
----------

We have a test case with a create table as select statement with a dop of 4.  The table used by the CTAS contains 500000 rows.

When we execute the statement, we note that Oracle spends all the time to parse (parse time elapsed 99%) and that wait class concurrency are 60% with 40% cursor: pin S wait on X.

We are also able to reproduce the same problem with an insert statement.


We can reproduce  the issue in Oracle 11.2.0.3  and 11.2.0.4.


High parse time elapsed (>85%) and high cursor : pin S wait on X wait event
(>60%) seen with parallel execution.

DIAGNOSTIC ANALYSIS:
--------------------
This affects both 11.2.0.3 and 11.2.0.4. Issue does not occur when ran in serial.

- Investigation 1
Setting  Parallelism to 4 on the source TABLE SR_TMP_TABLE.
We see the « cursor: pin S wait on X » wait event.

- Investigation 2
Checking what is generating those « cursor: pin S wait on X » wait.

By looking at MUTEX_SLEEP view, we notice that ONE main function generates those mutexes.
Function « kkslce [KKSCHLPIN2] ».

MUTEX_TYPE                       LOCATION                                    
SLEEPS  WAIT_TIME
-------------------------------- ----------------------------------------
---------- ----------
Cursor Pin                       kkslce [KKSCHLPIN2]                          
383360          0
Library Cache                    kglhdgn2 106                                
    74          0

When we set the trace cursor at level 612 on the cursor, we can see the
following reason for NOT sharing the cursor : PQ Slave mismatch(5).

To generate the necessary cursor tracing:

alter session set events 'immediate trace name cursortrace level 612, address &hashvalue';

Example:

select sql_id, hash_value from v$sql
where sql_text  LIKE  'insert /*+ NOAPPEND */ into SR_TMP%';

SQL_ID        HASH_VALUE
------------- ----------
9ykqjuv9zgb96 3556224294

alter session set events 'immediate trace name cursortrace level 612, address 3556224294';

< Run the sql statement>
To turn it off:

alter system set events 'immediate trace name cursortrace level 128, address 3556224294';

 

Cause

Sign In with your My Oracle Support account

Don't have a My Oracle Support account? Click to get started

My Oracle Support provides customers with access to over a
Million Knowledge Articles and hundreds of Community platforms