Hi, we are using version 11.2.0.4 of oracle. We have two databases with same configurations(both infrastructure wise and DB parameter wise), replica of each other and stats gathering for one of the partition in a table is taking ~40minutes in one database and in other database, it took ~5minutes, with exact same data. So wanted to understand the reason behind same. In V$active_session_history it was showing all db file sequential read wait event. Then we trace both the database executions , i notice the one in which its running slow having lot of disk reads. Does it mean that the stats gather actually running fast because of the blocks are cached in buffer pool for the fast execution, or any other underlying issue, causing this?
Its a Range partition and hash subpartition table. Table size is ~450GB having ~450 partitions.We are collecting stats for specific partition with granularity ALL. This specific partition(DT_20180520) is having ~128 subpartitions in it but having total size ~1GB. This table doesn't contain any LOB data type. So i am wondering why is it taking so much time for gathering stats? or i am doing anything wrong?
BEGIN DBMS_STATS.GATHER_TABLE_STATS('USER1','TAB1','DT_20180520',GRANULARITY=>'ALL',CASCADE=>TRUE); END;
below is comparison of execution stats of one of the sql which triggered internally by oracle..
/* SQL Analyze(0) */ select /*+ full(t) no_parallel(t) no_parallel_index(t) dbms_stats cursor_sharing_exact use_weak_name_resl dynamic_sampling(0) no_monitoring no_substrb_pad */to_char(count("COL1")).........
BEGIN DBMS_STATS.GATHER_TABLE_STATS('USER1','TAB1','DT_20180520',GRANULARITY=>'ALL',CASCADE=>TRUE); END;
below is comparison of execution stats of one of the sql which triggered internally by oracle..
/* SQL Analyze(0) */ select /*+ full(t) no_parallel(t) no_parallel_index(t) dbms_stats cursor_sharing_exact use_weak_name_resl dynamic_sampling(0) no_monitoring no_substrb_pad */to_char(count("COL1")).........
******Slow Execution trace:-
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.06 0.06 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 1 134.78 1488.59 1754722 1845662 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 3 134.84 1488.66 1754722 1845662 0 1
Misses in library cache during parse: 1
Optimizer mode: CHOOSE
Parsing user id: 25 (recursive depth: 1)
Number of plan statistics captured: 1
Rows (1st) Rows (avg) Rows (max) Row Source Operation
---------- ---------- ---------- ---------------------------------------------------
1 1 1 SORT AGGREGATE (cr=1845662 pr=1754722 pw=0 time=1488591307 us)
7480507 7480507 7480507 APPROXIMATE NDV AGGREGATE (cr=1845662 pr=1754722 pw=0 time=1414005768 us cost=578963 size=1518542921 card=7480507)
7480507 7480507 7480507 PARTITION RANGE ALL PARTITION: 1 740 (cr=1845662 pr=1754722 pw=0 time=1381566438 us cost=578963 size=1518542921 card=7480507)
7480507 7480507 7480507 PARTITION HASH ALL PARTITION: 1 128 (cr=1845662 pr=1754722 pw=0 time=1401516302 us cost=578963 size=1518542921 card=7480507)
7480507 7480507 7480507 TABLE ACCESS FULL TAB1 PARTITION: 1 94720 (cr=1845662 pr=1754722 pw=0 time=1436601572 us cost=578963 size=1518542921 card=7480507)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
db file scattered read 58528 0.14 608.59
db file sequential read 124612 0.20 756.93
latch: cache buffers lru chain 1 0.00 0.00
latch: object queue header operation 28 0.00 0.00
resmgr:cpu quantum 52 0.01 0.11
latch free 7 0.01 0.01
********************************************************************************
*********FAST Execution trace*********************
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.06 0.06 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 1 66.84 278.27 481927 1959908 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 3 66.90 278.34 481927 1959908 0 1
Misses in library cache during parse: 1
Optimizer mode: CHOOSE
Parsing user id: 60 (recursive depth: 1)
Number of plan statistics captured: 1
Rows (1st) Rows (avg) Rows (max) Row Source Operation
---------- ---------- ---------- ---------------------------------------------------
1 1 1 SORT AGGREGATE (cr=1959908 pr=481927 pw=0 time=278276709 us)
7480507 7480507 7480507 APPROXIMATE NDV AGGREGATE (cr=1959908 pr=481927 pw=0 time=264208361 us cost=436962 size=1518542921 card=7480507)
7480507 7480507 7480507 PARTITION RANGE ALL PARTITION: 1 740 (cr=1959908 pr=481927 pw=0 time=239705556 us cost=436962 size=1518542921 card=7480507)
7480507 7480507 7480507 PARTITION HASH ALL PARTITION: 1 128 (cr=1959908 pr=481927 pw=0 time=236846251 us cost=436962 size=1518542921 card=7480507)
7480507 7480507 7480507 TABLE ACCESS FULL TAB1 PARTITION: 1 94720 (cr=1959908 pr=481927 pw=0 time=229677586 us cost=436962 size=1518542921 card=7480507)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
Disk file operations I/O 29 0.00 0.00
db file sequential read 23320 0.05 10.09
db file scattered read 21906 0.07 40.52
read by other session 95558 0.07 151.41
latch: cache buffers chains 11925 0.01 0.60
latch free 15 0.00 0.01
latch: object queue header operation 1 0.00 0.00
latch: cache buffers lru chain 1 0.00 0.00
********************************************************************************