If you have identified a SQL statement that performs not as good as expected, you should follow the following step-by-step instructions to obtain as much information as possible that can be posted on the OTN forum. If you gather the information described here, in many cases it will be quite obvious what needs to be done to improve the performance of the SQL statement in question.
The following post on OTN should act as a template how a useful posting on OTN should ideally look like so that other people (or you yourself) are able to tell what might be wrong with the execution of the SQL statement.
So if you're posting a request about help on a particular SQL statement, make sure that your request includes all the information similar to the template post, and also make sure that you're using a proper formatting, otherwise the information posted can't be read properly, making it very hard for others to understand the meaning. I'll describe below how to apply this formatting on the OTN forum.
If you're facing a poor performing system but haven't identified yet what the issue this, these instructions here will not be very useful. There are other sources that provide helpful instructions in that case, e.g. Christian Antognini's book "Troubleshooting Oracle Performance" or Tanel Poder's "Advanced Oracle Troubleshooting".
The following steps should be taken to gather detailed information about the SQL statement:
1. Gather information about parameters relevant to the optimizer
2. Gather the output of the SQL*Plus AUTOTRACE and TIMING feature when executing your statement
3. Get the EXPLAIN PLAN output of DBMS_XPLAN.DISPLAY including the "Predicate Information" section
4. Run an extended SQL trace of your statement and analyze the generated trace file using a trace file analyzer like TKPROF
5. If you're on Oracle 10g or later, gather the output of DBMS_XPLAN.DISPLAY_CURSOR after executing your statement
Note that when using bind variables that the plans produced by EXPLAIN PLAN and AUTOTRACE - which does an EXPLAIN PLAN and unfortunately doesn't show the actual execution plan - are only of limited use, due to the bind variable peeking performed when actually executing the statement. Since the EXPLAIN PLAN doesn't execute the statement, the plans generated at runtime might be significantly different from the EXPLAIN PLAN output.
The SQL*Plus AUTOTRACE feature runs your statement, fetches all rows in case of a SELECT statement and shows afterwards basic performance related statistics about your statement. These statistics are already quite helpful and should be provided as part of your posting.
In case of a SELECT that returns a large number of rows it might be quite important what you set as bulk fetch size. You should try to find out which bulk fetch size your particular application uses (or if it fetches each row individually which is a bad idea in most cases) and set in SQL*Plus the ARRAYSIZE accordingly. Note that the default setting in SQL*Plus is to fetch 15 rows at a time, but usually a larger value offers better performance; a setting of at least 100 should be reasonable in most cases, which of course applies to your application as well.
For more information about this particular issue, look here.
It's usually a good idea to spool your SQL*Plus session to a file so that you can get the output from that file using a simple text editor.
You can gather above information in two steps. In the first step you'll run an EXPLAIN PLAN on your statement, generate a trace file and capture the AUTOTRACE output.
If you're on 10g or later you can capture the extended row source statistics using the DBMS_XPLAN.DISPLAY_CURSOR function in a second step.
The following sample scripts are only applicable to Oracle 9i or later.
For both steps I suggest to prepare a respective SQL script that is based on below code snippets, save it to a file and run it in SQL*Plus script mode using the following syntax:
SQLPLUS [user]/[password]@[database_alias] @[scriptfile_name]
Step 1
This is the code snippet for the first part covering relevant optimizer related settings, EXPLAIN PLAN output, extended SQL trace and the AUTOTRACE output.
Whenever you see "rem put your statement here" you should replace the demo SQL with your particular SQL statement that you want to diagnose.
If you're using bind variables, you need to define and initialize them accordingly. You need to remove the corresponding REMark keyword of that section below if you're using them.
If your SQL is sensitive and you don't want to it to show up in the SPOOLed log files, set the ECHO off in your version of the file.
rem Start of part 1 - save this to a file
rem This covers
rem relevant optimizer parameters
rem EXPLAIN PLAN
rem AUTOTRACE
rem extended trace with wait event information
rem whenever you see:
rem put your statement here
rem then replace the demo statement
rem with your SQL statement
-- if the SQL is sensitive
-- don't switch on the ECHO
-- set echo off
set echo on
set timing on trimspool on linesize 250 pagesize 999
-- this setting can influence your sorting
-- in particular if an index can satisfy your sort order
-- alter session set nls_language = 'AMERICAN';
-- enable timed_statistics (is enabled by default in 9i and later)
alter session set timed_statistics = true;
spool diag1.log
show parameter user_dump_dest
show parameter optimizer
show parameter db_file_multi
show parameter db_block_size
show parameter cursor_sharing
column sname format a20
column pname format a20
column pval2 format a20
select
sname
, pname
, pval1
, pval2
from
sys.aux_stats$;
explain plan for
-- put your statement here
select
*
from
t_demo
where
type = 'VIEW'
order by
id;
select * from table(dbms_xplan.display);
rollback;
rem Set the ARRAYSIZE according to your application
set autotrace traceonly arraysize 100
alter session set tracefile_identifier = 'mytrace1';
rem if you're using bind variables
rem define them here
rem variable b_var1 number
rem variable b_var2 varchar2(20)
rem and initialize them
rem exec :b_var1 := 1
rem exec :b_var2 := 'DIAG'
alter session set events '10046 trace name context forever, level 8';
-- put your statement here
select
*
from
t_demo
where
type = 'VIEW'
order by
id;
disconnect
spool off
exit
-- rem End of Part 1
The spool file "diag1.log" of this script should look similar to the following:
SQL> show parameter user_dump_dest
NAME TYPE VALUE
------------------------------------ ----------- ------------------------------
user_dump_dest string c:\oracle\diag\rdbms\orcl11\or
cl11\trace
SQL>
SQL> show parameter optimizer
NAME TYPE VALUE
------------------------------------ ----------- ------------------------------
optimizer_capture_sql_plan_baselines boolean FALSE
optimizer_dynamic_sampling integer 2
optimizer_features_enable string 11.1.0.7
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>
SQL> show parameter db_file_multi
NAME TYPE VALUE
------------------------------------ ----------- ------------------------------
db_file_multiblock_read_count integer 8
SQL>
SQL> show parameter db_block_size
NAME TYPE VALUE
------------------------------------ ----------- ------------------------------
db_block_size integer 8192
SQL>
SQL> show parameter cursor_sharing
NAME TYPE VALUE
------------------------------------ ----------- ------------------------------
cursor_sharing string EXACT
SQL>
SQL> column sname format a20
SQL> column pname format a20
SQL> column pval2 format a20
SQL>
SQL> select
2 sname
3 , pname
4 , pval1
5 , pval2
6 from
7 sys.aux_stats$;
SNAME PNAME PVAL1 PVAL2
-------------------- -------------------- ---------- --------------------
SYSSTATS_INFO STATUS COMPLETED
SYSSTATS_INFO DSTART 01-30-2009 16:25
SYSSTATS_INFO DSTOP 01-30-2009 16:25
SYSSTATS_INFO FLAGS 0
SYSSTATS_MAIN CPUSPEEDNW 494,397
SYSSTATS_MAIN IOSEEKTIM 10
SYSSTATS_MAIN IOTFRSPEED 4096
SYSSTATS_MAIN SREADTIM
SYSSTATS_MAIN MREADTIM
SYSSTATS_MAIN CPUSPEED
SYSSTATS_MAIN MBRC
SYSSTATS_MAIN MAXTHR
SYSSTATS_MAIN SLAVETHR
13 rows selected.
Elapsed: 00:00:00.04
SQL>
SQL> explain plan for
2 -- put your statement here
3 select
4 *
5 from
6 t_demo
7 where
8 type = 'VIEW'
9 order by
10 id;
Explained.
Elapsed: 00:00:00.01
SQL>
SQL> select * from table(dbms_xplan.display);
PLAN_TABLE_OUTPUT
----------------------------------------------------------------------------------------------------------------------------------
Plan hash value: 1390505571
----------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
----------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | 60 | 0 (0)| 00:00:01 |
| 1 | TABLE ACCESS BY INDEX ROWID| T_DEMO | 1 | 60 | 0 (0)| 00:00:01 |
|* 2 | INDEX RANGE SCAN | IDX_DEMO | 1 | | 0 (0)| 00:00:01 |
----------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
2 - access("TYPE"='VIEW')
14 rows selected.
Elapsed: 00:00:00.08
SQL>
SQL> rollback;
Rollback complete.
Elapsed: 00:00:00.00
SQL>
SQL> rem Set the ARRAYSIZE according to your application
SQL> set autotrace traceonly arraysize 100
SQL>
SQL> alter session set tracefile_identifier = 'mytrace1';
Session altered.
Elapsed: 00:00:00.00
SQL>
SQL> rem if you're using bind variables
SQL> rem define them here
SQL>
SQL> rem variable b_var1 number
SQL> rem variable b_var2 varchar2(20)
SQL>
SQL> rem and initialize them
SQL>
SQL> rem exec :b_var1 := 1
SQL> rem exec :b_var2 := 'DIAG'
SQL>
SQL> alter session set events '10046 trace name context forever, level 8';
Session altered.
Elapsed: 00:00:00.01
SQL>
SQL> -- put your statement here
SQL> select
2 *
3 from
4 t_demo
5 where
6 type = 'VIEW'
7 order by
8 id;
149938 rows selected.
Elapsed: 00:00:02.21
Execution Plan
----------------------------------------------------------
Plan hash value: 1390505571
----------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
----------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | 60 | 0 (0)| 00:00:01 |
| 1 | TABLE ACCESS BY INDEX ROWID| T_DEMO | 1 | 60 | 0 (0)| 00:00:01 |
|* 2 | INDEX RANGE SCAN | IDX_DEMO | 1 | | 0 (0)| 00:00:01 |
----------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
2 - access("TYPE"='VIEW')
Statistics
----------------------------------------------------------
0 recursive calls
0 db block gets
149101 consistent gets
800 physical reads
196 redo size
1077830 bytes sent via SQL*Net to client
16905 bytes received via SQL*Net from client
1501 SQL*Net roundtrips to/from client
0 sorts (memory)
0 sorts (disk)
149938 rows processed
SQL>
SQL> disconnect
Disconnected from Oracle Database 11g Enterprise Edition Release 11.1.0.7.0 - Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options
SQL>
SQL> spool off
Make sure you see the optimizer settings (provided your user has access to V$PARAMETER), the EXPLAIN PLAN output and the AUTOTRACE statistics.
If some of these things are missing or you get error messages, sort any missing privileges or missing objects out and try again.
Please note that it's crucial that the EXPLAIN PLAN output includes the "Predicate Information" section below the execution plan. If it's missing and you get instead the message "PLAN_TABLE is old version" in the "Notes" section, you need to either re-create the PLAN_TABLE using the server-side script "$ORACLE_HOME/rdbms/admin/utlxplan.sql" or in 10g you can simply drop any PLAN_TABLE not owned by SYS since the SYS schema already provides a global temporary table PLAN_TABLE$ that is exposed via public synonym, so there is no need for a private PLAN_TABLE any longer.
The next step that you need to perform is to analyze the trace file generated. The "USER_DUMP_DEST" setting in your script output tells you where your trace file has been generated on the server. It will have the "mytrace1" trace file identifier specified in its name, so it should be easy to identify, even if you have pass this request to a DBA.
Once the trace file has been located, you need to run the trace file analyzer. I suggest to use the one provided by Oracle (TKPROF), but you should know that there are other freely available trace analyzers, e.g. OraSRP by Egor Starostin or TVD$XTAT by Christian Antognini. Oracle offers an extended version of TKPROF on MetaLink called TRCANLZR, see MetaLink note 224270.1.
I recommend to use the version of TKPROF that is part of the database installation, but you can use also one which is part of your client installation. Ideally it should have the same version and patch level as your database.
In order to run TKPROF to analyze your trace file, simply run the following:
TKPROF [input_trace_filename] trace_output.txt
This will generate a file called "trace_output.txt" that looks similar to the following:
TKPROF: Release 11.1.0.7.0 - Production on Mo Feb 23 10:23:08 2009
Copyright (c) 1982, 2007, Oracle. All rights reserved.
Trace file: orcl11_ora_3376_mytrace1.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
********************************************************************************
select
*
from
t_demo
where
type = 'VIEW'
order by
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 1501 0.53 1.36 800 149101 0 149938
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 1503 0.53 1.36 800 149101 0 149938
Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 88
Rows Row Source Operation
------- ---------------------------------------------------
149938 TABLE ACCESS BY INDEX ROWID T_DEMO (cr=149101 pr=800 pw=0 time=60042 us cost=0 size=60 card=1)
149938 INDEX RANGE SCAN IDX_DEMO (cr=1881 pr=1 pw=0 time=0 us cost=0 size=0 card=1)(object id 74895)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 1501 0.00 0.00
db file sequential read 800 0.05 0.80
SQL*Net message from client 1501 0.00 0.69
********************************************************************************
SQL ID: g72kdvcacxvtf
Plan Hash: 2637181423
DELETE FROM PLAN_TABLE
WHERE
STATEMENT_ID=:1
...
You need to find the part in the trace file that corresponds to the statement that you've traced. It might contain other statements and cover even some statements recursively executed by Oracle.
Once you've located your statement in the trace file, the information below immediately following your statement is the crucial one:
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 1501 0.53 1.36 800 149101 0 149938
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 1503 0.53 1.36 800 149101 0 149938
Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 88
Rows Row Source Operation
------- ---------------------------------------------------
149938 TABLE ACCESS BY INDEX ROWID T_DEMO (cr=149101 pr=800 pw=0 time=60042 us cost=0 size=60 card=1)
149938 INDEX RANGE SCAN IDX_DEMO (cr=1881 pr=1 pw=0 time=0 us cost=0 size=0 card=1)(object id 74895)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 1501 0.00 0.00
db file sequential read 800 0.05 0.80
SQL*Net message from client 1501 0.00 0.69
This covers the summary timing and blocks related information, the "Parse" related information (was it a hard parse or soft parse represented by the "Misses in library cache..." information), the "Row Source Operations" and the wait events. If one of these sections is missing, something went wrong.
E.g. if you don't disconnect your session, the "Row Source Operation" part could be missing. Since this is a crucial analysis information, you should make sure that it is part of the trace file and the TKPROF output. If you check the raw trace file, this information is represented by lines beginning with "STAT ...".
Step 2
If you're on 10g or later, you can run in a second step the "DBMS_XPLAN.DISPLAY_CURSOR" function to gather some additional information about the execution of your statement.
This is the code snippet for the second part covering the DBMS_XPLAN.DISPLAY_CURSOR output.
Whenever you see "rem put your statement here" you should replace the demo SQL with your particular SQL statement that you want to diagnose.
Note that this is going to execute your statement a second time. I've included a (commented) "flush buffer_cache" instruction, but e.g. on a production system this might not be recommended, so you should be cautious.
Again you should save this to a file and executed it in SQL*Plus as outlined above.
Again, if you're using bind variables, you need to define and initialize them accordingly. You need to remove the corresponding REMark keyword of that section below if you're using them.
rem Start of part 2 - save this to a file
rem This covers
rem DBMS_XPLAN.DISPLAY_CURSOR
-- if you're on 10g or later
-- get the row source statistics
-- if the SQL is sensitive
-- don't switch on the ECHO
-- set echo off
set echo on
set timing on trimspool on linesize 250 pagesize 999
-- this setting can influence your sorting
-- in particular if an index can satisfy your sort order
-- alter session set nls_language = 'AMERICAN';
rem Set the ARRAYSIZE according to your application
set arraysize 100 termout off
rem make sure that this doesn't harm
rem the environment you're running this script
rem e.g. don't do this to a production system
rem alter system flush buffer_cache;
rem if you're using bind variables
rem define them here
rem variable b_var1 number
rem variable b_var2 varchar2(20)
rem and initialize them
rem exec :b_var1 := 1
rem exec :b_var2 := 'DIAG'
spool off
-- put your statement here
-- use the GATHER_PLAN_STATISTICS hint
-- if you're not using STATISTICS_LEVEL = ALL
select /*+ gather_plan_statistics */
*
from
t_demo
where
type = 'VIEW'
order by
id;
set termout on
spool diag2.log
select * from table(dbms_xplan.display_cursor(null, null, 'ALLSTATS LAST'));
spool off
exit
-- rem End of Part 2
The spool output "diag2.log" of this SQL script should look similar to the following:
SQL>
SQL> select * from table(dbms_xplan.display_cursor(null, null, 'ALLSTATS LAST'));
PLAN_TABLE_OUTPUT
----------------------------------------------------------------------------------------------------------------------------------
SQL_ID d4k5acu783vu8, child number 0
-------------------------------------
select /*+ gather_plan_statistics */ * from t_demo
where type = 'VIEW' order by id
Plan hash value: 1390505571
-----------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows | A-Rows | A-Time | Buffers | Reads |
-----------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | | 149K|00:00:00.02 | 149K| 1183 |
| 1 | TABLE ACCESS BY INDEX ROWID| T_DEMO | 1 | 1 | 149K|00:00:00.02 | 149K| 1183 |
|* 2 | INDEX RANGE SCAN | IDX_DEMO | 1 | 1 | 149K|00:00:00.02 | 1880 | 383 |
-----------------------------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
2 - access("TYPE"='VIEW')
20 rows selected.
Elapsed: 00:00:00.12
SQL>
SQL> spool off
Note that the DISPLAY_CURSOR function repeats the SQL analyzed so you need to remove it from the posted information if you are not allowed to disclose this information.
How to post the information on OTN
Now that you've collected the most important information about your SQL statement, here are the instructions how to post them properly on OTN.
Your post should start with a short description of what your SQL statement is about, e.g. if it covers some specific logic it might be good to mention this. Often things can be expressed differently in SQL and it's not unlikely that with the right information at hand someone might come with a different solution for the same problem which could be much more efficient making any further tuning efforts unnecessary.
Then you should of course post the SQL itself, if possible, this would be very helpful.
Note that a proper formatting of your SQL statement is very helpful, not only for others, but for yourself. If you want to get this done automatically, you can use some of the freely available online SQL formatting tools, e.g. SQLInform offers a quite powerful one.
You should also include an information about the expected runtime of your statement, simply saying that it takes "longer" is not really helpful. You could say e.g. that it is expected to return the whole result in 1 second, or 1 minute or similar.
In case you have the special requirement that you only need to fetch the first N rows of the result set this is also very important and should be mentioned explicitly, apart from the fact that your statement then usually should include an ORDER BY wrapped by a "ROWNUM < N" filter predicate.
After this general information you should post the information gathered, which is the following:
1. The version of your database with 4-digits (e.g. 10.2.0.4)
2. Parameters relevant to the optimizer
3. The TIMING and AUTOTRACE output
4. The EXPLAIN PLAN output
5. The TKPROF output snippet that corresponds to your statement
6. If you're on 10g or later, the DBMS_XPLAN.DISPLAY_CURSOR output as outlined above.
The most important point when posting spool/trace file output is the usage of the "code" tag. By using this "code" tag the information will be formatted in fixed font which preserves the formatting and makes it readable. Failure to do so will render the information more or less useless, since nobody can read your posted information, so make sure you use the "code" tag appropriately, which is not that complicated:
If you want to preserve the formatting and use fixed font formatting, enclose the information with the {code} tag before and after like that:
{code}
Here goes something
which is formatted in fixed font
and preserved formatting
{code}
So here is how a sample posting could look like:
Subject: SQL statement tuning request
-- Start of body --
The following SQL statement has been identified to perform poorly. It currently takes up to 10 seconds to execute, but it's supposed to take a second at most.
This is the statement:
{code}
select
*
from
t_demo
where
type = 'VIEW'
order by
id;
{code}
It should return data from a table in a specific order.
The version of the database is 11.1.0.7.
These are the parameters relevant to the optimizer:
{code}
SQL>
SQL> show parameter optimizer
NAME TYPE VALUE
------------------------------------ ----------- ------------------------------
optimizer_capture_sql_plan_baselines boolean FALSE
optimizer_dynamic_sampling integer 2
optimizer_features_enable string 11.1.0.7
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>
SQL> show parameter db_file_multi
NAME TYPE VALUE
------------------------------------ ----------- ------------------------------
db_file_multiblock_read_count integer 8
SQL>
SQL> show parameter db_block_size
NAME TYPE VALUE
------------------------------------ ----------- ------------------------------
db_block_size integer 8192
{code}
Here is the output of EXPLAIN PLAN:
{code}
SQL> explain plan for
2 -- put your statement here
3 select
4 *
5 from
6 t_demo
7 where
8 type = 'VIEW'
9 order by
10 id;
Explained.
Elapsed: 00:00:00.01
SQL>
SQL> select * from table(dbms_xplan.display);
PLAN_TABLE_OUTPUT
----------------------------------------------------------------------------------------------------------------------------------
Plan hash value: 1390505571
----------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
----------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | 60 | 0 (0)| 00:00:01 |
| 1 | TABLE ACCESS BY INDEX ROWID| T_DEMO | 1 | 60 | 0 (0)| 00:00:01 |
|* 2 | INDEX RANGE SCAN | IDX_DEMO | 1 | | 0 (0)| 00:00:01 |
----------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
2 - access("TYPE"='VIEW')
14 rows selected.
{code}
Here is the output of SQL*Plus AUTOTRACE including the TIMING information:
{code}
SQL> select
2 *
3 from
4 t_demo
5 where
6 type = 'VIEW'
7 order by
8 id;
149938 rows selected.
Elapsed: 00:00:02.21
Execution Plan
----------------------------------------------------------
Plan hash value: 1390505571
----------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
----------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | 60 | 0 (0)| 00:00:01 |
| 1 | TABLE ACCESS BY INDEX ROWID| T_DEMO | 1 | 60 | 0 (0)| 00:00:01 |
|* 2 | INDEX RANGE SCAN | IDX_DEMO | 1 | | 0 (0)| 00:00:01 |
----------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
2 - access("TYPE"='VIEW')
Statistics
----------------------------------------------------------
0 recursive calls
0 db block gets
149101 consistent gets
800 physical reads
196 redo size
1077830 bytes sent via SQL*Net to client
16905 bytes received via SQL*Net from client
1501 SQL*Net roundtrips to/from client
0 sorts (memory)
0 sorts (disk)
149938 rows processed
SQL>
SQL> disconnect
Disconnected from Oracle Database 11g Enterprise Edition Release 11.1.0.7.0 - Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options
{code}
The TKPROF output for this statement looks like the following:
{code}
TKPROF: Release 11.1.0.7.0 - Production on Mo Feb 23 10:23:08 2009
Copyright (c) 1982, 2007, Oracle. All rights reserved.
Trace file: orcl11_ora_3376_mytrace1.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
********************************************************************************
select
*
from
t_demo
where
type = 'VIEW'
order by
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 1501 0.53 1.36 800 149101 0 149938
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 1503 0.53 1.36 800 149101 0 149938
Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 88
Rows Row Source Operation
------- ---------------------------------------------------
149938 TABLE ACCESS BY INDEX ROWID T_DEMO (cr=149101 pr=800 pw=0 time=60042 us cost=0 size=60 card=1)
149938 INDEX RANGE SCAN IDX_DEMO (cr=1881 pr=1 pw=0 time=0 us cost=0 size=0 card=1)(object id 74895)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 1501 0.00 0.00
db file sequential read 800 0.05 0.80
SQL*Net message from client 1501 0.00 0.69
********************************************************************************
{code}
The DBMS_XPLAN.DISPLAY_CURSOR output:
{code}
SQL>
SQL> select * from table(dbms_xplan.display_cursor(null, null, 'ALLSTATS LAST'));
PLAN_TABLE_OUTPUT
----------------------------------------------------------------------------------------------------------------------------------
SQL_ID d4k5acu783vu8, child number 0
-------------------------------------
select /*+ gather_plan_statistics */ * from t_demo
where type = 'VIEW' order by id
Plan hash value: 1390505571
-----------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows | A-Rows | A-Time | Buffers | Reads |
-----------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | | 149K|00:00:00.02 | 149K| 1183 |
| 1 | TABLE ACCESS BY INDEX ROWID| T_DEMO | 1 | 1 | 149K|00:00:00.02 | 149K| 1183 |
|* 2 | INDEX RANGE SCAN | IDX_DEMO | 1 | 1 | 149K|00:00:00.02 | 1880 | 383 |
-----------------------------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
2 - access("TYPE"='VIEW')
20 rows selected.
{code}
I'm looking forward for suggestions how to improve the performance of this statement.
-- End of body --
I'm sure that if you follow these instructions and obtain the information described, post them using a proper formatting (don't forget about the {code} tag) you'll receive meaningful advice very soon.
So, just to make sure you didn't miss this point:
{code}
Use proper formatting!
{code}
If you think I missed something important in this sample post let me know so that I can improve it.