Re: fluctuating execution times

Could it not be the acquisition of a new initialised block / acquisition of transaction entry in the block etc.?

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!

"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
>
Received on Mon Jan 07 2002 - 00:33:57 CST