On Oracle: "library cache: bucket mutex X" on V$ Fixed Views: Case Test

Oracle DB experienced heavy "library cache: bucket mutex X" when V$ Fixed Views were queried frequently,
which impeded Oracle normal functions like background processes Mnnn and MZnn.

Note: Tested on Oracle 19c.

1. Test Setup

In the following code, we query V$LIBCACHE_LOCKS (similar behavior for DBA_KGLLOCK), which is a union of X$KGLLK and X$KGLPN.


create or replace procedure test_bucket_mutex(p_job_id number, p_loop_count number) as
begin
  for i in 1..p_loop_count loop
    for c in (select * from V$LIBCACHE_LOCKS where rownum <= p_job_id) loop
      null;
    end loop;
  end loop;
end;
/

-- exec test_bucket_mutex(1, 1);

create or replace procedure test_bucket_mutex_jobs(p_job_count number, p_loop_count number) as
begin
  for i in 1..p_job_count loop
    dbms_scheduler.create_job (
      job_name        => 'TEST_JOB_'||i,
      job_type        => 'PLSQL_BLOCK',
      job_action      => 'begin test_bucket_mutex('||i||', '||p_loop_count||'); end;',    
      start_date      => systimestamp,
      --repeat_interval => 'systimestamp',
      auto_drop       => true,
      enabled         => true);
  end loop;
end;
/

2. Test Run

Run a test with 16 Jobs:


exec test_bucket_mutex_jobs(16, 1e4);

AWR shows:

Top 10 Foreground Events by Total Wait Time

Event	Waits	Total Wait Time (sec)	Avg Wait	% DB time	Wait Class
library cache: bucket mutex X	939,402	17.1K	18.22ms	59.8	Concurrency
DB CPU		7062.2		24.7
library cache: mutex X	5,139	69.3	13.48ms	.2	Concurrency
control file sequential read	20,874	2.9	137.27us	.0	System I/O
db file sequential read	3,195	1.8	557.97us	.0	User I/O
Disk file operations I/O	2,602	.2	72.88us	.0	User I/O
cursor: pin S	8	.1	17.55ms	.0	Concurrency
log file sync	20	.1	6.52ms	.0	Commit
direct path write	59	0	217.10us	.0	User I/O
latch free	1	0	10.66ms	.0	Other

SQL ordered by Elapsed Time

Elapsed Time (s)	Executions	Elapsed Time per Exec (s)	%Total	%CPU	SQL Id	SQL Module	SQL Text
28,575.23	159,710	0.18	99.89	24.66	9sz3zkc69bpjh	DBMS_SCHEDULER	SELECT * FROM V$LIBCACHE_LOCKS...
1,790.62	1	1,790.62	6.26	24.82	0f1dxm6hd2c2u	DBMS_SCHEDULER	DECLARE job BINARY_INTEGER := ...
1,790.18	1	1,790.18	6.26	24.65	5vp17fw0hgrz1	DBMS_SCHEDULER	DECLARE job BINARY_INTEGER := ...

Mutex Sleep Summary

Mutex Type	Location	Sleeps	Wait Time (ms)
Library Cache	kglic1 49	1,696,792	15,671,698
Library Cache	kglic4 145	172,634	1,423,319
Library Cache	kglGetHandleReference 123	8,262	61,133
Library Cache	kglReleaseHandleReference 124	1,176	8,110
Library Cache	kglhdgn1 62	9	71
Cursor Pin	kksLockDelete [KKSCHLPIN6]	9	138
Cursor Pin	kksfbc [KKSCHLFSP2]	2	2
Row Cache	[14] kqrScan	1	0

Top SQL with Top Row Sources

SQL ID	Plan Hash	Executions	% Activity	Row Source	% Row Source	Top Event	% Event	SQL Text
9sz3zkc69bpjh	2131580607	2794	98.87	FIXED TABLE - FULL	49.95	library cache: bucket mutex X	30.36	SELECT * FROM V$LIBCACHE_LOCKS...
				FIXED TABLE - FULL	48.57	library cache: bucket mutex X	31.00

During the test, we can monitor "library cache: bucket mutex X" waits by:


select 'BLOCKING_SESSION'   sess, program, event, mod(s.p1, power(2, 17)) "buckt muext(child_latch)", s.p1, s.p2, s.p3, s.sql_id, q.sql_text, m.*, s.*, q.* 
from v$session s, v$mutex_sleep_history m, v$sqlarea q
 where s.sid = m.blocking_session and s.sql_id = q.sql_id and m.sleep_timestamp > sysdate-5/1440 and m.sleeps > 3
union all
select 'REQUESTING_SESSION' sess, program, event, mod(s.p1, power(2, 17)) "buckt muext(child_latch)", s.p1, s.p2, s.p3, s.sql_id, q.sql_text, m.*, s.*, q.* 
from v$session s, v$mutex_sleep_history m, v$sqlarea q
 where s.sid = m.requesting_session and s.sql_id = q.sql_id and m.sleep_timestamp > sysdate-5/1440 and m.sleeps > 3;

select bs.session_id, bs.session_serial#, bs.program, bs.event, bs.p1, bs.blocking_session, bs.blocking_session_serial#, bs.sql_id
      ,s.sample_time, s.session_id, s.session_serial#, s.program, s.event, s.p1, s.blocking_session, s.blocking_session_serial#, s.sql_id
  from v$active_session_history bs, v$active_session_history s
where s.event  = 'library cache: mutex X'
  and bs.event = 'library cache: bucket mutex X'
  and s.sample_time = bs.sample_time
  and mod(s.p1, power(2, 17)) = bs.p1
  and s.session_id != bs.session_id
  and s.sample_time > sysdate-5/1440
order by s.sample_time desc, bs.session_id, s.session_id;

select sql_id, last_active_time, executions, disk_reads, direct_writes, buffer_gets, rows_processed, sql_text, v.* 
from v$sqlarea v where sql_id in ('9sz3zkc69bpjh');

3. "library cache: bucket mutex X" Tracing

Open one Sqlplus window, execute bpftrace on its process (UNIX pid 293988):


bpftrace -e 'uprobe:/orabin/app/oracle/product/19.27.0.0.250415-212/bin/oracle:kglGetBucketMutex+2, 
             uprobe:/orabin/app/oracle/product/19.27.0.0.250415-212/bin/oracle:kglGetMutex+2 / pid==293988 /
   {@ustack_cnt[probe] = count();}'

Run query to fetch rows with rownum limit:


SQL > select * from V$LIBCACHE_LOCKS where rownum <= 10;
  10 rows selected.

Here bpftrace output:


	@ustack_cnt[uprobe:/orabin/app/oracle/product/19.27.0.0.250415-212/bin/oracle:kglGetBucketMutex+2]: 123462
	@ustack_cnt[uprobe:/orabin/app/oracle/product/19.27.0.0.250415-212/bin/oracle:kglGetMutex+2]:       269774

Same bpftrace output for count query:


SQL > select count(*) from V$LIBCACHE_LOCKS where rownum <= 10;
    COUNT(*)
  ----------
          10

Run query without rownum limit, we get the similar output due to FIXED TABLE FULL on X$KGLLK and X$KGLPN.


SQL >  select * from V$LIBCACHE_LOCKS;
  1226 rows selected.
        
	@ustack_cnt[uprobe:/orabin/app/oracle/product/19.27.0.0.250415-212/bin/oracle:kglGetBucketMutex+2]: 123488
	@ustack_cnt[uprobe:/orabin/app/oracle/product/19.27.0.0.250415-212/bin/oracle:kglGetMutex+2]:       269939

Same bpftrace output for count query:


SQL > select count(*) from V$LIBCACHE_LOCKS;
    COUNT(*)
  ----------
        1226

To get Parameter P1 and P3 of "library cache: bucket mutex X", we can use bpftrace script:


bpftrace -e 'uprobe:/orabin/app/oracle/product/19.27.0.0.250415-212/bin/oracle:kglGetBucketMutex+2 / pid==293988 /
   {@ustack_cnt["kglGetBucketMutex", reg("si"), reg("r8")] = count();}'

Pick a few output lines (first number is P1, second is P3):


  @ustack_cnt[kglGetBucketMutex, 6574, 145]: 2
  @ustack_cnt[kglGetBucketMutex, 5442, 49]:  2
  @ustack_cnt[kglGetBucketMutex, 3311, 49]:  2

Then we can find them in v$db_object_cache:


select child_latch, hash_value, mod(hash_value, power(2, 17)) bucket_p1, owner, substr(name, 1, 50) name, namespace, type 
from v$db_object_cache t where child_latch in (
6574,
5442,
3311
);  

CHILD_LATCH HASH_VALUE  BUCKET_P1 OWNER NAME                                          NAMESPACE            TYPE
----------- ---------- ---------- ----- --------------------------------------------- -------------------- ----------
       3311 1185156335       3311 SYS   java/util/function/DoubleBinaryOperator       TABLE/PROCEDURE      JAVA CLASS
       5442 1797395778       5442       UPDATE SYS.WRI$_ADV_                          SQL AREA             CURSOR
       6574  363993518       6574       WITH binds as           (select :dbid         SQL AREA             CURSOR

To get Parameter P3 of library cache: bucket mutex X, we can use bpftrace script:


bpftrace -e 'uprobe:/orabin/app/oracle/product/19.27.0.0.250415-212/bin/oracle:kglGetBucketMutex+2 / pid==293988 /
   {@ustack_cnt["kglGetBucketMutex", reg("r8")] = count();}'
   
  @ustack_cnt[kglGetBucketMutex, 64]:  1
  @ustack_cnt[kglGetBucketMutex, 62]:  9
  @ustack_cnt[kglGetBucketMutex, 49]:  57846
  @ustack_cnt[kglGetBucketMutex, 145]: 65558

We can see that bpftrace output [kglGetBucketMutex, 49] and [kglGetBucketMutex, 145] big numbers match "kglic1 49" and "kglic1 145" big stats in AWR - Mutex Sleep Summary.

If we query normal tables, there are much less kglGetBucketMutex and kglGetMutex:


SQL > select count(*) from dba_objects;

    COUNT(*)
  ----------
     2004127
   
bpftrace -e 'uprobe:/orabin/app/oracle/product/19.27.0.0.250415-212/bin/oracle:kglGetBucketMutex+2, 
             uprobe:/orabin/app/oracle/product/19.27.0.0.250415-212/bin/oracle:kglGetMutex+2 / pid==293988 /
   {@ustack_cnt[probe] = count();}'
   
  @ustack_cnt[uprobe:/orabin/app/oracle/product/19.27.0.0.250415-212/bin/oracle:kglGetBucketMutex+2]: 1
  @ustack_cnt[uprobe:/orabin/app/oracle/product/19.27.0.0.250415-212/bin/oracle:kglGetMutex+2]:       15

4. GV$LIBCACHE_LOCKS and DBA_KGLLOCK DDL and Xplan

Both V$LIBCACHE_LOCKS and SYS.DBA_KGLLOCK are union of X$KGLLK and X$KGLPN. Any queries on them are FIXED TABLE FULL on X$KGLLK and X$KGLPN (rownum limit has no effect).


------ V$LIBCACHE_LOCKS ------
SELECT INST_ID, 'LOCK', KGLLKADR, KGLLKUSE, KGLLKSES, KGLLKHDL, KGLLKPNC, KGLLKCNT, KGLLKMOD, KGLLKREQ, KGLLKSPN, CON_ID
  FROM X$KGLLK
UNION
SELECT INST_ID, 'PIN',  KGLPNADR, KGLPNUSE, KGLPNSES, KGLPNHDL, KGLPNLCK, KGLPNCNT, KGLPNMOD, KGLPNREQ, KGLPNSPN, CON_ID
  FROM X$KGLPN
  
select * from V$LIBCACHE_LOCKS where rownum <= :B1;

Plan hash value: 2131580607
 
---------------------------------------------------------------------------------------------------
| Id  | Operation             | Name              | Rows  | Bytes |TempSpc| Cost (%CPU)| Time     |
---------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT      |                   | 20956 |  2414K|       |   868   (1)| 00:00:01 |
|*  1 |  COUNT STOPKEY        |                   |       |       |       |            |          |
|   2 |   VIEW                | GV$LIBCACHE_LOCKS | 20956 |  2414K|       |   868   (1)| 00:00:01 |
|*  3 |    SORT UNIQUE STOPKEY|                   | 20956 |  2361K|  3656K|   868   (1)| 00:00:01 |
|   4 |     UNION-ALL         |                   |       |       |       |            |          |
|*  5 |      FIXED TABLE FULL | X$KGLLK           | 18837 |  1048K|       |     0   (0)| 00:00:01 |
|*  6 |      FIXED TABLE FULL | X$KGLPN           |  2119 |   132K|       |     0   (0)| 00:00:01 |
---------------------------------------------------------------------------------------------------


------ DBA_KGLLOCK ------

CREATE OR REPLACE FORCE NONEDITIONABLE VIEW SYS.DBA_KGLLOCK
(KGLLKUSE, KGLLKHDL, KGLLKMOD, KGLLKREQ, KGLLKTYPE)
BEQUEATH DEFINER
AS 
  select kgllkuse, kgllkhdl, kgllkmod, kgllkreq, 'Lock' kgllktype from x$kgllk
    union all
  select kglpnuse, kglpnhdl, kglpnmod, kglpnreq, 'Pin'  kgllktype from x$kglpn;
  
  
select * from DBA_KGLLOCK where rownum <= :B1;

Plan hash value: 3293675002
 
-----------------------------------------------------------------------------------
| Id  | Operation           | Name        | Rows  | Bytes | Cost (%CPU)| Time     |
-----------------------------------------------------------------------------------
|   0 | SELECT STATEMENT    |             | 20956 |   982K|     0   (0)| 00:00:01 |
|*  1 |  COUNT STOPKEY      |             |       |       |            |          |
|   2 |   VIEW              | DBA_KGLLOCK | 20956 |   982K|     0   (0)| 00:00:01 |
|   3 |    UNION-ALL        |             |       |       |            |          |
|   4 |     FIXED TABLE FULL| X$KGLLK     | 18837 |   423K|     0   (0)| 00:00:01 |
|   5 |     FIXED TABLE FULL| X$KGLPN     |  2119 | 48737 |     0   (0)| 00:00:01 |
-----------------------------------------------------------------------------------

5. Related Work

(1). Dynamic_plan_table, x$kqlfxpl and extreme library cache latch contention (Posted by Riyaj Shamsudeen on March 13, 2009)
(https://orainternals.wordpress.com/tag/kglic/)

We traced following two queries with above bpftrace scripts,
and the output shows that kglGetBucketMutex requests are proptional to rownum limit (:B1).
(For V$LIBCACHE_LOCKS and DBA_KGLLOCK, kglGetBucketMutex requests are constant, irrelvant to rownum limit)


select count(*) from GV$SQL_PLAN where rownum <= :B1;       --FIXED TABLE FULL on X$KQLFXPL
select count(*) from GV$ALL_SQL_PLAN where rownum <= :B1;   --FIXED TABLE FULL on X$ALL_KQLFXPL

Here the test output:


bpftrace -e 'uprobe:/orabin/app/oracle/product/19.27.0.0.250415-212/bin/oracle:kglGetBucketMutex+2,
             uprobe:/orabin/app/oracle/product/19.27.0.0.250415-212/bin/oracle:kglGetMutex+2 / pid==299591 /
   {@ustack_cnt[probe] = count();}'
Attaching 2 probes...

select count(*) from GV$SQL_PLAN where rownum <= 1;
  @ustack_cnt[uprobe:/orabin/app/oracle/product/19.27.0.0.250415-212/bin/oracle:kglGetBucketMutex+2]: 47
  @ustack_cnt[uprobe:/orabin/app/oracle/product/19.27.0.0.250415-212/bin/oracle:kglGetMutex+2]:       111

select count(*) from GV$SQL_PLAN where rownum <= 10;
  @ustack_cnt[uprobe:/orabin/app/oracle/product/19.27.0.0.250415-212/bin/oracle:kglGetBucketMutex+2]: 117
  @ustack_cnt[uprobe:/orabin/app/oracle/product/19.27.0.0.250415-212/bin/oracle:kglGetMutex+2]:       287

select count(*) from GV$SQL_PLAN where rownum <= 100;
  @ustack_cnt[uprobe:/orabin/app/oracle/product/19.27.0.0.250415-212/bin/oracle:kglGetBucketMutex+2]: 436
  @ustack_cnt[uprobe:/orabin/app/oracle/product/19.27.0.0.250415-212/bin/oracle:kglGetMutex+2]:       974

select count(*) from GV$SQL_PLAN where rownum <= 1000;
  @ustack_cnt[uprobe:/orabin/app/oracle/product/19.27.0.0.250415-212/bin/oracle:kglGetBucketMutex+2]: 3523
  @ustack_cnt[uprobe:/orabin/app/oracle/product/19.27.0.0.250415-212/bin/oracle:kglGetMutex+2]:       7725

(2). Oracle PLITBLM "library cache: mutex X"
(https://ksun-oracle.blogspot.com/2021/04/oracle-plitblm-library-cache-mutex-x.html)

(3). Row Cache Object and Row Cache Mutex Case Study
(https://ksun-oracle.blogspot.com/2020/08/row-cache-object-and-row-cache-mutex.html)

6. GDB script

We can also use following GDB script to trace "library cache: bucket mutex X":


---------------- bucket_mutex_1, gdb -x bucket_mutex_1 -p 293988 ----------------

set pagination off
set logging file bucket_mutex_1.log
set logging overwrite on
set logging on
set $kmutexget = 1
set $kbucketget = 1

break kglGetBucketMutex
command 
printf "------kglGetBucketMutex (%i) ---> Bucket (rsi): %d (%X), Location(r8d): %d (%X)\n", $kbucketget++, $rsi, $rsi, $r8d, $r8d
backtrace 4
continue
end

break kglGetMutex
command 
printf "------kglGetMutex (%i) ---> Mutex addr (rsi): %d (%X), Location(r8d): %d (%X)\n", $kmutexget++, $rsi, $rsi, $r8d, $r8d
continue
end

7. kglMutexLocations[] array

For all kglMutexLocations, we can try to list them with following command.
They often appear in AWR section "Mutex Sleep Summary" for Mutex Type: "Library Cache"
(or V$MUTEX_SLEEP / V$MUTEX_SLEEP_HISTORY.location).


define PrintkglMutexLocations
  set pagination off
  set $i = 0
  while $i < $arg0
    x /s *((uint64_t *)&kglMutexLocations + $i)
    set $i = $i + 1
  end
end

(gdb) PrintkglMutexLocations 150

0x15f42524:     "kglic1    49"
0x15f42a24:     "kglic2 127"
0x15f42b68:     "kglic3       144"
0x15f42b7c:     "kglic4       145"

(Only "kglic" Mutex are shown here)

Thursday, July 10, 2025

"library cache: bucket mutex X" on V$ Fixed Views: Case Test