Need help with performance issues reported in below forun thread
9659541
The following SQL statement has been identified to perform poorly on my new Sun Solaris machine. It performs as expected on my Wondows 2003 x64 server.
It currently takes 15 seconds to execute on Windows and 78 seconds on Solaris.
OS Configurations
---------------------
Windows: 2003 Server x64 with single 250GB HDD 4GB RAM
Solaris:
Operating System : Solaris 5.10/08
Sun SPARC T3 -1 Server
CPU : SPARC T3 16-Core 1.65 GHz Processor
RAM : 16 GB DDR3
HDD : 4*300 GB= 1200 TB
This is the statement:
--------------------------
select * from v_a_rd_data_entry; -- This is a view.
The view query is:
SELECT 1 RN,
I.RD_TYPE_CODE,
I.RD_TYPE,
I.RD_CODE,
I.TCNT,
V1.VERSION_ID,
V1.FLAG_1,
V1.FLAG_2,
V1.QUANTITY_1,
V1.QUANTITY_2,
V2.IDENTITY_START_DATE,
V2.IDENTITY_TERMINATION_DATE,
V1.VERSION_VALID_FROM,
V1.CRE_USER,
V1.CRE_DATIM,
V1.IS_DELETING_VERSION,
V1.DELETES_VERSION_ID,
V1.CODE_1,
V1.CODE_2,
CAST (NULL AS DATE) AS lc_start,
CAST (NULL AS DATE) AS lc_end,
CAST (NULL AS DATE) AS version_valid_till,
CAST (NULL AS DATE) AS next_lc_start,
CAST ( MULTISET
(
SELECT RD_TYPE_CODE,
VERSION_ID,
LANGUAGE_CODE,
SHORT_DESCRIPTION,
LONG_DESCRIPTION
FROM RD_DATA_ENTRY_T
WHERE RD_DATA_ENTRY_T.RD_TYPE_CODE = V1.RD_TYPE_CODE
AND RD_DATA_ENTRY_T.VERSION_ID = V1.VERSION_ID
) AS RD_DATA_ENTRY_T_TAB_TYPE) RD_DATA_ENTRY_T
FROM RD_DATA_ENTRY_I I,
RD_DATA_ENTRY_V V1,
RD_DATA_ENTRY_V V2
WHERE V1.RD_TYPE_CODE = I.RD_TYPE_CODE
AND V2.RD_TYPE_CODE = I.RD_TYPE_CODE
AND V1.version_id = get_version_id.RD_DATA_ENTRY (V1.RD_TYPE_CODE, 'CURRENT', V1.VERSION_VALID_FROM)
AND V2.version_id = get_version_id.RD_DATA_ENTRY (V2.RD_TYPE_CODE, 'KNOWLEDGE');
The DB parameters:
Windows:
SQL> show parameters optimizer
NAME TYPE VALUE
------------------------------------ ----------- -------------
optimizer_capture_sql_plan_baselines boolean FALSE
optimizer_dynamic_sampling integer 2
optimizer_features_enable string 11.1.0.6
optimizer_index_caching integer 0
optimizer_index_cost_adj integer 100
optimizer_mode string ALL_ROWS
optimizer_secure_view_merging boolean TRUE
optimizer_use_invisible_indexes boolean FALSE
optimizer_use_pending_statistics boolean FALSE
optimizer_use_sql_plan_baselines boolean TRUE
SQL> show parameter db_file_multi
NAME TYPE VALUE
------------------------------------ ----------- -------------
db_file_multiblock_read_count integer 128
SQL> show parameter db_block_size
NAME TYPE VALUE
------------------------------------ ----------- -------------
db_block_size integer 8192
SQL> show parameter cursor_sharing
NAME TYPE VALUE
------------------------------------ ----------- -------------
cursor_sharing string EXACT
select
sname
, pname
, pval1
, pval2
from
sys.aux_stats$;
SNAME PNAME PVAL1 PVAL2
------------------------------ ------------------------------ ---------------------- ------------------
SYSSTATS_INFO STATUS COMPLETED
SYSSTATS_INFO DSTART 06-13-2011 20:36
SYSSTATS_INFO DSTOP 06-13-2011 20:37
SYSSTATS_INFO FLAGS 1
SYSSTATS_MAIN CPUSPEEDNW 2600.213
SYSSTATS_MAIN IOSEEKTIM 11.207
SYSSTATS_MAIN IOTFRSPEED 4096
SYSSTATS_MAIN SREADTIM 3.226
SYSSTATS_MAIN MREADTIM
SYSSTATS_MAIN CPUSPEED 2600
SYSSTATS_MAIN MBRC
SYSSTATS_MAIN MAXTHR
SYSSTATS_MAIN SLAVETHR
13 rows selected
Solaris:
SQL> show parameters optimizer
NAME TYPE VALUE
------------------------------------ -------------------------------- ----------------
optimizer_capture_sql_plan_baselines boolean FALSE
optimizer_dynamic_sampling integer 2
optimizer_features_enable string 11.2.0.1
optimizer_index_caching integer 50
optimizer_index_cost_adj integer 50
optimizer_mode string ALL_ROWS
optimizer_secure_view_merging boolean TRUE
optimizer_use_invisible_indexes boolean FALSE
optimizer_use_pending_statistics boolean FALSE
optimizer_use_sql_plan_baselines boolean TRUE
SQL> show parameter db_file_multi
NAME TYPE VALUE
------------------------------------ -------------------------------- ----------------
db_file_multiblock_read_count integer 256
SQL> show parameter db_block_size
NAME TYPE VALUE
------------------------------------ -------------------------------- ----------------
db_block_size integer 8192
SQL> show parameter cursor_sharing
NAME TYPE VALUE
------------------------------------ -------------------------------- ----------------
cursor_sharing string SIMILAR
select
sname
, pname
, pval1
, pval2
from
sys.aux_stats$;
SNAME PNAME PVAL1 PVAL2
------------------------------ ------------------------------ ---------------------- -----------------
SYSSTATS_INFO STATUS COMPLETED
SYSSTATS_INFO DSTART 06-13-2011 20:32
SYSSTATS_INFO DSTOP 06-13-2011 20:33
SYSSTATS_INFO FLAGS 1
SYSSTATS_MAIN CPUSPEEDNW 411.566
SYSSTATS_MAIN IOSEEKTIM 6.197
SYSSTATS_MAIN IOTFRSPEED 52653.625
SYSSTATS_MAIN SREADTIM 463.529
SYSSTATS_MAIN MREADTIM
SYSSTATS_MAIN CPUSPEED 412
SYSSTATS_MAIN MBRC
SYSSTATS_MAIN MAXTHR
Here is the output of EXPLAIN PLAN:
Windows:
SQL> select * from v_a_rd_data_entry;
4434 rows selected.
Elapsed: 00:00:03.26
Execution Plan
----------------------------------------------------------
Plan hash value: 275055418
-------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
-------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | 111 | 73 (3)| 00:00:01 |
| 1 | TABLE ACCESS BY INDEX ROWID | RD_DATA_ENTRY_T | 1 | 38 | 2 (0)| 00:00:01 |
|* 2 | INDEX RANGE SCAN | RD_DE_T_RD_DE_V_FK1X | 1 | | 1 (0)| 00:00:01 |
| 3 | NESTED LOOPS | | | | | |
| 4 | NESTED LOOPS | | 1 | 111 | 73 (3)| 00:00:01 |
| 5 | NESTED LOOPS | | 1 | 79 | 71 (3)| 00:00:01 |
|* 6 | TABLE ACCESS FULL | RD_DATA_ENTRY_V | 1 | 60 | 70 (3)| 00:00:01 |
| 7 | TABLE ACCESS BY INDEX ROWID| RD_DATA_ENTRY_I | 1 | 19 | 1 (0)| 00:00:01 |
|* 8 | INDEX UNIQUE SCAN | RD_DATA_ENTRY_I_PKX | 1 | | 0 (0)| 00:00:01 |
|* 9 | INDEX RANGE SCAN | RD_DATA_ENTRY_V_PKX | 1 | | 1 (0)| 00:00:01 |
| 10 | TABLE ACCESS BY INDEX ROWID | RD_DATA_ENTRY_V | 1 | 32 | 2 (0)| 00:00:01 |
-------------------------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
2 - access("RD_DATA_ENTRY_T"."RD_TYPE_CODE"=:B1 AND "RD_DATA_ENTRY_T"."VERSION_ID"=:B2)
6 - filter("V1"."VERSION_ID"="GET_VERSION_ID"."RD_DATA_ENTRY"("V1"."RD_TYPE_CODE",'CURRENT',
INTERNAL_FUNCTION("V1"."VERSION_VALID_FROM")))
8 - access("V1"."RD_TYPE_CODE"="I"."RD_TYPE_CODE")
9 - access("V2"."RD_TYPE_CODE"="I"."RD_TYPE_CODE")
filter("V2"."VERSION_ID"="GET_VERSION_ID"."RD_DATA_ENTRY"("V2"."RD_TYPE_CODE",'KNOWLEDGE
'))
Statistics
----------------------------------------------------------
53704 recursive calls
0 db block gets
197001 consistent gets
0 physical reads
0 redo size
785437 bytes sent via SQL*Net to client
3747 bytes received via SQL*Net from client
299 SQL*Net roundtrips to/from client
26850 sorts (memory)
0 sorts (disk)
4434 rows processed
Solaris:
SQL> select * from v_a_rd_data_entry;
4015 rows selected.
Elapsed: 00:00:09.50
Execution Plan
----------------------------------------------------------
Plan hash value: 1399662582
-------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
-------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | 135 | 19 (16)| 00:00:01 |
| 1 | TABLE ACCESS BY INDEX ROWID | RD_DATA_ENTRY_T | 1 | 39 | 1 (0)| 00:00:01 |
|* 2 | INDEX RANGE SCAN | RD_DE_T_RD_DE_V_FK1X | 1 | | 1 (0)| 00:00:01 |
| 3 | NESTED LOOPS | | | | | |
| 4 | NESTED LOOPS | | 1 | 135 | 19 (16)| 00:00:01 |
| 5 | NESTED LOOPS | | 1 | 51 | 19 (16)| 00:00:01 |
|* 6 | TABLE ACCESS FULL | RD_DATA_ENTRY_V | 1 | 32 | 18 (17)| 00:00:01 |
| 7 | TABLE ACCESS BY INDEX ROWID| RD_DATA_ENTRY_I | 1 | 19 | 1 (0)| 00:00:01 |
|* 8 | INDEX UNIQUE SCAN | RD_DATA_ENTRY_I_PKX | 1 | | 1 (0)| 00:00:01 |
|* 9 | INDEX RANGE SCAN | RD_DE_V_RDE_I_FK1X | 2 | | 1 (0)| 00:00:01 |
|* 10 | TABLE ACCESS BY INDEX ROWID | RD_DATA_ENTRY_V | 1 | 84 | 1 (0)| 00:00:01 |
-------------------------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
2 - access("RD_DATA_ENTRY_T"."RD_TYPE_CODE"=:B1 AND "RD_DATA_ENTRY_T"."VERSION_ID"=:B2)
6 - filter("V2"."VERSION_ID"="GET_VERSION_ID"."RD_DATA_ENTRY"("V2"."RD_TYPE_CODE",'KNOWLEDGE
'))
8 - access("V2"."RD_TYPE_CODE"="I"."RD_TYPE_CODE")
9 - access("V1"."RD_TYPE_CODE"="I"."RD_TYPE_CODE")
10 - filter("V1"."VERSION_ID"="GET_VERSION_ID"."RD_DATA_ENTRY"("V1"."RD_TYPE_CODE",'CURRENT',
INTERNAL_FUNCTION("V1"."VERSION_VALID_FROM")))
Note
-----
- 'PLAN_TABLE' is old version
Statistics
----------------------------------------------------------
32000 recursive calls
0 db block gets
101816 consistent gets
0 physical reads
0 redo size
631809 bytes sent via SQL*Net to client
2214 bytes received via SQL*Net from client
271 SQL*Net roundtrips to/from client
15998 sorts (memory)
0 sorts (disk)
4015 rows processed
The problematic portion is the call to the package function. The queries in there are the ones causing trouble
The TRCANLZR output for those statement looks like the following:
Windows:
224270.1 TRCA Trace Analyzer 11.4.2.4 Report: trcanlzr_43915.txt
hecr_ora_3300.trc (32608792 bytes)
Total Trace Response Time: 15.286 secs.
2011-JUN-03 11:12:56.453 (start of first db call in trace 3717579.240823).
2011-JUN-03 11:13:11.739 (end of last db call in trace 3717594.526453).
************************************************************************************************************************************
RESPONSE TIME SUMMARY
~~~~~~~~~~~~~~~~~~~~~
pct of pct of pct of
Time total Time total Time total
Response Time Component (in secs) resp time (in secs) resp time (in secs) resp time
------------------------ ----------- ----------- ----------- ----------- ----------- -----------
CPU: 6.422 42.0%
Non-idle Wait: 0.000 0.0%
ET Unaccounted-for: 0.359 2.4%
Total Elapsed(1): 6.782 44.4%
Idle Wait: 14.745 96.5%
RT Unaccounted-for: -6.241 -40.8%
Total Response(2): 15.286 100.0%
----------------------
---SQl in question
----------------------
2262144708 cv4dua23db5q4
Rank:3(14.1%) Self:3.036s Recursive:0.003s Invoker:83 Definer:83 Depth:1
SELECT V.VERSION_ID FROM RD_DATA_ENTRY_V V WHERE V.RD_TYPE_CODE = :B3 AND V.VERSION_VALID_FROM <= :B2 AND V.CRE_DATIM <= :B1 AND
V.DELETES_VERSION_ID IS NULL AND NOT EXISTS (SELECT NULL FROM RD_DATA_ENTRY_V V2 WHERE V.VERSION_ID = V2.DELETES_VERSION_ID AND
V2.VERSION_VALID_FROM <= :B2 AND V2.CRE_DATIM <= :B1 ) ORDER BY V.VERSION_VALID_FROM DESC, V.CRE_DATIM DESC
SQL SELF - TIME, TOTALS, WAITS, BINDS AND ROW SOURCE PLAN
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
Response Time Elapsed Non-Idle Elapsed Time Idle
Call Accounted-for Time CPU Time Wait Time Unaccounted-for Wait Time
-------- -------------- -------- --------- ---------- ---------------- ----------
Parse: 0.000 0.000 0.000 0.000 0.000 0.000
Execute: 2.456 2.456 2.438 0.000 0.019 0.000
Fetch: 0.579 0.579 0.547 0.000 0.032 0.000
-------- -------------- -------- --------- ---------- ---------------- ----------
Total: 3.036 3.036 2.984 0.000 0.051 0.000
OS BG Consistent BG Current Rows Library Times Times
Call Buffer Gets Read Mode Mode Processed Cache Waited Waited
Call Count (disk) (query) (current) or Returned Misses Non-Idle Idle
-------- ------ ------------ -------------- ----------- ------------ -------- --------- -------
Parse: 1 0 0 0 0 1 0 0
Execute: 13260 0 0 0 0 1 0 0
Fetch: 13260 0 100502 0 13070 0 0 0
-------- ------ ------------ -------------- ----------- ------------ -------- --------- -------
Total: 26521 0 100502 0 13070 2 0 0
BG OS OS
Consistent Buffer Write Estim
Estim Actual Read Mode Gets Calls Time Size
ID PID Card Rows Row Source Operation (cr) (pr) (pw) (secs) ObjCost (bytes)
--- ---- ------ ------- ---------------------------------------------- ----------- ------- ------ ------- ------ -- --------
1: 0 1 1 SORT ORDER BY 8 0 0 0.000 0 6 58
2: 1 1 4 NESTED LOOPS ANTI 8 0 0 0.000 0 5 58
3: 2 3 4 . TABLE ACCESS BY INDEX ROWID RD_DATA_ENTRY_V 6 0 0 0.000 73471 4 111
4: 3 3 4 .. INDEX RANGE SCAN RD_DE_V_RDE_I_FK1X 2 0 0 0.000 73475 1 0
5: 2 109 0 . TABLE ACCESS BY INDEX ROWID RD_DATA_ENTRY_V 2 0 0 0.000 73471 1 2289
6: 5 1 0 .. INDEX RANGE SCAN RD_DE_V_RD_DE_V_FK2X 2 0 0 0.000 73476 0 0
EXPLAIN PLAN
~~~~~~~~~~~~
Estim Search
ID PID Card Cost Explain Plan Operation Cols(1)
--- ---- ------ ----- ----------------------------------------------- --------
0: 1 11 SELECT STATEMENT
1: 0 1 11 SORT ORDER BY
2: 1 1 10 . HASH JOIN ANTI
3: 2 1 4 .. TABLE ACCESS BY INDEX ROWID RD_DATA_ENTRY_V
4: 3 3 1 ... INDEX RANGE SCAN RD_DE_V_RDE_I_FK1X 1/1
5: 2 1 5 .. TABLE ACCESS BY INDEX ROWID RD_DATA_ENTRY_V
6: 5 1 4 ... INDEX RANGE SCAN RD_DE_V_VVF_CDT_ID1 2/2
(1) X/Y: Where X is the number of searched columns from index, which has a total of Y columns.
Indexed Cols and Predicates(1)
--------------------------------
2 - Access Predicates: V2.DELETES_VERSION_ID=V.VERSION_ID
3 - Filter Predicates: V.VERSION_VALID_FROM<=:B2 AND V.CRE_DATIM<=TO_TIMESTAMP(:B1)
AND V.DELETES_VERSION_ID IS NULL
4 - Indexed Cols for RD_DE_V_RDE_I_FK1X (search 1/1):
RD_TYPE_CODE
4 - Access Predicates: V.RD_TYPE_CODE=:B3
5 - Filter Predicates: V2.DELETES_VERSION_ID IS NOT NULL
6 - Indexed Cols for RD_DE_V_VVF_CDT_ID1 (search 2/2):
SYS_NC00014$
SYS_NC00015$
6 - Access Predicates: SYS_OP_DESCEND(VERSION_VALID_FROM)>=SYS_OP_DESCEND(:B2) AND SYS_OP_DESCEND(CRE_DATIM)>=SYS_OP_DESCEND(TO_TIMESTAMP(:B1))
AND SYS_OP_DESCEND(VERSION_VALID_FROM) IS NOT NULL
6 - Filter Predicates: SYS_OP_UNDESCEND(SYS_OP_DESCEND(VERSION_VALID_FROM))<=:B2
AND
SYS_OP_UNDESCEND(SYS_OP_DESCEND(CRE_DATIM)
)<=TO_TIMESTAMP(:B1)
(1) Identified by operation ID.
TABLES AND INDEXES
~~~~~~~~~~~~~~~~~~
in Row in Avg
Source Explain Current Num Sample Row Chain Empty Avg Global
# Owner.Table Name Plan Plan Count(*)(2) Rows(1) Size(1) Last Analyzed(1) Len(1) Count(1) Blocks(1) Blocks(1) Space(1) Stats(1) Part Temp
--- --------------------- ------- -------- ------------ -------- -------- ------------------- ------- --------- ---------- ---------- --------- --------- ----- -----
1: HECR.RD_DATA_ENTRY_V Y Y 13261 13255 13255 30-MAY-11 22:02:09 90 0 244 12 3864 YES NO N
(1) CBO statistics.
(2) COUNT(*) up to threshold value of 1000000 (tool configuartion parameter).
in Row in
Source Explain Cols
# Owner.Table Name Owner.Index Name Plan Plan Index Type Uniqueness Count Indexed Columns
--- --------------------- -------------------------- ------- -------- ---------------------- ----------- ------ --------------------------
1: HECR.RD_DATA_ENTRY_V HECR.RD_DATA_ENTRY_V_PKX N N NORMAL UNIQUE 2 RD_TYPE_CODE VERSION_ID
2: HECR.RD_DATA_ENTRY_V HECR.RD_DE_V_RDE_I_FK1X N Y NORMAL NONUNIQUE 1 RD_TYPE_CODE
3: HECR.RD_DATA_ENTRY_V HECR.RD_DE_V_RD_DE_V_FK2X N N NORMAL NONUNIQUE 1 DELETES_VERSION_ID
4: HECR.RD_DATA_ENTRY_V HECR.RD_DE_V_VID_UN1X N N NORMAL UNIQUE 1 VERSION_ID
5: HECR.RD_DATA_ENTRY_V HECR.RD_DE_V_VVF_CDT_ID1 N Y FUNCTION-BASED NORMAL NONUNIQUE 2 SYS_NC00014$ SYS_NC00015$
Avg Avg
Leaf Data
Blocks Blocks
Num Sample Distinct Leaf per per Clustering Global
# Owner.Table Name Owner.Index Name Rows(1) Size(1) Last Analyzed(1) Keys(1) Blevel(1) Blocks(1) Key(1) Key(1) Factor(1) Stats(1) Part Temp
--- --------------------- -------------------------- -------- -------- ------------------- --------- ---------- ---------- ------- ------- ----------- --------- ----- -----
1: HECR.RD_DATA_ENTRY_V HECR.RD_DATA_ENTRY_V_PKX 13255 13255 30-MAY-11 22:02:09 13255 1 75 1 1 12018 YES NO N
2: HECR.RD_DATA_ENTRY_V HECR.RD_DE_V_RDE_I_FK1X 13255 13255 30-MAY-11 22:02:10 4389 1 59 1 2 11986 YES NO N
3: HECR.RD_DATA_ENTRY_V HECR.RD_DE_V_RD_DE_V_FK2X 114 114 30-MAY-11 22:02:10 114 0 1 1 1 61 YES NO N
4: HECR.RD_DATA_ENTRY_V HECR.RD_DE_V_VID_UN1X 13255 13255 30-MAY-11 22:02:10 13255 1 53 1 1 687 YES NO N
5: HECR.RD_DATA_ENTRY_V HECR.RD_DE_V_VVF_CDT_ID1 13255 13255 30-MAY-11 22:02:10 1015 2 143 1 1 807 YES NO N
(1) CBO statistics.
Col Asc/ Num Sample Num Num Num
# Owner.Index Name Pos Column Name Desc Rows(1) Size(1) Last Analyzed(1) Nulls(1) Distinct(1) Density(1) Buckets(1)
--- -------------------------- ---- ------------------- ----- -------- -------- ------------------- --------- ------------ ------------- -----------
1: HECR.RD_DATA_ENTRY_V_PKX 1 RD_TYPE_CODE ASC 13255 13255 30-MAY-11 22:02:08 0 4389 2.8920e-04 254
2: HECR.RD_DATA_ENTRY_V_PKX 2 VERSION_ID ASC 13255 13255 30-MAY-11 22:02:08 0 13255 7.5443e-05 1
3: HECR.RD_DE_V_RDE_I_FK1X 1 RD_TYPE_CODE ASC 13255 13255 30-MAY-11 22:02:08 0 4389 2.8920e-04 254
4: HECR.RD_DE_V_RD_DE_V_FK2X 1 DELETES_VERSION_ID ASC 13255 114 30-MAY-11 22:02:08 13141 114 8.7719e-03 1
5: HECR.RD_DE_V_VID_UN1X 1 VERSION_ID ASC 13255 13255 30-MAY-11 22:02:08 0 13255 7.5443e-05 1
6: HECR.RD_DE_V_VVF_CDT_ID1 1 SYS_NC00014$ DESC 13255 13255 30-MAY-11 22:02:08 0 126 3.7722e-05 126
7: HECR.RD_DE_V_VVF_CDT_ID1 2 SYS_NC00015$ DESC 13255 13255 30-MAY-11 22:02:08 0 1010 4.1923e-03 254
(1) CBO statistics.
RECURSIVE SQL - TIME AND TOTALS
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
Response Time Elapsed Non-Idle Elapsed Time Idle
Call Accounted-for Time CPU Time Wait Time Unaccounted-for Wait Time
-------- -------------- -------- --------- ---------- ---------------- ----------
Parse: 0.000 0.000 0.000 0.000 0.000 0.000
Execute: 0.003 0.003 0.000 0.000 0.003 0.000
Fetch: 0.000 0.000 0.000 0.000 0.000 0.000
-------- -------------- -------- --------- ---------- ---------------- ----------
Total: 0.003 0.003 0.000 0.000 0.003 0.000
OS BG Consistent BG Current Rows Library Times Times
Call Buffer Gets Read Mode Mode Processed Cache Waited Waited
Call Count (disk) (query) (current) or Returned Misses Non-Idle Idle
-------- ------ ------------ -------------- ----------- ------------ -------- --------- -------
Parse: 0 0 0 0 0 0 0 0
Execute: 44 0 60 0 300 0 0 0
Fetch: 0 0 0 0 0 0 0 0
-------- ------ ------------ -------------- ----------- ------------ -------- --------- -------
Total: 44 0 60 0 300 0 0 0
RELEVANT EXECUTIONS
~~~~~~~~~~~~~~~~~~~
There are 2 relevant executions of this SQL statement.
Their aggregate "Response Time Accounted-for" represents 0.1% of this "SQL Response Time Accounted-for", and 0.0% of the "Total Response Time Accounted-for".
Within these 2 SQL execuctions, there isn't any with "Response Time Accounted-for" larger than threshold of 5.0% of the "SQL Response Time Accounted-for".
SQL Trace Self Recursive
First/ RT RT Response Elapsed Non-Idle Idle Response Response
Last Rank Pct(1) Pct(2) Time(3) Time CPU Time Wait Time Wait Time Time(4) Start Timestamp End Timestamp Time(5)
------- ------ ------- ------- --------- -------- --------- ---------- ---------- ---------- -------------------- -------------------- ---------
First: 3 0.1% 0.0% 0.004 0.004 0.000 0.000 0.000 0.003 JUN-03 11:12:56.497 JUN-03 11:12:56.504 0.007
Last: 12638 0.0% 0.0% 0.000 0.000 0.000 0.000 0.000 0.000 JUN-03 11:13:11.738 JUN-03 11:13:11.739 0.000
(1) Percent of "SQL Response Time Accounted-for", which is 3.036 secs.
(2) Percent of "Total Response Time Accounted-for", which is 21.526 secs.
(3) "Self Response Time Accounted-for" in secs (caused by this execution).
(4) "Recursive Response Time Accounted-for" in secs (caused by recursive SQL invoked by this execution).
(5) According to timestamps of first and last calls for this execution.