Oracle mechanics

31.10.2013

Использование ASH для трассировки коротких частовыполняемых запросов

Filed under: Active Session History,commonplace,Oracle,SQL Tuning — Игорь Усольцев @ 23:43
Tags: ,

Для примера попалась несложная задача — улучшить план выполнения критичного запроса, недостаточно долгого для попадания в V$SQL_PLAN_MONITOR (ср.время выполнения менее секунды), со следующей статистикой выполнения*:

11.1.0.7.@ SQL> @dba_hist_sqlstat111 "sql_id = 'g6fcqwyqukvb2'"

SNAP_ID EXECS_DELTA PLAN_HASH_VALUE COST OPT_MODE ELA_PER_EXEC CPU_PER_EXEC GETS_PER_EXEC ROWS_PER_EXEC IOW_PER_EXEC
------- ----------- --------------- ---- -------- ------------ ------------ ------------- ------------- ------------
  64388        2581      3615699284  294 ALL_ROWS       405642        13789          4771             1       393699
  64387        2479      3615699284  294 ALL_ROWS       510154        15752          4740             1       495260
  64386        1088      3615699284  294 ALL_ROWS      1418873        26509          4751             1      1392524
  64385         925      3615699284  294 ALL_ROWS       351538        13708          4714             1       339622
  64384        1284      3615699284  294 ALL_ROWS       673089        17084          4739             1       659024

Для получения статистики плана выполнения можно потестировать запрос со сбором статистики плана выполнения, или побаловаться с SQL Monitoring-ом, соответственно, параметром _sqlmon_threshold или подсказкой /*+ MONITOR */

Однако, учитывая распостранённость автоматически заполняемых обзоров ASH и частое выполнение (а, значит, и попадание в историю активных сессий) запроса, проще и быстрее получить данные по статистике плана выполнения из истории простым запросом типа ASH_SQLMON.SQL, например**:

SQL> @ash_sqlmon g6fcqwyqukvb2

ID PLAN_OPERATION                             OBJECT_NAME    WAIT_PROFILE
-- ------------------------------------------ -------------- ---------------------------------------------------------------------
 0   SELECT STATEMENT                                        ON CPU(2);
 1     FILTER
 2       TABLE ACCESS BY INDEX ROWID          UPLOADS
 3         INDEX UNIQUE SCAN                  SYS_C00200062  db file sequential read(4);
 4           SORT AGGREGATE
 5             FILTER
 6               TABLE ACCESS BY INDEX ROWID  UPLOADS        ON CPU(98);
 7                 INDEX RANGE SCAN           FILE_IDX       db file sequential read(5016); ON CPU(55); read by other session(10);

— судя по WAIT_PROFILE, основное время/кол-во записей в ASH приходится на чтение индекса на шаге 7:

Plan hash value: 3615699284

--------------------------------------------------------------------------------------------------
| Id  | Operation                        | Name          | Rows  | Bytes | Cost (%CPU)| Time     |
--------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                 |               |       |       |   294 (100)|          |
|*  1 |  FILTER                          |               |       |       |            |          |
|*  2 |   TABLE ACCESS BY INDEX ROWID    | UPLOADS       |     1 |    73 |     1   (0)| 00:00:01 |
|*  3 |    INDEX UNIQUE SCAN             | SYS_C00200062 |     1 |       |     1   (0)| 00:00:01 |
|   4 |     SORT AGGREGATE               |               |     1 |    52 |            |          |
|*  5 |      FILTER                      |               |       |       |            |          |
|*  6 |       TABLE ACCESS BY INDEX ROWID| UPLOADS       |   348 | 18096 |   293   (0)| 00:00:04 | -- основная стоимость
|*  7 |        INDEX RANGE SCAN          | FILE_IDX      |  2919 |       |     4   (0)| 00:00:01 | -- основное время
--------------------------------------------------------------------------------------------------

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

   1 - filter(:1<=:2)
   2 - filter(("FILE_NAME"=:4 AND "SERVICE_NAME"=:3 AND "STATUS"=:5 AND "UPLOAD_TS">=:1
              AND "UPLOAD_TS"<=:2))
   3 - access("U1"."ID"=)
   5 - filter(:6<=:7)
   6 - filter(("SERVICE_NAME"=:8 AND "STATUS"=:10 AND "UPLOAD_TS">=:6 AND
              "UPLOAD_TS"<=:7))
   7 - access("FILE_NAME"=:9)

— что логично следует из плана: на шаге 7 INDEX RANGE SCAN по полю FILE_NAME, с последующей фильтрацией данных таблицы UPLOADS по значениям SERVICE_NAME и STATUS на шаге 6 (границы поля UPLOAD_TS в запросе оказались неселективными, типа ’01-01-1900′ и ’31-12-2199′, видимо, предикат добавлен «для будущего использования»)

На шаге 6 плана время/ресурсы кроме ЦПУ не расходуются по причине плотного кэширования блоков таблицы, в основном, в статусе CURRENT — OLTP всё-ж-таки:

SQL> @db_seg_cache UPLOADS

AREA         STATUS     DISTINCT_BLOCK_COUNT  BLOCK_COUNT
------------ ---------- --------------------- ------------
BUFFER CACHE cr         1831                  3020
BUFFER CACHE xcur       231108                231108
BUFFER CACHE summary    231108                234128      -- 99.53%
DATABASE     db blocks  232192

Естественно-логичным способом «оптимизации запроса» без соприкосновения с кодом будет создание индекса по 3-м интересующим столбцам:

create index FILE_IDX3 on UPLOADS(file_name, service_name, status)

И пока курсор со старым планом (Cost=294) находится в кэше можно наблюдать изменения по данным обзора V$SQLSTATS:

SQL> @sql_stat g6fcqwyqukvb2

SQL_ID        CHILD_NUMBER       PLAN COST   EXECS ELA_PER_EXEC CPU_PER_EXEC IOWAITS_PER_EXEC
------------- ------------ ---------- ---- ------- ------------ ------------ ----------------
g6fcqwyqukvb2            0  992897702    6    5456         3318         2426              543 -- новый индекс
g6fcqwyqukvb2            2 3615699284  294  122391       435418        14672           421212 -- старый индекс

, либо по прошествии времени по истории из DBA_HIST_SQLSTAT:

SQL> @dba_hist_sqlstat111 "sql_id = 'g6fcqwyqukvb2'"

SNAP_ID EXECS_DELTA PLAN_HASH_VALUE COST OPT_MODE ELA_PER_EXEC CPU_PER_EXEC GETS_PER_EXEC ROWS_PER_EXEC IOW_PER_EXEC
------- ----------- --------------- ---- -------- ------------ ------------ ------------- ------------- ------------
  64408        2212       992897702    6 ALL_ROWS          539          443           113             1           80 -- стало
  64404        2212       992897702    6 ALL_ROWS          522          436           112             1           53
  64403        2648       992897702    6 ALL_ROWS         6044         5261          2201             1          437
  64400        2212       992897702    6 ALL_ROWS          434          382           111             1           60
  64399         832      3615699284  294 ALL_ROWS       558305        17090          4737             1       541174 -- было
  64398        1216      3615699284  294 ALL_ROWS       548747        17871          4761             1       526089
  64397         233      3615699284  294 ALL_ROWS       428482        12015          4722             1       418612
  64396        2670      3615699284  294 ALL_ROWS       438182        13246          4738             1       426340

*) Времена ELA_PER_EXEC, CPU_PER_EXEC и IOW_PER_EXEC — в микросекундах

**) Скрипт ASH_SQLMON.SQL запускался с одним параметром sql_id, поскольку на тот момент в ASH находились записи только одного плана выполнения:

SQL> select distinct sql_plan_hash_value from v$active_session_history where sql_id = 'g6fcqwyqukvb2'
  2  /

SQL_PLAN_HASH_VALUE
-------------------
         3615699284

, в иных обстоятельствах случаях можно фильтровать статистику плана выполнения по plan_hash_value и / или sql_exec_id

3 комментария »

  1. Я использую похожий скрипт от Танела Подера: http://blog.tanelpoder.com/files/scripts/ash/asqlmon.sql

    Игорь, кстати, я тоже начал причесывать свои скрипты, чтобы создать хороший переносимый универсальный набор. Может присоединишься?
    Посмотри: http://src.orasql.org/public/projects/root/xt_scripts или https://github.com/xtender/xt_scripts

    комментарий от Sayan Malakshinov — 01.11.2013 @ 01:03 | Ответить

    • Кстати, я еще немного модифицировал asqlmon, чтобы и до 11g использовать можно было. Правда, не объединил версии. Сделаю это на днях

      комментарий от Sayan Malakshinov — 01.11.2013 @ 01:06 | Ответить

    • Обязательно посмотрю, хорошая идея

      комментарий от Igor Usoltsev — 01.11.2013 @ 18:17 | Ответить


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