Archives de l’auteur :  CHERIF BEN HENDA

Missing rows under dba_hist_sqlstat : is it a BUG?

During monitoring of PROD long running reporting… 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 sec 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 cannot share with you the real issue, I succeed in reproducing it.

Tested under 12.1.0.2.0 and 19.8
optimizer_adaptive_features =false and optimizer_adaptive_plans =true
*
Oracle Database 12c Enterprise Edition Release 12.1.0.2.0 - 64bit Production
PL/SQL Release 12.1.0.2.0 - Production
CORE    12.1.0.2.0      Production
TNS for Linux: Version 12.1.0.2.0 - Production
NLSRTL Version 12.1.0.2.0 - Production
*/

---------------------------------------------------------------------------
BEGIN
  DBMS_WORKLOAD_REPOSITORY.modify_snapshot_settings(interval  => 10);          
-- Minutes. Current value retained if NULL.
END;
---------------------------------------------------------------------------

TEST CASE

with LiveSQL Test Case: 

---------------------------------------------------------------------------

select a.ELAPSED_TIME,a.executions from gv$sqlstats a where
sql_id='6daxqtyukunhf';

ELAPSED_TIME   EXECUTIONS
1964510271      1
---------------------------------------------------------------------------

select distinct snap_id
from dba_hist_active_sess_history where sql_id='6daxqtyukunhf';
SNAP_ID 
52546
52545
52544
52543
52542


select a.snap_id,round(a.ELAPSED_TIME_TOTAL/1e6) ELAPSED_TIME_TOTAL,
round(a.ELAPSED_TIME_DELTA /1e6) ELAPSED_TIME_DELTA
from dba_hist_sqlstat a where sql_id=’6daxqtyukunhf’

SNAP_IDELAPSED
_TIME_TOTAL		ELAPSED_
TIME_DELTA
525431138602
525441739600
525451965226
  1428

AWR

              Snap Id      Snap Time      Sessions Curs/Sess
            --------- ------------------- -------- ---------
Begin Snap:     52542 01-Nov-20 14:40:27       204       2.0
  End Snap:     52546 01-Nov-20 15:10:29       199       2.0
   Elapsed:               30.03 (mins)
   DB Time:               47.84 (mins)


SQL ordered by Elapsed Time                               Snaps: 52542-52546
-> Captured SQL account for   64.3% of Total DB Time (s):           2,870
-> Captured PL/SQL account for    0.3% of Total DB Time (s):           2,870

        Elapsed                  Elapsed Time                                   
        Time (s)    Executions  per Exec (s)  %Total   %CPU    %IO    SQL Id    
---------------- -------------- ------------- ------ ------ ------ -------------
         1,428.4              0           N/A   49.8   99.9     .0 6daxqtyukunhf
Module: PL/SQL Developer
SELECT /*+optimizer_adaptive_plans_True1 */ count(CHB_t1.pad), count(CHB_t2.pad)
FROM CHB_t1, CHB_t2 WHERE CHB_t1.id = CHB_t2.id AND CHB_t1.n = 666 AND burn
_cpu(CHB_t1.id/CHB_t1.id) = 1

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

insert into wrh$_sqlstat SELECT ...
     FROM X$KEWRSQLIDTAB sie, X$KGLCURSOR_CHILD_SQLIDPH sql
   WHERE (1 = 1)
     AND sie.sqlid_kewrsie = sql.kglobt03
     AND nlssort(sie.sqlid_kewrsie, 'nls_sort = binary') =
         nlssort(sql.kglobt03, 'nls_sort = binary')
     AND sie.pdbid_kewrsie = decode(sql.con_id, NULL, 1, 0, 1, sql.con_id)

Plan hash value: 1821829401
 
--------------------------------------------------------------------------------------------------
|   Id  | Operation                      | Name          | Rows  | Bytes | Cost (%CPU)| Time     |
--------------------------------------------------------------------------------------------------
|     0 | SELECT STATEMENT               |               |       |       |    50 (100)|          |
|     1 |  SORT AGGREGATE                |               |     1 |   214 |            |          |
|  *  2 |   HASH JOIN                    |               |     1 |   214 |    50   (0)| 00:00:01 |
|-    3 |    NESTED LOOPS                |               |     1 |   214 |    50   (0)| 00:00:01 |
|-    4 |     NESTED LOOPS               |               |     1 |   214 |    50   (0)| 00:00:01 |
|-    5 |      STATISTICS COLLECTOR      |               |       |       |            |          |
|  *  6 |       TABLE ACCESS FULL        | CHB_T1        |     1 |   109 |    49   (0)| 00:00:01 |
|- *  7 |      INDEX UNIQUE SCAN         | SYS_C00604946 |     1 |       |     0   (0)|          |
|-    8 |     TABLE ACCESS BY INDEX ROWID| CHB_T2        |     1 |   105 |     1   (0)| 00:00:01 |
|     9 |    TABLE ACCESS FULL           | CHB_T2        |     1 |   105 |     1   (0)| 00:00:01 |
--------------------------------------------------------------------------------------------------
 
Predicate Information (identified by operation id):
---------------------------------------------------
 
   2 - access("CHB_T1"."ID"="CHB_T2"."ID")
   6 - filter(("CHB_T1"."N"=666 AND "BURN_CPU"("CHB_T1"."ID"/"CHB_T1"."ID")=1))
   7 - access("CHB_T1"."ID"="CHB_T2"."ID")
 
Note
-----
   - this is an adaptive plan (rows marked '-' are inactive)

This should be a bug. Disable optimizer_adaptive_plan fix this issue…

Let’s wait for oracle analyze…

Unnesting of coalesced subqueries

Mohamed Houri’s Oracle Notes

The 12cR1 way used by Oracle to coalesce two correlated disjunctive subqueries has prevented a real life query from unnesting its two subqueries causing a serious performance issue. This article examines a representative model of this real life query. The first paragraph explains the any-to-exists subquery conversion. The second paragraph shows how two correlated exists subqueries can be coalesced to form a single subquery. Once these two transformations introduced the third paragraph will examine how the previously coalesced subqueries can be unnested. It will particularly show that the ability of Oracle to unnest two coalesced correlated subqueries depends strongly on the coalescing method as this one differs from version to version.

1. Any-to-exists subquery conversion

Before coalescing two (or more) subqueries Oracle starts first by transforming ANY and ALL subqueries into EXISTS and NOT EXISTS respectively. Consider, for example, the following query:

If you examine its corresponding 10053…

Voir l’article original 927 mots de plus

Real-Time SQL Monitoring : settings

 The Real-Time SQL Monitoring feature of Oracle Database enables monitoring the performance of SQL statements while they are executing. By default, SQL monitoring is automatically started when a SQL statement either runs in parallel or has consumed at least 5 seconds of combined CPU and I/O time in a single execution. 

select ksppinm, ksppstvl, ksppdesc
  from sys.x$ksppi a, sys.x$ksppsv b
 where a.indx = b.indx
   and lower(ksppinm) like lower('%sqlmon%')
 order by ksppinm;

KSPPINM                   KSPPSTVL  KSPPDESC

————————- ——— ——————————————————————————–

_sqlmon_binds_xml_format  default   format of column binds_xml in [G]V$SQL_MONITOR

_sqlmon_max_plan          640       Maximum number of plans entry that can be monitored. Defaults to 20 per CPU

_sqlmon_max_planlines     300       Number of plan lines beyond which a plan cannot be monitored

_sqlmon_recycle_time      60        Minimum time (in s) to wait before a plan entry can be recycled

_sqlmon_threshold         5         CPU/IO time threshold before a statement is monitored. 0 is disabled