Re: Missing rows under dba_hist_sqlstat

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