Friday, December 7, 2012

Delete Restart and new Active Undo Extent

Oracle dbms_lock.allocate_unique allocates a unique lock ID to a named lock,  and returns the handle associated with the lock ID so that application can use this handle in subsequent calls to request, convert, and release.

allocate_unique occasionally runs:
   delete dbms_lock_allocated where expiration < sysdate;
to clean up expired UL locks.

This delete statement makes me rethink my previous Blog: "Update Restart and new Active Undo Extent"

is this delete can also cause Restart ?

The appended test code confirms it (tested on AIX and Solaris in Release 11.2.0.3.0).

When several sessions call allocate_unique, it can cause certain "enq: TX - row lock contention" on dbms_lock_allocated.

As a unintentional side effect, once more than 100000 "UL" locks are generated by dbms_lock.request, queries on v$lock and v$enqueue_lock are heavily affected, even after all "UL" locks are released.

Test Code


create or replace function get_undo_extent_cnt return number
as
  l_cnt number;
begin  
 select count(*) into l_cnt from dba_undo_extents where status = 'ACTIVE';
 return l_cnt;
end;
/


create or replace package pacepack
as
  type array is table of number index by varchar2(40);
  g_data                  array;
  g_cnt                   number;
  g_restart_cnt           number;
  g_undo_extent_cnt       number;
end pacepack;
/


drop table delete_data;

create table delete_data as
  select sysdate + level/86400 tim, rpad('abc', 100, 'x') txt from dual connect by level <= 100000;
   
create or replace trigger delete_data_bt
  before delete or update on delete_data
  for each row
begin
  if ( pacepack.g_data.exists(rowidtochar(:old.rowid)))
  then
    pacepack.g_restart_cnt := pacepack.g_restart_cnt + 1;
  
    dbms_output.put_line( 'doing "' || :old.rowid ||
                           '" again was called ' || pacepack.g_cnt );
    dbms_output.put_line('-- Restart#: ' || pacepack.g_restart_cnt ||
                            ', Undo Extent Count: ' || get_undo_extent_cnt);
  else
    pacepack.g_data(rowidtochar(:old.rowid)) := 1;
  end if;
     
  pacepack.g_cnt        := pacepack.g_cnt + 1;
end;
/


create or replace procedure testp as
  l_cnt     number := 0;
  l_del_cnt number;
begin
  pacepack.g_data.delete;
  pacepack.g_cnt         := 0;
  pacepack.g_restart_cnt := 0;
       
  delete delete_data where tim <= (select max(tim) from delete_data);
  
  l_del_cnt := sql%rowcount;
  dbms_output.put_line( 'trigger_count (' || pacepack.g_cnt         || ') = ' ||
                        'delete_count  (' || l_del_cnt              || ') + ' ||
                        'restart_count (' || pacepack.g_restart_cnt || ') = ' ||
                         (l_del_cnt +  pacepack.g_restart_cnt)
                      );
       
  commit;
 
 end;
/


exec testp;
/

Output


doing "AAC2jpAAAAAHmm2AAF" again was called 10716
-- Restart#: 1, Undo Extent Count: 5
doing "AAC2jpAAAAAHmoFAAS" again was called 15581
-- Restart#: 2, Undo Extent Count: 6
doing "AAC2jpAAAAAHmpSAAf" again was called 20446
-- Restart#: 3, Undo Extent Count: 7
doing "AAC2jpAAAAAHmqhAAs" again was called 25311
-- Restart#: 4, Undo Extent Count: 8
doing "AAC2jpAAAAAHmruAA5" again was called 30176
-- Restart#: 5, Undo Extent Count: 9
doing "AAC2jpAAAAAHms+AAH" again was called 35041
-- Restart#: 6, Undo Extent Count: 10
doing "AAC2jpAAAAAHmuNAAU" again was called 39906
-- Restart#: 7, Undo Extent Count: 11
doing "AAC2jpAAAAAHmvaAAh" again was called 44771
-- Restart#: 8, Undo Extent Count: 12
doing "AAC2jpAAAAAHmwpAAu" again was called 49636
-- Restart#: 9, Undo Extent Count: 13
doing "AAC2jpAAAAAHmx2AA7" again was called 54501
-- Restart#: 10, Undo Extent Count: 14
doing "AAC2jpAAAAAHmzGAAJ" again was called 59366
-- Restart#: 11, Undo Extent Count: 15
doing "AAC2jpAAAAAHm0VAAW" again was called 64231
-- Restart#: 12, Undo Extent Count: 16
doing "AAC2jpAAAAAHm1iAAj" again was called 69096
-- Restart#: 13, Undo Extent Count: 17
doing "AAC2jpAAAAAHm2xAAw" again was called 73961
-- Restart#: 14, Undo Extent Count: 18
doing "AAC2jpAAAAAHm3+AA9" again was called 78826
-- Restart#: 15, Undo Extent Count: 19
doing "AAC2jpAAAAAHm5OAAL" again was called 83691
-- Restart#: 16, Undo Extent Count: 20
doing "AAC2jpAAAAAHm6dAAY" again was called 88556
-- Restart#: 17, Undo Extent Count: 21
doing "AAC2jpAAAAAHm7qAAl" again was called 93421
-- Restart#: 18, Undo Extent Count: 22
doing "AAC2jpAAAAAHm85AAy" again was called 98286
-- Restart#: 19, Undo Extent Count: 23
trigger_count (100019) = delete_count  (100000) + restart_count (19) = 100019


So for each restart, a new active Undo Extent is created.