Oracle mechanics

25.03.2016

12c: Automatic Dynamic Statistics в присутствии SPM Baseline

Восстановление default значения optimizer_dynamic_sampling = 2, последовавшее после обновления на 12c выявило краткосрочную проблему:

Top 5 Foreground Events by Total Wait Time
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
                                           Total Wait       Wait   % DB Wait    
Event                                Waits Time (sec)    Avg(ms)   time Class   
------------------------------ ----------- ---------- ---------- ------ -----------
DB CPU                                          53.2K              55.8         
db file sequential read          1,998,398      15.5K       7.74   16.2 User I/O
cursor: pin S wait on X             29,094      11.5K     396.15   12.1 Concurrency -- тут
db file parallel read               72,823       3284      45.09    3.4 User I/O
db file scattered read             164,408       2134      12.98    2.2 User I/O

локализованную одним запросом:

12.1.0.2.@ SQL> @ash_sql_wait_tree "event = 'cursor: pin S wait on X'"
 
LVL BLOCKING_TREE  EVENT                    WAIT_CLASS   WAITS_COUNT EXECS_COUNT AVG_WA SESS_COUNT BLOCK_SID  MIN_STIME                   MAX_STIME                   SQL_ID        SQL_PLAN_HASH_VALUE SQL_TEXT
--- -------------- ------------------------ ------------ ----------- ----------- ------ ---------- ---------- --------------------------- --------------------------- ------------- ------------------- -----------------------------------------------
  1 (USER)         cursor: pin S wait on X  Concurrency         9872           0    991        214 VALID i#1  03-MAR-16 03.00.13.029 PM   03-MAR-16 03.01.36.228 PM   5rrd8z9nt7t2j          1613548637 select 1 from dual where exists (select 1  from
  1 (USER)         cursor: pin S wait on X  Concurrency          474           0    986         17 VALID i#1  03-MAR-16 03.00.16.029 PM   03-MAR-16 03.01.31.218 PM   5rrd8z9nt7t2j           633295841 select 1 from dual where exists (select 1  from
...
  1 (USER)         cursor: pin S wait on X  Concurrency          135           0    988          4 VALID i#1  03-MAR-16 03.00.19.029 PM   03-MAR-16 03.01.29.218 PM   5rrd8z9nt7t2j          2447725225 select 1 from dual where exists (select 1  from
  1 (USER)         cursor: pin S wait on X  Concurrency          104           0    981          3 VALID i#1  03-MAR-16 03.00.14.029 PM   03-MAR-16 03.01.29.218 PM   5rrd8z9nt7t2j          3045292599 select 1 from dual where exists (select 1  from
...

с одним действующим PHV=1613548637 (и несколькими переходными «фантомными» не оставившими следов планами) в течение непродолжительной фазы hard [re-]parse последовавшей сразу после модификации параметра OPTIMIZER_DYNAMIC_SAMPLING. По природе ожидания конкуренция (WAIT_CLASS=»Concurrency») естественно наблюдалась между сессиями, ожидавшими окончания parse/разбора того же самого курсора

Статистика V$SQL/V$SQL_SHARED_CURSOR демонстрирует что оба курсора, старый и новый построены на основе SPM Baseline SQL_PLAN_7vhy2s4xp4rjjf9ed9122 и используют один и тот же PHV=1613548637. При этом сформированный в момент изменения системного значения OPTIMIZER_DYNAMIC_SAMPLING 0 => 2 (примерно в 2016-03-03/15:01) активноиспользуемый (USERS_OPENING) непараллельный (PARSES_PER_EXEC) курсор CHILD=0:

SQL> @shared_cu12_noxml 5rrd8z9nt7t2j
 
  EXECS USERS_OPENING LAST_LOAD_TIME       LAST_ACTIVE_TIME    ELA_PER_EXEC CPU_PER_EXEC PARSES_PER_EXEC GETS_PER_EXEC READS_PER_EXEC UIO_PER_EXEC CONC_PER_EXEC CURSOR_STATUS PLAN_HASH_VALUE FULL_PLAN_HASH_VALUE OPTIMIZER_COST CHILD BIND_SENSE BIND_AWARE SHAREABLE  USE_FEEDBACK_STATS REOPT REOPT_HINTS ADAPT SPD_Valid SPD_Used  DS_LEVEL DOP DOP_REASON OPTIMIZER_STATS  BIND_EQ_FAILURE  ROLL REASON#1                              SQL_PLAN_BASELINE              SQL_PATCH OUTLINE_CATEGORY SQL_PROFILE IS_OBSOLETE
------- ------------- -------------------- ------------------- ------------ ------------ --------------- ------------- -------------- ------------ ------------- ------------- --------------- -------------------- -------------- ----- ---------- ---------- ---------- ------------------ ----- ----------- ----- --------- --------- -------- --- ---------- ---------------- ---------------- ---- ------------------------------------- ------------------------------ --------- ---------------- ----------- -----------
 602804             0 2016-02-28/08:16:40  03.03.2016 15:00:09        23662        11071               1          2001              1        12166            11 VALID              1613548637           4193095970            744     3 N          N          Y          N                  N                                                                   N                N                Y    Optimizer mismatch(12)                SQL_PLAN_7vhy2s4xp4rjjf9ed9122                                        N
  27405           223 2016-03-03/15:01:37  03.03.2016 17:30:44       391390        16456               1          2523              1        12020        363189 VALID              1613548637           4193095970             10     0 N          N          Y          N                  N                                                                   N                N                N    Rolling Invalidate Window Exceeded(2) SQL_PLAN_7vhy2s4xp4rjjf9ed9122                                        N

временно демонстрирует более медленную скорость выполнения (ELA_PER_EXEC) за счёт вышеописанной краткосрочной конкуренции cursor: pin S wait on X (CONC_PER_EXEC) в момент рекомпиляции

В итоге курсор, построенный с помощью Baseline, т.е. с фиксированным современными средствами SQL Plan Management (SPM) планом:

SQL> SELECT * FROM TABLE(dbms_xplan.display_cursor('5rrd8z9nt7t2j',0,format => 'note'));

SQL_ID  5rrd8z9nt7t2j, child number 0
-------------------------------------
...

Plan hash value: 1613548637

...
 
Note
-----
   - SQL plan baseline SQL_PLAN_7vhy2s4xp4rjjf9ed9122 used for this statement

испытывает резкое торможение в момент hard [re-]parse. DBMS_XPLAN.DISPLAY_CURSOR никак не указывает причину такого поведения, которой мог бы быть, например, Dynamic Sampling, очевидно связанная с включением параметра OPTIMIZER_DYNAMIC_SAMPLING
Вероятно, это является регламентированным поведением — не указывать ADS и адаптивные эффекты для планов, использующих SQL plan baseline (?)

SQL-мониторинг выполнения запроса по данным ASH:

SQL> @ash_sqlmon2 5rrd8z9nt7t2j
 
LAST_PLSQL  SQL_ID        PLAN_HASH_VALUE   ID PLAN_OPERATION                                  ASH_ROWS WAIT_PROFILE
----------- ------------- --------------- ---- --------------------------------------------- ---------- ----------------------------------------------------------------------------------------------------------------------------------
Hard Parse  5rrd8z9nt7t2j               0    0 sql_plan_hash_value = 0                               41 cursor: pin S wait on X(36); ON CPU(4); db file sequential read(1)
Soft Parse  5rrd8z9nt7t2j       633295841    0 sql_plan_hash_value > 0; sql_exec_id is null         549 cursor: pin S wait on X(474); db file sequential read(43); ON CPU(17); db file scattered read(14); control file sequential read(1)
Soft Parse  5rrd8z9nt7t2j       633295841    1 sql_plan_hash_value > 0; sql_exec_id is null           1 ON CPU(1)
Soft Parse  5rrd8z9nt7t2j       633295841    4 sql_plan_hash_value > 0; sql_exec_id is null           1 db file sequential read(1)
Soft Parse  5rrd8z9nt7t2j      1613548637    0 sql_plan_hash_value > 0; sql_exec_id is null        9888 cursor: pin S wait on X(9872); library cache: mutex X(10); ON CPU(3); kksfbc child completion(3)
Soft Parse  5rrd8z9nt7t2j      2447725225    0 sql_plan_hash_value > 0; sql_exec_id is null         135 cursor: pin S wait on X(135)
Soft Parse  5rrd8z9nt7t2j      3045292599    0 sql_plan_hash_value > 0; sql_exec_id is null         110 cursor: pin S wait on X(104); db file sequential read(3); ON CPU(3)
...
SQL Summary                             0    0 ASH fixed 932 execs from 629 sessions              11692  ash rows were fixed from 03.03.2016 13:26:06 to 03.03.2016 17:31:52

— показывает, что основное время (9872 of 11692 samples) запрос проводит в конкуренции на cursor: pin S wait on X, правда, по записям ASH это можно рассматривать скорее как soft parse («sql_plan_hash_value > 0; sql_exec_id is null») с уже имеющимся в Shared Pool и единственным используемым планом 1613548637, плюс на той же стадии можно видеть следы других «фантомных» планов

Поскольку проблемный запрос один, и проблема, очевидно, относится к фазе [re]parsing, решение (воизбежание проблем в будущем) может быть простым:

SQL> @sqlpatch+
&SQL_ID: 5rrd8z9nt7t2j
&SQL_PATCH_TEXT: OPT_PARAM(''optimizer_dynamic_sampling'' 0)
&SQL_PATCH_NAME: 5rrd8z9nt7t2j_NO_ADS
 
PL/SQL procedure successfully completed
 
SQL_PATCH_HINTS
-----------------------------------------
OPT_PARAM('optimizer_dynamic_sampling' 0)

и эффективным:

SQL> @shared_cu12_noxml 5rrd8z9nt7t2j
 
  EXECS USERS_OPENING LAST_LOAD_TIME       LAST_ACTIVE_TIME    ELA_PER_EXEC CPU_PER_EXEC PARSES_PER_EXEC GETS_PER_EXEC READS_PER_EXEC UIO_PER_EXEC CONC_PER_EXEC CLU_PER_EXEC PLSQL_PER_EXEC CURSOR_STATUS  PLAN_HASH_VALUE FULL_PLAN_HASH_VALUE OPTIMIZER_COST CHILD BIND_SENSE BIND_AWARE SHAREABLE  USE_FEEDBACK_STATS REOPT REOPT_HINTS ADAPT SPD_Valid SPD_Used  DS_LEVEL OPTIMIZER_STATS  BIND_EQ_FAILURE  ROLL REASON#1                              SQL_PLAN_BASELINE              SQL_PATCH
------- ------------- -------------------- ------------------- ------------ ------------ --------------- ------------- -------------- ------------ ------------- ------------ -------------- -------------- --------------- -------------------- -------------- ----- ---------- ---------- ---------- ------------------ ----- ----------- ----- --------- --------- -------- ---------------- ---------------- ---- ------------------------------------- ------------------------------ --------------------
 602804             0 2016-02-28/08:16:40  03.03.2016 15:00:09        23662        11071               1          2001              1        12166            11            0              0 INVALID_UNAUTH      1613548637           4193095970            744     3 N          N          Y          N                  N                                                    N                N                Y    Optimizer mismatch(12)                SQL_PLAN_7vhy2s4xp4rjjf9ed9122                     
  22312           180 2016-03-03/17:54:18  03.03.2016 21:46:13        26737        13730               1          3248              1        12639             0            0              0 VALID               1613548637           4193095970            724     1 N          N          Y          N                  N                                                    N                N                N    Rolling Invalidate Window Exceeded(2) SQL_PLAN_7vhy2s4xp4rjjf9ed9122 5rrd8z9nt7t2j_NO_ADS

При таком решении запрос 5rrd8z9nt7t2j при построении курсора использует одновременно два механизма SPM, что не всегда возможно:

SQL> @spm_check4sql_id 5rrd8z9nt7t2j
 
SIGNATURE             SPM_TYPE          SQL_HANDLE                     PATCH_NAME                     ORIGIN         VERSION    CREATED             LAST_MODIFIED       LAST_EXECUTED       LAST_VERIFIED       ENABLED ACCEPTED FIXED REPRODUCED AUTOPURGE
--------------------- ----------------- ------------------------------ ------------------------------ -------------- ---------- ------------------- ------------------- ------------------- ------------------- ------- -------- ----- ---------- ---------
  9062301010379300401 SQL Patch         SQL_7dc3c2c13b525e31           5rrd8z9nt7t2j_NO_ADS           MANUAL-SQLTUNE 12.1.0.2.0 03.03.2016 17:54:18 03.03.2016 17:54:18                                         YES     NO       NO    YES        NO
  9062301010379300401 SQL Plan Baseline SQL_7dc3c2c13b525e31           SQL_PLAN_7vhy2s4xp4rjjf9ed9122 MANUAL-LOAD    12.1.0.2.0 20.11.2012 17:10:24 01.03.2016 05:43:08 01.03.2016 05:43:08                     YES     YES      YES   YES        YES

и получающийся план выполнения содержит/комбинирует элементы Baseline и SQLPatch:

SQL> SELECT * FROM TABLE(dbms_xplan.display_cursor('5rrd8z9nt7t2j',0,format => 'note outline'));

SQL_ID  5rrd8z9nt7t2j, child number 0
-------------------------------------
...
 
Plan hash value: 1613548637
 
...

Outline Data
-------------
 
/*+
    BEGIN_OUTLINE_DATA
    IGNORE_OPTIM_EMBEDDED_HINTS
    OPTIMIZER_FEATURES_ENABLE('11.2.0.3')     -- из SPM Baseline
    DB_VERSION('12.1.0.2')
    OPT_PARAM('optimizer_dynamic_sampling' 0) -- из SQLPatch
    ALL_ROWS
    ...
    END_OUTLINE_DATA
*/

...

Note
-----
   - SQL patch "5rrd8z9nt7t2j_NO_ADS" used for this statement
   - SQL plan baseline SQL_PLAN_7vhy2s4xp4rjjf9ed9122 used for this statement

Однако до применения какого-либо решения остаётся вопрос: что замедляет hard parse запроса с ENABLED/ACCEPTED/FIXED/REPRODUCED Baseline? И как используются ли при этом Automatic Dynamic Sampling(ADS) и пр.Adaptive Features?

Одной из причин ADS для непараллельного запроса могут быть присутствие SQL Plan Directives (SPD), которых, к примеру, на одну из таблиц запроса приходится более чем достаточно:

SQL> @spd_obj BUILDING COMPANY_INFO
 
...
 
330 rows selected

, и даже исключив SPD в статусе SUPERSEDED:

SQL> @spd_obj BUILDING COMPANY_INFO USABLE
 
...
 
129 rows selected

— остаётся достаточно много USABLE Directives

Старый добрый EXPLAIN PLAN для оригинального запроса, использующего Baseline, как упоминалось выше, не показывает ни использования Sql Plan Directive, ни признаков Adaptive Plan, ни ADS:)

SQL> explain plan for
  2  select
...
 31  /

Explained.

SQL> select * from table(dbms_xplan.display('','','+metrics'));

PLAN_TABLE_OUTPUT
---------------------------
Plan hash value: 1613548637

...

Note
-----
   - SQL plan baseline "SQL_PLAN_7vhy2s4xp4rjjf9ed9122" used for this statement

, но план видоизменённого (во избежание применения Baseline) запроса может показать подозрительную SPD директиву и намёки на dynamic statistics+adaptive plan:

SQL> explain plan for
  2  select /***/     -- изменение FORCE_MATCHING_SIGNATURE запроса
...
 31  /

Explained.

SQL> select * from table(dbms_xplan.display('','','+metrics'));

PLAN_TABLE_OUTPUT
--------------------------
Plan hash value: 633295841

...

Predicate Information (identified by operation id):
---------------------------------------------------

...
  35 - filter("END_DATE" IS NULL OR "END_DATE">=TRUNC(SYSDATE@!)) -- *
  36 - filter("END_DATE" IS NULL OR "END_DATE">=TRUNC(SYSDATE@!))
...

Sql Plan Directive information:
-------------------------------

  Valid directive ids:
    6112913102543271509
    4253509024280283947
    9651363439450447987
    10019355768076239671
    14181338022147814388
    12466260497111925485
    2595151263586374287
    4798120066876802332
    783946019608419594

  Used directive ids:
    2767715493554281984                                  -- Используемая директива,

Note
-----
   - dynamic statistics used: dynamic sampling (level=2) -- ADS как следствие,
   - this is an adaptive plan                            -- плюс адаптивные эффекты
   - 1 Sql Plan Directive used for this statement        -- Источник ADS

Что, конечно, ничего не доказывает, просто не исключает, учитывая соответствие указанной директивы предикатам (*) запроса:

SQL> @spd_id 2767715493554281984
 
DIRECTIVE_ID           TYPE             ENABLED INT_STATE     STATE      REASON                                  TAB_CNT REDUNDANT TABLE_LIST             COLUMN_LIST  EQ_PRED_ONLY  SIMPLE_COL_PRED_ONLY  IND_ACCESS_BY_JOIN_PRED  FILTER_ON_JOIN_OBJ  CREATED
---------------------- ---------------- ------- ------------- ---------- ------------------------------------ ---------- --------- ---------------------- ------------ ------------- --------------------- ------------------------ ------------------- -----------------
   2767715493554281984 DYNAMIC_SAMPLING YES     PERMANENT     USABLE     SINGLE TABLE CARDINALITY MISESTIMATE          1 NO        BUILDING.COMPANY_INFO  END_DATE     NO            YES                   NO                       NO                  01.12.15 05:42:08

Проверить эти домыслы можно лишь практическим трейсом оптимизатора для запроса, использующего только Baseline:

SQL> var 1 number -- PL/SQL Developer позволяет определять порядковые переменные в Command Window !
SQL> var 2 number
SQL> var 3 number
SQL> var 4 number
SQL> exec :1 := 92168307; :2 := 1270674; :3 := 1270674; :4 := 20350140
 
PL/SQL procedure successfully completed
 
SQL> @10053+
SQL> select 1
...
 29             and m.id > :4)
 30  /
 
1 rows selected

И далее из трейса в формате less -N можно видеть (longread, для любителей:)

    128 SPM: statement found in SMB -- baseline найден на первых строках

-- I. THE OPTIMIZER GENERATES A BEST-COST PLAN

    233 AP - adaptive plans
    234 ***************************************
    235 PARAMETERS USED BY THE OPTIMIZER
    236 ********************************
    237   *************************************
    238   PARAMETERS WITH ALTERED VALUES             -- без изменений
    239   ******************************
    240 Compilation Environment Dump
    241 _pga_max_size                       = 2097152 KB
    242 Bug Fix Control Environment
    243
    244
    245   *************************************
    246   PARAMETERS WITH DEFAULT VALUES
    247   ******************************

    250 optimizer_features_hinted           = 0.0.0    -- пока без изменений

    257 optimizer_features_enable           = 12.1.0.2 -- default

    351 optimizer_dynamic_sampling          = 2        -- default

    482 optimizer_capture_sql_plan_baselines = false   -- default
    483 optimizer_use_sql_plan_baselines    = true     -- default

    594 _px_adaptive_dist_method            = choose -- по умолчанию включены адаптивные фичи

    611 _optimizer_dsdir_usage_control      = 126    -- и разрешено использование SQL Plan Directives

    618 _optimizer_adaptive_plans           = true   -- --//--

    635 _optimizer_strans_adaptive_pruning  = true   -- --//--

    694 _optimizer_nlj_hj_adaptive_join     = true   -- --//--

   2453 Access path analysis for COMPANY_INFO
   2454 ***************************************
   2455 SINGLE TABLE ACCESS PATH
   2456   Single Table Cardinality Estimation for COMPANY_INFO[COMPANY_INFO]
   2457   SPD: Directive valid: dirid = 2767715493554281984, state = 5, flags = 1, loc = 1 {C(170890)[5]}
   2458   SPD: Return code in qosdDSDirSetup: EXISTS, estType = TABLE -- Найденная выше директива - в рабочем состоянии
   2459   Column (#5):
   2460     NewDensity:0.000383, OldDensity:0.000395 BktCnt:19065.000000, PopBktCnt:3609.000000, PopValCnt:10, NDV:2128
   2461   Column (#5): END_DATE(DATE)
   2462     AvgLen: 2 NDV: 2128 Nulls: 132045 Density: 0.000383 Min: 2453372.000000 Max: 2457452.000000
   2463     Histogram: Hybrid  #Bkts: 254  UncompBkts: 19065  EndPtVals: 254  ActualVal: yes
   2464   Using prorated density: 3.8145e-04 of col #5 as selectivity of out-of-range/non-existent value pred
   2465   Table: COMPANY_INFO  Alias: COMPANY_INFO                    -- успешно активирует adaptive dynamic sampling (1.1):
   2466     Card: Original: 151110.000000    >> Single Tab Card adjusted from 132045.917534 to 132948.000000 due to adaptive dynamic sampling -- ADS

   2503 Access path analysis for A_CLIENTS
   2504 ***************************************
   2505 SINGLE TABLE ACCESS PATH
   2506   Single Table Cardinality Estimation for A_CLIENTS[AC]
   2507   SPD: Directive valid: dirid = 12466260497111925485, state = 5, flags = 1, loc = 1 {EC(170926)[2]} -- находятся и другие директивы,
   2508   SPD: Return code in qosdDSDirSetup: EXISTS, estType = TABLE
   2509   Column (#2):
   2510     NewDensity:0.000403, OldDensity:0.000466 BktCnt:8849.000000, PopBktCnt:3620.000000, PopValCnt:35, NDV:1503
   2511   Column (#2): A_CLIENT_ID(NUMBER)
   2512     AvgLen: 6 NDV: 1503 Nulls: 0 Density: 0.000403 Min: 48.000000 Max: 7929082.000000
   2513     Histogram: Hybrid  #Bkts: 254  UncompBkts: 8849  EndPtVals: 254  ActualVal: yes
   2514   Table: A_CLIENTS  Alias: AC                                                                       -- также успешно работающие:
   2515     Card: Original: 8849.000000    >> Single Tab Card adjusted from 3.561989 to 1.000000 due to adaptive dynamic sampling

   2539  ****** Costing Index IDX_A_CLIENTS
   2540   SPD: Directive valid: dirid = 12466260497111925485, state = 5, flags = 1, loc = 1 {EC(170926)[2]}
   2541   SPD: Return code in qosdDSDirSetup: EXISTS, estType = INDEX_SKIP_SCAN
   2542
   2543     >> Index Card adjusted from 3.561989 to 1.000000 due to adaptive dynamic sampling               -- и ещё одна, и т.д...

   2613   SPD: Directive valid: dirid = 14181338022147814388, state = 5, flags = 1, loc = 2 {F(170926)[]; F(170890)[]}
   2614   SPD: Return code in qosdDSDirSetup: EXISTS, estType = JOIN
   2615 Join Card:  1.254380 = outer (1.000000) * inner (132948.000000) * sel (9.4351e-06)
   2616 >> Join Card adjusted from 1.254380 to 1.000000 due to adaptive dynamic sampling, prelen=2

   2666 *********************************
   2667 Number of join permutations tried: 2 -- Используются разные варианты перестановок (1.2)
   2668 *********************************

  20834 AP: Computing costs for inflection point at max value 349525.33     -- Adaptive plan успешно рассматриваются (1.3)
  20835 AP: Costing Nested Loops Join for inflection point at card 349525.33
  20836 Access path analysis for COMPANY_INFO
  20837  ****** Costing Index I_COMPANY_INFO_CLIENT                         -- с использованием директив
  20838   SPD: Directive valid: dirid = 10019355768076239671, state = 5, flags = 1, loc = 1 {ECJ(170890)[3]}
  20839   SPD: Return code in qosdDSDirSetup: EXISTS, estType = INDEX_SCAN
  20840   SPD: Directive valid: dirid = 10019355768076239671, state = 5, flags = 1, loc = 1 {ECJ(170890)[3]}
  20841   SPD: Return code in qosdDSDirSetup: EXISTS, estType = INDEX_FILTER
  20842   Access Path: index (AllEqJoinGuess)
  20843     Index: I_COMPANY_INFO_CLIENT
  20844     resc_io: 3.000000  resc_cpu: 31059
  20845     ix_sel: 8.8867e-06  ix_sel_with_filters: 8.8867e-06
  20846     NL Join : Cost: 1048976.678580  Resp: 1048976.678580  Degree: 1
  20847       Cost_io: 1048582.000000  Cost_cpu: 10857888069
  20848       Resp_io: 1048582.000000  Resp_cpu: 10857888069
  20849
  20850 AP: Costing Hash Join for inflection point at card 349525.33
  20851   Outer table:  A_CLIENTS  Alias: AC
  20852     resc: 7.076431  card 349525.333333  bytes:   deg: 1  resp: 7.076431
  20853   Inner table:  COMPANY_INFO  Alias: COMPANY_INFO
  20854     resc: 146.889275  card: 132948.000000  bytes:   deg: 1  resp: 146.889275
  20855     using dmeth: 2  #groups: 1
  20856     Cost per ptn: 486.113362  #ptns: 1
  20857     hash_area: 128 (max=131072) buildfrag: 512  probefrag: 211  ppasses: 1
  20858   Hash join: Resc: 640.079068  Resp: 640.079068  [multiMatchCost=0.000000]
  20859 AP: lcost=1048976.68, rcost=640.08                                  -- вплоть до вычисления/сравнения NL vs HJ стоимостей

  23031 Final cost for query block SEL$6 (#1) - All Rows Plan:              -- расчёт CBO-based плана (SEL$6 - головной Query Block запроса), без оформления
  23032   Best join order: 1
  23033   Cost: 451.427121  Degree: 1  Card: 1.000000  Bytes: 0.000000
  23034   Resc: 451.427121  Resc_io: 444.000000  Resc_cpu: 204325362
  23035   Resp: 451.427121  Resp_io: 444.000000  Resc_cpu: 204325362

-- II. SPM REPRODUCE PHASE

  23376 SPM: finding a match for the generated plan, planId = 2263719562          -- Далее - попытка воспроизвести план из Baseline (2.0)
  23377 SPM: fixed planId''s of plan baseline are: 4193095970
  23378 SPM: using qksan to reproduce, cost and select accepted plan, sig = 5744910732422050174
  23379 SPM: plan reproducibility round 1 (plan outline + session OFE)
  23380 SPM: using qksan to reproduce accepted plan, planId = 4193095970 

  23411 SPM: plan reproducibility - session OFE = 12010002, hinted OFE = 11020003 -- выполняется, похоже, с отличным OFE (2.1)

  23622 ***************************************
  23623 PARAMETERS USED BY THE OPTIMIZER
  23624 ********************************
  23625   *************************************
  23626   PARAMETERS WITH ALTERED VALUES
  23627   ******************************
  23628 Compilation Environment Dump
  23629 optimizer_mode_hinted               = true     -- OFE изменена
  23630 optimizer_features_hinted           = 12.1.0.2 -- на параметр по умолчанию (?)
  23631 _pga_max_size                       = 2097152 KB
  23632 is_recur_flags                      = 8
  23633 Bug Fix Control Environment
  23634
  23635
  23636   *************************************
  23637   PARAMETERS WITH DEFAULT VALUES
  23638   ******************************
  23639 Compilation Environment Dump

  23646 optimizer_features_enable           = 12.1.0.2

  25385 Join Elimination (JE)
  25386 *************************
  25387 SQL:******* UNPARSED QUERY IS *******                             -- для запроса с ACCESS PATH подсказками из Baseline (2.2):
  25388 SELECT /*+ LEADING ("C" "RC") USE_NL ("RC") INDEX ("RC" "I_RECIPIENT_CONTACT_CID") */ .., ( (SELECT /*+ INDEX_RS_ASC ("CONTACT" "I_CON  25388 TACT_UID") INDEX_RS_ASC ("CONTACT" "I_CONTACT_UID") */ ...

  27612 AP: Checking validity for query block SEL$2, sqlid=gfs0u0nsstzm2. -- при этом оказывается что в фазе воспроизведения AP уже неприменим (2.3):
  27613 AP: Adaptive plans bypassed for query block SEL$2 due to SPM plan reproducibility phase
  27614 AP: Adaptive joins bypassed for query block SEL$2 due to adaptive plans disabled

  28647 Access path analysis for MESSAGE
  28648 ***************************************
  28649 SINGLE TABLE ACCESS PATH
  28650   Single Table Cardinality Estimation for MESSAGE[M]
  28651   SPD: Directive valid: dirid = 6112913102543271509, state = 5, flags = 1, loc = 1 {C(171296)[1]}
  28652   SPD: Return code in qosdDSDirSetup: EXISTS, estType = TABLE -- , а вот SPD директивы успешно используются
  28653
  28654   Using prorated density: 3.0276e-07 of col #1 as selectivity of out-of-range/non-existent value pred
  28655   Table: MESSAGE  Alias: M                                    -- и ADS, как следствие также:
  28656     Card: Original: 3299514.000000    >> Single Tab Card adjusted from 0.926481 to 63098.582500 due to adaptive dynamic sampling
  28657   Rounded: 63099  Computed: 63098.582500  Non Adjusted: 0.926481

  29183 SPM: planId in plan baseline = 4193095970, planId of reproduced plan = 4193095970 -- подтверждена воспроизводимость
  29184 SPM: best cost so far = 660.422246, current accepted plan cost = 660.422246
  29185 Starting SQL statement dump
  29186
  ...
  29188 sql_id=gfs0u0nsstzm2 plan_hash_value=1613548637 problem_type=3
  29189 ----- Current SQL Statement for this session (sql_id=gfs0u0nsstzm2) ----- Фаза воспроизведения выполнялись для "тестового" запроса,
  29190 /* SQL Analyze(1066,0) */                                              -- отличающегося от выполняемого комментарием
  29191 select 1
  29192   from dual
  29193  where exists
  ...
  29219            and m.id > :4)
  29220 sql_text_length=1385

  29253 ----- Explain Plan Dump -----
  29254 ----- Plan Table -----
  29255
  29256 ============
  29257 Plan Table
  29258 ============
  29259 ------------------------------------------------------------------------------+-----------------------------------+
  29260 | Id  | Operation                               | Name                        | Rows  | Bytes | Cost  | Time      |
  29261 ------------------------------------------------------------------------------+-----------------------------------+
  29262 | 0   | SELECT STATEMENT                        |                             |       |       |   660 |           |

  29313 Content of other_xml column
  29314 ===========================
  29315   db_version     : 12.1.0.2
  29316   parse_schema   : SYS
  29317   dynamic_sampling: 2
  29318   plan_hash_full : 4193095970 -- планы в фазе воспроизведения совпадают с целевыми планами Baseline
  29319   plan_hash      : 1613548637
  29320   plan_hash_2    : 4193095970
  29322 Peeked Binds
  29323 ============
...
  29356 <spd>
  29357 <cv>4</cv>                    --   кол-во доступных SQL Plan Directive AVAILABLE = 4,
  29358 <cu>6</cu>                    -- а кол-во используемых SQL Plan Directive USED = 6, т.е. директивы (и как следствие ADS) при подготовке этого предварительного плана использовались
  29359 </spd>
  29360   Outline Data:
  29361   /*+
  29362     BEGIN_OUTLINE_DATA
  29363       IGNORE_OPTIM_EMBEDDED_HINTS
  29364       OPTIMIZER_FEATURES_ENABLE('12.1.0.2') -- кроме того, в этом плане воспроизведения OFE=12.1.0.2 в отличие от Baseline
  29365       DB_VERSION('12.1.0.2')
  29366       ALL_ROWS
...
  29416     END_OUTLINE_DATA
  29417   */
  29418
  29419 Optimizer state dump:
  29420 Compilation Environment Dump
  29421 optimizer_mode_hinted               = true
  29422 optimizer_features_hinted           = 12.1.0.2 -- окружение компиляции в этом месте также отличается

  29429 optimizer_features_enable           = 12.1.0.2

-- III. SPM RE-PARSE SELECTED ACCEPTED PLAN

  31000 SPM: re-parse to use selected accepted plan, planId = 4193095970 -- новый "подход" с использованием успешно воспроизведенного на предыдущем этапе плана (3.0)

  31101 SPM: statement found in SMB
  31102 SPM: re-parsing to generate selected accepted plan,  planId = 4193095970

  31198 AP - adaptive plans
  31199 ***************************************
  31200 PARAMETERS USED BY THE OPTIMIZER
  31201 ********************************
  31202   *************************************
  31203   PARAMETERS WITH ALTERED VALUES
  31204   ******************************
  31205 Compilation Environment Dump
  31206 optimizer_mode_hinted               = true
  31207 optimizer_features_hinted           = 11.2.0.3 -- теперь уже с правильно модифицированным параметром OFE=11203 из Baseline,
  31208 _pga_max_size                       = 2097152 KB
  31209 Bug Fix Control Environment
  31210
  31211
  31212   *************************************
  31213   PARAMETERS WITH DEFAULT VALUES
  31214   ******************************

  31559 _px_adaptive_dist_method            = off      -- в рез-те чего выключены Adaptive PX
  
  31576 _optimizer_dsdir_usage_control      = 0        -- , запрещено использование SQL Plan Directives

  31583 _optimizer_adaptive_plans           = false    -- , выключены Adaptive plan, и т.д...

  31600 _optimizer_strans_adaptive_pruning  = false    -- --//--

  31659 _optimizer_nlj_hj_adaptive_join     = false    -- --//--

  34972 AP: Adaptive joins bypassed for query block SEL$2 due to disabled by adaptive join parameter -- сразу по параметру

  36352 SPM: finding a match for the generated plan, planId = 4193095970
  36353 SPM: re-parsed to use selected accepted plan, planId = 4193095970
  36354 Starting SQL statement dump
  36355

  36357 sql_id=5rrd8z9nt7t2j plan_hash_value=1613548637 problem_type=3
  36358 ----- Current SQL Statement for this session (sql_id=5rrd8z9nt7t2j) ----- план строится для правильного целевого SQL_ID
  36359 select 1
  36360   from dual
  36361  where exists
  ...
  36387            and m.id > :4)
  36388 sql_text_length=1358

  36421 ----- Explain Plan Dump -----
  36422 ----- Plan Table -----
  36423
  36424 ============
  36425 Plan Table
  36426 ============
  36427 ------------------------------------------------------------------------------+-----------------------------------+
  36428 | Id  | Operation                               | Name                        | Rows  | Bytes | Cost  | Time      |
  36429 ------------------------------------------------------------------------------+-----------------------------------+
  36430 | 0   | SELECT STATEMENT                        |                             |       |       |   763 |           | -- скоректированная стоимость

  36481 Content of other_xml column
  36482 ===========================
  36483   db_version     : 12.1.0.2
  36484   parse_schema   : SYS
  36485   plan_hash_full : 4193095970 -- в рез-те повторного разбора / re-parse воспроизведенного плана
  36486   plan_hash      : 1613548637 -- получены/подтверждены те же планы выполнения
  36487   plan_hash_2    : 4193095970
  36489 Peeked Binds
  36490 ============

  36523   Outline Data:
  36524   /*+
  36525     BEGIN_OUTLINE_DATA
  36526       IGNORE_OPTIM_EMBEDDED_HINTS
  36527       OPTIMIZER_FEATURES_ENABLE('11.2.0.3')    -- OFE из Baseline
  36528       DB_VERSION('12.1.0.2')
  36529       ALL_ROWS

  36579     END_OUTLINE_DATA
  36580   */
  36581
  36582 Optimizer state dump:
  36583 Compilation Environment Dump
  36584 optimizer_mode_hinted               = true
  36585 optimizer_features_hinted           = 11.2.0.3 -- и соотв.параметра компиляции

  36592 optimizer_features_enable           = 12.1.0.2

  38159 End of Optimizer State Dump
  38160 Dumping Hints
  38161 =============
  38162 ====================== END SQL Statement Dump ====================== -- после успешного использования Baseline обновлены данные SQL Management Base:
  38163 SPM: kkopmCheckSmbUpdate (enter) xscP=0x7fd282d57c40, pmExCtx=0x570d8ad70, ciP=0x255a37d58, dtCtx=0x7fd28510df40, sig=5744910732422050174, planId=4193095970

В процессе парсинга запроса с успешным применением SPM Baseline версии 12c можно выделить следующие моменты:

1) разбираемый запрос в SPM находится быстро и в самом начале разбора — благо это просто по хэшу/FORCE_MATCHING_SIGNATURE — и это учитывается следующих этапах

2) оптимизатор выполняет три sql parse операции (фазы I, II и III) и формирует в трейсе 2 плана выполнения

3) на этапе II. SPM REPRODUCE PHASE используется запрос с комментарием /* SQL Analyze(1066,0) */ (как при выполнении DBMS_SQLDIAG.DUMP_TRACE) для проверки воспроизводимости SPM плана с параметром OFE(‘12.1.0.2’) из окружения сессии

4) в процессе parse/разбора на первых 2-х этапах (I и II) штатно используются SQL Plan Directives + Automatic Dynamic Sampling, не испльзуемые в фазе III. SPM RE-PARSE SELECTED ACCEPTED PLAN этого примера, вероятно, ввиду понижения OFE(‘11.2.0.3’) из Baseline и, как следствие, изменения параметров оптимизатора (_optimizer_dsdir_usage_control, _optimizer_adaptive_plans, _optimizer_nlj_hj_adaptive_join,..)

5) Adaptive plan используется/обсчитывается на первом этапе (I. THE OPTIMIZER GENERATES A BEST-COST PLAN), однако отключен на этапе II в принципе AP: Adaptive plans bypassed for query block … due to SPM plan reproducibility phase и недоступен на этапе III ввиду того же OFE(‘11.2.0.3’) из Baseline

6) для обоих сгенерированных в трейсе планов (фазы проверки воспроизводимости II и генерации III) используются ACCESS PATH HINTS из Baseline

В документации тот же процесс кратко описан след.образом:

When the database performs a hard parse of a SQL statement, the optimizer generates a best-cost plan. --**
By default, the optimizer then attempts to find a matching plan in the SQL plan baseline for the statement.
--  If no plan baseline exists, then the database runs the statement with the best-cost plan.
If a plan baseline exists, then the optimizer behavior depends on whether the newly generated plan is in the plan baseline:
--   If the new plan is in the baseline, then the database executes the statement using the found plan.
   If the new plan is not in the baseline, then the optimizer marks the newly generated plan as unaccepted and adds it to the plan history. Optimizer behavior depends on the contents of the plan baseline:
        If fixed plans exist in the plan baseline, then the optimizer uses the fixed plan (see "Fixed Plans") with the lowest cost.
--        If no fixed plans exist in the plan baseline, then the optimizer uses the baseline plan with the lowest cost.
--        If no reproducible plans exist in the plan baseline, which could happen if every plan in the baseline referred to a dropped index, then the optimizer uses the newly generated cost-based plan

— из чего можно заключить, что на первом этапе (**) генерации A BEST-COST PLAN ничто не запрещает использовать SPD/ADS/AP, что и наблюдалось в виде краткосрочной проблемы при изменении параметра OPTIMIZER_DYNAMIC_SAMPLING / окружения оптимизатора

Как результат вышерассмотренного трейса формируется курсор:

SQL> SELECT * FROM TABLE(dbms_xplan.display_cursor('5rrd8z9nt7t2j',0,format => '+adaptive +metrics -predicate -projection -peeked_binds'));

PLAN_TABLE_OUTPUT
-----------------------------------------------------------------------------------------------------------------------
SQL_ID  3mzkqccb31pku, child number 0
-------------------------------------
 select 1   from dual  where exists  (select 1           from
...

Plan hash value: 1613548637

-------------------------------------------------------------------------------------
| Id  | Operation             | Name        | Rows  | Bytes | Cost (%CPU)| Time     |
-------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT      |             |       |       |   763 (100)|          |
|   1 |  FILTER               |             |       |       |            |          |
|   2 |   FAST DUAL           |             |     1 |       |     2   (0)| 00:00:01 |
...
-------------------------------------------------------------------------------------

Note
-----
   - SQL plan baseline SQL_PLAN_7vhy2s4xp4rjjf9ed9122 used for this statement

— справедливо не отражающий ни Adaptive Plan, ни SQL Plan Directives+ADS в качестве факторов, влияющих на итоговый план, основанный на Baseline, несмотря на очевидное участие/влияние 12c Adaptive Features в процессе генерации курсора

Добавить комментарий »

Комментариев нет.

RSS feed for comments on this post. TrackBack URI

Добавить комментарий

Заполните поля или щелкните по значку, чтобы оставить свой комментарий:

Логотип WordPress.com

Для комментария используется ваша учётная запись WordPress.com. Выход / Изменить )

Фотография Twitter

Для комментария используется ваша учётная запись Twitter. Выход / Изменить )

Фотография Facebook

Для комментария используется ваша учётная запись Facebook. Выход / Изменить )

Google+ photo

Для комментария используется ваша учётная запись Google+. Выход / Изменить )

Connecting to %s

Создайте бесплатный сайт или блог на WordPress.com.

%d такие блоггеры, как: