Re: Missing rows under dba_hist_sqlstat

I have a wrecked thumb at the moment so typing is slow, but when it's a bit better I'll do a couple more tests and write up a blog note

Regards
Jonathan Lewis

On Thu, 26 Nov 2020 at 08:27, Cherif Ben Henda <cherif.benhenda_at_gmail.com> wrote:

> Hello,
> They will perform a test and come back to me .
> Thanks
> Cherif
>
> Le mer. 25 nov. 2020 à 18:39, Jonathan Lewis <jlewisoracle_at_gmail.com> a
> écrit :
>
>>
>> Another oddity is that Oracle is using v$sqlarea_plan_hash rather than
>> v$sqlstats_plan_hash which does get updated in a more timely manner.
>>
>> Regards
>> Jonathan Lewis
>>
>>
>> On Wed, 25 Nov 2020 at 17:25, Jonathan Lewis <jlewisoracle_at_gmail.com>
>> wrote:
>>
>>>
>>> I may have isolated the approximate location of the bug.
>>>
>>> The query and its cost go into the structure fot v$sqlarea immediately
>>> it starts to run using the pre-adapted plan, but it doesn't go into
>>> v$sqlarea_plan_hash at that point - it looks like it is only copied across
>>> as the final plan execution completes (or, possibly) returns its first
>>> row. As the plan resolves,the plan_hash_value in v$sqlarea changes from
>>> the initial plan to the final plan, and the various stats carry on growing.
>>>
>>>
>>>
>>> Regards
>>> Jonathan Lewis
>>>
>>>
>>> On Wed, 25 Nov 2020 at 12:02, Cherif Ben Henda <
>>> cherif.benhenda_at_gmail.com> wrote:
>>>
>>>> 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_at_gmail.com> 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_at_gmail.com>
>>>>> 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_at_gmail.com> 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_at_gmail.com>
>>>>>>> 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_at_gmail.com> 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
>>>>
>>>>
>>>>
>
> --
> Cordialement,
> Cherif Ben Henda
>
>
>

--
http://www.freelists.org/webpage/oracle-l