Oracle mechanics

09.10.2013

Сравнение тестовой и рабочей сред через время выполнения запроса

Filed under: Диагностика системы (instance),Oracle — Игорь Усольцев @ 22:25
Tags:

Простой вопрос — отчего люди не летают так, как птицы?, в смысле почему один и тот же запрос выполняется в течение
существенно разного времени в ПРОДАКШН и ТЕСТовой средах? Учитывая, что планы выполнения совпадают, и данные в тестовой среде достаточно «свежие», неоригинальный ответ напрашивается сам собой — от того что среды разные!

Далее — не слишком полезный, но, как мне показалось, забавный пример разбора различий скорости выполнения одного запроса

Итак, в среде ПРОДАКШН запрос выполняется условно быстро — менее 3-х секунд:

11.1.0.7.@ SQL> SELECT COUNT(*)
...
 11 /

  COUNT(*)
----------
         4

Elapsed: 00:00:02.53

SELECT * FROM TABLE(dbms_xplan.display_cursor( '',format => 'all allstats last'));

Plan hash value: 2143365355

-----------------------------------------------------------------------------------------------------------------------------------------
| Id  | Operation                    | Name           | Starts | E-Rows |E-Bytes| Cost (%CPU)| E-Time   | A-Rows |   A-Time   | Buffers |
-----------------------------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT             |                |      1 |        |       | 30416 (100)|          |      1 |00:00:02.48 |     514K|
|   1 |  SORT AGGREGATE              |                |      1 |      1 |   239 |            |          |      1 |00:00:02.48 |     514K|
|*  2 |   TABLE ACCESS BY INDEX ROWID| PRUDE          |      1 |   4536 |  1058K| 30414   (1)| 00:04:59 |      4 |00:00:02.48 |     514K|
|*  3 |    INDEX RANGE SCAN          | I_TEST3_IDX    |      1 |    566K|       |   445   (1)| 00:00:05 |    604K|00:00:00.01 |    6083 |
|*  4 |    TABLE ACCESS FULL         | MOD_LAST_PRUDE |      1 |      1 |    16 |     2   (0)| 00:00:01 |      1 |00:00:00.01 |      15 |
-----------------------------------------------------------------------------------------------------------------------------------------

— статистика плана выполнения при этом, демонстрируя достаточно большие (514K за 2,48 сек. ~ 207К+ чтений в секунду) цифры буферных чтений, совсем не показывает столбца Reads, т.е. при всей неэффективности плана запрос выполняется за разумное время благодаря надёжному кэшированию блоков таблицы PRUDE в Buffer Cache SGA

На тестовом экземпляре тот же запрос отрабатывает заметно дольше — почти 30 минут:

SQL> SELECT COUNT(*)
...
 11 /

  COUNT(*)
----------
       570                  -- количество возвращаемых строк не имеет значения в этом случае

Elapsed: 00:29:51.75

SQL> SELECT * FROM TABLE(dbms_xplan.display_cursor( '',format => 'all allstats last'));

Plan hash value: 2143365355 -- тот же план выполнения

--------------------------------------------------------------------------------------------------------------------------------------------------
| Id  | Operation                    | Name           | Starts | E-Rows |E-Bytes| Cost (%CPU)| E-Time   | A-Rows |   A-Time   | Buffers | Reads  |
--------------------------------------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT             |                |      1 |        |       | 31149 (100)|          |      1 |00:29:51.80 |     512K|    321K|
|   1 |  SORT AGGREGATE              |                |      1 |      1 |   239 |            |          |      1 |00:29:51.80 |     512K|    321K|
|*  2 |   TABLE ACCESS BY INDEX ROWID| PRUDE          |      1 |   4536 |  1058K| 31147   (1)| 00:05:07 |    570 |00:29:51.80 |     512K|    321K|-- here be dragonz!
|*  3 |    INDEX RANGE SCAN          | I_TEST3_IDX    |      1 |    566K|       |   374   (1)| 00:00:04 |    604K|00:00:36.95 |    3601 |   3600 |
|*  4 |    TABLE ACCESS FULL         | MOD_LAST_PRUDE |      1 |      1 |    16 |     2   (0)| 00:00:01 |      1 |00:00:00.06 |      15 |     14 |
--------------------------------------------------------------------------------------------------------------------------------------------------

— при этом наряду с ожидаемо значительными буферными чтениями в статистике отражено 321K физических чтений таблицы PRUDE, на которые в основном и тратится время. Чтения выполняются со штатной для некэшированных шпиндельных дисков скоростью ~ 1800 сек / 321K ~ 5.6 мс

Приблизительно тот же результат показывает вывод скрипта ash_sqlmon.sql, агрегирующего записи ASH по шагам плана выполнения аналогично SQL Monitor, но при этом способный также показать суммарную статистику множества выполнений запроса с одним и тем же планом (что может быть полезно, например, для многочиленных коротких запросов, по умолчанию не попадающих в стандартный мониторинг):

SQL> @ash_sqlmon duujgr3v716jf 2143365355 [16777217] -- последний параметр SQL_EXEC_ID - необязательный

ID PLAN_OPERATION                     OBJECT_OWNER OBJECT_NAME    WAIT_PROFILE
-- ---------------------------------- ------------ -------------- --------------------------------------------------------------------
 0   SELECT STATEMENT
 1     SORT AGGREGATE
 2       TABLE ACCESS BY INDEX ROWID  PRUDE        PRUDE          db file sequential read(2734); ON CPU(14); read by other session(2);
 3         INDEX RANGE SCAN           PRUDE        I_TEST3_IDX    db file sequential read(52);
 4         TABLE ACCESS FULL          PRUDE        MOD_LAST_PRUDE

— основные записи в ASH (и время выполнения) занимают операции TABLE ACCESS BY INDEX ROWID таблицы PRUDE

Проблема вырисовывается достаточно ясно — вероятно, на ТЕСТе просто недостаточно памяти, кэп!

И чтобы бесповоротно убедиться в справдивости данного предположения, недолго думая, запускаю скрипт db_seg_cache.sql, который по имени владельца и наименованию сегмента покажет расположение блоков объекта бд в памяти и на диске (+ общий объём доступной памяти)

На тестовой системе:

SQL> @db_seg_cache PRUDE PRUDE

AREA         STATUS                         DISTINCT_BLOCK_COUNT                     BLOCK_COUNT
------------ ------------------------------ ---------------------------------------- ------------
BUFFER CACHE read                           6                                        6
BUFFER CACHE xcur                           395075                                   395075
BUFFER CACHE summary                        395081                                   395081       -- кэшируется не более 1/3
DATABASE     db blocks                      1282048                                               -- из 1,2+ млн. блоков
SGA          BUFFER CACHE of MAX SGA SIZE   2,701,131,776 of 3,206,836,224           (Resizeable) -- при буферном кэше SGA ~ 2,7 ГБ

, в то время как на боевом инстансе:

SQL> @db_seg_cache PRUDE PRUDE

AREA         STATUS                         DISTINCT_BLOCK_COUNT                     BLOCK_COUNT
------------ ------------------------------ ---------------------------------------- ------------
BUFFER CACHE cr                             67                                       80
BUFFER CACHE xcur                           1279824                                  1279824      -- в статусе CURRENT
BUFFER CACHE summary                        1279824                                  1279904      -- кэшируется 99,8% блоков таблицы
DATABASE     db blocks                      1282048
SGA          BUFFER CACHE of MAX SGA SIZE   15,502,147,584 of 17,103,163,392         (Resizeable) -- кэш 15,5 ГБ

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

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

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