Hello,
I got a simple query that is performing very slow. To test, I've copied the table from production and only use three columns.
create table test (id number(10),tmestamp date, description char(100) default 'filling up space to make it big, unique index smaller');
create unique index id_idx_test on test (id);
exec dbms_stats.gather_table_stats('SYSTEM','TEST');
insert into test value(id,tmestamp) select id, tmestamp from production.log;
The "test" table contains 7.6 million rows, consuming 994MB of disk space.
The index is unique on "id" column is 185MB.
I ran this query:
select count(*) from system.test;
I took about 4-7 seconds to run.
Here is an execution plan
-------------------------------------------------------------------
| Id | Operation | Name | Rows | Cost (%CPU)| Time |
-------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | 228K (1)|105:15:56 |
| 1 | SORT AGGREGATE | | 1 | | |
| 2 | TABLE ACCESS FULL| TEST | 7605K| 228K (1)|105:15:56 |
-------------------------------------------------------------------
Note the estimated execution time is 105 hours, 15 minutes and 56 seconds. The number of rows is accurate at 7605K.
I have two questions:
1. Why is the estimated execution time way off? The actual execution time is about 7 seconds (i/o speed would be 994MB/7 = 142MB/second).
2. Why didn't the optimizer choose the index when the size of the index is only 185MB? The query would return in less than one second.
Here is the output from tkprof:
TKPROF: Release 11.2.0.4.0 - Development on Wed Aug 30 14:45:32 2017
Copyright (c) 1982, 2011, Oracle and/or its affiliates. All rights reserved.
Trace file: test_ora_25526.trc
Sort options: prsela exeela fchela
********************************************************************************
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
********************************************************************************
SQL ID: d6v6a7d8h6rc1 Plan Hash: 3467505462
TKPROF: Release 11.2.0.4.0 - Development on Wed Aug 30 14:45:32 2017
Copyright (c) 1982, 2011, Oracle and/or its affiliates. All rights reserved.
Trace file: test_ora_25526.trc
Sort options: prsela exeela fchela
********************************************************************************
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
********************************************************************************
SQL ID: d6v6a7d8h6rc1 Plan Hash: 3467505462
select count(*)
from
system.test
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 2 1.68 6.37 126636 126659 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 4 1.68 6.37 126636 126659 0 1
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 5
Number of plan statistics captured: 1
Rows (1st) Rows (avg) Rows (max) Row Source Operation
---------- ---------- ---------- ---------------------------------------------------
1 1 1 SORT AGGREGATE (cr=126659 pr=126636 pw=0 time=6378181 us)
7605369 7605369 7605369 TABLE ACCESS FULL TEST (cr=126659 pr=126636 pw=0 time=2094541 us cost=228689 size=0 card=7605369)
********************************************************************************
SQL ID: 1a2g3z4rj1uq2 Plan Hash: 0
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 mode: ALL_ROWS
Parsing user id: 5
********************************************************************************
OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 2 0.00 0.00 0 0 0 0
Fetch 2 1.68 6.37 126636 126659 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 5 1.68 6.37 126636 126659 0 1
Misses in library cache during parse: 1
Misses in library cache during execute: 1
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
2 user SQL statements in session.
0 internal SQL statements in session.
2 SQL statements in session.
********************************************************************************
Trace file: test_ora_25526.trc
Trace file compatibility: 11.1.0.7
Sort options: prsela exeela fchela
1 session in tracefile.
2 user SQL statements in trace file.
0 internal SQL statements in trace file.
2 SQL statements in trace file.
2 unique SQL statements in trace file.
49 lines in trace file.
8 elapsed seconds in trace file.
Oracle realease: 11.2.0.4 on HPUX.
Thank you.