Oracle FAQ | Your Portal to the Oracle Knowledge Grid |
![]() |
![]() |
Home -> Community -> Usenet -> c.d.o.server -> Re: Performance problem on inserting
Hi everybody, here you are with the tkprof report file...
Tnx in advance if you read it.
TKPROF: Release 9.2.0.1.0 - Production on Tue Feb 4 17:05:07 2003
Copyright (c) 1982, 2002, Oracle Corporation. All rights reserved.
Trace file: test_ora_33588.trc
Sort options: default
count = number of times OCI procedure was executed cpu = cpu time in seconds executing elapsed = elapsed time in seconds executing disk = number of physical reads of buffers from disk query = number of buffers gotten for consistent read current = number of buffers gotten in current mode (usually for update) rows = number of rows processed by the fetch or execute call ********************************************************************************
alter session set sql_trace=TRUE
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 0 0.00 0.00 0 0 0 0 Execute 1 0.00 0.00 0 0 0 0 Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 1 0.00 0.00 0 0 0 0
Misses in library cache during parse: 0
Misses in library cache during execute: 1
Optimizer goal: CHOOSE
Parsing user id: 87
BEGIN
FOR I in 1..200000 LOOP
INSERT INTO TEST VALUES ('AAAAA ');
END LOOP;
END;
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.01 0.01 0 0 0 0 Execute 1 56.43 31.48 0 0 0 1 Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2 56.45 31.49 0 0 0 1
Misses in library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: 87
INSERT INTO TEST
VALUES
('AAAAA ')
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0 Execute 200000 124.53 28.22 3 446 203199 200000 Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 200001 124.53 28.22 3 446 203199 200000
Misses in library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: 87 (recursive depth: 1)
select file#
from
file$ where ts#=:1
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 3 0.00 0.00 0 0 0 0 Execute 3 0.00 0.01 0 0 0 0 Fetch 6 0.00 0.00 0 9 0 3
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 12 0.00 0.01 0 9 0 3
Misses in library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: SYS (recursive depth: 2)
Rows Row Source Operation
------- --------------------------------------------------- 1 TABLE ACCESS BY INDEX ROWID FILE$ 1 INDEX RANGE SCAN I_FILE2 (object id 42) ********************************************************************************
select file#,block#,length
from
fet$ where length>=:1 and ts#=:2 and file#=:3
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 3 0.00 0.00 0 0 0 0 Execute 3 0.00 0.00 0 0 0 0 Fetch 6 0.00 0.00 0 9 0 3
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 12 0.00 0.00 0 9 0 3
Misses in library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: SYS (recursive depth: 2)
Rows Row Source Operation
------- --------------------------------------------------- 1 TABLE ACCESS CLUSTER FET$ 1 INDEX UNIQUE SCAN I_TS# (object id 7) ********************************************************************************
select length
from
fet$ where file#=:1 and block#=:2 and ts#=:3
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 3 0.00 0.00 0 0 0 0 Execute 3 0.00 0.00 0 0 0 0 Fetch 3 0.00 0.00 0 6 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 9 0.00 0.00 0 6 0 0
Misses in library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: SYS (recursive depth: 2)
Rows Row Source Operation
------- --------------------------------------------------- 0 TABLE ACCESS CLUSTER FET$ 1 INDEX UNIQUE SCAN I_TS# (object id 7) ********************************************************************************
select file#,block#,length
from
uet$ where ts#=:1 and segfile#=:2 and segblock#=:3 and ext#=:4
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 3 0.01 0.00 0 0 0 0 Execute 3 0.00 0.00 0 0 0 0 Fetch 3 0.00 0.00 0 9 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 9 0.01 0.00 0 9 0 0
Misses in library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: SYS (recursive depth: 2)
Rows Row Source Operation
------- --------------------------------------------------- 0 TABLE ACCESS CLUSTER UET$ 1 INDEX UNIQUE SCAN I_FILE#_BLOCK# (object id 9) ********************************************************************************
insert into uet$ (segfile#,segblock#,ext#,ts#,file#,block#,length)
values
(:1, :2, :3, :4, :5, :6, :7)
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 3 0.00 0.00 0 0 0 0 Execute 3 0.00 0.00 0 6 3 3 Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 6 0.00 0.00 0 6 3 3
Misses in library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: SYS (recursive depth: 2)
update tsq$ set blocks=:3,maxblocks=:4,grantor#=:5,priv1=:6,priv2=:7,priv3=:8
where
ts#=:1 and user#=:2
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 3 0.00 0.00 0 0 0 0 Execute 3 0.00 0.00 0 12 3 3 Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 6 0.00 0.00 0 12 3 3
Misses in library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: SYS (recursive depth: 2)
Rows Row Source Operation
------- --------------------------------------------------- 0 UPDATE 1 TABLE ACCESS CLUSTER TSQ$ 1 INDEX UNIQUE SCAN I_USER# (object id 11) ********************************************************************************
select o.owner#,o.name,o.namespace,o.remoteowner,o.linkname,o.subname,
o.dataobj#,o.flags
from
obj$ o where o.obj#=:1
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0 Execute 1 0.00 0.00 0 0 0 0 Fetch 1 0.00 0.01 2 3 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 3 0.00 0.01 2 3 0 1
Misses in library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: SYS (recursive depth: 3)
insert into fet$ (file#,block#,ts#,length)
values
(:1,:2,:3,:4)
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 3 0.00 0.00 0 0 0 0 Execute 3 0.00 0.00 0 3 3 3 Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 6 0.00 0.00 0 3 3 3
Misses in library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: SYS (recursive depth: 2)
delete from fet$
where
file#=:1 and block#=:2 and ts#=:3
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 3 0.00 0.00 0 0 0 0 Execute 3 0.01 0.00 0 15 3 3 Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 6 0.01 0.00 0 15 3 3
Misses in library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: SYS (recursive depth: 2)
Rows Row Source Operation
------- --------------------------------------------------- 0 DELETE 1 TABLE ACCESS CLUSTER FET$ 1 INDEX UNIQUE SCAN I_TS# (object id 7) ********************************************************************************
update seg$ set type#=:4,blocks=:5,extents=:6,minexts=:7,maxexts=:8,extsize=
:9,extpct=:10,user#=:11,iniexts=:12,lists=decode(:13, 65535, NULL, :13),
groups=decode(:14, 65535, NULL, :14), cachehint=:15, hwmincr=:16, spare1=
DECODE(:17,0,NULL,:17)
where
ts#=:1 and file#=:2 and block#=:3
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 3 0.00 0.00 0 0 0 0 Execute 3 0.00 0.00 0 18 3 3 Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 6 0.00 0.00 0 18 3 3
Misses in library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: SYS (recursive depth: 2)
Rows Row Source Operation
------- --------------------------------------------------- 0 UPDATE 1 TABLE ACCESS CLUSTER SEG$ 1 INDEX UNIQUE SCAN I_FILE#_BLOCK# (object id 9) ********************************************************************************
commit
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0 Execute 1 0.00 0.00 0 0 1 0 Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2 0.00 0.00 0 0 1 0
Misses in library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: 87
OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 2 0.01 0.01 0 0 0 0 Execute 3 56.43 31.48 0 0 1 1 Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 5 56.45 31.49 0 0 1 1
Misses in library cache during parse: 2
Misses in library cache during execute: 1
OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 29 0.01 0.02 0 0 0 0 Execute 200028 124.54 28.24 3 500 203214 200015 Fetch 19 0.00 0.01 2 36 0 7
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 200076 124.56 28.28 5 536 203214 200022
Misses in library cache during parse: 11
4 user SQL statements in session.
28 internal SQL statements in session.
32 SQL statements in session.
1 session in tracefile. 4 user SQL statements in trace file. 28 internal SQL statements in trace file. 32 SQL statements in trace file. 14 unique SQL statements in trace file.200286 lines in trace file. Received on Fri Feb 07 2003 - 09:11:38 CST
![]() |
![]() |