Recently, I had few email exchanges about HW enqueue contention in oracle-l list and offline. There were few interesting observations emerged from test cases created during that discussion.
HW enqueue
When a session needs access to a resource, it requests a lock on that resource in a specific mode. Internally, lock and resource structures are used to control access to a resource. Enqueues, as name suggests, have First In First Out queueing mechanism. You can find more information about internals of locks in my paper [printed in 2001 ]Internals of locks
Segments have High Water Mark (HWM) indicating that blocks below that HWM have been formatted. New tables or truncated tables [ that is truncated without reuse storage clause ], have HWM value set to segment header block. Meaning, there are zero blocks below HWM. As new rows inserted or existing rows updated (increasing row length), more blocks are added to the free lists and HWM bumped up to reflect these new blocks. HW enqueues are acquired in Exclusive mode before updating HWM and essentially HW enqueues operate as a serializing mechanism for HWM updates.
In non-ASSM tablespaces, HWM is bumped up by 5 blocks at a time ( Actually, undocumented parameter _bump_highwater_mark_count controls this behavior and defaults to 5). Heavy inserts in to a table can result in increased HWM activity leading to HW enqueue contention. This issue is prevalent if the table has LOB columns or if the row length is big.
Measuring HW enqueue contention
We will use few test cases to see how underlying extent size and table structures are affecting HW enqueue contention. But, before we need to find a way to measure total number of gets on HW enqueue. If total number of gets on HW enqueue is reduced, enqueue contention can be relieved.
Fixed table x$ksqst stores statistics about total number of enqueue gets, success and failures of those gets at instance level. For example, to see total number of gets on HW enqueue, following query can be used. Column ksqstreq indicates total # of gets and ksqstwat shows total # of waits.
SQL> select ksqstreq, ksqstwat from x$ksqst where ksqsttyp='HW';
KSQSTREQ KSQSTWAT
---------- ----------
546953 50
From Oracle version 10g and above, x$ksqst is externalized as v$enqueue_statistics.
However, this statistics shows activity at instance level. While we can use this statistics to measure HW enqueue activity , we need to make sure that there is no other session acquiring HW enqueue. Event 10704 can be used to trace enqueues and every call to get an enqueue prints few lines in the trace file. SQL statement to dump this information to trace file is :
alter session set events ‘10704 trace name context forever, level 15′;
Event 10704 is documented as below:
10704, 00000, "Print out information about what enqueues are being obtained" // *Cause: When enabled, prints out arguments to calls to ksqcmi and // ksqlrl and the return values. // *Action: Level indicates details: // Level: 1-4: print out basic info for ksqlrl, ksqcmi // 5-9: also print out stuff in callbacks: ksqlac, ksqlop // 10+: also print out time for each line
Few lines from the trace files printed below. ksq is internal Oracle module names for enqueues and ksqgtl is to get locks on a resource. From the lines below, we can see that HW enqueue is acquired in mode 6, exclusive mode. Timestamp is also printed since we enabled this event at level 15. If we need count number of HW enqueue gets, we need to count occurrences of HW- string in the trace file.
*** 2008-05-04 10:08:35.734 ksqgtl *** HW-00000007-01800014 mode=6 flags=0x11 timeout=21474836 *** ksqgtl: xcb=0x1E283158, ktcdix=2147483647, topxcb=0x1E283158 ktcipt(topxcb)=0x0 *** 2008-05-04 10:08:35.734 ksucti: init session DID from txn DID: ksqgtl: ksqlkdid: 0001-0014-00000016 *** 2008-05-04 10:08:35.734 *** ksudidTrace: ksqgtl ktcmydid(): 0001-0014-00000016 ksusesdi: 0000-0000-00000000 ksusetxn: 0001-0014-00000016 ksqgtl: RETURNS 0 *** 2008-05-04 10:08:35.750 ksqrcl: HW,7,1800014 ksqrcl: returns 0
Now, we can grep for HW- in the trace file, count it and match that against v$enqueue_statistics. Following test case illustrates this method using an example table below:
SQL> select ksqstreq, ksqstwat from x$ksqst where ksqsttyp='HW';
KSQSTREQ KSQSTWAT
---------- ----------
546198 50
SQL> insert into test_hw
select n, lpad(n, 4000,'a') v1 from
(select level n from dual connect by level SQL> SQL> commit;
Commit complete.
SQL> select ksqstreq, ksqstwat from x$ksqst where ksqsttyp='HW';
KSQSTREQ KSQSTWAT
---------- ----------
546953 50
A difference of 755 (546953-546198) total gets to HW enqueue.
Searching for HW- enqueues in the trace file also prints 755.
/oracle/app/oracle/admin/TEST1/udump> grep ‘HW-’ test1_ora_26668.trc |wc -l
755
So, in my test database, my session is the only session and we could query v$enqueue_statistics for our test cases.
Test case
Following test case will be used to see the impact of extent size, segment management on HW enqueue gets. If total number of HW enqueue gets can be reduced, contention can be relieved.
Following script creates a tablespace, then creates a table with lob column in that tablespace, inserts 9999 rows in to that table and prints difference in total enqueue gets before and after insert statement.
-- Script enq_hw1.sql ----------- variable v_begin_cnt number variable v_end_cnt number prompt prompt Tablespace: Locally managed with \&1 prompt drop tablespace TS_LMT_HW including contents and datafiles; create tablespace TS_LMT_HW datafile 'D:\ORACLE\ORADATA\ORCL11G\TS_LMT_AUTO_1M_01.DBF' size 200M extent management local \&1; create table test_hw (n1 number , c1 clob ) tablespace TS_LMT_HW; begin select total_req# into :v_begin_cnt from v$enqueue_statistics where eq_type ='HW'; end; / insert into test_hw select n, lpad(n, 4000,'a') v1 from (select level n from dual connect by level <10000); commit; select total_req#, succ_req#, failed_req# from v$enqueue_statistics where eq_type ='HW'; begin select total_req# into :v_end_cnt from v$enqueue_statistics where eq_type ='HW'; end; / select :v_end_cnt - :v_begin_cnt diff from dual; --- script end enq_hw1.sql -----------
Above script is called by following script passing various tablespace attributes, essentially running same test for different types of tablespaces:
spool call_eng_hw1.lst REM Test cases #1 through #6 @enq_hw1 "uniform size 5M segment space management manual" @enq_hw1 "uniform size 5M segment space management auto" @enq_hw1 "uniform size 40K segment space management manual" @enq_hw1 "uniform size 40K segment space management auto" @enq_hw1 "autoallocate segment space management manual" @enq_hw1 "autoallocate segment space management auto" spool off
Test Results
Tested above script for tablespace in versions 10.2.0.4 and 11.1.0.6. Here are the test results:
| test | Extent management | Segment space management | 10.2.0.4 | 11.1.0.6 |
|---|---|---|---|---|
| #1 | uniform size 5M | manual | 2049 | 64 |
| #2 | uniform size 5M | auto | 50 | 48 |
| #3 | uniform size 40K | manual | 6604 | 6045 |
| #4 | uniform size 40K | auto | 7552 | 7554 |
| #5 | autoallocate | manual | 2231 | 279 |
| #6 | autoallocate | auto | 269 | 291 |
There are few key points here.
1. In test cases #1 and #5, there is a dramatic decrease in enqueue gets between 10g and 11g for tablespace with segment space management set to manual. Looks like, a new feature faster lob is kicking in. Tested above script for a table without lob column. Virtually there is no difference between 10g and 11g, if the table has no lob column. row length is kept around 3000 bytes for this test.
create table test_hw (n1 number , v1 varchar2(1000), v2 varchar2(1000), v3 varchar2(1000) ) tablespace TS_LMT_HW;
...
declare
i number;
begin
for i in 1 .. 10000
loop
insert into test_hw values ( i, lpad(i, 1000, 'a'), lpad(i, 1000, 'a'), lpad(i, 1000, 'a') );
commit;
end loop;
end;
/
...
| test | Extent management | Segment space management | 10.2.0.4 | 11.1.0.6 |
|---|---|---|---|---|
| #1 | uniform size 5M | manual | 1020 | 1019 |
| #2 | uniform size 5M | auto | 33 | 31 |
| #3 | uniform size 40K | manual | 3004 | 3004 |
| #4 | uniform size 40K | auto | 3055 | 3055 |
| #5 | autoallocate | manual | 1132 | 1132 |
| #6 | autoallocate | auto | 163 | 164 |
2. If tablespace uniform size is too low, then # of HW enqueue gets increases sharply. Compare test cases #1 & #3 for 11g. Enqueue gets decreased 10 times for tablespace with appropriate extent size.
3. In all test cases, automatic segment space management tablespaces performed fewer enqueue gets. In ASSM tablespaces HWM is bumped up by much higher number. I am not suggesting to use ASSM, since space wastage *can* increase in ASSM tablespaces. However, if resolving HW contention is primary issue, then consider ASSM.
4. Allocating additional extent with instance keyword seems to help in non-ASSM tablespace [ Behavior is different for ASSM tablespace and needs more research to understand that ]. In test case #1 above, HWM for the table was set at file_id 6, block_id 80 and that extent starting at file 6, block_id 9. That is, 70 blocks were below HWM initially. After allocating an extent with instance 1 keyword, HWM was bumped up by 1209 blocks.
[ Yong has a test case for this using dbms_space package: http://yong321.freeshell.org/oranotes/Dbms_Space.txt ]
From segment header block, before allocating extent, HWM: 0×01800050 (dba for file 6,block 80)
alter table test_hw allocate extent (instance 1);
From segment header block, after allocating extent, HWM: 0×01802f89 (dba for file 6,block 12169)
Extent Map
—————————————————————–
0×0180000a length: 639
0×01802d09 length: 640
5. High HW enqueue contention is prevalent during Oracle applications upgrade also. During one of our recent upgrade from 11.5.8 to 11.5.0, there was heavy HW enqueue contention on sys.source$ table due to many packages compiled/added during the upgrade. Only option was to increase _bump_highwater_mark_count during upgrade, to relieve excessive waits on HW enqueue contention. Of course, Oracle support must be contacted before adding any underscore parameters in production environment. Side effect of setting this parameter is that, for smaller tables, more blocks might be added below HWM leading to full table scan reading more blocks then necessary.
Besides growing Segments, there is a much more problematic ASSM reclaim Problem with Blobs and HW-enqueue. This is supposed to be fixed in 10.2.0.4, but only(?) if you set the Event 44951.
This will batch-reclaim inactive (undo) LOB chunks and reduce the number of enqueues needed for tht operation. Do you have experiences with that, as well? This typically happens on LOB segments with concurrent insert/delete/update activity.
Comment by Bernd Eckenfels — June 25, 2008 @ 10:50 am |
Hi Bernd
I guess, you are referring to bug 6376915. No, I have not personally encountered it. Looks very intrusive though. Posting a summary here for others:
The bug states that in effect space reclamation can cause HW enqueu’s – and what we are seeing is that if we truncate the table – we don’t see the HW:enqueue’s until we fill up the pre-allocated extents – then the HW enqueue’s start en masse.
Fix:
This fix causes ASSM LOB space to batch up reclaim instead of just reclaiming the requested/required number of LOB chunks. To enable this fix, set event 44951 to the maximum number of chunks that you would like to have reclaimed per attempt. The maximum allowed is 1024. Anything larger becomes 1024. However, if the requested amount of space is larger than the event’s value, the reclaim will be for the requested amount of space.
Thanks for pointing out this bug, Bernd
Cheers
Riyaj
Comment by orainternals — July 26, 2008 @ 7:55 pm |
I noticed in our 10.2.0.3 database with ASSM in AIX 5.3 box that some staging table (with insert and delete operations) are using a huge number of extents and is continuously growing. It seems that for some reason even if there are deletions, oracle cannot reclaim back the space and lower the HHWM. Is any way or any event we can set at instance level to trace the time of the extent is added in the staging table.
I noticed some notes from Steve Adams email that this can be shown dumping the redo log with layer 14.4 but the problem is that we don’t when it happens, thus we cannot check every log
Thank you in advance,
khair
Comment by Kostas Hairopoulos — September 20, 2009 @ 3:30 pm |
Hello Khair
I don’t think, there is an event to print when an extent is added, at least, not that aware of. My recommendation is to write a small piece of code to get timestamp and # of extents every hour or so for that tablespace/object. With that output, you can pin down the hour at which extent is added and dump the log file during that time period.
Correct approach here is to understand root cause by dumping the log files. This might also mean that you may have to dump the ASSM segments with dbms_Space_admin.segment_dump to see block status of various blocks. With these two trace files, you may be able to understand, why extents are allocated even when not needed.
There are many bugs in 10.2.0.3 in ASSM for extent management. You may be hitting one of that. So, you might want to consider upgrading to version 10.2.0.4 and see if this problem reproduces.
Cheers
Riyaj
Comment by orainternals — September 21, 2009 @ 9:50 pm |