Oracle Scratchpad

February 18, 2013

Transactions 2

Filed under: Oracle,Statspack,Troubleshooting — Jonathan Lewis @ 7:54 am BST Feb 18,2013

Here’s a little follow-on from Friday’s posting. I’ll start it off as a quiz, and follow up tomorrow with an explanation of the results (though someone will probably have given the correct solution by then anyway).

I have a simple heap table t1(id number(6,0), n1 number, v1 varchar2(10), padding varchar2(100)). The primary key is the id column, and the table holds 3,000 rows where id takes the values from 1 to 3,000. There are no other indexes. (I’d show you the code, but I don’t want to make it too easy to run the code, I want you to try to work it out in your heads).

I run the following pl/sql block.

begin
	--
	--	Going to fail on primary key constraint
	--
	for i in 1..200 loop
		begin
			insert into t1 values(50,i,'x','x');
			commit;
		exception
			when others then null;
		end;
	end loop;

	--
	--	Explicit rollback
	--
	for i in 1..40 loop
		begin
			insert into t1 values(4000 + i,i,'x','x');
			rollback;
		end;
	end loop;

	--
	--	Explicit commit
	--
	for i in 1..50 loop
		begin
			insert into t1 values(4500 + i,i,'x','x');
			commit;
		end;
	end loop;

	--
	--	Rolling back to savepoint
	--
	for i in 1..70 loop
		begin
			savepoint A;
			insert into t1 values(4600 + i,i,'x','x');
			rollback to savepoint A;
		end;
	end loop;

end;
/

If (from another session) you take an AWR (or Statspack) snapshot before and after running the block, what will you see for the statistics

user commits
user rollbacks
transaction rollbacks
rollback changed – undo records applied

and, for a bonus point, what will the value of “Rollback per transaction %” be ?

Note – since the snapshots are global, your results will be affected by other work on the system; in particular I noticed that simply taking two AWR snapshots in a row on the instance I used resulted in 8 user commits.

Update

And the answers – cut from an AWR report – are:


Statistic                                     Total     per Second     per Trans
-------------------------------- ------------------ -------------- -------------
rollback changes - undo records                 420           25.2           4.3
transaction rollbacks                           240            4.7           2.5
user commits                                     58            1.1           0.6
user rollbacks                                   40            0.8           0.4

 Rollback per transaction %:   40.82       Rows per Sort:   122.70

The 40 “user rollbacks” come from the loop with the explicit rollback. At the same time the 40 rollbacks introduced 80 “rollback changes – undo records applied” – one for the table index and one for the table for each call to rollback. Our “user rollbacks” have been “real” rollbacks, so they’ve introduced 40 transaction rollbacks at the same time.

The 50 “user commits” come from the loop with the explicit commit – except that the picture is slightly blurred by the fact that simply running the AWR snapshot introduced a few extra commits.

The 40.82% is 40 / (40 + 58) expressed as a percentage.

The “rollback to savepoint” calls haven’t contributed to the user rollbacks – even though, in this case, they have rolled back 40 transaction starts, and a check of various other statistics would show a TX enqueue being requested and released, and transactions rotating through the undo segments. Despite this clearing of the TX locks, these rollbacks to savepoint don’t count towards transaction rollbacks; however, the 70 “rollback to savepoint” calls have introduced a further 140 “rollback changes – undo records applied” (again, one for the table and one for the index for each call).

Finally the failed attempts to insert duplicate keys have, in these circumstances, introduced 200 transaction rollbacks (though not user rollbacks – we didn’t ask for them explicitly). They are also responsible for the final 200 “rollback changes – undo records applied” that we need to account for. The changes, very specifically, are the changes to the table – Oracle does actually have to insert the row into the table before trying to insert the index entry (after all, the index entry needs to know the rowid), and so it has to reverse that insert when it discovers that the relevant entry already exists in the primary key index. The requirement to insert and then rollback is one of the reasons why it is often better for “batch merge by pl/sql loop” to try an update then insert is sql%rowcount is zero rather than trying to insert, capture the exception, and then update; it’s also a good reason for creating the unique indexes on a table before creating the non-unique indexes – Oracle maintains indexes in the order they were created so you want it to find the duplicate key error as soon as possible to minimise the amount of change and rollback.

If you want to experiment further, there are a couple of slightly different variations of the code that exhibit interesting variations in results. There are also other events that can cause transaction rollbacks to appear without user rollbacks being invoked.

13 Comments »

  1. Here are my guesses

    the first loop will be responsible for 200 ORA-1 errors which should turn into:
    0 transaction rollbacks ( because the transaction does not start at all)
    0 user rollbacks ( since these are not explicit rollbacks)
    200 rollback changed – undo records applied (to “repair” the ORA-1 errors on the index)

    the second loop will be responsible for 40 insert+rollback which should turn into:
    40 transaction rollbacks
    40 user rollbacks ( since these are explicit rollbacks)
    80 rollback changed – undo records applied (40 changes on the index and 40 changes on the table)

    the third loop will be responsible for 50 insert+commit which should turn into:
    0 transaction rollbacks
    50 user commits
    0 rollback changed – undo records applied (since the ORA-1 errors will not allow us to change anything)

    the fourth loop will be responsible for 70 insert+rollback to savepoint which should turn into:
    0 transaction rollback (the “rollback to savepoint” does not close the transaction even if we rollback to the “starting” savepoint)
    0 user rollbacks (same as before)
    140 rollback changed – undo records applied (70 changes on the index and 70 changes on the table)

    Comment by Andrea Monti — February 18, 2013 @ 8:50 am BST Feb 18,2013 | Reply

    • obviously the “(since the ORA-1 errors will not allow us to change anything)” sentence is due to a wrong cut&paste.
      I forgot to do the arithmetic: we should get

      420 rollback changes – undo records applied
      240 transaction rollbacks
      40 user rollbacks
      50 user commits

      regards
      Andrea

      Comment by Andrea Monti — February 18, 2013 @ 9:01 am BST Feb 18,2013 | Reply

      • How do you get “240 transaction rollbacks” if you post before that “0 transaction rollbacks ( because the transaction does not start at all)” and others give you just 40 ?

        Comment by Valentin Nikotin — February 18, 2013 @ 11:41 am BST Feb 18,2013 | Reply

      • I was in a hurry and my first post was (partially) wrong. The right picture is :

        The first loop will be responsible for 200 ORA-1 errors which should turn into:
        200 transaction rollbacks
        0 user rollbacks
        200 rollback changed – undo records applied (to “repair” the ORA-1 errors on the index only: we did no change on the base table, thus we have no undo record applied on the base table)

        The second loop will be responsible for 40 insert+rollback which should turn into:
        40 transaction rollbacks
        40 user rollbacks ( since these are explicit rollbacks)
        80 rollback changed – undo records applied (40 changes on the index and 40 changes on the table)

        The third loop will be responsible for 50 insert+commit which should turn into:
        0 transaction rollbacks
        50 user commits
        0 rollback changed – undo records applied

        The fourth loop will be responsible for 70 insert+rollback to savepoint which should turn into:
        0 transaction rollback (the “rollback to savepoint” does not close the transaction even if we rollback to the “starting” savepoint)
        0 user rollbacks (same as before)
        140 rollback changed – undo records applied (70 changes on the index and 70 changes on the table)

        We should thus get
        420 rollback changes – undo records applied
        240 transaction rollbacks
        40 user rollbacks
        50 user commits
        (200+40+50) = 290 closed transactions from the first three loops,
        1 open transaction from the last loop
        (40) / (40+50) = 0.44 “Rollback per transaction %” since we should only account for “user commits” and “user rollback” to evaluate this metric

        Next time I’ll double-check my guesses. Regards, Andrea

        Comment by Andrea Monti — February 18, 2013 @ 1:39 pm BST Feb 18,2013 | Reply

  2. 50 user commits
    40 user rollbacks
    240 transaction rollbacks = 200 + 40
    420 rollback changes – undo record = 200 + (40 + 70) * 2 (for index and table)
    0.137 Rollback per transaction % = 40 / (200 + 40 + 50 + 1)

    Comment by Valentin Nikotin — February 18, 2013 @ 9:14 am BST Feb 18,2013 | Reply

  3. user commits                                                             54
    user rollbacks                                                           40
    rollback changes - undo records applied                 420
    transaction rollbacks                                                240
    

    Comment by Mohamed Houri — February 18, 2013 @ 9:39 am BST Feb 18,2013 | Reply

  4. a small correction for user commits

    user commits                                 50  
    user rollbacks                               40  
    rollback changes - undo records applied      420  
    transaction rollbacks                        240 
    

    Comment by Mohamed Houri — February 18, 2013 @ 9:54 am BST Feb 18,2013 | Reply

  5. I’ve now updated the post with my results and a few comments.

    Comment by Jonathan Lewis — February 18, 2013 @ 9:52 pm BST Feb 18,2013 | Reply

  6. Jonathan,

    Unless I missed something I found a different behavior for transaction rollbacks statistic when using DML error logging. This statistic seems not be incremented in this particular case. The column id is the primary key of table t1 and id = 1 has already been inserted into t1.The test has been conducted under Oracle Database 10g Enterprise Edition Release 10.2.0.4.0 – 64bi

    SQL> start c:\stats#
    
    NAME                                      VALUE
    ---------------------------------------- -------
    user commits                               1
    user rollbacks                             0
    rollback changes - undo records applied    0
    transaction rollbacks                      0
    
    SQL> begin
      2          insert into t1(id) values(1);
      3          commit;
      4        exception
      5         when others then
      6           null;
      7        end;
      8        /
    
    PL/SQL procedure successfully completed.
    
    SQL> start c:\stats#
    
    NAME                                      VALUE
    ----------------------------------------- ------
    user commits                               1
    user rollbacks                             0
    rollback changes - undo records applied    1
    transaction rollbacks                      1
    
    SQL> select count(1) from t1;
    
      COUNT(1)
    ----------
             1
    
    SQL> select count(1) from err$_t1;
    
      COUNT(1)
    ----------
             0
    
    SQL> begin
      2          insert into t1(id) values(1)
      3          log errors into err$_t1 reject limit unlimited;
      4          commit;
      5        exception
      6         when others then
      7           null;
      8        end;
      9        /
    
    PL/SQL procedure successfully completed.
    
    SQL> start c:\stats#
    
    NAME                                          VALUE
    --------------------------------------------- ------
    user commits                                   1
    user rollbacks                                 0
    rollback changes - undo records applied        2
    transaction rollbacks                          1
    
    SQL> select count(1) from t1;
    
      COUNT(1)
    ----------
             1
    
    SQL> select count(1) from err$_t1;
    
      COUNT(1)
    ----------
             1
    

    Comment by Houri — February 19, 2013 @ 8:31 am BST Feb 19,2013 | Reply

    • The same for forall save exceptions:

      [oracle@DB1 ~]$ cat test.sql
      drop table u.t1 purge;
      
      create table u.t1(id number(6,0) primary key, n1 number, v1 varchar2(10), padding varchar2(100));
      insert into u.t1 select level, 1, 'x', 'x' from dual connect by level <= 3000;
      
      exec dbms_workload_repository.create_snapshot;
      
      declare
          a1 dbms_sql.number_table;
      begin
          for i in 1 .. &1 loop
            a1(i) := i;
          end loop;
          
          begin
              forall i in 1..&1 save exceptions
                  insert into u.t1 values(50,a1(i),'x','x');
          exception
              when others then null;
          end;
      
          for i in 1..&2 loop
              begin
                  insert into u.t1 values(50,i,'x','x');
                  commit;
              exception
                  when others then null;
              end;
          end loop;
      
      end;
      /
      
      exec dbms_workload_repository.create_snapshot;
      
      define num_days = 1;
      
      column inst_num   new_value inst_num  format 99999;
      column inst_name  new_value inst_name format a12;
      column db_name    new_value db_name   format a12;
      column dbid       new_value dbid      format 9999999999;
      
      select d.dbid            dbid
           , d.name            db_name
           , i.instance_number inst_num
           , i.instance_name   inst_name
        from v$database d,
             v$instance i;
      
      column begin_snap new_value begin_snap  format 99999;
      column end_snap   new_value end_snap    format 99999;
      
      select max(snap_id) end_snap, max(snap_id)-1 begin_snap from dba_hist_snapshot;
      
      define  report_type  = 'text';
      define  report_name  = '';
      
      @@?/rdbms/admin/awrrpti
      
      exit
      
      [oracle@DB1 ~]$ sqlplus / as sysdba @test 200 0 | egrep "user commits|user rollbacks|transaction rollbacks|rollback changes"
      rollback changes - undo records                 201          348.4          18.3
      transaction rollbacks                             0            0.0           0.0
      user commits                                     11           19.1           1.0
      user rollbacks                                    0            0.0           0.0
      [oracle@DB1 ~]$ sqlplus / as sysdba @test 0 200 | egrep "user commits|user rollbacks|transaction rollbacks|rollback changes"
      rollback changes - undo records                 200          338.4          18.2
      transaction rollbacks                           200          338.4          18.2
      user commits                                     11           18.6           1.0
      user rollbacks                                    0            0.0           0.0
      [oracle@DB1 ~]$ 
      

      Comment by Valentin Nikotin — February 19, 2013 @ 9:18 am BST Feb 19,2013 | Reply

      • Valentin,

        Thanks for the demo; if you hadn’t come up with this example, I would have suggested it as another area for Mohamed to look at.

        One of the big problems I find with Oracle – as soon as I start looking at something a little bit too closely I keep finding more and more cases that ought to be examined at the same time. Are there any differences regarding recursive call counts between the bulk exceptions strategy and the error logging strategy, for example ? And does this change with version ?

        I thought I had a blog with some quick demos of the interesting side effects and costs of error logging – but it turns out that the thing I had in mind was an article that Mark Rittman wrote about it nearly 8 years ago, with a little 11g follow-up reference a couple of years later.

        Comment by Jonathan Lewis — February 19, 2013 @ 10:59 am BST Feb 19,2013 | Reply

    • Mohamed,

      Thanks for the example. I think the results are as I would have guessed. Having covered this case, it would be interesting to extend the checks to get to (a) multiple indexes, not all unique, (b) multiple rows rejected, including first, middle, and last rows of insert as select. It would also be interesting to take a note of how the logging action affected the number of recursive calls.

      Comment by Jonathan Lewis — February 19, 2013 @ 10:51 am BST Feb 19,2013 | Reply

  7. Jonathan,
    I have tried what you’ve suggested me to do and here are the results:
    The model is :

    drop table t_target purge;
    drop table err$_t_target purge;
    drop table t_source;
    
    create table t_target
    as 
       select 
        level  n1
      ,trunc(dbms_random.value(1,250)) n2
      ,date'2012-06-07' + mod((level-1)*5,10)   start_date   
    	 ,rpad('xx',10) padding
       from dual
      connect
        by level <= 1000;	 
    
    alter table t_target add constraint t_g_pk primary key(n1);
    alter table t_target modify start_date not null;
    create index t_g_ind1 on t_target(n2);
    exec dbms_errlog.create_error_log('t_target');
    
    create table t_source as
        select 
         case rownum 
            when 1 then 1 
            when 10 then 10
          else rownum + 1000 end id1
        , mod(rownum-1, 10) id2
        ,case mod(rownum,3)
            when 0 then null
        else sysdate + rownum end date1
    from dual
      connect by level <= 10;
    

    Run without DML error logging

    /* 
    1. insert id 1 --> duplicate record rejected
    2. insert several successful rows
    3. insert 3 rejected rows dues to null start_date
    4. insert several successful rows
    5. insert id = 10 --> duplicate record rejected
    */
    @@c:\stats#
    begin
      for x in (select   
            id1
           ,id2
           ,date1
           ,'yy'
      from
          t_source
    ) loop
    begin
      insert into t_target
       (n1, n2,start_date, padding)
      values
        (x.id1, x.id2, x.date1, 'yy');  
      commit;
     exception
       when others then
         null;
     end;
    end loop;
    end;        
    /
    @@c:\stats#
    
    NAME                                       VALUE
    ----------------------------------------- ----------
    user commits                                9
    user rollbacks                              0
    recursive calls                             25331
    rollback changes - undo records applied     0
    transaction rollbacks                       0
    
    PL/SQL procedure successfully completed.
    
    NAME                                        VALUE
    ------------------------------------------- ----------
    user commits                                14
    user rollbacks                              0
    recursive calls                             25482  151
    rollback changes - undo records applied     2
    transaction rollbacks                       2      2 
    

    Run with DML error logging

    /* -------------------------------------------------
    1. insert id 1 --> duplicate record rejected
    2. insert several successful rows
    3. insert 3 rejected rows dues to null start_date
    4. insert several successful rows
    5. insert id = 10 --> duplicate record rejected
    * -------------------------------------------------- */
    @@c:\stats#
    
    begin
      for x in (select   
            id1
           ,id2
           ,date1
           ,'yy'
      from
          t_source
    ) loop
    begin
      insert into t_target
       (n1, n2,start_date, padding)
      values
        (x.id1, x.id2, x.date1, 'yy')
      log errors into err$_t_target reject limit unlimited;
      commit;
     exception
       when others then
         null;
     end;
    end loop;
    end;        
    /
    @@c:\stats#
    
    NAME                                        VALUE
    ------------------------------------------- -------
    user commits                                22
    user rollbacks                              0
    recursive calls                             34291
    rollback changes - undo records applied     2
    transaction rollbacks                       2
    
    PL/SQL procedure successfully completed.
    
    NAME                                        VALUE
    ---------------------------- -------------- -----
    user commits                                27
    user rollbacks                              0
    recursive calls                             34488  197
    rollback changes - undo records applied     4
    transaction rollbacks                       2      0
    

    When I changed a little bit my DML error logging script in order to use direct path load I got the following results:

    @@c:\stats#
    
    begin
      insert /*+ append */ into t_target
       (n1, n2,start_date, padding)
      select   
            id1
           ,id2
           ,date1
           ,'yy'
      from
          t_source
      log errors into err$_t_target reject limit unlimited;
      commit;
    end;
    /
    @@c:\stats#
    
    
    
    NAME                                         VALUE
    -------------------------------------------- ----------
    user commits                                 62
    user rollbacks                               0
    recursive calls                              99427
    rollback changes - undo records applied      7
    transaction rollbacks                        3
    
    begin
    *
    ERROR at line 1:
    ORA-00001: unique constraint (XXX.T_G_PK) violated
    ORA-06512: at line 2
    
    
    NAME                                         VALUE
    -------------------------------------------- ----------
    user commits                                 62
    user rollbacks                               0
    recursive calls                              99571
    rollback changes - undo records applied      8
    transaction rollbacks                        4   1
    
    SQL> select ORA_ERR_MESG$ from err$_t_target;
    
    ORA_ERR_MESG$
    --------------------------------------------------------------------
    ORA-01400: cannot insert NULL into ("XXX"."T_TARGET"."START_DATE")
    ORA-01400: cannot insert NULL into ("XXX"."T_TARGET"."START_DATE")
    ORA-01400: cannot insert NULL into ("XXX"."T_TARGET"."START_DATE")
    

    As far as the DML Error logging is able to catch the error and let the insert continue there seem to be no transaction rollbacks applied. Unless you hit a restriction of the DML error logging (as unique constraint during direct path) where transaction rollbacks statistics starts to be incremented.

    Comment by Houri — February 20, 2013 @ 8:27 am BST Feb 20,2013 | Reply


RSS feed for comments on this post. TrackBack URI

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s

The Rubric Theme Blog at WordPress.com.

Follow

Get every new post delivered to your Inbox.

Join 3,453 other followers