Re[4]: what exactly 'tim' means in a 10046 TRACE file ?
- From: Edgar Chupit <chupit@xxxxxx>
- To: Anjo Kolk <oracle-l@xxxxxxxxxxxxx>
- Date: Wed, 31 Mar 2004 19:34:53 +0300
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 //www.freelists.org/archives/oracle-l/
FAQ is at //www.freelists.org/help/fom-serve/cache/1.html
-----------------------------------------------------------------
Other related posts:
