| Oracle FAQ | Your Portal to the Oracle Knowledge Grid | |
 |
 | |||
| Oracle FAQ | Your Portal to the Oracle Knowledge Grid | |
|
| |||
Home -> Community -> Usenet -> c.d.o.server -> Re: fluctuating execution times
In article <Pfb_7.5309$wd1.655718_at_news11-gui.server.ntli.net>, "Keith says...
>
>Could it not be the acquisition of a new initialised block / acquisition of
>transaction entry in the block etc.?
doubt it.
>
>The values being inserted are three zeroes, which at about 2 bytes each plus
>a 1 byte row header, plus a little block overhead would workout at around
>1000 rows per 8k block. If you could fit just a little more than this in the
>block, and block acquisition was significant, you might get the behaviour
>observed.
>
>I don't think the redo logs would be as small as 8K!
three columns, one index (and not knowing about anything else) and the redo would be 64k or so for a SINGLE insert with 1,000 rows, it will be 1/2meg if you insert 1000 rows INDIVIDUALLY and closer to 1meg if you insert 1000 rows and commit each one -- you never know. I've seen worse...
ops$tkyte_at_ORA817DEV.US.ORACLE.COM> create table t ( x int, y int, z int );
Table created.
ops$tkyte_at_ORA817DEV.US.ORACLE.COM> create index t_idx on t(x);
Index created.
ops$tkyte_at_ORA817DEV.US.ORACLE.COM> ops$tkyte_at_ORA817DEV.US.ORACLE.COM> ops$tkyte_at_ORA817DEV.US.ORACLE.COM> set serveroutput on ops$tkyte_at_ORA817DEV.US.ORACLE.COM> declare 2 begin_value number; 3 end_value number; 4 begin 5 select b.value into begin_value 6 from v$statname a, v$mystat b 7 where a.statistic# = b.statistic# 8 and a.name = 'redo size' 9 and b.value > 0; 10 11 insert into t select '0', '0', '0' from all_objects where rownum <= 1000; 12 13 select b.value-begin_value into end_value 14 from v$statname a, v$mystat b 15 where a.statistic# = b.statistic# 16 and a.name = 'redo size' 17 and b.value > 0; 18 19 dbms_output.put_line( 'redo size = ' ||to_char(end_value,'999,999,999') );
PL/SQL procedure successfully completed.
ops$tkyte_at_ORA817DEV.US.ORACLE.COM> ops$tkyte_at_ORA817DEV.US.ORACLE.COM> ops$tkyte_at_ORA817DEV.US.ORACLE.COM> ops$tkyte_at_ORA817DEV.US.ORACLE.COM> declare 2 begin_value number; 3 end_value number; 4 begin 5 select b.value into begin_value 6 from v$statname a, v$mystat b 7 where a.statistic# = b.statistic# 8 and a.name = 'redo size' 9 and b.value > 0; 10 11 for i in 1 .. 1000 12 loop 13 insert into t values ( '0', '0', '0' ); 14 end loop;
17 select b.value-begin_value into end_value 18 from v$statname a, v$mystat b 19 where a.statistic# = b.statistic# 20 and a.name = 'redo size' 21 and b.value > 0; 22 23 dbms_output.put_line( 'redo size = ' ||to_char(end_value,'999,999,999') );
PL/SQL procedure successfully completed.
ops$tkyte_at_ORA817DEV.US.ORACLE.COM>
ops$tkyte_at_ORA817DEV.US.ORACLE.COM> declare
2 begin_value number; 3 end_value number; 4 begin 5 select b.value into begin_value 6 from v$statname a, v$mystat b 7 where a.statistic# = b.statistic# 8 and a.name = 'redo size' 9 and b.value > 0; 10 11 for i in 1 .. 1000 12 loop 13 insert into t values ( '0', '0', '0' ); 14 commit; 15 end loop;
18 select b.value-begin_value into end_value 19 from v$statname a, v$mystat b 20 where a.statistic# = b.statistic# 21 and a.name = 'redo size' 22 and b.value > 0; 23 24 dbms_output.put_line( 'redo size = ' ||to_char(end_value,'999,999,999') );
PL/SQL procedure successfully completed.
>
>"Thomas Kyte" <tkyte_at_us.oracle.com> wrote in message
>news:a1a3ha01mhm_at_drn.newsguy.com...
>> In article <a19ov5$p3sst$1_at_ID-54600.news.dfncis.de>, "Steffen says...
>> >
>> >
>> >"Thomas Kyte" <tkyte_at_us.oracle.com> wrote in message
>> >news:a17h6c02fqq_at_drn.newsguy.com...
>> >> In article <a17bh5$m5jr8$1_at_ID-54600.news.dfncis.de>, "Steffen says...
>> >> >
>> >> >i execute a stmt 1000 times in 10 loops against a oracle 8.0.5, but
>the
>> >> >execution time fluctuates dramatic
>> >> >i have no clue why
>> >> >
>> >>
>> >> are you working in a dust free lab with your own network, no other
>users?
>> >
>> >yap
>> >
>> >> Is the database a single user database?
>> >
>> >yap
>> >
>> >> is the server a single user server?
>> >
>> >yap
>> >
>> >> is the network free from all other traffic?
>> >
>> >yap
>> >
>> >
>> >> If not, everything will flucuate.
>> >>
>> >> Although, based on the pattern I see below (fast, slow, fast, slow,
>fast,
>> >slow
>> >> or fast, fast, slow, fast, fast, slow and so on) -- it could very well
>be
>> >that
>> >> your redo logs are undersized, your alert log is full of "cannot
>allocate
>> >new
>> >> log" and you are seeing the system pause while a checkpoint or archival
>> >> completes.
>> >>
>> >> Review your alert log. Use things like STATSPACK and TKPROF/SQL_TRACE
>to
>> >> diagnose performance releated issues.
>> >
>> >
>> >i'll check this out, but.. if it would be the redo log shouldn't it be
>same
>> >same for all tests, because redos depend on the amount of inserted rows
>> >
>>
>> It does apppear to be the same for all tests.
>>
>> fast, slow, fast, slow, fast, slow = 1000 rows inserted.
>>
>> fast, fast, slow, fast, fast, slow, fast, fast, slow = 333 rows inserted.
>>
>>
>> slow, slow, slow, slow, slow = not using prepared statements so you burnt
>so
>> many CPU cycles parsing, the IO didn't count anymore (it had a chance to
>catch
>> up all on its own).
>>
>>
>> Looks like you fit maybe about 1,000 rows into the redo logs before
>wrapping and
>> then wait for a checkpoint to complete. Looks fairly consistent.
>>
>> >>
>> >> >i thought:
>> >> >allocating extends takes times - no it seems to be another thing, coz
>it
>> >> >does depends on the number of rows how offen the exec. time fluctuates
>> >> >lazy writer?
>> >> >other?
>> >> >
>> >> >damned!!! plz help :-)
>> >> >
>> >> >
>> >> >Oracle JDBC driver
>> >> >batchsupport: true
>> >> >1) 1000 unprepared stmts: insert into BatchTest (c1, c2, c3) values
>> >> >('0','0',0) : 4997 ms
>> >> >1) 1000 unprepared stmts: insert into BatchTest (c1, c2, c3) values
>> >> >('0','0',0) : 6449 ms
>> >> >1) 1000 unprepared stmts: insert into BatchTest (c1, c2, c3) values
>> >> >('0','0',0) : 4106 ms
>> >> >1) 1000 unprepared stmts: insert into BatchTest (c1, c2, c3) values
>> >> >('0','0',0) : 6249 ms
>> >> >1) 1000 unprepared stmts: insert into BatchTest (c1, c2, c3) values
>> >> >('0','0',0) : 4106 ms
>> >> >1) 1000 unprepared stmts: insert into BatchTest (c1, c2, c3) values
>> >> >('0','0',0) : 6319 ms
>> >> >1) 1000 unprepared stmts: insert into BatchTest (c1, c2, c3) values
>> >> >('0','0',0) : 4206 ms
>> >> >1) 1000 unprepared stmts: insert into BatchTest (c1, c2, c3) values
>> >> >('0','0',0) : 6800 ms
>> >> >1) 1000 unprepared stmts: insert into BatchTest (c1, c2, c3) values
>> >> >('0','0',0) : 4427 ms
>> >> >1) 1000 unprepared stmts: insert into BatchTest (c1, c2, c3) values
>> >> >('0','0',0) : 6589 ms
>> >> >2) single unprepared jdbc batch with 1000 stmts: insert into BatchTest
>> >(c1,
>> >> >c2, c3) values ('0','0',0) : 4476 ms
>> >> >2) single unprepared jdbc batch with 1000 stmts: insert into BatchTest
>> >(c1,
>> >> >c2, c3) values ('0','0',0) : 6630 ms
>> >> >2) single unprepared jdbc batch with 1000 stmts: insert into BatchTest
>> >(c1,
>> >> >c2, c3) values ('0','0',0) : 4497 ms
>> >> >2) single unprepared jdbc batch with 1000 stmts: insert into BatchTest
>> >(c1,
>> >> >c2, c3) values ('0','0',0) : 6970 ms
>> >> >2) single unprepared jdbc batch with 1000 stmts: insert into BatchTest
>> >(c1,
>> >> >c2, c3) values ('0','0',0) : 4527 ms
>> >> >2) single unprepared jdbc batch with 1000 stmts: insert into BatchTest
>> >(c1,
>> >> >c2, c3) values ('0','0',0) : 6920 ms
>> >> >2) single unprepared jdbc batch with 1000 stmts: insert into BatchTest
>> >(c1,
>> >> >c2, c3) values ('0','0',0) : 4587 ms
>> >> >2) single unprepared jdbc batch with 1000 stmts: insert into BatchTest
>> >(c1,
>> >> >c2, c3) values ('0','0',0) : 6669 ms
>> >> >2) single unprepared jdbc batch with 1000 stmts: insert into BatchTest
>> >(c1,
>> >> >c2, c3) values ('0','0',0) : 4616 ms
>> >> >2) single unprepared jdbc batch with 1000 stmts: insert into BatchTest
>> >(c1,
>> >> >c2, c3) values ('0','0',0) : 7571 ms
>> >> >4) 1000 prepared stmts: insert into BatchTest (c1, c2, c3) values (?,
>?,
>> >?):
>> >> >2794 ms
>> >> >4) 1000 prepared stmts: insert into BatchTest (c1, c2, c3) values (?,
>?,
>> >?):
>> >> >5468 ms
>> >> >4) 1000 prepared stmts: insert into BatchTest (c1, c2, c3) values (?,
>?,
>> >?):
>> >> >2654 ms
>> >> >4) 1000 prepared stmts: insert into BatchTest (c1, c2, c3) values (?,
>?,
>> >?):
>> >> >4787 ms
>> >> >4) 1000 prepared stmts: insert into BatchTest (c1, c2, c3) values (?,
>?,
>> >?):
>> >> >2634 ms
>> >> >4) 1000 prepared stmts: insert into BatchTest (c1, c2, c3) values (?,
>?,
>> >?):
>> >> >4907 ms
>> >> >4) 1000 prepared stmts: insert into BatchTest (c1, c2, c3) values (?,
>?,
>> >?):
>> >> >2664 ms
>> >> >4) 1000 prepared stmts: insert into BatchTest (c1, c2, c3) values (?,
>?,
>> >?):
>> >> >4907 ms
>> >> >4) 1000 prepared stmts: insert into BatchTest (c1, c2, c3) values (?,
>?,
>> >?):
>> >> >2654 ms
>> >> >4) 1000 prepared stmts: insert into BatchTest (c1, c2, c3) values (?,
>?,
>> >?):
>> >> >5007 ms
>> >> >5) 333 prepared stored proc calls: { call BT1 (?,?,?) }: 1632 ms
>> >> >5) 333 prepared stored proc calls: { call BT1 (?,?,?) }: 1633 ms
>> >> >5) 333 prepared stored proc calls: { call BT1 (?,?,?) }: 3936 ms
>> >> >5) 333 prepared stored proc calls: { call BT1 (?,?,?) }: 1592 ms
>> >> >5) 333 prepared stored proc calls: { call BT1 (?,?,?) }: 1593 ms
>> >> >5) 333 prepared stored proc calls: { call BT1 (?,?,?) }: 3915 ms
>> >> >5) 333 prepared stored proc calls: { call BT1 (?,?,?) }: 1582 ms
>> >> >5) 333 prepared stored proc calls: { call BT1 (?,?,?) }: 1813 ms
>> >> >5) 333 prepared stored proc calls: { call BT1 (?,?,?) }: 2764 ms
>> >> >5) 333 prepared stored proc calls: { call BT1 (?,?,?) }: 1602 ms
>> >> >7) single prepared jdbc batch with 1000 stmts: insert into BatchTest
>(c1,
>> >> >c2, c3) values (?, ?, ?): 110 ms
>> >> >7) single prepared jdbc batch with 1000 stmts: insert into BatchTest
>(c1,
>> >> >c2, c3) values (?, ?, ?): 90 ms
>> >> >7) single prepared jdbc batch with 1000 stmts: insert into BatchTest
>(c1,
>> >> >c2, c3) values (?, ?, ?): 180 ms
>> >> >7) single prepared jdbc batch with 1000 stmts: insert into BatchTest
>(c1,
>> >> >c2, c3) values (?, ?, ?): 80 ms
>> >> >7) single prepared jdbc batch with 1000 stmts: insert into BatchTest
>(c1,
>> >> >c2, c3) values (?, ?, ?): 90 ms
>> >> >7) single prepared jdbc batch with 1000 stmts: insert into BatchTest
>(c1,
>> >> >c2, c3) values (?, ?, ?): 90 ms
>> >> >7) single prepared jdbc batch with 1000 stmts: insert into BatchTest
>(c1,
>> >> >c2, c3) values (?, ?, ?): 90 ms
>> >> >7) single prepared jdbc batch with 1000 stmts: insert into BatchTest
>(c1,
>> >> >c2, c3) values (?, ?, ?): 90 ms
>> >> >7) single prepared jdbc batch with 1000 stmts: insert into BatchTest
>(c1,
>> >> >c2, c3) values (?, ?, ?): 331 ms
>> >> >7) single prepared jdbc batch with 1000 stmts: insert into BatchTest
>(c1,
>> >> >c2, c3) values (?, ?, ?): 140 ms
>> >> >8) single prepared jdbc batch with 333 stored proc calls: { call BT1
>> >> >(?,?,?) }: 1862 ms
>> >> >8) single prepared jdbc batch with 333 stored proc calls: { call BT1
>> >> >(?,?,?) }: 1642 ms
>> >> >8) single prepared jdbc batch with 333 stored proc calls: { call BT1
>> >> >(?,?,?) }: 4106 ms
>> >> >8) single prepared jdbc batch with 333 stored proc calls: { call BT1
>> >> >(?,?,?) }: 1643 ms
>> >> >8) single prepared jdbc batch with 333 stored proc calls: { call BT1
>> >> >(?,?,?) }: 1652 ms
>> >> >8) single prepared jdbc batch with 333 stored proc calls: { call BT1
>> >> >(?,?,?) }: 3915 ms
>> >> >8) single prepared jdbc batch with 333 stored proc calls: { call BT1
>> >> >(?,?,?) }: 1903 ms
>> >> >8) single prepared jdbc batch with 333 stored proc calls: { call BT1
>> >> >(?,?,?) }: 1703 ms
>> >> >8) single prepared jdbc batch with 333 stored proc calls: { call BT1
>> >> >(?,?,?) }: 4176 ms
>> >> >8) single prepared jdbc batch with 333 stored proc calls: { call BT1
>> >> >(?,?,?) }: 1693 ms
>> >> >6) single unprepared sql batch with 333 stored proc calls:
>> >BT1('0','0',0); :
>> >> >921 ms
>> >> >6) single unprepared sql batch with 333 stored proc calls:
>> >BT1('0','0',0); :
>> >> >330 ms
>> >> >6) single unprepared sql batch with 333 stored proc calls:
>> >BT1('0','0',0); :
>> >> >781 ms
>> >> >6) single unprepared sql batch with 333 stored proc calls:
>> >BT1('0','0',0); :
>> >> >620 ms
>> >> >6) single unprepared sql batch with 333 stored proc calls:
>> >BT1('0','0',0); :
>> >> >340 ms
>> >> >6) single unprepared sql batch with 333 stored proc calls:
>> >BT1('0','0',0); :
>> >> >340 ms
>> >> >6) single unprepared sql batch with 333 stored proc calls:
>> >BT1('0','0',0); :
>> >> >952 ms
>> >> >6) single unprepared sql batch with 333 stored proc calls:
>> >BT1('0','0',0); :
>> >> >491 ms
>> >> >6) single unprepared sql batch with 333 stored proc calls:
>> >BT1('0','0',0); :
>> >> >330 ms
>> >> >6) single unprepared sql batch with 333 stored proc calls:
>> >BT1('0','0',0); :
>> >> >331 ms
>> >> >3) single unprepared sql batch with 1000 stmts: insert into BatchTest
>> >(c1,
>> >> >c2, c3) values ('0','0',0); : 4677 ms
>> >> >3) single unprepared sql batch with 1000 stmts: insert into BatchTest
>> >(c1,
>> >> >c2, c3) values ('0','0',0); : 4426 ms
>> >> >3) single unprepared sql batch with 1000 stmts: insert into BatchTest
>> >(c1,
>> >> >c2, c3) values ('0','0',0); : 4396 ms
>> >> >3) single unprepared sql batch with 1000 stmts: insert into BatchTest
>> >(c1,
>> >> >c2, c3) values ('0','0',0); : 4377 ms
>> >> >3) single unprepared sql batch with 1000 stmts: insert into BatchTest
>> >(c1,
>> >> >c2, c3) values ('0','0',0); : 4436 ms
>> >> >3) single unprepared sql batch with 1000 stmts: insert into BatchTest
>> >(c1,
>> >> >c2, c3) values ('0','0',0); : 4707 ms
>> >> >3) single unprepared sql batch with 1000 stmts: insert into BatchTest
>> >(c1,
>> >> >c2, c3) values ('0','0',0); : 4366 ms
>> >> >3) single unprepared sql batch with 1000 stmts: insert into BatchTest
>> >(c1,
>> >> >c2, c3) values ('0','0',0); : 4427 ms
>> >> >3) single unprepared sql batch with 1000 stmts: insert into BatchTest
>> >(c1,
>> >> >c2, c3) values ('0','0',0); : 4426 ms
>> >> >3) single unprepared sql batch with 1000 stmts: insert into BatchTest
>> >(c1,
>> >> >c2, c3) values ('0','0',0); : 4747 ms
>> >> >
>> >> >
>> >> >
>> >>
>> >> --
>> >> Thomas Kyte (tkyte@us.oracle.com) http://asktom.oracle.com/
>> >> Expert one on one Oracle, programming techniques and solutions for
>Oracle.
>> >> http://www.amazon.com/exec/obidos/ASIN/1861004826/
>> >> Opinions are mine and do not necessarily reflect those of Oracle Corp
>> >>
>> >
>> >
>>
>> --
>> Thomas Kyte (tkyte@us.oracle.com) http://asktom.oracle.com/
>> Expert one on one Oracle, programming techniques and solutions for Oracle.
>> http://www.amazon.com/exec/obidos/ASIN/1861004826/
>> Opinions are mine and do not necessarily reflect those of Oracle Corp
>>
>
>
-- Thomas Kyte (tkyte@us.oracle.com) http://asktom.oracle.com/ Expert one on one Oracle, programming techniques and solutions for Oracle. http://www.amazon.com/exec/obidos/ASIN/1861004826/ Opinions are mine and do not necessarily reflect those of Oracle CorpReceived on Mon Jan 07 2002 - 08:50:17 CST
 |
 |