Re: fluctuating execution times

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