Library cache lock

This is a very simple note, as much for my own documentation as anything else, showing how I have extremely rapidly identified what was causing a database application to wait on a library cache lock wait event.

The ASH of my customer case was showing the following list of predominant wait events:

select event, count(1)
from gv$active_session_history
where
    sample_time between to_date('09032018 00:46:00', 'ddmmyyyy hh24:mi:ss')
                and     to_date('09032018 10:44:00', 'ddmmyyyy hh24:mi:ss')
group by event
order by 2 desc;

EVENT                                  COUNT(1)
------------------------------------ ----------
library cache lock                       350174
library cache: mutex X                    54474
cursor: pin S wait on X                   10896
                                           2964

Naturally I wanted to know what sql_id is responsible of these library cache wait events first via ASH

select sql_id, count(1)
from gv$active_session_history
where
    sample_time between to_date('09032018 00:46:00', 'ddmmyyyy hh24:mi:ss')
                and     to_date('09032018 10:44:00', 'ddmmyyyy hh24:mi:ss')
and event in 
 ('library cache lock','library cache: mutex X','cursor: pin S wait on X')
group by sql_id
order by 2 desc;

SQL_ID            COUNT(1)
----------------- --------
6tcs65pchhp71       147902
9mqzzppbpa64j         7373
                         3	

And then via classical dbms_xplan to get the corresponding execution plan and v$sql to get the SQL text respectively:

SQL> select * from table(dbms_xplan.display_cursor('6tcs65pchhp71',null));

PLAN_TABLE_OUTPUT
----------------------------------------------------------------------------
SQL_ID: 6tcs65pchhp71 cannot be found

SQL> select sql_fulltext, executions, end_of_fetch_count
    from gv$sql
    where sql_id = '6tcs65pchhp71';

no rows selected

Let’s summarize: there is a sql_id which is responsible of a dramatic library cache wait event that I am monitoring at real time basis and which

• has no execution plan in memory
• and is not present in gv$sql

The above two points manifestly are symptoms of a sql query which hasn’t gone beyond the parse phase. In other words it might be a query which Oracle is not able to soft parse and thereby it has never reached the hard parse phase nor the execution step. Hopefully ASH can clearly show this:

select 
     in_parse
    ,in_hard_parse
    ,in_sql_execution
    ,count(1)
from gv$active_session_history
where
    sample_time between to_date('09032018 00:46:00', 'ddmmyyyy hh24:mi:ss')
                and     to_date('09032018 10:44:00', 'ddmmyyyy hh24:mi:ss')
and
   sql_id = '6tcs65pchhp71'
group by 
     in_parse
    ,in_hard_parse
    ,in_sql_execution
order by 4 desc;

I I I   COUNT(1)
- - - ----------
Y N N     162758
Y Y N        385

Indeed this query is almost always in the “parse” phase. So the initial question of what is causing this dramatic library cache lock turned to be : why this query is sticking at the parse phase?

I don’t know why I decided to look at the dba_hist_sqltext but it made my day:

SQL> select sql_text from dba_hist_sqltext where sql_id = '6tcs65pchhp71';

SQL_TEXT
--------------------------------------------------------------------------------
select col1, col2,...,coln from t1;

I was again lucky that this query has no where clause and no bind variable value to use so that I tried to run it as is and here what I found:

select col1, col2,...,coln 
from t1;
     *
ERROR at line 15:
ORA-00600 : internal error code, arguments: [qksvcGetGuardCol:2], [50574], [0], [],
[],[],[],[],[],[],[],[],[],

The multi-user concurrent system was repeating the same query several times and since this query was always failing during the parse phase we observed this library cache lock at the top of the wait events.