Oracle mechanics

25.03.2015

12c: ASH.SQL_PLAN_HASH_VALUE и адаптивные эффекты

Filed under: Active Session History,Oracle — Игорь Усольцев @ 00:15
Tags: ,

В Active Session History (ASH) версии 11g содержалось относительно небольшое кол-во записей с PLAN_HASH_VALUE = 0 о запросах в стадии выполнения (IN_SQL_EXECUTION = ‘Y’):

11.2@ SQL> select decode(sql_plan_hash_value, 0, '0', '>0') as sql_plan_hash_value,
  2         case when sql_plan_line_id is null then 'NULL' else '>= 0' end as SQL_PLAN_LINE_ID,
  3        count(*)
  4   from v$active_session_history
  5  where IN_PARSE         = 'N'
  6    and IN_HARD_PARSE    = 'N'
  7    and IN_SQL_EXECUTION = 'Y'
  8  group by decode(sql_plan_hash_value, 0, '0', '>0'),
  9           case when sql_plan_line_id is null then 'NULL' else '>= 0' end
 10  order by count(*)
 11  /
 
SQL_PLAN_HASH_VALUE SQL_PLAN_LINE_ID   COUNT(*)
------------------- ---------------- ----------
>0                  NULL                   1120
0                   NULL                   1903 -- немного, SQL_PLAN_LINE_ID is NULL - "служебные записи"
>0                  >= 0                 141186

, и, в основном, это ожидаемые куски PL/SQL кода или какие-то специальные случаи типа ожиданий по db link, etc…

В Oracle 12c кол-во таких записей может внезапно/периодически увеличиться:

12.1@ SQL> select decode(sql_plan_hash_value, 0, '0', '>0') as sql_plan_hash_value,
  2         count(*)
  3    from v$active_session_history
  4   where IN_PARSE         = 'N'
  5     and IN_HARD_PARSE    = 'N'
  6     and IN_SQL_EXECUTION = 'Y'
  7   group by decode(sql_plan_hash_value, 0, '0', '>0')
  8   order by count(*)
  9  /
 
SQL_PLAN_HASH_VALUE   COUNT(*)
------------------- ----------
0                        33215
>0                      163247

При этом, если строки с SQL_PLAN_LINE_ID is NULL (*) можно отнести к упомянутым специальным случаям:

SQL> select decode(sql_plan_hash_value, 0, '0', '>0')                      as SQL_PLAN_HASH_VALUE,
  2         decode(sql_full_plan_hash_value, 0, '0', '>0')                 as SQL_FULL_PLAN_HASH_VALUE,
  3         decode(sql_exec_id, 0, '0', '>0')                              as SQL_EXEC_ID,
  4         case when sql_plan_line_id is null then 'NULL' else '>= 0' end as SQL_PLAN_LINE_ID,
  5         count(*)
  6    from v$active_session_history
  7   where IN_PARSE         = 'N'
  8     and IN_HARD_PARSE    = 'N'
  9     and IN_SQL_EXECUTION = 'Y'
 10   group by decode(sql_plan_hash_value, 0, '0', '>0'),
 11            decode(sql_full_plan_hash_value, 0, '0', '>0'),
 12            decode(sql_exec_id, 0, '0', '>0'),
 13            case when sql_plan_line_id is null then 'NULL' else '>= 0' end
 14   order by count(*)
 15  /
 
SQL_PLAN_HASH_VALUE SQL_FULL_PLAN_HASH_VALUE SQL_EXEC_ID SQL_PLAN_LINE_ID   COUNT(*)
------------------- ------------------------ ----------- ---------------- ----------
>0                  0                        >0          >= 0                      2
0                   >0                       >0          NULL                     66 -- *
0                   >0                       >0          >= 0                  10395 -- **
>0                  >0                       >0          NULL                  10474 -- *
0                   0                        >0          NULL                  22777 -- *
>0                  >0                       >0          >= 0                 152748

, то строки (**) с вменяемыми значениями SQL_PLAN_LINE_ID >= 0 вызывают смутные подозрения :)

Например, выделив TOP таких запросов:

SQL> select sql_id,
  2         top_level_sql_id,
  3         decode(session_state, 'WAITING', event, session_state) as event,
  4         IN_PLSQL_EXECUTION || IN_PLSQL_RPC || IN_PLSQL_COMPILATION ||
  5         IN_JAVA_EXECUTION || IN_BIND || IN_CURSOR_CLOSE || IN_SEQUENCE_LOAD as sql_state,
  6         count(*)
  7    from v$active_session_history
  8   where IN_PARSE = 'N'
  9     and IN_HARD_PARSE = 'N'
 10     and IN_SQL_EXECUTION = 'Y'
 11     and SQL_PLAN_HASH_VALUE = 0
 12     and SQL_FULL_PLAN_HASH_VALUE > 0
 13     and SQL_PLAN_LINE_ID > 0
 14     and SQL_EXEC_ID > 0
 15   group by sql_id,
 16            top_level_sql_id,
 17            decode(session_state, 'WAITING', event, session_state),
 18            IN_PLSQL_EXECUTION || IN_PLSQL_RPC || IN_PLSQL_COMPILATION ||
 19            IN_JAVA_EXECUTION || IN_BIND || IN_CURSOR_CLOSE ||
 20            IN_SEQUENCE_LOAD
 21   having count(*) > 100
 22   order by count(*) desc
 23  /
 
SQL_ID        TOP_LEVEL_SQL_ID EVENT                                    SQL_STATE   COUNT(*)
------------- ---------------- ---------------------------------------- --------- ----------
65d6qy0tzvqrk 65d6qy0tzvqrk    ON CPU                                   NNNNNNN         3645
fbdkn5h1txdpz fbdkn5h1txdpz    ON CPU                                   NNNNNNN         3605 -- ***
1hdvt2xjutv5r 1hdvt2xjutv5r    ON CPU                                   NNNNNNN         1040
avxmz09d1usr8 3wh3vh443p184    ON CPU                                   NNNNNNN          540
1hdvt2xjutv5r 1hdvt2xjutv5r    direct path write temp                   NNNNNNN          368
avxmz09d1usr8 3wh3vh443p184    db file scattered read                   NNNNNNN          237
65d6qy0tzvqrk 65d6qy0tzvqrk    direct path read                         NNNNNNN          175
fbdkn5h1txdpz fbdkn5h1txdpz    direct path read                         NNNNNNN          170

можно заметить что запрос fbdkn5h1txdpz (***) на протяжении всего своего небыстрого выполнения (SQL_EXEC_ID > 0):

SQL> select sql_plan_hash_value,
  2         sql_full_plan_hash_value,
  3         sql_exec_id,
  4         decode(session_state, 'WAITING', event, session_state) as EVENT,
  5         sql_adaptive_plan_resolved,
  6         count(*)
  7    from v$active_session_history
  8   where sql_id = 'fbdkn5h1txdpz'
  9     and sql_exec_id > 0
 10   group by sql_plan_hash_value,
 11            sql_full_plan_hash_value,
 12            sql_exec_id,
 13            decode(session_state, 'WAITING', event, session_state),
 14            sql_adaptive_plan_resolved
 15   order by count(*) desc
 16  /
 
SQL_PLAN_HASH_VALUE SQL_FULL_PLAN_HASH_VALUE SQL_EXEC_ID EVENT                     SQL_ADAPTIVE_PLAN_RESOLVED   COUNT(*)
------------------- ------------------------ ----------- ------------------------- -------------------------- ----------
                  0               1728691197    16777216 ON CPU                                             0       3606
                  0               1728691197    16777216 direct path read                                   0        170
                  0               1728691197    16777216 db file scattered read                             0         40
                  0               1728691197    16777216 direct path read temp                              0         28
                  0               1728691197    16777216 direct path write temp                             0         23
                  0               1728691197    16777216 gc cr multi block request                          0          6
                  0               1728691197    16777216 PX Deq: Signal ACK EXT                             0          1

— имел SQL_PLAN_HASH_VALUE = 0, какие-то осмысленные состояния / ожидания и SQL_ADAPTIVE_PLAN_RESOLVED = 0 что, казалось бы, должно говорить о неадаптивности использованного при этом выполнении плана. Такое отображение типично для большей части запросов, выполняющихся с SQL_PLAN_HASH_VALUE = 0 среди которых много INSERT-ов, пользовательских или вызываемых DBMS_REFRESH.REFRESH

Отрадно, что Oracle в таких случаях предоставляет SQL_FULL_PLAN_HASH_VALUE, который однозначно соответствует привычному SQL_PLAN_HASH_VALUE, вопрос в том как определить этот SQL_PLAN_HASH_VALUE проблемного запроса, например, для дальнейшей работы с DBMS_XPLAN.DISPLAY_AWR, трейсировки плана выполнения по истории ASH и т.д.

На примере этого запроса можно видеть, что значение SQL_ADAPTIVE_PLAN_RESOLVED = 0 в ASH, видимо, пока не заполняется точно:

SQL> @shared_cu12 fbdkn5h1txdpz
 
EXECS ELA_PER_EXEC PLAN_HASH_VALUE OPTIMIZER_COST CHILD BIND_SENSE BIND_AWARE SHAREABLE  REOPT ADAPT USE_FEEDBACK_STATS OPTIMIZER_STATS
----- ------------ --------------- -------------- ----- ---------- ---------- ---------- ----- ----- ------------------ ---------------
    1   3924297463      3809734651        2692519     0 N          N          Y          Y     Y     Y                  N

— что заметно по полю V$SQL.IS_RESOLVED_ADAPTIVE_PLAN = ‘Y’ (столбец ADAPT) пока курсор находится в Shared Pool

Итак, найти действующий PLAN_HASH_VALUE можно по некоторым записям той же ASH:

SQL> select SQL_EXEC_ID,
  2         SQL_PLAN_HASH_VALUE,
  3         SQL_FULL_PLAN_HASH_VALUE,
  4         IN_PARSE || IN_HARD_PARSE || IN_SQL_EXECUTION || IN_PLSQL_EXECUTION ||
  5         IN_PLSQL_RPC || IN_PLSQL_COMPILATION || IN_JAVA_EXECUTION || IN_BIND ||
  6         IN_CURSOR_CLOSE || IN_SEQUENCE_LOAD as SQL_STATE,
  7         count(*)
  8    from v$active_session_history
  9   where sql_id = 'fbdkn5h1txdpz'
 10   group by SQL_EXEC_ID,
 11            SQL_PLAN_HASH_VALUE,
 12            SQL_FULL_PLAN_HASH_VALUE,
 13            IN_PARSE || IN_HARD_PARSE || IN_SQL_EXECUTION ||
 14            IN_PLSQL_EXECUTION || IN_PLSQL_RPC || IN_PLSQL_COMPILATION ||
 15            IN_JAVA_EXECUTION || IN_BIND || IN_CURSOR_CLOSE ||
 16            IN_SEQUENCE_LOAD
 17  /
 
SQL_EXEC_ID SQL_PLAN_HASH_VALUE SQL_FULL_PLAN_HASH_VALUE SQL_STATE    COUNT(*)
----------- ------------------- ------------------------ ---------- ----------
   16777216                   0               1728691197 NNYNNNNNNN       3874
                     3809734651               1728691197 YYNNNNNNNN         37 -- ****
                     3809734651               1728691197 YYYNNNNNNN         14 -- ****
                              0               1728691197 NNNNNNNNNN          3

— при этом, правда, неочевидно к какому именно акту выполнения SQL_EXEC_ID относится найденный SQL_PLAN_HASH_VALUE, т.к. в ASH он фиксировался только на этапе PARSE (****). Та же проблема с поиском по историческим данным в DBA_HIST_ACTIVE_SESS_HISTORY усугубляется естественной усушкой значительным уменьшением кол-ва этих данных в истории

Другим источником реального SQL_PLAN_HASH_VALUE могут быть обзоры:

SQL> select distinct SQL_PLAN_HASH_VALUE, SQL_FULL_PLAN_HASH_VALUE from v$sql_monitor where sql_id = 'fbdkn5h1txdpz';
 
SQL_PLAN_HASH_VALUE SQL_FULL_PLAN_HASH_VALUE
------------------- ------------------------
         3809734651               1728691197

SQL> select distinct plan_hash_value from V$SQL_PLAN where full_plan_hash_value = 1728691197;
 
PLAN_HASH_VALUE
---------------
     3809734651

— информация в которых опять же ограничена временем жизни курсора в Shared Pool

И, наконец, в трейсе оптимизатора можно найти прямое указание на место хранения хэшей планов:

Content of other_xml column
===========================
  derived_cpu_dop: 0
  derived_io_dop : 0
  dop_reason     : table property
  dop            : 2
  px_in_memory_imc: no
  px_in_memory   : no
  pdml_reason    : PDML is disabled in current session
  db_version     : 12.1.0.2
  parse_schema   : SYS
  dynamic_sampling: 11
  plan_hash_full : 1728691197
  plan_hash      : 3809734651
  plan_hash_2    : 3365355736
  adaptive_plan  : yes

и получать планы напрямую из столбца DBA_HIST_SQL_PLAN.OTHER_XML (или v$sql_plan по мере доступности):

SQL> with plan_hashs as
  2   (select p.plan_hash_value,
  3           to_number(extractvalue(h.column_value, '/info')) plan_full_hash_value
  4      from dba_hist_sql_plan p,
  5           table(xmlsequence(extract(xmltype(p.other_xml), '/other_xml/info'))) h
  6     where p.other_xml is not null
  7       and sql_id = 'fbdkn5h1txdpz'
  8       and extractvalue(h.column_value, '/info/@type') = 'plan_hash_full'
  9    union
 10    select distinct plan_hash_value, full_plan_hash_value
 11      from v$sql_plan
 12     where sql_id = 'fbdkn5h1txdpz')
 13  select plan_hash_value
 14    from plan_hashs
 15   where plan_full_hash_value = 1728691197
 16  /
 
PLAN_HASH_VALUE
---------------
     3809734651

Предложения, как обычно, приветствуются

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

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

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 такие блоггеры, как: