3

Background

I've got an application which is doing a large number of concurrent inserts into an Oracle table. The Top Activity view is reporting a lot of index contention and I am attempting to reduce this to improve performance.

The table in question has several indexes, but my suspicion is that the problem is leaf-block contention on the PK which is a monotonically increasing sequence. I know about reverse key indexes, but I'd like to be able to pin-point the problem before I dive in with guesswork fixes.

Trace File Contents

I've extracted a trace from the database when under load. I've included a chunk of it at the bottom, but one part in particular is puzzling me. The largest "enq: TX - index contention" entry accounts for 94% of the total time:

WAIT #47156432773600: nam='enq: TX - index contention' ela= 113183 name|mode=1415053316 usn<<16 | slot=4259845 sequence=43226 obj#=-1 tim=1329387810694927

I don't understand how to interpret this line. Googling has yielded that name|mode=1415053316 means Transaction in share mode (hex TX04), and that obj# would reference the object in SYS.OBJ$.

For the other waits where obj# is specified (see below), it points to the PK index I have suspicions about, but in the largest wait, the obj#=-1.

So, my questions are:

  • What does it mean for obj# to be -1 in this wait?
  • What does the usn<<16 | slot=4259845 parameter mean? Is it useful to me?
  • Does the sequence=43226 tell me anything useful?

More trace detail

PARSING IN CURSOR #47156432773600 len=654 dep=0 uid=41 oct=2 lid=41 tim=1329387810581386 hv=3365236844 ad='2977ccca8' sqlid='31r3hm349aw3c'
insert into AnonymousTable (a, b, c ...) values (:1, :2, :3 ...)
END OF STMT
PARSE #47156432773600:c=0,e=51,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=0,tim=1329387810581384
WAIT #47156432773600: nam='enq: TX - index contention' ela= 113183 name|mode=1415053316 usn<<16 | slot=4259845 sequence=43226 obj#=-1 tim=1329387810694927
WAIT #47156432773600: nam='latch: ges resource hash list' ela= 3958 address=11249153232 number=91 tries=0 obj#=-1 tim=1329387810698944
WAIT #47156432773600: nam='enq: TX - index contention' ela= 1891 name|mode=1415053316 usn<<16 | slot=655387 sequence=48341 obj#=-1 tim=1329387810700949
WAIT #47156432773600: nam='buffer busy waits' ela= 162 file#=32 block#=618823 class#=1 obj#=28134 tim=1329387810701223
WAIT #47156432773600: nam='buffer busy waits' ela= 1572 file#=32 block#=618823 class#=1 obj#=28134 tim=1329387810702840
WAIT #47156432773600: nam='enq: TX - index contention' ela= 1809 name|mode=1415053316 usn<<16 | slot=5767194 sequence=85968 obj#=28134 tim=1329387810704709
WAIT #47156432773600: nam='buffer busy waits' ela= 2254 file#=32 block#=618823 class#=1 obj#=28134 tim=1329387810707018
WAIT #47156432773600: nam='enq: TX - index contention' ela= 15306 name|mode=1415053316 usn<<16 | slot=4784132 sequence=53965 obj#=28134 tim=1329387810722436
EXEC #47156432773600:c=1999,e=142776,p=0,cr=50,cu=364,mis=0,r=28,dep=0,og=1,plh=0,tim=1329387810724203
STAT #47156432773600 id=1 cnt=0 pid=0 pos=1 obj=0 op='LOAD TABLE CONVENTIONAL  (cr=50 pr=0 pw=0 time=142726 us)'
WAIT #47156432773600: nam='SQL*Net message to client' ela= 2 driver id=1413697536 #bytes=1 p3=0 obj#=28134 tim=1329387810724288
WAIT #47156432773600: nam='SQL*Net message from client' ela= 363 driver id=1413697536 #bytes=1 p3=0 obj#=28134 tim=1329387810724667
CLOSE #47156432773600:c=0,e=7,dep=0,type=1,tim=1329387810724701
Improve this question
10
  • What are the INITRANS and MAXTRANS settings for the table and indexes in question? It's possible that the blocks in question lack an appropriate number of ITL slots.
    – Adam Musch
    Commented Feb 16, 2012 at 15:49
  • The INITRANS is small. I agree that it's likely that there's contention for ITL slots. What I'd really like though is concrete evidence that this index is the problem before I go changing stuff.
    – Tim Gage
    Commented Feb 16, 2012 at 17:45
  • I also think that swapping to a reverse-key index or a non-increasing sequence might be a better solution that just increasing INITRANS. Do you agree? I really need this to work in a RAC environment too.
    – Tim Gage
    Commented Feb 16, 2012 at 17:53
  • The lowest impact solution would be to increase INITRANS to an appropriate level. Another solution would be to hash-partition the index; suddenly one really hot leaf block is now 8 or 16 leaf blocks under 1/8th or 1/16 of the pressure. If using RAC and the load on this is going to be coming from multiple nodes, you need to partition both the table and the load along another dimension; tossing the leaf blocks across the interconnect is not going to work at all.
    – Adam Musch
    Commented Feb 16, 2012 at 20:38
  • Roughly how many inserts per second are you pushing into the table? Have you any option to use array inserts with less concurrent sessions to complete your workload? I think the TX Contention wait doesn't point you at the block / object that is causing the problems, but my memory is a bit fuzzy in that area.
    – Stephen ODonnell
    Commented Feb 16, 2012 at 21:07

2 Answers 2

Reset to default
2

OBJ#=-1 means either means that the object number is missing or it's not related to an object. The best idea is to go into V$active_session_history and find the SQL_ID then get the SQL text via the SQL_ID and look at the object sin the SQL and what the SQL was doing.

As far as people suggesting INIT TRANS, that is unlikely as there is a separate wait event for INIT TRANS.

USN, SLOT and SEQUENCE map the UNDO entry for the transaction. They could be used to map back to activity in the UNDO but it's probably easier to get the transaction id the XID and use VERSIONS_XID on the objects involved.

see http://www.slideshare.net/khailey/ukoug-oracle-transaction-locks

Example ASH query

col object for A15
col otype for A10
select
      substr(event,0,20)    lock_name,
      ash.session_id        waiter,
      mod(ash.p1,16)        lmode,
      --ash.p2                p2,
      --ash.p3                p3,
      o.object_name           object,
      o.object_type           otype,
      CURRENT_FILE#           filen,
      CURRENT_BLOCK#          blockn,
      ash.SQL_ID             waiting_sql,
      BLOCKING_SESSION        blocker
      --,ash.xid
from
        v$active_session_history ash,
        all_objects o
where
          event like 'enq: TX - index contention'
  and o.object_id (+)= ash.CURRENT_OBJ#
/
Improve this answer
0

OBJ#=-1 means that the event is not relateable to any particular object.

These values are almost certainly the P1 P2 and P3 values dumped from the wait event. You should query v$event_name if you want to know what these values mean, although this will almost certainly send you tumbling further down the rabbit hole that is Oracle performance.

Improve this answer
2
  • Agreed, but v$event_name just tells me the same thing as is reported in the trace: name|mode, usn<<16|slot, sequence In the end I gave up went of the old fashioned method of making assumptions and testing them. It worked, but it's a shame that there isn't more detail available to diagnose these problems non-intrusively.
    – Tim Gage
    Commented Mar 20, 2014 at 9:26
  • It's one of the ways that Oracle allows you to look "under the hood" as it were, but it's a mixed blessing.
    – Andrew Brennan
    Commented Mar 20, 2014 at 10:38

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge you have read our privacy policy.

Not the answer you're looking for? Browse other questions tagged or ask your own question.