4 Replies Latest reply: Jan 8, 2013 2:48 PM by MaJo RSS

    tx-transaction

    MaJo
      Hello !

      Env: redhat Linux 5, Oracle 11.2.0.3.4 single instance

      we have an application that processes "messages", the message comes in and passes various steps (up to 25 steps)
      for each step the application does a commit.

      Only one session per message (according to the vendor) so there shouldn't be two sessions updating the same data
      but we processes many messages at the same time so we have around 90 sessions performing inserts and updates.

      the messages are in one table and uses blobs, for each step the blob is updated

      From time to time we see enq: tx - contention

      Snap Id Snap Time Sessions Curs/Sess
      --------- ------------------- -------- ---------
      Begin Snap: 22507 08-Jan-13 16:30:58 294 12.4
      End Snap: 22508 08-Jan-13 16:45:04 293 12.4
      Elapsed: 14.08 (mins)
      DB Time: 139.55 (mins)

      Top 5 Timed Foreground Events
      ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
      Avg
      wait % DB
      Event Waits Time(s) (ms) time Wait Class
      ------------------------------ ------------ ----------- ------ ------ ----------
      enq: TX - contention 7,901 4,836 612 57.8 Other
      db file sequential read 280,463 1,421 5 17.0 User I/O
      DB CPU 872 10.4
      log file sync 147,117 492 3 5.9 Commit
      direct path write 26,445 434 16 5.2 User I/O

      Enqueue Activity DB/Inst: GGBISP01/ggbisp01 Snaps: 22507-22508
      -> only enqueues with waits are shown
      -> Enqueue stats gathered prior to 10g should not be compared with 10g data
      -> ordered by Wait Time desc, Waits desc

      Enqueue Type (Request Reason)
      ------------------------------------------------------------------------------
      Requests Succ Gets Failed Gets Waits Wt Time (s) Av Wt Time(ms)
      ------------ ------------ ----------- ----------- ------------ --------------
      TX-Transaction
      287,537 229,859 57,678 7,896 4,835 612.33
      TX-Transaction (index contention)
      322 322 0 287 16 55.92
      TX-Transaction (row lock contention)
      5 5 0 5 0 2.00
      DX-Distributed Transaction
      748,789 748,705 0 2 0 .00


      I have read various notes on Oracle Support but are a bit puzzled. If I understand rights this enqueue
      is not related to "row locks" and if I'm right it shouldn't since only one sessions update the data and row locks contention has its own event
      The same for itl issues and index contention.

      So my question is can I drill down further to understand what is going on here ? (like locking info when it happens)
      or is this as much information I get, what conclusions should I make if that is the case ?

      Appreciate your comments !

      Best regards
      Magnus Johansson
        • 1. Re: tx-transaction
          jgarry
          Please surround your output with
           tags to make it more readable.
          
          See this: what causes enq: TX - index contention?
          
          If you have Enterprise Edition with the perf packs you may be able to visualize the issue with top activity screens.                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                    
          • 2. Re: tx-transaction
            Dom Brooks
            You need to drill down and find the lock mode and the object.

            I would suggest using ASH to do this (which requires Diagnostic Pack license which is the same as AWR which you're already using).

            Look at V$ACTIVE_SESSION_HISTORY and DBA_HIST_ACTIVE_SESS_HISTORY and you should see if there is a outlier in terms of mode and object.

            For example, a simple aggregation over your recent history might be done like this:
            select event, mod(p1,16), current_obj#
            ,      (select object_name from dba_objects where object_id = current_obj#) obj
            from   v$active_session_history
            where  event like 'enq: TX%'
            group by event, mod(p1,16), current_obj#
            order by count(*) desc;
            You can also get crucial information about who is blocking who and the sql being executed by the session that is blocked.

            V$ACTIVE_SESSION_HISTORY is a sample of all active sessions taken every second. It's a in-memory buffer so the period covered depends on the size of the buffer and the volume of active sessions.
            You can go back further using DBA_HIST_ACTIVE_SESS_HISTORY but it's a one-in-ten sample of V$ACTIVE_SESSION_HISTORY so you can start to miss some crucial details.
            • 3. Re: tx-transaction
              Jonathan Lewis
              MaJo wrote:

              From time to time we see enq: tx - contention
              Top 5 Timed Foreground Events
              ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
              Avg
              wait   % DB
              Event                                 Waits     Time(s)   (ms)   time Wait Class
              ------------------------------ ------------ ----------- ------ ------ ----------
              enq: TX - contention                  7,901       4,836    612   57.8 Other
              db file sequential read             280,463       1,421      5   17.0 User I/O
              DB CPU                                              872          10.4
              log file sync                       147,117         492      3    5.9 Commit
              direct path write                    26,445         434     16    5.2 User I/O
              
              
              Enqueue Type (Request Reason)
              ------------------------------------------------------------------------------
              Requests    Succ Gets Failed Gets       Waits  Wt Time (s) Av Wt Time(ms)
              ------------ ------------ ----------- ----------- ------------ --------------
              TX-Transaction
              287,537      229,859      57,678       7,896        4,835         612.33
              TX-Transaction (index contention)
              322          322           0         287           16          55.92
              TX-Transaction (row lock contention)
              5            5           0           5            0           2.00
              DX-Distributed Transaction
              748,789      748,705           0           2            0            .00
              Dom Brooks has given you a method for researching this (if you have the relevant licences), but here are a couple of thoughts about possibilities.

              There are several things that result in the generic "enq: tx - contention", some of them are about space management - which could fit with your use of blobs - one of them is about distributed transactions - which could fit with the DX enqueues, and given the order of magnitude of the two you've got it's possible that that one is the more likely.

              In a two-phase commit, one session does a "prepare" (phase 1) folllowed by a "commit" (phase 2). If a second session tries to read the block between the prepare and the commit, it isn't allowed to, and has to wait for the commit to complete. (The actual mechanism changed to eliiminate the wait when using a transaction processing monitor, but it is still relevant to two oracle databases using db links.) There's a note I wrote about this some 12 years ago here: http://www.jlcomp.demon.co.uk/02_tpm.rtf

              If it's about space management - blobs tends to grow very quickly, and can cause a demand for tablespace (or file) growth if you're files are autoextend. If two sessions need space in the same segment which needs to grow, and they have to grow the file before they can grow the segment, one of them will wait on the other and record this event. If this is the case you will probably see a number for "TBS Extension: files extended" in the instance activity statistics.

              In both cases the TX mode will be mode 4.

              Regards
              Jonathan Lewis
              • 4. Re: tx-transaction
                MaJo
                Thanks all for your feedback, I appreciate it.

                Space issue has crossed my mind, before christmas we saw frequent w000-w009 processes
                and they were consuming a lot of cpu. I found a note about that and it was pointing out a bug
                Wnnn processes consuming high CPU [ID 1492880.1]
                It is fixed in future releases, but a one of patch exists but not for the exact version we are on.

                I disabled the SMCO process and the processes consuming cpu was gone.

                Reading what SMCO does I think disabling SMCO would introduce another way of handling auto extent of datafiles and perhaps also lob segments
                which I think can have put us in the current situation.

                We have adjusted size for auto extent of datafiles and next extent of tables and blob segments
                but I have to check that again.

                I will also use the information you provided to diagnose and hopefully confirm the scenario. I expect to see the behavior tomorrow again.

                Thanks !

                Magnus Johansson