Query performance Issue
933257 Aug 17, 2018 1:35 PMWe are using version 11.2.0.4 of oracle. We have a query running in ~30 seconds in one database(DB1) and the same query is taking ~5minutes in another database(DB2) with data volume and all other configuration remain same in both the databases. i have captured the sql monitor and the session stats for both the databases. I was checking the table/column/index stats and i see from the statistics of the table from both the databases there exists non zero chain_count in one of the databases(DB2), wondering if that is the reason which is causing this query running slow, btw i don't see significant different in "table fetch continued row" value of the both the session stats, so wanted to understand the actual cause of slowness?
SELECT c1, c2, c3, c4, c5, c6, c7, c8.. FROM TAB1 WHERE STS IN ( 'A', 'B') AND cnt < '4' AND dt < sysdate and rownum <=1; Sql_monitor and stats from DB1 ****************************** Global Information ------------------------------ STS : DONE (ALL ROWS) Instance ID : 1 Execution Started : 08/17/2018 08:31:22 First Refresh Time : 08/17/2018 08:31:22 Last Refresh Time : 08/17/2018 08:31:53 Duration : 31s Program : sqlplus.exe Fetch Calls : 1 Global Stats =============================================================================== | Elapsed | Cpu | IO | Concurrency | Fetch | Buffer | Read | Read | | Time(s) | Time(s) | Waits(s) | Waits(s) | Calls | Gets | Reqs | Bytes | =============================================================================== | 33 | 3.00 | 30 | 0.08 | 1 | 102K | 38571 | 301MB | =============================================================================== SQL Plan Monitoring Details (Plan Hash Value=715774357) ====================================================================================================================================================================================== | Id | Operation | Name | Rows | Cost | Time | Start | Execs | Rows | Read | Read | Activity | Activity Detail | | | | | (Estim) | | Active(s) | Active | | (Actual) | Reqs | Bytes | (%) | (# samples) | ====================================================================================================================================================================================== | 0 | SELECT STATEMENT | | | | 1 | +31 | 1 | 1 | | | | | | 1 | COUNT STOPKEY | | | | 1 | +31 | 1 | 1 | | | | | | 2 | INLIST ITERATOR | | | | 1 | +31 | 1 | 1 | | | | | | 3 | TABLE ACCESS BY INDEX ROWID | TAB1 | 114K | 33399 | 32 | +0 | 2 | 1 | 38377 | 300MB | 96.77 | Cpu (1) | | | | | | | | | | | | | | db file sequential read (16) | | | | | | | | | | | | | | read by other session (13) | | 4 | INDEX RANGE SCAN | TAB1_STS_IDX | 115K | 723 | 30 | +2 | 2 | 118K | 194 | 2MB | 3.23 | read by other session (1) | ====================================================================================================================================================================================== Elapsed: 00:00:31.62 Execution Plan ---------------------------------------------------------- Plan hash value: 715774357 --------------------------------------------------------------------------------------------------------- | Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time | --------------------------------------------------------------------------------------------------------- | 0 | SELECT STATEMENT | | 1 | 1847 | 33399 (1)| 00:03:14 | |* 1 | COUNT STOPKEY | | | | | | | 2 | INLIST ITERATOR | | | | | | |* 3 | TABLE ACCESS BY INDEX ROWID| TAB1 | 114K| 201M| 33399 (1)| 00:03:14 | |* 4 | INDEX RANGE SCAN | TAB1_STS_IDX | 114K| | 723 (1)| 00:00:05 | --------------------------------------------------------------------------------------------------------- Predicate Information (identified by operation id): --------------------------------------------------- 1 - filter(ROWNUM<=1) 3 - filter("cnt"<'4' AND "dt"<SYSDATE@!) 4 - access("STS"='A' OR "STS"='B') Statistics ---------------------------------------------------------- 1 recursive calls 0 db block gets 102354 consistent gets 38573 physical reads 0 redo size 1649 bytes sent via SQL*Net to client 785 bytes received via SQL*Net from client 5 SQL*Net roundtrips to/from client 0 sorts (memory) 0 sorts (disk) 1 rows processed Table stats:- table_name,num_rows,blocks,empty_blocks,chain_cnt,avg_row_len TAB1 79654925 22416917 0 0 1847 column_stats(STS):- table_name, column_name, num_distinct,num_nulls,density, avg_col_len TAB1 STS 5 0 6.2049410678782E-9 2 Index_stats(on STS):- index_name,leaf_blocks,distinct_keys,avg_leaf_blocks_per_key,avg_data_blocks_per_key, clustering_factor,num_rows TAB1_STS_IDX 487939 5 97587 4458874 22294372 78308939 Session Stats:- process last non-idle time 1534508966 session connect time 1534508966 logical read bytes from cache 839663616 cell physical IO interconnect bytes 316055552 physical read bytes 316055552 physical read total bytes 316055552 file io wait time 17044083 session pga memory 8643880 session pga memory max 8643880 temp space allocated (bytes) 4194304 session uga memory 1755696 session uga memory max 1755696 buffer is pinned count 135743 table fetch by rowid 117519 non-idle wait count 107301 session logical reads 102500 consistent gets 102450 consistent gets from cache 102448 no work - consistent read gets 102368 buffer is not pinned count 101741 free buffer inspected 43458 free buffer requested 38592 physical read total IO requests 38581 physical read IO requests 38581 physical reads 38581 physical reads cache 38579 hot buffers moved to head of LRU 37258 bytes sent via SQL*Net to client 7370 bytes received via SQL*Net from client 6869 redo size 5536 undo change vector size 4432 DB time 3166 non-idle wait time 2962 user I/O wait time 2954 table fetch continued row 2423
Sql_monitor and stats from DB2 ****************************** Global Information ------------------------------ STS : DONE (ALL ROWS) Instance ID : 1 Execution Started : 08/17/2018 08:21:47 First Refresh Time : 08/17/2018 08:21:47 Last Refresh Time : 08/17/2018 08:26:29 Duration : 282s Module/Action : SQL*Plus/- Program : sqlplus.exe Fetch Calls : 1 Global Stats ================================================================ | Elapsed | Cpu | IO | Fetch | Buffer | Read | Read | | Time(s) | Time(s) | Waits(s) | Calls | Gets | Reqs | Bytes | ================================================================ | 287 | 8.76 | 278 | 1 | 110K | 110K | 858MB | ================================================================ SQL Plan Monitoring Details (Plan Hash Value=715774357) ====================================================================================================================================================================================== | Id | Operation | Name | Rows | Cost | Time | Start | Execs | Rows | Read | Read | Activity | Activity Detail | | | | | (Estim) | | Active(s) | Active | | (Actual) | Reqs | Bytes | (%) | (# samples) | ====================================================================================================================================================================================== | 0 | SELECT STATEMENT | | | | 1 | +282 | 1 | 1 | | | | | | 1 | COUNT STOPKEY | | | | 1 | +282 | 1 | 1 | | | | | | 2 | INLIST ITERATOR | | | | 1 | +282 | 1 | 1 | | | | | | 3 | TABLE ACCESS BY INDEX ROWID | TAB1 | 142K | 40211 | 282 | +1 | 2 | 1 | 109K | 854MB | 100.00 | db file sequential read (277) | | 4 | INDEX RANGE SCAN | TAB1_STS_IDX | 142K | 892 | 280 | +3 | 2 | 118K | 491 | 4MB | | | ====================================================================================================================================================================================== Elapsed: 00:04:42.34 Execution Plan ---------------------------------------------------------- Plan hash value: 715774357 --------------------------------------------------------------------------------------------------------- | Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time | --------------------------------------------------------------------------------------------------------- | 0 | SELECT STATEMENT | | 1 | 1847 | 40211 (1)| 00:08:03 | |* 1 | COUNT STOPKEY | | | | | | | 2 | INLIST ITERATOR | | | | | | |* 3 | TABLE ACCESS BY INDEX ROWID| TAB1 | 141K| 249M| 40211 (1)| 00:08:03 | |* 4 | INDEX RANGE SCAN | TAB1_STS_IDX | 141K| | 892 (1)| 00:00:11 | --------------------------------------------------------------------------------------------------------- Predicate Information (identified by operation id): --------------------------------------------------- 1 - filter(ROWNUM<=1) 3 - filter("cnt"<'4' AND "dt"<SYSDATE@!) 4 - access("STS"='A' OR "STS"='B') Statistics ---------------------------------------------------------- 1 recursive calls 0 db block gets 110182 consistent gets 109818 physical reads 0 redo size 9177 bytes sent via SQL*Net to client 4547 bytes received via SQL*Net from client 5 SQL*Net roundtrips to/from client 0 sorts (memory) 0 sorts (disk) 1 rows processed Table stats:- table_name,num_rows,blocks,empty_blocks,chain_cnt,avg_row_len TAB1 79447350 22318667 710 537597 1847 column_stats(STS):- table_name, column_name, num_distinct,num_nulls,density, avg_col_len TAB1 STS 5 0 6.17895322507497E-9 2 Index_stats(on STS):- index_name,leaf_blocks,distinct_keys,avg_leaf_blocks_per_key,avg_data_blocks_per_key, clustering_factor,num_rows TAB1_STS_IDX 493152 5 98630 4382625 21913127 79106263 Session Stats:- process last non-idle time 1534508200 session connect time 1534508200 logical read bytes from cache 903790592 physical read total bytes 899629056 cell physical IO interconnect bytes 899629056 physical read bytes 899629056 file io wait time 277881742 session pga memory 8586744 session pga memory max 8586744 temp space allocated (bytes) 4194304 session uga memory max 1690184 session uga memory 1690184 buffer is pinned count 129148 table fetch by rowid 117521 session logical reads 110326 consistent gets 110276 consistent gets from cache 110276 no work - consistent read gets 110071 non-idle wait count 109879 free buffer requested 109830 physical read IO requests 109818 physical reads cache 109818 physical reads 109818 physical read total IO requests 109818 buffer is not pinned count 109577 free buffer inspected 70740 hot buffers moved to head of LRU 31910 DB time 28203 non-idle wait time 27788 user I/O wait time 27788 dirty buffers inspected 19067 bytes sent via SQL*Net to client 14927 bytes received via SQL*Net from client 10607 redo size 5440 undo change vector size 4432 table fetch continued row 3660