Hi Kalter,
Pl. find the tkprof output. The mentiond SQL stmt's fetch time is 31.97 which is quite large as compared to other stmts.
Yes, You are right my case not of multithreading.
Pl. let me know what can be done to make the stmt execute in lesser time.
TKPROF: Release 9.2.0.3.0 - Production on Wed Aug 16 14:15:40 2006
Copyright (c) 1982, 2002, Oracle Corporation. All rights reserved.
Trace file: rproods_ora_1800.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
Optimizer goal: CHOOSE
Parsing user id: SYS
********************************************************************************
alter session set optimizer_mode = first_rows
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 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2 0.00 0.00 0 0 0 0
Misses in library cache during parse: 0
Optimizer goal: CHOOSE
Parsing user id: SYS
********************************************************************************
select to_char(userenv('SESSIONID'))
from
dual
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.00 0 3 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 3 0.00 0.00 0 3 0 1
Misses in library cache during parse: 0
Optimizer goal: FIRST_ROWS
Parsing user id: SYS
Rows Row Source Operation
------- ---------------------------------------------------
1 TABLE ACCESS FULL DUAL (cr=3 r=0 w=0 time=47 us)
********************************************************************************
Select /* Toolkit */ name, created, log_mode
from
v$Database
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.02 0 0 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 3 0.00 0.02 0 0 0 1
Misses in library cache during parse: 0
Optimizer goal: FIRST_ROWS
Parsing user id: SYS
Rows Row Source Operation
------- ---------------------------------------------------
1 FIXED TABLE FULL X$KCCDI (cr=0 r=0 w=0 time=28584 us)
********************************************************************************
SELECT /*Toolkit*/ a.member file_name, b.group#, b.thread#,
b.sequence#, b.bytes, b.members,
b.archived, b.status, b.first_change#,
b.first_time, 'Redo Log' tablespace_name
FROM v$logfile a, v$log b
WHERE a.group# = b.group#
ORDER BY a.member
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.43 0 0 0 3
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 3 0.00 0.43 0 0 0 3
Misses in library cache during parse: 0
Optimizer goal: FIRST_ROWS
Parsing user id: SYS
********************************************************************************
SELECT /*Toolkit*/ a.file_name, a.file_id, a.tablespace_name,
a.bytes, a.blocks, a.status, a.autoextensible,
a.maxbytes, a.maxblocks,
(a.increment_by *
(SELECT b.block_size
FROM dba_tablespaces b
WHERE b.tablespace_name = a.tablespace_name))
next_extent
FROM dba_data_files a
ORDER BY a.tablespace_name, a.file_id
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.11 0 45 10 10
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 3 0.00 0.11 0 45 10 10
Misses in library cache during parse: 0
Optimizer goal: FIRST_ROWS
Parsing user id: SYS
Rows Row Source Operation
------- ---------------------------------------------------
10 SORT ORDER BY (cr=45 r=0 w=0 time=112547 us)
10 VIEW (cr=36 r=0 w=0 time=112243 us)
10 UNION-ALL (cr=36 r=0 w=0 time=112202 us)
0 NESTED LOOPS (cr=12 r=0 w=0 time=39238 us)
0 NESTED LOOPS (cr=12 r=0 w=0 time=39234 us)
10 FIXED TABLE FULL X$KCCFN (cr=0 r=0 w=0 time=38940 us)
0 TABLE ACCESS BY INDEX ROWID FILE$ (cr=12 r=0 w=0 time=240 us)
10 INDEX UNIQUE SCAN I_FILE1 (cr=2 r=0 w=0 time=123 us)(object id 41)
0 TABLE ACCESS CLUSTER TS$ (cr=0 r=0 w=0 time=0 us)
0 INDEX UNIQUE SCAN I_TS# (cr=0 r=0 w=0 time=0 us)(object id 7)
10 NESTED LOOPS (cr=24 r=0 w=0 time=72831 us)
10 NESTED LOOPS (cr=12 r=0 w=0 time=72591 us)
10 NESTED LOOPS (cr=12 r=0 w=0 time=72351 us)
10 FIXED TABLE FULL X$KCCFN (cr=0 r=0 w=0 time=72122 us)
10 TABLE ACCESS BY INDEX ROWID FILE$ (cr=12 r=0 w=0 time=145 us)
10 INDEX UNIQUE SCAN I_FILE1 (cr=2 r=0 w=0 time=49 us)(object id 41)
10 FIXED TABLE FIXED INDEX X$KTFBHC (ind:1) (cr=0 r=0 w=0 time=143 us)
10 TABLE ACCESS CLUSTER TS$ (cr=12 r=0 w=0 time=159 us)
10 INDEX UNIQUE SCAN I_TS# (cr=2 r=0 w=0 time=47 us)(object id 7)
********************************************************************************
SELECT /*Toolkit*/ a.file_name, a.file_id, a.tablespace_name,
a.bytes, a.blocks, a.status, a.autoextensible,
a.maxbytes, a.maxblocks,
(a.increment_by *
(SELECT b.block_size
FROM dba_tablespaces b
WHERE b.tablespace_name = a.tablespace_name))
next_extent
FROM dba_temp_files a
ORDER BY a.tablespace_name, a.file_id
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.07 0 6 2 2
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 3 0.00 0.07 0 6 2 2
Misses in library cache during parse: 0
Optimizer goal: FIRST_ROWS
Parsing user id: SYS
Rows Row Source Operation
------- ---------------------------------------------------
2 SORT ORDER BY (cr=6 r=0 w=0 time=71799 us)
2 NESTED LOOPS (cr=4 r=0 w=0 time=71646 us)
2 NESTED LOOPS (cr=0 r=0 w=0 time=71566 us)
2 FIXED TABLE FULL X$KCCFN (cr=0 r=0 w=0 time=71486 us)
2 FIXED TABLE FIXED INDEX X$KTFTHC (ind:1) (cr=0 r=0 w=0 time=56 us)
2 TABLE ACCESS CLUSTER TS$ (cr=4 r=0 w=0 time=56 us)
2 INDEX UNIQUE SCAN I_TS# (cr=2 r=0 w=0 time=23 us)(object id 7)
********************************************************************************
SELECT /*Toolkit*/ VALUE
FROM
v$parameter WHERE name = 'log_archive_dest'
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.00 0 0 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 3 0.00 0.00 0 0 0 1
Misses in library cache during parse: 0
Optimizer goal: FIRST_ROWS
Parsing user id: SYS
Rows Row Source Operation
------- ---------------------------------------------------
1 NESTED LOOPS (cr=0 r=0 w=0 time=407 us)
1 FIXED TABLE FULL X$KSPPI (cr=0 r=0 w=0 time=368 us)
1 FIXED TABLE FIXED INDEX X$KSPPCV (ind:2) (cr=0 r=0 w=0 time=25 us)
********************************************************************************
SELECT /*Toolkit*/ file_name, Tablespace_name
FROM
dba_data_files UNION SELECT file_name, Tablespace_name FROM dba_temp_files
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.04 0 40 12 12
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 3 0.00 0.04 0 40 12 12
Misses in library cache during parse: 0
Optimizer goal: FIRST_ROWS
Parsing user id: SYS
Rows Row Source Operation
------- ---------------------------------------------------
12 SORT UNIQUE (cr=40 r=0 w=0 time=42686 us)
12 UNION-ALL (cr=40 r=0 w=0 time=42581 us)
10 VIEW (cr=36 r=0 w=0 time=41087 us)
10 UNION-ALL (cr=36 r=0 w=0 time=41051 us)
0 NESTED LOOPS (cr=12 r=0 w=0 time=39322 us)
0 NESTED LOOPS (cr=12 r=0 w=0 time=39319 us)
10 FIXED TABLE FULL X$KCCFN (cr=0 r=0 w=0 time=39107 us)
0 TABLE ACCESS BY INDEX ROWID FILE$ (cr=12 r=0 w=0 time=167 us)
10 INDEX UNIQUE SCAN I_FILE1 (cr=2 r=0 w=0 time=59 us)(object id 41)
0 TABLE ACCESS CLUSTER TS$ (cr=0 r=0 w=0 time=0 us)
0 INDEX UNIQUE SCAN I_TS# (cr=0 r=0 w=0 time=0 us)(object id 7)
10 NESTED LOOPS (cr=24 r=0 w=0 time=1643 us)
10 NESTED LOOPS (cr=12 r=0 w=0 time=1412 us)
10 NESTED LOOPS (cr=12 r=0 w=0 time=1194 us)
10 FIXED TABLE FULL X$KCCFN (cr=0 r=0 w=0 time=991 us)
10 TABLE ACCESS BY INDEX ROWID FILE$ (cr=12 r=0 w=0 time=126 us)
10 INDEX UNIQUE SCAN I_FILE1 (cr=2 r=0 w=0 time=40 us)(object id 41)
10 FIXED TABLE FIXED INDEX X$KTFBHC (ind:1) (cr=0 r=0 w=0 time=117 us)
10 TABLE ACCESS CLUSTER TS$ (cr=12 r=0 w=0 time=160 us)
10 INDEX UNIQUE SCAN I_TS# (cr=2 r=0 w=0 time=42 us)(object id 7)
2 NESTED LOOPS (cr=4 r=0 w=0 time=1401 us)
2 NESTED LOOPS (cr=0 r=0 w=0 time=1348 us)
2 FIXED TABLE FULL X$KCCFN (cr=0 r=0 w=0 time=1298 us)
2 FIXED TABLE FIXED INDEX X$KTFTHC (ind:1) (cr=0 r=0 w=0 time=27 us)
2 TABLE ACCESS CLUSTER TS$ (cr=4 r=0 w=0 time=34 us)
2 INDEX UNIQUE SCAN I_TS# (cr=2 r=0 w=0 time=11 us)(object id 7)
********************************************************************************
SELECT /*Toolkit*/ sequence#
FROM
v$log WHERE Lower(status) = Lower('CURRENT')
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.00 0 0 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 3 0.00 0.00 0 0 0 1
Misses in library cache during parse: 0
Optimizer goal: FIRST_ROWS
Parsing user id: SYS
Rows Row Source Operation
------- ---------------------------------------------------
1 NESTED LOOPS (cr=0 r=0 w=0 time=9787 us)
3 FIXED TABLE FULL X$KCCLE (cr=0 r=0 w=0 time=8053 us)
1 FIXED TABLE FIXED INDEX X$KCCRT (ind:1) (cr=0 r=0 w=0 time=1704 us)
********************************************************************************
select /*Toolkit*/ value
from
v$parameter where Lower(name) = Lower('Log_Archive_Format')
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 2 0.00 0.00 0 0 0 0
Execute 2 0.00 0.00 0 0 0 0
Fetch 2 0.00 0.00 0 0 0 2
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 6 0.00 0.00 0 0 0 2
Misses in library cache during parse: 0
Optimizer goal: FIRST_ROWS
Parsing user id: SYS
Rows Row Source Operation
------- ---------------------------------------------------
1 NESTED LOOPS (cr=0 r=0 w=0 time=735 us)
1 FIXED TABLE FULL X$KSPPI (cr=0 r=0 w=0 time=706 us)
1 FIXED TABLE FIXED INDEX X$KSPPCV (ind:2) (cr=0 r=0 w=0 time=18 us)
********************************************************************************
SELECT /*Toolkit*/ File_Name
FROM
dba_data_files UNION SELECT File_Name FROM dba_temp_files
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 2 0.00 0.00 0 0 0 0
Execute 2 0.00 0.00 0 0 0 0
Fetch 2 0.00 0.00 0 80 24 24
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 6 0.00 0.00 0 80 24 24
Misses in library cache during parse: 0
Optimizer goal: FIRST_ROWS
Parsing user id: SYS
Rows Row Source Operation
------- ---------------------------------------------------
12 SORT UNIQUE (cr=40 r=0 w=0 time=4080 us)
12 UNION-ALL (cr=40 r=0 w=0 time=3987 us)
10 VIEW (cr=36 r=0 w=0 time=2859 us)
10 UNION-ALL (cr=36 r=0 w=0 time=2830 us)
0 NESTED LOOPS (cr=12 r=0 w=0 time=1169 us)
0 NESTED LOOPS (cr=12 r=0 w=0 time=1165 us)
10 FIXED TABLE FULL X$KCCFN (cr=0 r=0 w=0 time=995 us)
0 TABLE ACCESS BY INDEX ROWID FILE$ (cr=12 r=0 w=0 time=125 us)
10 INDEX UNIQUE SCAN I_FILE1 (cr=2 r=0 w=0 time=55 us)(object id 41)
0 TABLE ACCESS CLUSTER TS$ (cr=0 r=0 w=0 time=0 us)
0 INDEX UNIQUE SCAN I_TS# (cr=0 r=0 w=0 time=0 us)(object id 7)
10 NESTED LOOPS (cr=24 r=0 w=0 time=1580 us)
10 NESTED LOOPS (cr=12 r=0 w=0 time=1360 us)
10 NESTED LOOPS (cr=12 r=0 w=0 time=1152 us)
10 FIXED TABLE FULL X$KCCFN (cr=0 r=0 w=0 time=955 us)
10 TABLE ACCESS BY INDEX ROWID FILE$ (cr=12 r=0 w=0 time=126 us)
10 INDEX UNIQUE SCAN I_FILE1 (cr=2 r=0 w=0 time=43 us)(object id 41)
10 FIXED TABLE FIXED INDEX X$KTFBHC (ind:1) (cr=0 r=0 w=0 time=120 us)
10 TABLE ACCESS CLUSTER TS$ (cr=12 r=0 w=0 time=142 us)
10 INDEX UNIQUE SCAN I_TS# (cr=2 r=0 w=0 time=44 us)(object id 7)
2 NESTED LOOPS (cr=4 r=0 w=0 time=1035 us)
2 NESTED LOOPS (cr=0 r=0 w=0 time=985 us)
2 FIXED TABLE FULL X$KCCFN (cr=0 r=0 w=0 time=943 us)
2 FIXED TABLE FIXED INDEX X$KTFTHC (ind:1) (cr=0 r=0 w=0 time=21 us)
2 TABLE ACCESS CLUSTER TS$ (cr=4 r=0 w=0 time=34 us)
2 INDEX UNIQUE SCAN I_TS# (cr=2 r=0 w=0 time=12 us)(object id 7)
********************************************************************************
Select /*Toolkit*/ value
from
v$nls_parameters where lower(parameter) = 'nls_date_format'
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.00 0 0 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 3 0.00 0.00 0 0 0 1
Misses in library cache during parse: 0
Optimizer goal: FIRST_ROWS
Parsing user id: SYS
Rows Row Source Operation
------- ---------------------------------------------------
1 FIXED TABLE FULL X$NLS_PARAMETERS (cr=0 r=0 w=0 time=50 us)
********************************************************************************
Select /*Toolkit*/ value
from
v$nls_parameters where lower(parameter) = 'nls_time_format'
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.00 0 0 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 3 0.00 0.00 0 0 0 1
Misses in library cache during parse: 0
Optimizer goal: FIRST_ROWS
Parsing user id: SYS
Rows Row Source Operation
------- ---------------------------------------------------
1 FIXED TABLE FULL X$NLS_PARAMETERS (cr=0 r=0 w=0 time=43 us)
********************************************************************************
Select /*Toolkit*/ member
from
v$logfile
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.00 0 0 0 3
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 3 0.00 0.00 0 0 0 3
Misses in library cache during parse: 0
Optimizer goal: FIRST_ROWS
Parsing user id: SYS
Rows Row Source Operation
------- ---------------------------------------------------
3 FIXED TABLE FULL X$KCCFN (cr=0 r=0 w=0 time=1224 us)
********************************************************************************
select 'x'
from
dual
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.00 0 3 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 3 0.00 0.00 0 3 0 1
Misses in library cache during parse: 0
Optimizer goal: FIRST_ROWS
Parsing user id: SYS
Rows Row Source Operation
------- ---------------------------------------------------
1 TABLE ACCESS FULL DUAL (cr=3 r=0 w=0 time=38 us)
********************************************************************************
Select d.File#, d.name as Data_File_Name, t.name Tbs_Name, d.Status as
File_Status, d.Enabled, d.bytes
from
v$datafile d, v$tablespace t where d.TS# = t.TS#
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 31.97 0 0 0 10
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 3 0.00 31.97 0 0 0 10
Misses in library cache during parse: 0
Optimizer goal: FIRST_ROWS
Parsing user id: SYS
********************************************************************************
OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 18 0.00 0.00 0 0 0 0
Execute 19 0.00 0.00 0 0 0 0
Fetch 17 0.00 32.68 0 177 48 73
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 54 0.00 32.69 0 177 48 73
Misses in library cache during parse: 0
OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 0 0.00 0.00 0 0 0 0
Execute 0 0.00 0.00 0 0 0 0
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 0 0.00 0.00 0 0 0 0
Misses in library cache during parse: 0
19 user SQL statements in session.
0 internal SQL statements in session.
19 SQL statements in session.
********************************************************************************
Trace file: rproods_ora_1800.trc
Trace file compatibility: 9.00.01
Sort options: default
1 session in tracefile.
19 user SQL statements in trace file.
0 internal SQL statements in trace file.
19 SQL statements in trace file.
17 unique SQL statements in trace file.
296 lines in trace file.