Re: Missing rows under dba_hist_sqlstat

  • From: Cherif Ben Henda <cherif.benhenda@xxxxxxxxx>
  • To: Jonathan Lewis <jlewisoracle@xxxxxxxxx>
  • Date: Wed, 25 Nov 2020 13:02:39 +0100

Please see output of below queries


  select a.snap_id,   min(sample_time) mint,   MAX(sample_time) Maxt,
a.sql_id,   a.SQL_ADAPTIVE_PLAN_RESOLVED,   a.SQL_FULL_PLAN_HASH_VALUE,
a.SQL_PLAN_HASH_VALUE
   from dba_hist_active_sess_history a
   where sql_id IN (select a.sql_id   FROM v$sql a
   where sql_text like '%optimizer_adaptive_plans_True%'
   and sql_text not like '%sql_text%')
   group by a.SNAP_ID,   a.sql_id,   a.SQL_ADAPTIVE_PLAN_RESOLVED,
   a.SQL_FULL_PLAN_HASH_VALUE,   a.SQL_PLAN_HASH_VALUE   Order by 1 ,5   ;



   SNAP_ID | MINT                      | MAXT                      SQL_ID
     |  SQL_ADAPTIVE_PLAN_RESOLVED |SQL_FULL_PLAN_HASH_VALUE |
SQL_PLAN_HASH_VALUE

-------------------------------------------------------------------------------|-----------------------------|-------------------------|------------

   53954   | 25-NOV-20 11.44.03.539 AM | 25-NOV-20 11.50.34.130 AM
8mngkgqh4c2x6 | 0                           | 2910268920              |   0

   53955   | 25-NOV-20 11.50.44.130 AM | 25-NOV-20 11.53.44.196 AM
8mngkgqh4c2x6 | 0                           | 2910268920              |   0

   53955   | 25-NOV-20 11.53.54.201 AM | 25-NOV-20 12.00.34.310 PM
8mngkgqh4c2x6 | 1                           | 2910268920              |
1821829401
   53956   | 25-NOV-20 12.00.44.310 PM | 25-NOV-20 12.10.34.423 PM
8mngkgqh4c2x6 | 1                           | 2910268920              |
1821829401
   53957   | 25-NOV-20 12.10.44.425 PM | 25-NOV-20 12.14.04.489 PM
8mngkgqh4c2x6 | 1                           | 2910268920              |
1821829401

   select   round(sum(a.ELAPSED_TIME_DELTA/1e6 )) sum_delta,
   round(max(a.ELAPSED_TIME_total/1e6)) tot,
   count(*) count_snaps
   from dba_hist_sqlstat a where sql_id in(
   (select a.sql_id   FROM v$sql a   where sql_text like
'%optimizer_adaptive_plans_True%'   and sql_text not like '%sql_text%')   )
  group by sql_id   ;


   SUM_DELTA TOT    COUNT_SNAPS
   201       1814   1

Le mer. 25 nov. 2020 à 13:00, Cherif Ben Henda <cherif.benhenda@xxxxxxxxx>
a écrit :

They respond .This is not a bug.
They did not reproduce this issue.
Every time, they send me DOCs, or  link to an issue related to
DBA_HIST_SQLSTAT.., how to analyze a performance issue... and asked for
Disable optimizer_adaptive_plan.
Currently is not possible to disable optimizer_adaptive_plan. ( for many
raisons ....)

I explained to them many times that my request is not to fix the
performance issue , I need to see my query on top consuming resources
queries in AWR.

I have reproduced the issue under 19.6.


Thanks,
Cherif














Le mer. 25 nov. 2020 à 12:50, Jonathan Lewis <jlewisoracle@xxxxxxxxx> a
écrit :


I noticed your livesql link the first time around - but I prefer
eliminating the unstated easy options and collecting relevant collateral
information before trying to run up a matching database to do a test, so
I'll repeat the question: what was the justification offered by Oracle
support? We've got your explanation for the anomaly, did they agree with
that then use that to dismiss the anomaly as expected behaviour, or did
they say something else?


Regards
Jonathan Lewis



On Wed, 25 Nov 2020 at 11:10, Cherif Ben Henda <cherif.benhenda@xxxxxxxxx>
wrote:

Hello Maris,  Jonathan,
I have worked on many cases where "wall clock time" >>  real execution
time of the query.
( file generation taking time par example) .
In that case , sum(DBA_HIST_SQLSTAT.ELAPSED_TIME_DELTA)
=MAX(DBA_HIST_SQLSTAT.ELAPSED_TIME_TOTAL)
and MAX(DBA_HIST_SQLSTAT.ELAPSED_TIME_TOTAL) << "wall clock time"
I assumed that this query was executed one time.

In my case , the query is executed via PL/SQL function.

Another finding, the insertion into wrh$_sqlstat (DBA_HIST_SQLSTAT) is
based on V$SQLAREA_PLAN_HASH . When the query is under execution , there is
no row into V$SQLAREA_PLAN_HASH.

I have shared a simple test case
https://livesql.oracle.com/apex/livesql/s/kv21hp90yyy8j142r41w00n3s

set optimizer_adaptive_plan = false => I dont have this behavior.

Thanks
Cherif

Le mer. 25 nov. 2020 à 11:50, Jonathan Lewis <jlewisoracle@xxxxxxxxx> a
écrit :

In the absence of further information I think Maris' observation is the
correct one, and you would get a better handle on this by taking a snapshot
of the session activity stats and session events for your test case.

However, I would be interested in seeing the justification Oracle
support gave for their 'not a bug' conclusion.

Regards
Jonathan Lewis


On Wed, 25 Nov 2020 at 10:17, Cherif Ben Henda <
cherif.benhenda@xxxxxxxxx> wrote:

Hi All,
 During monitoring of PROD long running reporting...
Oracle version 12.1/ optimizer_adaptive_features =false and 
optimizer_adaptive_plans
=true, I identified a query taking more than 17 000 sec. The next day
when I generated AWR covering its execution period, I found that this 
query
had taken 2600 sec.  I have checked dba_hist_sqlstat , there is only one
row / one snap. The delta elapsed time was 2600 but the total elapsed time
was exact / AWR report is based on delta columns. Under
dba_hist_active_sess_history  , I get the exact number of snap_id,  in 
fact
, there are many missing rows under dba_hist_sqlstat .
I have identified the root cause. During these snapshots , we
don't have a final execution plan ( it was a complex query with more than
14 tables), it was executed with an adaptive execution plan.
I identified that this behavior happened with dozens of queries.

I can not share with you the real issue , I succeed in reproducing it.
I need to know if you have encountered a similar issue ? It seems like
a bug
Please find a test case, I have changed AWR snap duration to 5 min.
https://livesql.oracle.com/apex/livesql/s/kv21hp90yyy8j142r41w00n3s

I have opened an SR but they think it is not a bug ....
--
Cordialement,
Cherif Ben Henda




--
Cordialement,
Cherif Ben Henda




--
Cordialement,
Cherif Ben Henda




-- 
Cordialement,
Cherif Ben Henda

Other related posts: