Home » RDBMS Server » Performance Tuning » High enqueue waits in statspack - lock contention on Primary key index showing 98% of db wait time (9.2.0.6)
High enqueue waits in statspack - lock contention on Primary key index showing 98% of db wait time [message #442930] Thu, 11 February 2010 07:23 Go to next message
mwansa
Messages: 14
Registered: December 2009
Junior Member
Inserts in a table very slow. Primary key index on this table showing high internal lock contention. This is seeing using third party gui monitoring tool.

The table is only 30M with 101705 rows

statspack Top wait events show:

--
Top 5 Timed Events
~~~~~~~~~~~~~~~~~~ % Total
Event Waits Time (s) Ela Time
--------------------------- ------------ ----------- --------
enqueue 17,089 50,160 93.65
CPU time 2,925 5.46
sbtbackup 2 230 .43
sbtclose2 2 161 .30
SQL*Net message from dblink 3,267 29 .05
---

why is there a high lock contention on this index.

there are a number of insert statements on the same table and not appearing in top sqls.

any thing need to be done on the index.

ddl for index

CREATE UNIQUE INDEX "xxxx"."PKEY_xxxxx"
ON "xxxxxx"."xxxxxx" ("PPUID", "PPSEQ")
TABLESPACE "xxxxxx" PCTFREE 10 INITRANS 4 MAXTRANS 255
STORAGE ( INITIAL 64K NEXT 0K MINEXTENTS 1 MAXEXTENTS
2147483645 PCTINCREASE 0)
LOGGING
---

They are no foreign keys referencing this index keys.






Re: High enqueue waits in statspack - lock contention on Primary key index showing 98% of db wait t [message #442960 is a reply to message #442930] Thu, 11 February 2010 11:47 Go to previous messageGo to next message
John Watson
Messages: 8960
Registered: January 2010
Location: Global Village
Senior Member
This doesn't sound right. Your statspack excerpt shows a row locking, or enqueue, problem. There is no way that can be interpreted as "Primary key index on this table showing high internal lock contention"; I'm not sure what that means, but it sounds more like buffer busy wait. Are you sure this third party tool is actually any good? And is its message related to the enqueue wait events, or to something else?
Re: High enqueue waits in statspack - lock contention on Primary key index showing 98% of db wait t [message #443030 is a reply to message #442960] Fri, 12 February 2010 02:50 Go to previous messageGo to next message
mwansa
Messages: 14
Registered: December 2009
Junior Member
I have attached the monitoring graphs. The highlights in red bar shows the problems exprienced at the slow performance as internal lock contention.

The red bar also shows it was an insert on the table and most of it was waiting on locks on the index shown in second graph.

Statspack show top 5 wait event was enqueue highest.. this is a lock wait event.
It did not show any buffer busy waits.
Re: High enqueue waits in statspack - lock contention on Primary key index showing 98% of db wait t [message #443038 is a reply to message #442930] Fri, 12 February 2010 03:42 Go to previous messageGo to next message
cookiemonster
Messages: 13958
Registered: September 2008
Location: Rainy Manchester
Senior Member
You haven't actually attached anything.

How are the primary key columns getting populated? from a sequence or some other method?
Re: High enqueue waits in statspack - lock contention on Primary key index showing 98% of db wait t [message #443056 is a reply to message #443038] Fri, 12 February 2010 05:25 Go to previous messageGo to next message
mwansa
Messages: 14
Registered: December 2009
Junior Member
apologies, i thought i attached the file.

Yes the primary key is been populated using a sequence.

INSERT INTO XXXXXX(BATCHNUMBER,CHANGE,PPUID,PPSEQ,PPTYPE,PPNAME,PPDATA) VALUES (
......)

the primary index is on (ppuid,ppseq)...

Re: High enqueue waits in statspack - lock contention on Primary key index showing 98% of db wait t [message #443058 is a reply to message #442930] Fri, 12 February 2010 05:29 Go to previous messageGo to next message
cookiemonster
Messages: 13958
Registered: September 2008
Location: Rainy Manchester
Senior Member
Can you run a trace on one of the sessions that's inserting into this table? That might give a better view of what's going on than statspack.
Re: High enqueue waits in statspack - lock contention on Primary key index showing 98% of db wait t [message #443068 is a reply to message #443056] Fri, 12 February 2010 07:11 Go to previous messageGo to next message
mwansa
Messages: 14
Registered: December 2009
Junior Member
ok, will do a trace.
Re: High enqueue waits in statspack - lock contention on Primary key index showing 98% of db wait t [message #443089 is a reply to message #443068] Fri, 12 February 2010 09:00 Go to previous messageGo to next message
entekeralam
Messages: 19
Registered: January 2010
Junior Member
How is the application generating PK values ( ("PPUID", "PPSEQ") ?

Can you please check the object/row session is waiting when waiting session is waiting for "enq: TX - row lock contention" event.
Re: High enqueue waits in statspack - lock contention on Primary key index showing 98% of db wait t [message #443099 is a reply to message #443089] Fri, 12 February 2010 10:02 Go to previous messageGo to next message
mwansa
Messages: 14
Registered: December 2009
Junior Member
The application populates the values for ppseq using a sequence.

for every value of ppuid there are some many records which populates the ppseq by a sequence value.

Re: High enqueue waits in statspack - lock contention on Primary key index showing 98% of db wait t [message #443101 is a reply to message #443099] Fri, 12 February 2010 10:05 Go to previous messageGo to next message
BlackSwan
Messages: 26766
Registered: January 2009
Location: SoCal
Senior Member
post problem SQL & its EXPLAIN PLAN
Re: High enqueue waits in statspack - lock contention on Primary key index showing 98% of db wait t [message #443329 is a reply to message #443101] Mon, 15 February 2010 02:57 Go to previous messageGo to next message
mwansa
Messages: 14
Registered: December 2009
Junior Member
The sql is an insert

the explain plan
[2]Insert statement (Optimizer mode: CHOSE)
[1]Table access (in insert)XXXXXX


The sequence used
CREATE SEQUENCE "xxxxxxxxx" INCREMENT
BY 1 START WITH 1839 MAXVALUE 9999999 MINVALUE 1 CYCLE
NOCACHE NOORDER

The table is a dictionary managed table and has INITRANS 4

I was looking at caching the sequence with a high value say 100 and increasing the initrans to say 20. I am looking at reducing the contention on the index.

This may be applying to our situation

----

Certain scenarios can require that Oracle apply locks above the row level of granularity. These include:

Unindexed foreign keys
Bitmap indexes
Inability to grow the Interested Transaction List (ITL)

Oracle sometimes applies internal locks and in some circumstances these can cause contention at the application level. Two examples of problematic internal locking are:

- Space Transaction (ST) locks in dictionary managed tablespaces
- Row cache locks caused by sequences with low CACHE settings.
----

As a proposal towards the solution, will be ok i initially start with my suggestion, to see if this will sortout the issue.




Re: High enqueue waits in statspack - lock contention on Primary key index showing 98% of db wait t [message #443347 is a reply to message #442930] Mon, 15 February 2010 04:14 Go to previous messageGo to next message
John Watson
Messages: 8960
Registered: January 2010
Location: Global Village
Senior Member
Hi - I do wonder if you are going in the right direction here. It is hard to see how a sequence cache will solve a row enqueue problem. And I still wonder what your tool means by the phrase "internal lock contention": it doesn't sound like a TX enqueue.
By the way, you never did post the monitoring graphs, and the statspack report might help too.
Have you tried to find out what session is doing the blocking, and what it is (or more likely, isn't) doing? I would run the utllockt script to identify the blocking and waiting sessions, then make the joins from v$session to v$sql to see what code the blocking and waiting sessions are running: the join columns are sql_id and prev_sql_id in v$session to sql_id in v$sql.


Re: High enqueue waits in statspack - lock contention on Primary key index showing 98% of db wait t [message #443360 is a reply to message #443347] Mon, 15 February 2010 05:12 Go to previous messageGo to next message
mwansa
Messages: 14
Registered: December 2009
Junior Member
I can not attach the statspack file as it may contain senstive data..

The problem happens once in a time. I can not get the sessions blocking as this will have dissappeard.

Statspack indicates ( period 14:30 - 15:50pm when problem happened)

Top 5 Timed Events
~~~~~~~~~~~~~~~~~~ % Total
Event Waits Time (s) Ela Time
------------------------------- --------- ----------- --------
enqueue 21,322 62,570 92.22
CPU time 4,771 7.03
sbtbackup 2 230 .34
sbtclose2 2 161 .24
SQL*Net message from dblink 3,267 29 .04



^LEnqueue activity for DB: xxxxxx Instance: xxxxxxx Snaps: 50318 -50352
-> Enqueue stats gathered prior to 9i should not be compared with 9i data
-> ordered by Wait Time desc, Waits desc

Avg Wt Wait
Eq Requests Succ Gets Failed Gets Waits Time (ms) Time (s)
-- ------------ ------------ ----------- ----------- ------------- ------------
TX 41,281 41,278 0 766 270,124.09 206,915
TC 20 20 0 4 11,926.00 48
CF 13,784 13,783 1 33 6.06 0
CU 211,493 211,493 0 29 1.48 0
US 166,026 166,026 0 1 10.00 0
---

I will try to get the proper file formate from the GUI and will attach soon.
Re: High enqueue waits in statspack - lock contention on Primary key index showing 98% of db wait t [message #443364 is a reply to message #443360] Mon, 15 February 2010 05:57 Go to previous messageGo to next message
mwansa
Messages: 14
Registered: December 2009
Junior Member
I have attached the graph, that show the problem.

[Updated on: Mon, 15 February 2010 06:00]

Report message to a moderator

Re: High enqueue waits in statspack - lock contention on Primary key index showing 98% of db wait t [message #443365 is a reply to message #443364] Mon, 15 February 2010 06:02 Go to previous messageGo to next message
mwansa
Messages: 14
Registered: December 2009
Junior Member
graph attached
Re: High enqueue waits in statspack - lock contention on Primary key index showing 98% of db wait t [message #443368 is a reply to message #443365] Mon, 15 February 2010 06:09 Go to previous messageGo to next message
mwansa
Messages: 14
Registered: December 2009
Junior Member
The other graphs when it happened again. on same table and index inserts.
  • Attachment: graph_3.JPG
    (Size: 27.19KB, Downloaded 1080 times)
Re: High enqueue waits in statspack - lock contention on Primary key index showing 98% of db wait t [message #443369 is a reply to message #443368] Mon, 15 February 2010 06:10 Go to previous messageGo to next message
mwansa
Messages: 14
Registered: December 2009
Junior Member
No Message Body
  • Attachment: graph_2.JPG
    (Size: 48.67KB, Downloaded 1049 times)
Re: High enqueue waits in statspack - lock contention on Primary key index showing 98% of db wait t [message #443386 is a reply to message #443369] Mon, 15 February 2010 07:52 Go to previous messageGo to next message
entekeralam
Messages: 19
Registered: January 2010
Junior Member
If you are on 10g, Can you please run below sql. ( Modify the sample_time period to match the time "when problem happened")

select session_id,session_serial#,event,current_obj#,count(*) from v$active_session_history 
where sample_time between to_timestamp('15-FEB-10 19:10','DD-MON-YY HH24:MI') and 
to_timestamp('15-FEB-10 19:15','DD-MON-YY HH24:MI')
group by session_id,session_serial#,event,current_obj# order by count(*)


and

select session_id,session_serial#,event,current_obj#,count(*) from dba_hist_active_sess_history 
where sample_time between to_timestamp('15-FEB-10 19:10','DD-MON-YY HH24:MI') and 
to_timestamp('15-FEB-10 19:15','DD-MON-YY HH24:MI')
group by session_id,session_serial#,event,current_obj# order by count(*)
Re: High enqueue waits in statspack - lock contention on Primary key index showing 98% of db wait t [message #443387 is a reply to message #443386] Mon, 15 February 2010 07:55 Go to previous messageGo to next message
mwansa
Messages: 14
Registered: December 2009
Junior Member
The version is 9.2.0.6.0 and no ASH tables.
Re: High enqueue waits in statspack - lock contention on Primary key index showing 98% of db wait t [message #443424 is a reply to message #443329] Mon, 15 February 2010 11:47 Go to previous messageGo to next message
BlackSwan
Messages: 26766
Registered: January 2009
Location: SoCal
Senior Member
> I am looking at reducing the contention on the index.

CREATE UNIQUE INDEX "xxxx"."PKEY_xxxxx"
ON "xxxxxx"."xxxxxx" ("PPUID", "PPSEQ")
TABLESPACE "xxxxxx" PCTFREE 10 INITRANS 4 MAXTRANS 255
STORAGE ( INITIAL 64K NEXT 0K MINEXTENTS 1 MAXEXTENTS
2147483645 PCTINCREASE 0)
LOGGING REVERSE

>REVERSE Specify REVERSE to store the bytes of the index block in reverse order, excluding the rowid.

http://download.oracle.com/docs/cd/B19306_01/server.102/b14200/statements_5010.htm#i2062403
Re: High enqueue waits in statspack - lock contention on Primary key index showing 98% of db wait t [message #443425 is a reply to message #443424] Mon, 15 February 2010 11:52 Go to previous messageGo to next message
John Watson
Messages: 8960
Registered: January 2010
Location: Global Village
Senior Member
It looks as though what your Symantec product calls an "internal lock" is what anyone else would call a TX enqueue. So it is nothing to do with an index: reverse keying won't help, because your problem is enqueues, not buffer busy wait.
Your problem is probably that that you are trying to insert the same row twice. You had better look at the code that generates values for PPUID and PPSEQ.
Re: High enqueue waits in statspack - lock contention on Primary key index showing 98% of db wait t [message #443426 is a reply to message #443425] Mon, 15 February 2010 11:56 Go to previous messageGo to next message
BlackSwan
Messages: 26766
Registered: January 2009
Location: SoCal
Senior Member
>because your problem is enqueues,

If above is true then following SQL will be conflicting sessions

SELECT DECODE(request,0,'Holder: ','Waiter: ')||sid sess,
id1, id2, lmode, request, type
FROM V$LOCK
WHERE (id1, id2, type) IN
(SELECT id1, id2, type FROM V$LOCK WHERE request>0)
ORDER BY id1, request
/

Re: High enqueue waits in statspack - lock contention on Primary key index showing 98% of db wait t [message #443427 is a reply to message #443387] Mon, 15 February 2010 11:58 Go to previous message
S.Rajaram
Messages: 1027
Registered: October 2006
Location: United Kingdom
Senior Member
                                                       Avg Wt          Wait
Eq Requests        Succ Gets Failed Gets  Waits        Time (ms)     Time (s)
-- ------------ ------------ ----------- ----------- ------------- ------------
TX 41,281          41,278      0           766          270,124.09   206,915
TC  20              20         0           4            11,926.00    48
CF 13,784          13,783      1           33            6.06         0
CU 211,493         211,493     0           29            1.48         0
US 166,026         166,026     0            1            10.00        0


To me it looks like you are hitting a tx enqueue which is most likely caused by a lock contention (as already mentioned). I don't think you can tune this by increasing the ITL or cache size. You have to fix the underlying the code.

Refer this link for more details about tx enqueue

http://hoopercharles.wordpress.com/2009/12/06/enqueue-experimentations/

Your best bet will be is to sample the v$lock and v$session_wait when this process is running.

Also from next time if you could format your report like I did it will be much appreciated.

Last but not least you are on a version 9.2.0.6 which is not supported (I think). Atleast upgrade to 9.2.0.8.

Happy profiling.

Cheers

Raj
Previous Topic: Performance Pruning on fact table
Next Topic: Tuning Distributed Queries
Goto Forum:
  


Current Time: Fri Nov 22 08:28:54 CST 2024