Re[4]: what exactly 'tim' means in a 10046 TRACE file ?

Hello Anjo,

AK> 24381, 00000, "error(s) in array DML"
AK> // *Cause:  One or more rows failed in the DML.
AK> // *Action: Refer to the error stack in the error handle.

AK> that  will  consume  the  CPU. In fact your error is not really an
AK> error  but  an  indication  that  the  application need to check a
AK> couple of rows of the array that failed.

It's  exactly  whats  happening,  but  isn't  error  handling (such as
checking  that  index  block  already  filled  with data, saving error
information, something else?) consumes some amount of response time?

I've  created  test  using  Tom  Kytes  runstats_pkg and it shows that
processing of duplicate rows consumes "some" amount of resources.

I  have verified Niall hypothesis, but have found out that ERROR's tim
value is value returned by v$timer (Note:43735.1):
Time  is measured since the beginning of the epoch, which is operating
system  specific,  and  wraps  around  to  0  again whenever the value
overflows four bytes (roughly 497 days).

At  least  on  Linux  this  seams  to  be  true  and  to  convert from
gettimeofday to value that is returned from v$timer you simply need to
strip highest bit something like tv_sec&~0x80000000 and this gives the
same value as in tim line of trace file for ERROR line.

Here  is  my  little  test,  could  somebody  confirm that by "fixing"
application  so  it  wouldn't insert "duplicate" rows we could perform
better than now?

-- test --
create table test1 ( id integer, value number )
/

insert into test1 
select rownum, rownum*rownum
from all_objects 
where rownum < 1000
/

create unique index test1_pk on test1(id)
/

begin
    otis.runstats_pkg.rs_start;
    
    declare 
      type row_type is table of test1%rowtype;
      rw row_type;
    begin
       select id, value bulk collect into rw from test1 where rownum < 100 ;
       
       forall i in rw.first .. rw.last save exceptions
          insert into test1 values rw(i);
    exception when others then
       null;
    end;

    otis.runstats_pkg.rs_middle;

    declare 
      type row_type is table of test1%rowtype;
      rw row_type;
    begin
       select id+10000, value bulk collect into rw from test1 where rownum < 
100;
       
       forall i in rw.first .. rw.last save exceptions
          insert into test1 values rw(i);
    exception when others then
       null;
    end;

    otis.runstats_pkg.rs_stop;
end;
/

-- results --
/*
Run1 ran in 12 hsecs
Run2 ran in 1 hsecs
run 1 ran in 1200% of the time
        

Name                                Run1      Run2      Diff
-- skip
LATCH.library cache pin            1,051        12    -1,039
LATCH.library cache                1,068        13    -1,055
STAT...recursive calls             1,392         5    -1,387
STAT...session logical reads       2,075       538    -1,537
LATCH.cache buffers chains         6,238     2,633    -3,605
STAT...redo size                 192,772    69,524  -123,248
STAT...session pga memory        131,072         0  -131,072
        

Run1 latches total versus runs -- difference and pct
      Run1      Run2      Diff     Pct
    10,063     3,456    -6,607 291.17%
*/


-- 
 Edgar                            

----------------------------------------------------------------
Please see the official ORACLE-L FAQ: http://www.orafaq.com
----------------------------------------------------------------
To unsubscribe send email to:  oracle-l-request@xxxxxxxxxxxxx
put 'unsubscribe' in the subject line.
--
Archives are at http://www.freelists.org/archives/oracle-l/
FAQ is at http://www.freelists.org/help/fom-serve/cache/1.html
-----------------------------------------------------------------

Other related posts: