首页 » ORACLE » Tuning “transaction” & TX lock wait event ,speeding up rollback dead transaction

Tuning “transaction” & TX lock wait event ,speeding up rollback dead transaction

Yesterday I received a warning and a production db instance found many TX lock and wait event “transaction”, I check the TX lock model is 6, so we can make sure is caused by multiple sessions update the same data, and wait event “transaction” is relatively rare, Here the record about my diagnosis method.

# I used TanelPoder‘s scripts package.

SQL> @snapper ash 5 1 all
Sampling SID all with interval 5 seconds, taking 1 snapshots...

-- Session Snapper v4.11 BETA - by Tanel Poder ( http://blog.tanelpoder.com ) - Enjoy the Most Advanced Oracle Troubleshooting Script on the Planet! :)


----------------------------------------------------------------------------------------------------
Active% | INST | SQL_ID          | SQL_CHILD | EVENT                               | WAIT_CLASS
----------------------------------------------------------------------------------------------------
  9900% |    1 | cw9pdvv3zkfn8   | 1         | transaction                         | Other
  9267% |    1 | 4fwxf7m2a81qc   | 1         | transaction                         | Other
  5933% |    1 | f88awm2ytk9hz   | 2         | transaction                         | Other
  4633% |    1 | cw9pdvv3zkfn8   | 1         | enq: TX - row lock contention       | Application
  4367% |    1 | 4fwxf7m2a81qc   | 1         | enq: TX - row lock contention       | Application
  2967% |    1 | f88awm2ytk9hz   | 2         | enq: TX - row lock contention       | Application
  2867% |    1 | 2w35cs2hkbbfm   | 2         | transaction                         | Other
  1333% |    1 | 2w35cs2hkbbfm   | 2         | enq: TX - row lock contention       | Application
   467% |    1 | bpxz52kqnzjzq   | 0         | db file scattered read              | User I/O
   400% |    1 | cw9pdvv3zkfn8   | 0         | transaction                         | Other


SQL> @xi 4fwxf7m2a81qc 1
eXplain the execution plan for sqlid 4fwxf7m2a81qc child 1...

PLAN_TABLE_OUTPUT
----------------------------------------------------------------------------
SQL_ID  4fwxf7m2a81qc, child number 1
-------------------------------------
UPDATE "PROD_ANBOB_TAB" SET
"PROD_ANBOB_TAB_A_ID" = :1                  ,
"PROD_ANBOB_TAB_Z_ID" = :2                  ,      "ROLE_CD" = :3
                ,      "RELATION_TYPE_CD" = :4                  ,
"EFF_DATE" = :5                  ,      "EXP_DATE" = :6
 ,      "STATUS_CD" = :7                  ,      "STATUS_DATE" = :8
                       WHERE "PROD_ANBOB_TAB_ID" = :9

Plan hash value: 447644083

--------------------------------------------------------------
| Id  | Operation          | Name                   | E-Rows |
--------------------------------------------------------------
|   0 | UPDATE STATEMENT   |                        |        |
|   1 |  UPDATE            | PROD_ANBOB_TAB    |        |
|*  2 |   INDEX UNIQUE SCAN| PK_PROD_ANBOB_TAB |      1 |
--------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------

   2 - access("PROD_ANBOB_TAB_ID"=:9)

SQL> @xi cw9pdvv3zkfn8 1
eXplain the execution plan for sqlid 4fwxf7m2a81qc child 1...

PLAN_TABLE_OUTPUT
----------------------------------------------------------------------------
SQL_ID  cw9pdvv3zkfn8, child number 1
-------------------------------------
UPDATE "PROD_ANBOB_TAB" SET
"PROD_ANBOB_TAB_A_ID" = :1                  ,
"PROD_ANBOB_TAB_Z_ID" = :2                  ,      "ROLE_CD" = :3
                ,      "RELATION_TYPE_CD" = :4                  ,
"EFF_DATE" = :5                  ,      "EXP_DATE" = :6
 ,      "STATUS_CD" = :7                  ,      "STATUS_DATE" = :8
                       WHERE "PROD_ANBOB_TAB_ID" = :9

Plan hash value: 447644083

--------------------------------------------------------------
| Id  | Operation          | Name                   | E-Rows |
--------------------------------------------------------------
|   0 | UPDATE STATEMENT   |                        |        |
|   1 |  UPDATE            | PROD_ANBOB_TAB    |        |
|*  2 |   INDEX UNIQUE SCAN| PK_PROD_ANBOB_TAB |      1 |
--------------------------------------------------------------

Note:
the top sql is same as update PROD_ANBOB_TAB table.

SQL> @a
A-Script: Display active sessions...

  COUNT(*) SQL_ID        STATE   EVENT
---------- ------------- ------- ----------------------------------------------------------------
       152 cw9pdvv3zkfn8 WAITING transaction
       138 4fwxf7m2a81qc WAITING transaction
        91 f88awm2ytk9hz WAITING transaction
        43 2w35cs2hkbbfm WAITING transaction
         5 bpxz52kqnzjzq WAITING db file scattered read
         5 6bcv04k8bwqqx WAITING db file scattered read
         4 bpxz52kqnzjzq WAITING db file parallel read
         3 6bcv04k8bwqqx WAITING db file parallel read
         3 8npvb7gq0hv9n WAITING db file sequential read
         2 3jxd62rcvgt3s WAITING db file sequential read
         2 311fvyd1dm8f9 WAITING enq: TX - row lock contention
...
sys@HBCRM>@session_rpt

USERNAME        STATUS                    CNT
--------------- -------- --------------------
                ACTIVE                     40
..
ANBOB   ACTIVE                    439
ANBOB   INACTIVE                  228
..
                         --------------------
sum                                      1039

                                                               displays active session

   SID SERIAL# USERNAME        wait event                     program                   MACHINE         SQL_ID            BLOCKING_SESSION
------ ------- --------------- ------------------------------ ------------------------- --------------- ------------- --------------------
  1498   14000 SYS             DIAG idle wait                 sqlplus@anboba (TNS V1- anboba        0fd4qt85gs6mu
  3035   17845 CANB        log file sync                  execproc@anboba (TNS V1 anboba        83utvtfqb8ckq
    42    2217 ANBOB   db file sequential read        JDBC Thin Client          WEEJAR      4fc4s72gwzk1z
   502    9480 ANBOB   db file sequential read        JDBC Thin Client          WEEJAR      09tb08vnskq8f
...
  1431   30205 ANBOB   enq: TX - row lock contention  JDBC Thin Client          WEEJAR      27zcr5rsv5h1n                 1345
  1438   15289 ANBOB   enq: TX - row lock contention  JDBC Thin Client          WEEJAR      9u051wusmvyyb                 1490
  1542    9217 ANBOB   enq: TX - row lock contention  JDBC Thin Client          WEEJAR      8x92ggpcg1n05                 1766
  1583   53380 ANBOB   enq: TX - row lock contention  JDBC Thin Client          WEEJAR      2cm6mhrukt83b                   69
  1606   22693 ANBOB   enq: TX - row lock contention  JDBC Thin Client          WEEJAR      bbxsfc0vydy0r                 1051
  1716   17672 ANBOB   enq: TX - row lock contention  JDBC Thin Client          WEEJAR      9u051wusmvyyb                 2081
  1740   53836 ANBOB   enq: TX - row lock contention  JDBC Thin Client          WEEJAR      8x92ggpcg1n05                  358
...
   316   37747 ANBOB   transaction                    JDBC Thin Client          WEEJAR      f88awm2ytk9hz
   323    3925 ANBOB   transaction                    JDBC Thin Client          WEEJAR      cw9pdvv3zkfn8
   331   20910 ANBOB   transaction                    JDBC Thin Client          WEEJAR      cw9pdvv3zkfn8
   333   23474 ANBOB   transaction                    JDBC Thin Client          WEEJAR      cw9pdvv3zkfn8
   336   21293 ANBOB   transaction                    JDBC Thin Client          WEEJAR      4fwxf7m2a81qc
   345   57215 ANBOB   transaction                    JDBC Thin Client          WEEJAR      f88awm2ytk9hz
   358   36644 ANBOB   transaction                    JDBC Thin Client          WEEJAR      f88awm2ytk9hz
   364   52258 ANBOB   transaction                    JDBC Thin Client          WEEJAR      4fwxf7m2a81qc

SQL> SELECT * FROM v$lock WHERE type='TX' AND lmode > 0;

ADDR             KADDR                   SID TY        ID1        ID2      LMODE    REQUEST      CTIME      BLOCK
---------------- ---------------- ---------- -- ---------- ---------- ---------- ---------- ---------- ----------
C000001307D95048 C000001307D95080          7 TX   58589202     536927          6          0      13105          1
C0000012FF11BCC0 C0000012FF11BCF8         14 TX  135659560      72553          6          0      17897          1
C0000013034A9E38 C0000013034A9E70         21 TX   41418764    2659285          6          0      10087          2
C000001305ADDA00 C000001305ADDA38         84 TX  128450588      72005          6          0      18462          1
C000001306713AD0 C000001306713B08        168 TX  126287877      72124          6          0      14636          2
C0000013005E06C0 C0000013005E06F8        182 TX   10551334   18158075          6          0      14947          1
C000001305B58B90 C000001305B58BC8        210 TX   14221324   10189189          6          0      18497          1
C000001307CE1DE8 C000001307CE1E20        266 TX  142082059      73158          6          0      10223          1
C000001300635270 C0000013006352A8        287 TX   53805060     721773          6          0       4256          2
C000001307CFA728 C000001307CFA760        301 TX  145752092      75333          6          0      15757          1
...

What is the “transaction” wait event?

Google it, I found Maclean‘blog had a article about it

Definition: Wait for a blocking transaction to be rolled back. Continue waiting until the transaction has been rolled back.

Wait Time: Wait for up to 1 second for a blocking transaction to be rolled back. Continue waiting until transaction has been
rolled out.

Parameters:
P1 – Undo Segment No | Slot No within Undo header.
P2 – Wrap Sequence [ max value is UB4MAXVAL ].
P3 – Count

undo seg#
SELECT * FROM v$rollstat WHERE usn =

slot# This is the slot# within the transaction table that is being used to store a transaction.
wrap# Wrap or sequence number of the slot. For each new transactionthis number increases.
count Number of times that Oracle7 has waited on this transaction.

Commentary: Used within kctwit() [ General TX wait routine . ]

Once we have acquired the TX enqueue of the transaction we are waiting for , we must continue waiting until the blocking transaction has been

committed/rolled back. If the transaction has been aborted, then we are waiting for PMON or SMON to complete the rollback (We may be waiting for SMON if a
rollback segment needs recovery).

This wait is interleaved with “undo segment recovery”, because on each ‘loop’ we call ktucun().
Whether we see this event depends on the availability of the failed transactions enqueue. This wait may be more prevalent in a 2pc environment.

Dependency: We are dependent on the transaction being rolled out, but we could be waiting for either the local PMON, or a PMON from another instance

[parallel server].

The Undo Segment No will tell us which instance we are waiting for , but at present this will remain an eyeball operation rather than automating it within

ph2.

Validity: N/A

Advise: The waiting basically depends on the size of that transaction that is being rolled back. You may want to check if PMON / SMON
is doing the rollback for a killed session and if so check Parameter:CLEANUP_ROLLBACK_ENTRIES.

From 7.3 onwards View:X$KTUXE can be used to see the state of a transaction – it shows the transaction table entries in the rollback segment header.

Related: Lock:TX
Note:34540.1 Enqueue Metrics.
Bug:960962 Oracle8 OPS issue which can cause OPS deferred transaction recovery to take a long time, hence causing ‘transaction’ waits.

# to diag

SQL>   select usn, state, undoblockstotal "Total", undoblocksdone "Done", undoblockstotal-undoblocksdone "ToDo",
      decode(cputime,0,'unknown',sysdate+(((undoblockstotal-undoblocksdone) / (undoblocksdone / cputime)) / 86400)) "Estimated time to complete" 
      from v$fast_start_transactions; 

       USN STATE                 Total       Done       ToDo Estimated time to complet
---------- ---------------- ---------- ---------- ---------- -------------------------
       763 RECOVERED              1984       1984          0 03-12月-2014 19:13:55
      1160 RECOVERED              2016       2016          0 03-12月-2014 19:13:55

SQL> SELECT
  2      ktuxeusn            usn#     -- 65535 = no-undo transaction
  3    , ktuxeslt            slot#    -- 65535 = invalid slot#
  4    , ktuxesqn            seq#
  5    , ktuxesta            status
  6    , ktuxecfl            flags
  7    , ktuxesiz            undo_blks
  8    , ktuxerdbf           curfile 
  9    , ktuxerdbb           curblock
 10    , ktuxescnw * power(2, 32) + ktuxescnb cscn -- commit/prepare commit SCN
 11    , ktuxeuel            
 12    -- distributed xacts
 13    --, ktuxeddbf           r_rfile
 14    --, ktuxeddbb           r_rblock
 15    --, ktuxepusn           r_usn#
 16    --, ktuxepslt           r_slot#
 17    --, ktuxepsqn           r_seq#
 18  FROM
 19      x$ktuxe
 20  WHERE ktuxesta != 'INACTIVE'
 21  ORDER BY
 22      ktuxeusn
 23    , ktuxeslt
 24  /


      USN#      SLOT#       SEQ# STATUS           FLAGS                     UNDO_BLKS    CURFILE   CURBLOCK       CSCN   KTUXEUEL
---------- ---------- ---------- ---------------- ------------------------ ---------- ---------- ---------- ---------- ----------
         4         22   31014027 ACTIVE           NONE                              1        264     967434 1.4027E+13         16
         5         21   30333340 ACTIVE           NONE                              3          2     817961 1.4027E+13         17
         7         45   31001476 ACTIVE           NONE                              6        264      61866 1.4027E+13         20
...
      1443         31     142002 ACTIVE           NONE                              2          8      29030 1.4027E+13         20
      1446         10     135047 ACTIVE           NONE                              2        259     400309 1.4027E+13         22
      1451         22     138059 ACTIVE           NONE                              1          8     613807 1.4027E+13         38
      1453         23     144618 ACTIVE           NONE                              1         10     604060 1.4027E+13         30
      1454          1     144624 ACTIVE           NONE                              1          2     919426 1.4027E+13         19
      1460         11     142710 ACTIVE           NONE                             12          7     516523 1.4027E+13         25
      1461         34     144127 ACTIVE           NONE                              1        265     134876 1.4027E+13         19
      1478         44     616678 ACTIVE           NONE                              1         14     776342 1.4027E+13          3
      1492         28     377606 ACTIVE           NONE                              1         11     546860 1.4027E+13         12
      1495         28     374646 ACTIVE           NONE                              1          9     842624 1.4027E+13          6
      1513         35     270415 ACTIVE           NONE                              1          9     623625 1.4027E+13          4
      1515         19     264799 ACTIVE           NONE                              2         12     952471 1.4027E+13          8
      1523          4     241934 ACTIVE           DEAD                          41200         11      32135 1.4027E+13          5
      1524         25     244697 ACTIVE           NONE                              1        262     251684 1.4027E+13          8
      1525         42     245672 ACTIVE           NONE                              6        263     599843 1.4027E+13         12
      1526          7     250715 ACTIVE           NONE                              1         12     666181 1.4027E+13         10
-- have truncated

SQL> select  to_char(scn_to_timestamp(3265*power(2,32)+3527577231),'yyyy-mm-dd hh24:mi:ss') start_date from x$ktuxe where  KTUXECFL ='DEAD';

start_date 
-------------------
2014-12-03 14:22:41

# To monitor Dead transaction rollback

SQL> select b.name "UNDO Segment Name", b.inst# "Instance ID", b.status$ STATUS, a.ktuxesiz "UNDO Blocks", a.ktuxeusn, a.ktuxeslt xid_slot, 
  2  a.ktuxesqn xid_seq, a.ktuxecfl from x$ktuxe a, undo$ b
  3   where a.ktuxesta = 'ACTIVE' and a.ktuxeusn = b.us#
  4  and KTUXECFL='DEAD';

UNDO Segment Name              Instance ID     STATUS UNDO Blocks   KTUXEUSN   XID_SLOT    XID_SEQ KTUXECFL
------------------------------ ----------- ---------- ----------- ---------- ---------- ---------- ------------------------
_SYSSMU1523$                             2          3       10239       1523          4     241934 DEAD

SQL> /

UNDO Segment Name              Instance ID     STATUS UNDO Blocks   KTUXEUSN   XID_SLOT    XID_SEQ KTUXECFL
------------------------------ ----------- ---------- ----------- ---------- ---------- ---------- ------------------------
_SYSSMU1523$                             2          3       10231       1523          4     241934 DEAD

SQL> /

UNDO Segment Name              Instance ID     STATUS UNDO Blocks   KTUXEUSN   XID_SLOT    XID_SEQ KTUXECFL
------------------------------ ----------- ---------- ----------- ---------- ---------- ---------- ------------------------
_SYSSMU1523$                             2          3       10228       1523          4     241934 DEAD

TIP:
x$ktuxe.KTUXEUSN=v$transaction.XIDUSN
x$ktuxe.KTUXESLT=v$transaction.XIDSLOT
x$ktuxe.KTUXESQN=v$transaction.XIDSQN

# we can dump undo to identify the transaction modify obj

SQL>ALTER SYSTEM DUMP UNDO HEADER "_SYSSMU1523$"; 
or 
SQL>ALTER SYSTEM DUMP UNDO BLOCK "_SYSSMU1523$" XID 1523 4     241934; 

trace file have objn: xxxx
SQL> select object_name,owner,object_type from dba_objects where object_id=xxx;

Note:
I found this object of rollback the dead transaction to update is same as the above update table of sessions waiting “transaction” event.

–Estimate of the duration of a rollback operation , or my previous notes

declare
l_start number;
l_end    number;
begin
select sum(ktuxesiz) into l_start from x$ktuxe where KTUXECFL ='DEAD';
  dbms_lock.sleep(60);
 select sum(ktuxesiz) into l_end from x$ktuxe where KTUXECFL ='DEAD';
  dbms_output.put_line('time est Day:'|| round(l_end/(l_start -l_end)/60/24,2));
end;
 /


SQL> show parameter roll

PARAMETER_NAME                                               TYPE        VALUE
--------------------------------- ----------- ------------------------
fast_start_parallel_rollback                                 string      FALSE
rollback_segments                                            string
transactions_per_rollback_segment                            integer     5

# Enable fast parallel rollback ,to speeding up rollback of dead transactions.(note: This will increase the OS load)

SQL> alter system set fast_start_parallel_rollback=high;

# To monitor Dead transaction rollback speed. wait for rollback completed.

select b.name "UNDO Segment Name", b.inst# "Instance ID", b.status$ STATUS, a.ktuxesiz "UNDO Blocks", a.ktuxeusn, a.ktuxeslt xid_slot, 
  a.ktuxesqn xid_seq, a.ktuxecfl from x$ktuxe a, undo$ b
   where a.ktuxesta = 'ACTIVE' and a.ktuxeusn = b.us#
  and KTUXECFL='DEAD';

# check current wait event

SQL> @a
A-Script: Display active sessions...

  COUNT(*) SQL_ID        STATE   EVENT
---------- ------------- ------- ----------------------------------------------------------------
        58 4fwxf7m2a81qc WAITING transaction
        45 f88awm2ytk9hz WAITING transaction
        36 cw9pdvv3zkfn8 WAITING transaction
        16 8x92ggpcg1n05 WAITING enq: TX - row lock contention
        13 2w35cs2hkbbfm WAITING transaction
         6 5bj7w9pqfdu8w ON CPU  On CPU / runqueue
...

SQL> @a
A-Script: Display active sessions...

  COUNT(*) SQL_ID        STATE   EVENT
---------- ------------- ------- ----------------------------------------------------------------
        15 4fwxf7m2a81qc WAITING enq: TX - row lock contention
        15 cw9pdvv3zkfn8 WAITING enq: TX - row lock contention
        10 f88awm2ytk9hz WAITING enq: TX - row lock contention
         6 5bj7w9pqfdu8w ON CPU  On CPU / runqueue
         3 4a0mttsu898qv WAITING db file sequential read
         3 2ps02qtsffqjn WAITING PX Deq Credit: send blkd
...
SQL> @a
A-Script: Display active sessions...

  COUNT(*) SQL_ID        STATE   EVENT
---------- ------------- ------- ----------------------------------------------------------------
         4 5bj7w9pqfdu8w ON CPU  On CPU / runqueue
         4 9mp66qkb11as8 ON CPU  On CPU / runqueue
         3 9mp66qkb11as8 WAITING direct path read
         3 2ps02qtsffqjn WAITING PX Deq Credit: send blkd
         3 93cwbs13dn0vd WAITING db file sequential read
...

Summary:
A person with a oracle IDE client Toad execute a large update transaction, But then transaction abort before commit or rollback. then SMON process to recover Dead transaction, But because the serial rollback takes a long time, so the new session will to wait “tx” and “transaction” to modify the same data. then I set fast_start_parallel_rollback=High (make sure that you have sufficient free resources for it ), to speed-up the rollback that was currently taking place.until wait the dead transaction rollback completed, the wait events not longer show in active session.

打赏

对不起,这篇文章暂时关闭评论。