Wednesday, February 09, 2011

Quick notes about troubleshooting a blocker issue involving an insert

Called to help troubleshooting a production issue: an insert statemnt blocked many others. However, when I checked the database on 7:30 PM, the symptoms have gone.

In retrospective, the problem is most  likely due to a configuration issue in context of DMT. This database was upgraded to 10g a year ago from 8i. A few tablespaces is still dictionary-managed.


Here is the AWR "Top 5 Timed Events" during the problem period:

Top 5 Timed Events (18:30 -19:00)

Event Waits Time(s) Avg Wait(ms) % Total Call Time Wait Class

enq: TX - contention 44,494 130,783 2,939 59.7 Other
enq: ST - contention 27,122 79,719 2,939 36.4 Configuration
CPU time 3,700 1.7
read by other session 839,265 2,843 3 1.3 User I/O
db file scattered read 405,142 2,121 5 1.0 User I/O


From: http://www.saptechies.com/faq-oracle-enqueues/,  we can read some info about Oracle enqueue.


System enqueues:

ST (space transaction enqueue): This enqueue is held in dictionary-managed tablespaces within extent allocations and releases.

TYPE = ST

Very large numbers of extents are allocated or deallocated.


You can solve the problem permanently by using LMTS instead of DMTS (refer to Notes 214995 and 659946). If you use DMTS, you must ensure that the extents of temporary segments, tables and indexes are sufficiently big so that you can avoid large quantities of extents being allocated and deallocated.




I wan able to find the blocker from the DBA_HIST_ACTIVE_SESS_HISTORY view. Drunig 18:30 - 19:00 Session 651 is blocking many other sessions, which either wait for enq: TX or enq:ST  for examples:

SAMPLE_TIME SESSION_ID SQL_ID EVENT BLOCKING_SESSION

---------------------------------------- ---------- ------------- ------------------------------ ----------------
08-FEB-11 06.59.56.243 PM 242 6wyrqa50whrjg enq: TX - contention 651
08-FEB-11 06.59.56.243 PM 345 6wyrqa50whrjg enq: TX - contention 651
08-FEB-11 06.59.56.243 PM 414 6wyrqa50whrjg enq: TX - contention 651
08-FEB-11 06.59.56.243 PM 469 6wyrqa50whrjg enq: TX - contention 651
08-FEB-11 06.59.56.243 PM 591 6wyrqa50whrjg enq: TX - contention 651
08-FEB-11 06.59.56.243 PM 593 6wyrqa50whrjg enq: TX - contention 651
08-FEB-11 06.59.56.243 PM 594 6wyrqa50whrjg enq: TX - contention 651
08-FEB-11 06.59.56.243 PM 595 6wyrqa50whrjg enq: TX - contention 651
08-FEB-11 06.59.56.243 PM 596 6wyrqa50whrjg enq: TX - contention 651

...


SAMPLE_TIME SESSION_ID SQL_ID EVENT BLOCKING_SESSION
---------------------------------------- ---------- ------------- ------------------------------ ----------------
08-FEB-11 06.59.56.243 PM 1976 dpc1k1djg5gh0 enq: ST - contention 651
08-FEB-11 06.59.56.243 PM 49 dpc1k1djg5gh0 enq: ST - contention 651
08-FEB-11 06.59.56.243 PM 1841 dpc1k1djg5gh0 enq: ST - contention 651
08-FEB-11 06.59.56.243 PM 1763 dpc1k1djg5gh0 enq: ST - contention 651
08-FEB-11 06.59.56.243 PM 1693 dpc1k1djg5gh0 enq: ST - contention 651
08-FEB-11 06.59.56.243 PM 1660 dpc1k1djg5gh0 enq: ST - contention 651

....

Session 651 that was doing the same insert lasted about 1hour, from about 6:17 to 7:15

SAMPLE_TIME SESSION_ID SQL_ID EVENT BLOCKING_SESSION
---------------------------------------- ---------- ------------- ------------------------------ ----------------
08-FEB-11 06.17.23.778 PM 651 6wyrqa50whrjg
08-FEB-11 06.17.33.998 PM 651 6wyrqa50whrjg
08-FEB-11 06.17.44.198 PM 651 6wyrqa50whrjg
08-FEB-11 06.17.54.508 PM 651 6wyrqa50whrjg
...

08-FEB-11 07.14.45.919 PM 651 6wyrqa50whrjg
08-FEB-11 07.14.56.049 PM 651 6wyrqa50whrjg
08-FEB-11 07.15.06.159 PM 651 6wyrqa50whrjg
-- end --



After this sql ( 6wyrqa50whrjg  is an  simple insert into a table) was done, things become normal.  I am still not sure why this insert took so long. I was unable to know what wait event it was experiencing. Apparantly, Oracle was allocating a new extent to the table segment, but why took about an hour? The table referred in the SQL has two extents now, first one has 64000 blocks, the second has 16000 blocks.

So the scenario appeared to be that a session wants to insert a row into a table that resides in a DMT tablespace, but  the table segment is run out of space, Oracle firstly has to allocate a new extent to the table segment; the session is waiting for this allocation to complete; it blocks all other sessions doing the same insert into the same table with the latter waiting for enq:TX. It also blocks other sessions with enq:ST events,  which  are doing DML on  different tables  that resides in the same tablespace.

Anyway we really need to migrate DMT to LMT asap.

No comments: