Re: UTL_FILE Performance.

From: Niall Litchfield <n-litchfield_at_audit-commission.gov.uk>
Date: Thu, 19 Feb 2004 16:09:35 -0000
Message-ID: <CFECD6EA683C524BB5FD22C0F1F34ACB06B125@bristol43.audit-commission.gov.uk>

It was suggested that I rewrite the procedure using FORALL and a PL/SQL table.

My initial attempt at this, using in fact 3 pl/sql tables and inserting every 10000 records yielded a reasonable performance improvement and is (I'm pretty sure) still 8i compatible. results below

BEGIN asql.read_asql_log('work_24.log','SCRIPTS'); END;

call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ----------

Parse 1 0.00 0.00 0 0 0 0
Execute 1 22.71 96.90 0 0 0 1
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ----------

total 2 22.71 96.90 0 0 0 1

Misses in library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: 76

Elapsed times include waiting on following events:

  Event waited on                             Times   Max. Wait  Total

Waited

Waited ----------
log file sync 1 0.07 0.07 SQL*Net message to client 1 0.00 0.00 SQL*Net message from client 1 56.37 56.37

INSERT into asql_log(tstamp,rows_affected,description) values
(:b1,:b2,:b3)

call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ----------

Parse 0 0.00 0.00 0 0 0 0
Execute 63 39.23 76.13 5 5641 1509976 626498
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ----------

total 63 39.23 76.13 5 5641 1509976 626498

however I didn't particularly like the ugly code or the 3 different pl/sql tables (one for each column into which I was inserting). So then I decided to abandon the IOT idea and the primary key (I will probably add a calculated line number in as a pk at a later date), and to use the ability to do a simple insert with a table of %ROWTYPE. The results are below and the revised script is at
http://www.niall.litchfield.dial.pipex.com/scripts/tests/read_asql_faste r.sql

BEGIN ASQL.READ_ASQL_LOG('work_24.log','SCRIPTS'); END;

call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ----------

Parse 1 0.01 0.00 0 0 0 0
Execute 1 22.91 23.84 0 157 824 1
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ----------

total 2 22.92 23.84 0 157 824 1

Misses in library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: 76

Elapsed times include waiting on following events:

  Event waited on                             Times   Max. Wait  Total

Waited

Waited ----------
log file sync 1 0.06 0.06 SQL*Net message to client 1 0.00 0.00 SQL*Net message from client 1 11.42 11.42

INSERT into asql_log
VALUES
(:b1,:b2,:b3)

call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ----------

Parse 0 0.00 0.00 0 0 0 0
Execute 62 1.69 3.66 2 4104 30587 620000
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ----------

total 62 1.69 3.66 2 4104 30587 620000

Misses in library cache during parse: 0
Misses in library cache during execute: 1 Optimizer goal: CHOOSE
Parsing user id: 76 (recursive depth: 1)

Elapsed times include waiting on following events:

  Event waited on                             Times   Max. Wait  Total

Waited

Waited ----------
db file sequential read 2 0.00 0.00 log buffer space 4 0.28 0.28 free buffer waits 2 0.44 0.69 log file switch completion 2 0.36 0.44

COMMIT call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ----------

Parse 0 0.00 0.00 0 0 0 0
Execute 1 0.00 0.33 0 0 1 0
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ----------

total 1 0.00 0.33 0 0 1 0

Misses in library cache during parse: 0
Optimizer goal: CHOOSE
Parsing user id: 76 (recursive depth: 1)

INSERT into asql_log
values
(:b1,:b2,:b3)

call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ----------

Parse 0 0.00 0.00 0 0 0 0
Execute 1 0.02 0.23 0 64 329 6498
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ----------

total 1 0.02 0.23 0 64 329 6498

Sorry if this is teaching you all to suck eggs, but it maybe that the lessons I learned might help someone else someday. Cheers to Connor et al for helping me out along the way.

Niall Litchfield
Oracle DBA
Audit Commission
+44 117 975 7805

This email contains information intended for the addressee only. It may be confidential and may be the subject of legal and/or
professional privilege. Any dissemination, distribution, copyright or use of this
communication without prior permission of the sender is strictly prohibited.

Please see the official ORACLE-L FAQ: http://www.orafaq.com

To unsubscribe send email to: oracle-l-request_at_freelists.org 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


-----------------------------------------------------------------

Received on Thu Feb 19 2004 - 10:09:35 CST