Divide and conquer the “true” mutex contention

Oracle 11.2.0.2 contains enhancements 9282521 and 9239863 named “Library cache: mutex X” for objects highly contended for. Part I and II. These enhancements introduce new interesting possibilities to tune some types of the mutex contention.

Contention for heavily accessed objects can now be divided between multiple copies of object in the library cache. According to notes 9282521.8 and 9239863.8 describing the patches, the enhancements should be used:
When there is true contention on a specific library cache object….
Let me investigate this deeper. I will use Oracle 11.2.0.2.2 for Solaris SPARC (64-bit) on 8Cores/32Threads Sun Fire T2000. I chose this platform in order to emphasize how the enhancements work.

Standard disclaimer: Production workloads are much more complex than testcases. Not yet officially supported technique described here may be or may be not applicable to your system. You must thoroughly investigate your workload and receive explicit approval of Oracle Support Services before implementing this in production system.

I. The “Library cache: mutex X” contention testcase.

First of all I need the reproducible testcase that will allow me to explore the “Library cache: mutex X” contention.

As I wrote in previous post about “Cursor: pin S” testcase the true contention arises when the same operator executes concurrently at high frequency. This differs from the contention induced by many versions of cursor. The testcase for “Library cache: mutex X” contention looks like:

declare
i number;
begin
for i in 1..1000000
loop
   execute immediate 'begin dbms_application_info.set_client_info(''mutex'');end;';
end loop;
end;
/

The script uses PL/SQL loop to “execute immediate” the following anonymous PL/SQL block one million times:

begin dbms_application_info.set_client_info('mutex');end;

Hash value of this block is 2253951259. The dbms_application_info.set_client_info() procedure is fast and does not need latches or other resources. This allows me to create pure testcase without unneeded contention. In addition, it is surprisingly common to see mutex contention for dbms_application_info in contemporary over-instrumented applications.

When executed alone, the script takes 3:20 min on average in T2000. Similarly to my previous post I will execute this script by several concurrent sessions. Each time the session ‘execute immediate’ the PL/SQL block, it needs to acquire corresponding “Cursor Pin” mutex to pin the block itself and “Library Cache” mutex to pin the dbms_application_info package in the Library Cache. This will induce the mutex contention.

Look at “library_cache_mutex_x_contention.sql” script. It spawns several sqlplus sessions to execute the above PL/SQL block concurrently. In addition, it takes AWR snapshots before and after the script execution. I will submit 30 concurrent sessions to thrash my 32 CMT T2000 server:

sqlplus /nolog @library_cache_mutex_x_contention 30

The following AWR report section confirms that testcase induced heavy “library cache: mutex X” contention:
…
Top 5 Timed Foreground Events

Event	Waits	Time(s)	Avg wait (ms)	% DB time	Wait Class
DB CPU		21,485		83.17
library cache: mutex X	90,680,016	14,489	0	56.09	Concurrency
cursor: pin S	10,357	2	0	0.01	Concurrency
log file sync	34	1	17	0.00	Commit
direct path sync	1	0	247	0.00	User I/O

 

Host CPU (CPUs: 32 Cores: 8 Sockets: 1)

 

…
As expected the server runqueue raised to 30. Due to concurrency, the average time to execute the script increased 4 times from 3:20 min to 14:27 min.

For the discussion of mutex wait event parameters, diagnostics tools and scripts see my previous post. It is interesting that “library cache: mutex X” wait event is still absent in 11.2 documentation. Up to now the only official information source is MOS Note WAITEVENT: “library cache: mutex X” [ID 727400.1]. Look at mutex waits during contention peak:

SQL> set markup HTML on
SQL> @mutex_ash_waits

SAMPLE_TIME	SID	SQL_ID	EVENT	IDN	BLK_SID	LOC	MUTEX_OBJECT
10:05:40	11	d8dxvkk7hxvq0	cursor: pin S	2253951259	161	8	begin dbms_application_info.set_client_i
10:05:41	155	d8dxvkk7hxvq0	cursor: pin S	2253951259	144	106	begin dbms_application_info.set_client_i
10:05:44	50	11c4s0a35j48v	library cache: mutex X	791245243	169	0	DBMS_APPLICATION_INFO
10:05:46	203	11c4s0a35j48v	library cache: mutex X	3225908833	26	0	DBMS_APPLICATION_INFO
10:05:47	11	11c4s0a35j48v	library cache: mutex X	3225908833	114	0	DBMS_APPLICATION_INFO
10:05:49	155	11c4s0a35j48v	cursor: pin S	2253951259	112	3	begin dbms_application_info.set_client_i

…

Most mutex waits occurred for heavily accessed PL/SQL anonymous block, package DBMS_APPLICATION_INFO and its body:

SQL> set markup HTML on
SQL> @library_cache_objects_heavily_accessed.sql

CURSOR	ADDRESS	NAME	HASH_VALUE	TYPE	Locked	Pinned	Executed	NAMESPACE
Child 0	000000038B975DC8	begin dbms_application_info.se	2253951259	CURSOR	30	56602935	27766476	0
Parent	000000038D8DE8E8	DBMS_APPLICATION_INFO	791245243	PACKAGE	444	30000414	0	1
Parent	000000038D1DD3A8	DBMS_APPLICATION_INFO	3225908833	PACKAGE BODY	234	30000204	30000846	2

…
According to x$mutex_sleeps most mutex waits were occurred during library cache pin/unpin activity inside kglpin (“KGL: PIN heaps and load data pieces of an object”), kglpndl (“KGL PiN DeLete”) and kglpnal1 (“KGL PiN ALlOcate”) routines:

SQL> set markup html on
SQL> select mutex_type,location_id,location,sleeps,wait_time from x$mutex_sleep order by sleeps desc;

MUTEX_TYPE	LOCATION_ID	LOCATION	SLEEPS	WAIT_TIME
Library Cache	90	kglpnal1 90	218814816	155840921
Library Cache	95	kglpndl1 95	217545345	248695706
Library Cache	4	kglpin1 4	209842796	155358935
Cursor Pin	9	kksLockDelete [KKSCHLPIN6]	26255	368250
Cursor Pin	8	kksxsccmp [KKSCHLPIN5]	17171	187894
Cursor Pin	3	kksfbc [KKSCHLFSP2]	9150	112699

…

II. Cloning the library cache objects

The root cause of this contention is the concurrent access to the same “hot” library cache objects. If each session would have its own copy of object there would be no contention! Before 11.2.0.2 this requires artificial tricks.

Enhancements 9282521 and 9239863 allow creation of multiple copies of specified library cache objects. Parameter “_kgl_hot_object_copies” controls the maximum number of copies. Complementary parameter _kgl_debug marks hot library cache objects as a candidate for cloning. Syntax of this parameter can be found in MOS descriptions of bugs 9684368, 11775293 and others. One form of such marking is:

“_kgl_debug”=”name=’schema=’ namespace= debug=33554432”

Both parameters are dynamic. However, my experiments showed that after dynamic change of parameters Oracle unevenly distributes mutex requests between hot object copies. This is why I will use these parameters in my demonstrations as static.

Let me make an experiment. In the above testcase the “library cache: mutex X” contention occurred for package DBMS_APPLICATION_INFO and its body. Corresponding library cache namespaces are 1 and 2. I can mark both the package and the body as “hot” using:

SQL>alter system set “_kgl_debug”=”name=’DBMS_APPLICATION_INFO’ schema=’SYS’ namespace=1 debug=33554432”, “name=’DBMS_APPLICATION_INFO’ schema=’SYS’ namespace=2 debug=33554432” scope=spfile;

If I allow only two copies of hot objects, the mutex contention will be halved. The average time to execute script will decrease from 14:27 min to 7:50 min. In order to demonstrate full-scale improvement I will go further and allow each concurrent session to have its copy of DBMS_APPLICATION_INFO:

SQL>alter system set “_kgl_hot_object_copies”= 255 scope=spfile;
SQL>@library_cache_mutex_x_contention 30
…
ORACLE instance started.
…
Now, the script takes 5:30 min to execute on average. The “library cache: mutex X” contention is magically disappeared:

Top 5 Timed Foreground Events

Event	Waits	Time(s)	Avg wait (ms)	% DB time	Wait Class
DB CPU		10,148		99.99
cursor: pin S	43,713	6	0	0.06	Concurrency
log file sync	35	0	13	0.00	Commit
direct path sync	1	0	294	0.00	User I/O
latch free	882	0	0	0.00	Other

Now concurrently executed PL/SQL blocks do not interfere with each other. The library_cache_objects_heavily_accessed.sql script shows that library cache contains 30 DBMS_APPLICATION_INFO packages and 30 bodies. Each object was pinned one million times:

CURSOR	ADDRESS	NAME	HASH_VALUE	TYPE	Locked	Pinned	Executed	NAMESPACE
Child 0	000000038BB05640	begin dbms_applicati	2253951259	CURSOR	30	22740992	10459264	0
Parent	000000038BAD6B08	DBMS_APPLICATION_INF	3759149138	PACKAGE	2	1000001	0	1
Parent	000000038BAD6D28	DBMS_APPLICATION_INF	778396835	PACKAGE	2	1000001	0	1
Parent	000000038BA0A0B0	DBMS_APPLICATION_INF	1977222849	PACKAGE BODY	1	1000000	1000000	2
Parent	000000038B9824E8	DBMS_APPLICATION_INF	2894603672	PACKAGE	1	1000000	0	1

…
Sessions execute independently after tuning. We have unleashed the full power of Oracle TSeries Chip Multithreading parallelism!

III. “Cursor: pin S” contention

Being inspired by successful resolution of “Library cache: mutex X” contention, I will use the same approach for “Cursor: pin S” waits. In my previous post, I published corresponding testcase. In T2000 environment the testcase load profile is:

sqlplus /nolog @cursor_pin_s_contention.sql 35 
...

Top 5 Timed Foreground Events

Event	Waits	Time(s)	Avg wait (ms)	% DB time	Wait Class
DB CPU		6,680		90.91
cursor: pin S	1,056,416	425	0	5.79	Concurrency
resmgr:cpu quantum	6,940	373	54	5.08	Scheduler
log file sync	8	0	27	0.00	Commit
direct path sync	1	0	208	0.00	User I/O

Now I need another form of _kgl_debug syntax to mark SQL cursor “select 1 from dual where 1=2” as ‘hot’:
“_kgl_debug”=”hash=’full hash value‘ debug=33554432″

The ordinary hash value of this SQL is 3222383532. However, we need a complete 128 bit hash value for library cache object here. You can find it in kglhahsv column of x$kglob:

SQL>select kglnahsv,kglnaobj from x$kglob where kglnahsh=3222383532 and kglhdadr =kglhdpar;

KGLNAHSV                          KGLNAOBJ
--------------------------------- ----------------------------------------
4d1ef2753f3bb11043fd2f61c011abac  select 1 from dual where 1=2
SQL>alter system set "_kgl_debug" = "hash='4d1ef2753f3bb11043fd2f61c011abac' debug=33554432" scope=spfile;
SQL>@cursor_pin_s_contention.sql 35
...
ORACLE instance started.
...

Again the mutex waits disappeared from AWR report after tuning:
Top 5 Timed Foreground Events

Event	Waits	Time(s)	Avg wait (ms)	% DB time	Wait Class
DB CPU		7,047		91.34
latch: shared pool	1,488	67	45	0.87	Concurrency
resmgr:cpu quantum	38	6	161	0.08	Scheduler
db file sequential read	1,268	1	1	0.01	User I/O
direct path sync	1	0	206	0.00	User I/O

The enhancements allow us to resolve the “Cursor: pin S” mutex contention also!

IV. No more underscores. The dbms_shared_pool.markhot() procedure.

I believe that supported way to use this functionality is not yet documented dbms_shared_pool.markhot() procedure. This new in 11.2.0.2 procedure takes two forms:

dbms_shared_pool.markhot(
schema IN VARCHAR2,
objname IN VARCHAR2,
namespace IN NUMBER DEFAULT 1, — library cache namespace to search
global IN BOOLEAN DEFAULT TRUE); — If TRUE mark hot on all RAC instances
and
dbms_shared_pool.markhot(
hash IN VARCHAR2, — 16-byte hash value for the object
namespace IN NUMBER DEFAULT 1,
global IN BOOLEAN DEFAULT TRUE);

corresponding to two _kgl_debug syntaxes described above. There is also dbms_shared_pool.unmarkhot() procedure to unmark the hot object.

I repeated the experiments now marking objects as ‘hot’ using:

exec dbms_shared_pool.markhot(‘SYS’,’DBMS_APPLICATION_INFO’,1);
exec dbms_shared_pool.markhot(‘SYS’,’DBMS_APPLICATION_INFO’,2);
exec dbms_shared_pool.markhot(hash=>’4d1ef2753f3bb11043fd2f61c011abac’, NAMESPACE=>0);

However, the results were not consistent enough in 11.2.0.2.2. Oracle created multiple copies of marked objects in library cache, but frequently uses only one of them. May be this depend upon history of object usage. To achieve more uniform distribution you should mark objects as hot immediately after the instance restart.

By default, Oracle created approximately “number of CPU Cores” hot objects copies. This observation should be further investigated. You can adjust this number by _kgl_hot_object_copies parameter.

Therefore if you prefer not to use hidden parameters, the dbms_shared_pool.markhot() can help you to resolve mutex contention.

In summary: Oracle 11.2.0.2 is the right patchset for mutexes. In this post I discussed how we can use new 11.2.0.2 features to “divide and conquer” the mutex contention which was caused by heavy concurrent access to library cache object.