Thank you so much.
So when I searched dba_hist_sqltext and dba_hist_reports, I saw a similar
pattern SELECT query ran ~11 times and each time it took ~2-3minutes. And
the difference in the sql_text was mainly the column name. So it's matching
with the number of height balanced histograms in that table which is ~11.
So does it mean that the way 11.2.0.4 version was calculating the height
balanced histogram is different from how it's now happening in 19c here.
And maybe in 11.2 it was scanning the table once VS here it's scanning many
times based on the number of columns on which histogram needs to be created?
SQL Text
------------------------------
BEGIN
dbms_stats.gather_table_stats(ownname=>'USER1',tabname=>'TAB1',DEGREE=>4,ESTIMATE_PERCENT=>50,CASCADE=>TRUE,method_opt
=> 'FOR ALL COLUMNS SIZE AUTO'); END;
Global Information
------------------------------
Status : DONE
Instance ID : 2
Session : SYS (735:13646)
SQL ID : XXXXXXXXXX
SQL Execution ID : 33554432
Execution Started : 06/20/2022 11:54:47
First Refresh Time : 06/20/2022 12:34:32
Last Refresh Time : 06/20/2022 12:34:35
Duration : 2388s
Service : SYS$USERS
PLSQL Entry Ids (Object/Subprogram) : 8032,84
PLSQL Current Ids (Object/Subprogram) : 8032,516
Global Stats
====================================================================================================================
| Elapsed | Cpu | IO | Application | Concurrency | Cluster | PL/SQL |
Other | Buffer | Read | Read |
| Time(s) | Time(s) | Waits(s) | Waits(s) | Waits(s) | Waits(s) | Time(s)
| Waits(s) | Gets | Reqs | Bytes |
====================================================================================================================
| 4.03 | 2.25 | 1.03 | 0.02 | 0.06 | 0.07 | 0.27 |
0.59 | 63289 | 557 | 4MB |
====================================================================================================================
Below is one of the sample sql monitors of one of those 11 queries which
ran as part of the stats gathered on the main table.
SQL Text
------------------------------
select min(minbkt),maxbkt,substrb(dump(min(val),16,0,64),1,240)
minval,substrb(dump(max(val),16,0,64),1,240) maxval,sum(rep) sumrep,
sum(repsq) sumrepsq, max(rep) maxrep, count(*) bktndv, sum(case when rep=1
then 1 else 0 end) unqrep from (select val,min(bkt) minbkt, max(bkt)
maxbkt, count(val) rep, count(val)*count(val) repsq from (select /*+
no_expand_table(t) index_rs(t) parallel(t,4) parallel_index(t,4) dbms_stats
cursor_sharing_exact use_weak_name_resl dynamic_sampling(0) no_monitoring
xmlindex_sel_idx_tbl opt_param('optimizer_inmemory_aware' 'false')
no_substrb_pad */"COL1" val, ntile(254) over (order by "COL1") bkt from
"USER1"."TAB1" sample ( 50.0000000000) t where "COL1" is not null) group by
val) group by maxbkt order by maxbkt
Global Information
------------------------------
Status : DONE (ALL ROWS)
Instance ID : 2
Session : SYS (735:13646)
SQL ID : c8qv5nmzyas4s
SQL Execution ID : 33554432
Execution Started : 06/20/2022 12:20:42
First Refresh Time : 06/20/2022 12:20:42
Last Refresh Time : 06/20/2022 12:23:45
Duration : 183s
Service : SYS$USERS
Fetch Calls : 1
Global Stats
=========================================================================================================================================
| Elapsed | Cpu | IO | Application | Concurrency | Cluster | Fetch |
Buffer | Read | Read | Write | Write | Offload |
| Time(s) | Time(s) | Waits(s) | Waits(s) | Waits(s) | Waits(s) | Calls |
Gets | Reqs | Bytes | Reqs | Bytes | Returned Bytes |
=========================================================================================================================================
| 738 | 147 | 514 | 0.00 | 0.00 | 78 | 1 |
16M | 61258 | 51GB | 3221 | 2GB | 3GB |
=========================================================================================================================================
Parallel Execution Details (DOP=4 , Servers Allocated=8)
Instances : 2
=============================================================================================================================================================================================
| Instance | Name | Type | Server# | Elapsed | Cpu | IO |
Application | Concurrency | Cluster | Buffer | Read | Read | Write | Write
| Offload | Wait Events |
| | | | | Time(s) | Time(s) | Waits(s) |
Waits(s) | Waits(s) | Waits(s) | Gets | Reqs | Bytes | Reqs | Bytes |
Returned Bytes | (sample #) |
=============================================================================================================================================================================================
| 2 | PX Coordinator | QC | | 0.05 | 0.05 | |
0.00 | | | 9 | | . | | . |
. | |
| 1 | p000 | Set 1 | 1 | 2.06 | 2.06 | |
| | | | | . | | . |
. | |
| 1 | p001 | Set 1 | 2 | 1.98 | 1.98 | |
| | | | | . | | . |
. | |
| 1 | p002 | Set 1 | 3 | 2.10 | 2.10 | |
| | | | | . | | . |
. | |
| 1 | p003 | Set 1 | 4 | 2.08 | 2.08 | |
| | | | | . | | . |
. | |
| 1 | p004 | Set 2 | 1 | 182 | 35 | 116 |
| 0.00 | 31 | 4M | 14935 | 12GB | 804 | 403MB |
805MB | |
| 1 | p005 | Set 2 | 2 | 182 | 33 | 141 |
| 0.00 | 7.04 | 4M | 15026 | 13GB | 805 | 403MB |
805MB | |
| 1 | p006 | Set 2 | 3 | 184 | 36 | 115 |
| 0.00 | 32 | 4M | 16092 | 14GB | 806 | 403MB |
806MB | |
| 1 | p007 | Set 2 | 4 | 182 | 34 | 142 |
| 0.00 | 7.02 | 4M | 15205 | 13GB | 806 | 403MB |
806MB | |
=============================================================================================================================================================================================
Instance Drill-Down
====================================================================================================================================================================================================
| Instance | Process Names | Elapsed | Cpu |
IO | Application | Concurrency | Cluster | Buffer | Read | Read | Write |
Write | Offload | Wait Events |
| | | Time(s) | Time(s) |
Waits(s) | Waits(s) | Waits(s) | Waits(s) | Gets | Reqs | Bytes | Reqs |
Bytes | Returned Bytes | |
====================================================================================================================================================================================================
| 1 | p000 p001 p002 p003 p004 p005 p006 p007 | 738 | 147 |
514 | | 0.00 | 78 | 16M | 61258 | 51GB | 3221 |
2GB | 3GB | |
| 2 | QC | 0.05 | 0.05 |
| 0.00 | | | 9 | | | | |
| |
====================================================================================================================================================================================================
SQL Plan Monitoring Details (Plan Hash Value=525667881)
========================================================================================================================================================================================================================
| Id | Operation |
Name | Rows | Cost | Time | Start | Execs | Rows | Read | Read
| Write | Write | Mem | Activity | Activity Detail |
| | |
| (Estim) | | Active(s) | Active | | (Actual) | Reqs |
Bytes | Reqs | Bytes | (Max) | (%) | (# samples) |
========================================================================================================================================================================================================================
| 0 | SELECT STATEMENT |
| | | 1 | +183 | 9 | 254 | |
| | | . | | |
| 1 | PX COORDINATOR |
| | | 171 | +13 | 9 | 254 | 10409 | 2GB
| 3221 | 2GB | 212KB | | |
| 2 | PX SEND QC (ORDER) | :TQ10003
| 2M | 19334 | 1 | +183 | 4 | 254 | |
| | | . | | |
| 3 | SORT GROUP BY |
| 2M | 19334 | 1 | +183 | 4 | 254 | |
| | | 71680 | | |
| 4 | PX RECEIVE |
| 2M | 19334 | 1 | +183 | 4 | 1016 | |
| | | . | | |
| 5 | PX SEND RANGE | :TQ10002
| 2M | 19334 | 1 | +183 | 4 | 1016 | |
| | | . | | |
| 6 | HASH GROUP BY |
| 2M | 19334 | 1 | +183 | 4 | 1016 | |
| | | 70MB | | |
| 7 | VIEW |
| 2M | 19295 | 1 | +183 | 4 | 2M | |
| | | . | | |
| 8 | HASH GROUP BY |
| 2M | 19295 | 1 | +183 | 4 | 2M | |
| | | 261MB | | |
| 9 | PX RECEIVE |
| 2M | 19295 | 1 | +183 | 4 | 2M | |
| | | . | | |
| 10 | PX SEND HASH |
:TQ10001 | 2M | 19295 | 1 | +183 | 4 | 2M |
| | | | . | | |
| 11 | HASH GROUP BY |
| 2M | 19295 | 2 | +182 | 4 | 2M | |
| | | 271MB | | |
| 12 | VIEW |
| 7M | 19295 | 2 | +182 | 4 | 7M | |
| | | . | | |
| 13 | WINDOW SORT |
| 7M | 19295 | 16 | +168 | 4 | 7M | |
| | | 302MB | | |
| 14 | PX RECEIVE |
| 7M | 19176 | 15 | +168 | 4 | 7M | |
| | | . | | |
| 15 | PX SEND RANGE |
:TQ10000 | 7M | 19176 | 181 | +2 | 4 | 7M |
| | | | . | | |
| 16 | PX BLOCK ITERATOR |
| 7M | 19176 | 181 | +2 | 8 | 34M | |
| | | . | | |
| 17 | TABLE ACCESS STORAGE SAMPLE BY ROWID RANGE | TAB1
| 7M | 19176 | 182 | +1 | 130 | 34M | 50849 |
50GB | | | . | | |
========================================================================================================================================================================================================================
On Thu, Jun 23, 2022 at 9:21 PM Mohamed Houri <mohamed.houri@xxxxxxxxx>
wrote:
Pap,
*However, we are trying to understand, why it's taking 30minutes more now
in 19c even with same 50% sample , which was used in 11.2? Is it because
any bug here in 19c?*
I don't know. And I don't think really that this could be linked to a bug.
And even if this could be due to any bug, Oracle support will suggest using
the default value of the sampling percentage
As Nenad has already suggested you can trace your dbms_stats call to this
table and check where time is spent.
Or you can check dba_hist_sqltext ( or v$sql_monitor (or dba_hist_reports)
) for SQL statement where sql_text like '%Analyse%' and sql_text like
'%YOUR_TABLE_NAME%' and investigate where time is spent for this SQL
statements
Best regards
Mohamed
Le jeu. 23 juin 2022 à 17:26, Nenad Noveljic <nenad.noveljic@xxxxxxxxx> a
écrit :
Why don‘t you trace the process?
Von meinem iPhone gesendet
Am 23.06.2022 um 15:40 schrieb Pap <oracle.developer35@xxxxxxxxx>:
Thank you Lothar. Actually all the indexes on this mon partitioned table
are btree indexes. And also I checked DBA_OPTSTAT_OPERATION_TASKS in which
there is breakup of howmuch time each index stats gather took. And it says
those all indexes are combined finishing in minutes.
On Thu, 23 Jun 2022, 6:40 pm l.flatz@xxxxxxxxxx, <l.flatz@xxxxxxxxxx>
wrote:
Hi,
there was a change in the way bitmap index stats are calculated.
Check out Doc ID 2611336.1
Thanks
Lothar
----Ursprüngliche Nachricht----
Von : oracle.developer35@xxxxxxxxx
Datum : 23/06/2022 - 14:10 (MS)
An : mohamed.houri@xxxxxxxxx
Cc : oracle-l@xxxxxxxxxxxxx
Betreff : Re: Stats gather taking longer -19c
Thank you Mohamed.
So basically we must have to remove the hard coded sample and use to
auto sample size in all the places. Without this the histogram would be old
types and also distinct value calculation would be old types.
However we are trying to understand, why it's taking 30minutes more now
in 19c even with same 50% sample , which was used in 11.2? Is it because
any bug here in 19c?
On Thu, 23 Jun 2022, 5:13 pm Mohamed Houri, < mohamed.houri@xxxxxxxxx>
wrote:
Pap,
*Its having histograms on ~36 columns but all of them are still showing
height-balanced and frequency. I was expecting those to be hybrid , but its
didnt happen, may be because of the way the stats getting gathered on this
table i.e. with hard coded 50% sample i.e as below. *
If you are in 12c and above and you still find histograms of the legacy
HEIGHT BALANCED type then it is either that
- the statistics for the concerned tables have not yet been
calculated in the newer Oracle version
- or that you are calculating the statistics with a non-default
value of the estimate_percent ( sampling percentage): default value
being
*AUTO_SAMPLE_SIZE *
It looks like you are in the second situation since you are using 50% a
sample percentage that you should never have done; since the
*AUTO_SAMPLE_SIZE *default value governs,among others, the
approximate_ndv algorithm and the new histogram types
Best regards
Mohamed Houri
Le jeu. 23 juin 2022 à 12:23, Pap < oracle.developer35@xxxxxxxxx> a
écrit :
Hi, We moved from 11.2.0.4 to version 19.11.0.0.0 of oracle for this
database. And we are seeing for one of the table the stats gather has been
taking longer. It was used to take ~5-6minutes vs now its taking
~30-40minutes. Dont have enough AWR history to verify the exact run time
from ASH/AWR. But we can see it from the application log which notes the
start and end time of the stats gather.
There does exists 5 indexes in this table but when i am seeing ,
DBA_OPTSTAT_OPERATION_TASKS its showing ~1 minutes for all the index stats
gather combinely. Its the table/column gather which takes longer.We are
not
able to test it as we dont have a 11.2 lower environment with us now
though.
The table size is 25Gb and is non partitioned one holding ~13million
rows. Its having 111 columns. Its having histograms on ~36 columns but all
of them are still showing height-balanced and frequency. I was expecting
those to be hybrid , but its didnt happen, may be because of the way the
stats getting gathered on this table i.e. with hard coded 50% sample i.e
as
below.
exec DBMS_STATS.GATHER_TABLE_STATS (OWNNAME => NULL, TABNAME =>
table_name, ESTIMATE_PERCENT => 50, CASCADE => TRUE, method_opt => 'FOR
ALL
COLUMNS SIZE AUTO', DEGREE => 4);
So my question is what must be the reason that same stats gather with
~50% sample size now taking ~30minutes more on 19C as compared to 11.2
where it was finishing in ~5minutes?
--
Houri Mohamed
Oracle DBA-Developer-Performance & Tuning
Visit My - Blog <http://www.hourim.wordpress.com/>
Let's Connect -
<http://fr.linkedin.com/pub/mohamed-houri/11/329/857/>*Linkedin
Profile <http://fr.linkedin.com/pub/mohamed-houri/11/329/857/>*
My Twitter <https://twitter.com/MohamedHouri> - MohamedHouri
<https://twitter.com/MohamedHouri>
--
Houri Mohamed
Oracle DBA-Developer-Performance & Tuning
Visit My - Blog <http://www.hourim.wordpress.com/>
Let's Connect -
<http://fr.linkedin.com/pub/mohamed-houri/11/329/857/>*Linkedin
Profile <http://fr.linkedin.com/pub/mohamed-houri/11/329/857/>*
My Twitter <https://twitter.com/MohamedHouri> - MohamedHouri
<https://twitter.com/MohamedHouri>
