Oracle mechanics

29.12.2013

Функциональный хинт IGNORE_ROW_ON_DUPKEY_INDEX

Filed under: hints,Oracle,PL/SQL — Игорь Усольцев @ 11:53
Tags:

По следам обсуждения необоснованного роста ASSM табличных сегментов в результате автоматической обработки исключений с использованием добавленной в 11.2 подсказки IGNORE_ROW_ON_DUPKEY_INDEXПочему занимаемый таблицей размер растет при холостых инсертах?

В версии 12.1.0.1 основная проблема была тихо исправлена (во всяком случае мне не удалось обнаружить упоминаний соотв.бага):

12.1.0.1.@ SQL> select segment_name, bytes, blocks from user_segments where segment_name like 'TIG%';

SEGMENT_NAME            BYTES     BLOCKS
-------------------- -------- ----------
TIG                  25165824       3072
TIG_PK                2097152        256

SQL> insert /*+ IGNORE_ROW_ON_DUPKEY_INDEX(tig tig_pk)*/ into tig
  2    select level, rpad('*', 200, '*') from dual connect by level <= 1e5
  3  /

0 rows created.

Elapsed: 00:00:57.78

SQL> select segment_name, bytes, blocks from user_segments where segment_name like 'TIG%';

SEGMENT_NAME            BYTES     BLOCKS
-------------------- -------- ----------
TIG                  25165824       3072
TIG_PK                2097152        256

— сегмент не растёт, однако скорость выполнения вставки с использованием такого хинта остаётся весьма невысокой по сравнению, например, с обработкой встроенного исключения DUP_VAL_ON_INDEX в PL/SQL блоке:

сравнение

Что проще всего, похоже, проверить с помощью INSTEAD OF INSERT триггера

Статистика тестового запроса с подсказкой:

SQL> insert /*+ IGNORE_ROW_ON_DUPKEY_INDEX(tig tig_pk)*/ into tig
  2    select level, rpad('*', 200, '*') from dual connect by level <= 1e5
  3  /

0 rows created.

Elapsed: 00:01:00.56

Execution Plan
----------------------------------------------------------
Plan hash value: 1236776825

------------------------------------------------------------------------------
| Id  | Operation                     | Name | Rows  | Cost (%CPU)| Time     |
------------------------------------------------------------------------------
|   0 | INSERT STATEMENT              |      |     1 |     2   (0)| 00:00:01 |
|   1 |  LOAD TABLE CONVENTIONAL      | TIG  |       |            |          |
|*  2 |   CONNECT BY WITHOUT FILTERING|      |       |            |          |
|   3 |    FAST DUAL                  |      |     1 |     2   (0)| 00:00:01 |
------------------------------------------------------------------------------

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

   2 - filter(LEVEL<=1e5)

Statistics
----------------------------------------------------------
     800025  recursive calls
    1804905  db block gets
     949995  consistent gets
        195  physical reads
  965925164  redo size                        -- почти гигабайт редо при вставке 25 МБ данных
...

PL/SQL (точнее, триггерная) обработка аналогичного исключения выполняется в 2 раза быстрее:

SQL> create view tig_view as select * from tig;

View created.

SQL> create trigger tig_view_tr
  2  INSTEAD OF INSERT on tig_view
  3  begin
  4          insert into tig values ( :new.x, :new.y );
  5  exception
  6          when dup_val_on_index then null;
  7  end;
  8  /

Trigger created.

SQL> insert into tig_view
  2    select level, rpad('*', 200, '*') from dual connect by level <= 1e5
  3  /

100000 rows created.

Elapsed: 00:00:30.12

Execution Plan
----------------------------------------------------------
Plan hash value: 1236776825 -- тот же план

...

Statistics
----------------------------------------------------------
    1000019  recursive calls
    1100645  db block gets
     800008  consistent gets
          1  physical reads
   68800928  redo size                        -- также немало, но в 15 раз меньше, чем с подсказкой
...
     100000  rows processed                   -- строки, вставленные в обзор, но не попавшие в таблицу

При использовании триггера обращает внимание незначительное время, затраченное на обработку PL/SQL:

Session Time Model
 
STAT_NAME                                          DELTA
------------------------------------------- ------------
DB time                                         30679152
sql execute elapsed time                        30672468
DB CPU                                          30669797
PL/SQL execution elapsed time                    2267565 -- ***
parse time elapsed                               1306234

— в том смысле, что это действительно хороший показатель, всего ~ 7.3% DB time

Большое количество рекурсивных запросов объяснимо, но в трейс запроса с хинтом попадает лишь один небыстрый:

SQL ID: 2jfqzrxhrm93b Plan Hash: 1027684349

select /*+ rule */ c.name, u.name 
from
 con$ c, cdef$ cd, user$ u  where c.con# = cd.con# and cd.enabled = :1 and 
  c.owner# = u.user#


call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse   100000      1.49       1.41          0          0          0           0
Execute 100000     16.31      16.38          0          0          0           0
Fetch   100000      3.04       3.27          0     800000          0      100000
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total   300000     20.85      21.07          0     800000          0      100000

— с большим количеством незначительных по времени разборов (Parse), вероятно, вызванных тем, что запрос выполняется к словарным таблицам, но этот системный/рекурсивный запрос выполняется в процессе обоих DML со сравнимыми временами и, очевидно, не может быть причиной 2-х кратного различия времен выполнения

В случае использования подсказки IGNORE_ROW_ON_DUPKEY_INDEX хорошо заметен объём сгенерируемого в процессе холостой вставки redo, никак не отражаемого в событиях ожидания:

Session Wait Events
 
NAME                                   WAITS      TIME_MS     TIMEOUTS AVG_WAIT_MS
------------------------------- ------------ ------------ ------------ -----------
SQL*Net message from client                1        43303            0       43303
db file sequential read                  188          119            0         0,6
Disk file operations I/O                   2           12            0         5,9
SQL*Net message to client                  1            0            0           0

и, очевидно, являющегося основной причиной медленного выполнения

Любопытно посмотреть содержимое сгенерированных логов:

SQL> select l.status, l.bytes, l.sequence#, lf.member from v$log l join v$logfile lf using (group#);

STATUS                BYTES  SEQUENCE# MEMBER
---------------- ---------- ---------- --------------------------------------------
INACTIVE           52428800        711 C:\ORACLE\ORACLE1201\ORADATA\ORCL\REDO03.LOG
INACTIVE           52428800        710 C:\ORACLE\ORACLE1201\ORADATA\ORCL\REDO02.LOG
CURRENT            52428800        712 C:\ORACLE\ORACLE1201\ORADATA\ORCL\REDO01.LOG

SQL> insert /*+ IGNORE_ROW_ON_DUPKEY_INDEX(tig tig_pk)*/ into tig
  2    select level, rpad('*', 200, '*') from dual connect by level <= 1e5
  3  /

0 rows created.

Elapsed: 00:00:59.63

SQL> select l.status, l.bytes, l.sequence#, lf.member from v$log l join v$logfile lf using (group#);

STATUS                BYTES  SEQUENCE# MEMBER
---------------- ---------- ---------- --------------------------------------------
ACTIVE             52428800        732 C:\ORACLE\ORACLE1201\ORADATA\ORCL\REDO03.LOG
ACTIVE             52428800        731 C:\ORACLE\ORACLE1201\ORADATA\ORCL\REDO02.LOG
CURRENT            52428800        733 C:\ORACLE\ORACLE1201\ORADATA\ORCL\REDO01.LOG

SQL> begin
  2    sys.dbms_logmnr.ADD_LOGFILE ('C:\ORACLE\ORACLE1201\ORADATA\ORCL\REDO02.LOG');
  3    sys.dbms_logmnr.ADD_LOGFILE ('C:\ORACLE\ORACLE1201\ORADATA\ORCL\REDO03.LOG');
  4    sys.dbms_logmnr.START_LOGMNR();
  5  end;
  6  /

PL/SQL procedure successfully completed.

SQL> select xid,
  2         rollback,
  3         operation,
  4         data_obj#,
  5         abs_file#,
  6         data_blk#,
  7         substr(sql_redo, 1, 50) as sql_redo,
  8         info,
  9         count(*),
 10         count(distinct row_id)
 11    from v$logmnr_contents
 12   group by xid,
 13            rollback,
 14            operation,
 15            data_obj#,
 16            substr(sql_redo, 1, 50),
 17            abs_file#,
 18            data_blk#,
 19            info
 20  /

XID              ROLLBACK OPERATION  DATA_OBJ#  ABS_FILE#  DATA_BLK# SQL_REDO                                           INFO                  COUNT(*) COUNT(DISTINCTROW_ID)
---------------- -------- --------- ---------- ---------- ---------- -------------------------------------------------- ------------------- ---------- ---------------------
010021007A150000        1 DELETE         94082          9      72196 delete from "UNKNOWN"."OBJ# 94082" where ROWID =   Dictionary Mismatch     197843                   34
010021007A150000        1 DELETE         94082          9      72255 delete from "UNKNOWN"."OBJ# 94082" where ROWID =   Dictionary Mismatch     144694                   28
010021007A150000        0 INSERT         94082          9      72196 insert into "UNKNOWN"."OBJ# 94082"("COL 1","COL 2" Dictionary Mismatch     197843                   34
010021007A150000        0 INSERT         94082          9      72255 insert into "UNKNOWN"."OBJ# 94082"("COL 1","COL 2" Dictionary Mismatch     144694                   28

— в рамках одной транзакции последовательно зафиксированы вставки и последующие удаления (в качестве ROLLBACK) нескольких десятков строк всего двух блоков таблицы TIG:

SQL> select segment_type, segment_name, block_id, blocks
  2  from dba_extents
  3   where file_id = 9
  4     and (72196 between block_id and block_id + blocks
  5          or
  6          72255 between block_id and block_id + blocks)
  7  /

SEGMENT_TYPE       SEGMENT_NAME         BLOCK_ID     BLOCKS
------------------ ------------------ ---------- ----------
TABLE              TIG                     72192        128

— при этом количество последовательно вставляемых/удаляемых строк, ~ 340,000 в 2-х логах, или ~ 3,400,000 в полном наборе из ~ 20-ти сгенерированных логов в процессе вставки 100,000 строк, наводит на мысль о записи ~ одного (из 2-х уникальных) блока таблицы TIG на каждую вставляемую с подсказкой строку:

SQL> select round(num_rows/blocks) as rows_per_block from user_tables where table_name = 'TIG';

ROWS_PER_BLOCK
--------------
            33

При использовании INSTEAD OF INSERT триггера:

SQL> alter system switch logfile;
 
System altered
 
SQL> insert into tig_view
  2    select level, rpad('*', 200, '*') from dual connect by level <= 1e5
  3  /

100000 rows created.

Elapsed: 00:00:30.68
 
SQL> select l.status, l.bytes, l.sequence#, lf.member from v$log l join v$logfile lf using (group#);
 
STATUS                BYTES  SEQUENCE# MEMBER
---------------- ---------- ---------- --------------------------------------------
ACTIVE             52428800        810 C:\ORACLE\ORACLE1201\ORADATA\ORCL\REDO03.LOG
CURRENT            52428800        812 C:\ORACLE\ORACLE1201\ORADATA\ORCL\REDO02.LOG
ACTIVE             52428800        811 C:\ORACLE\ORACLE1201\ORADATA\ORCL\REDO01.LOG

SQL> begin
  2    sys.dbms_logmnr.END_LOGMNR;
  3    sys.dbms_logmnr.ADD_LOGFILE ('C:\ORACLE\ORACLE1201\ORADATA\ORCL\REDO01.LOG'); -- возьмём последний лог
  4    sys.dbms_logmnr.START_LOGMNR();
  5  end;
  6  /
 
PL/SQL procedure successfully completed

SQL> select xid,
  2         rollback,
  3         operation,
  4         data_obj#,
  5         abs_file#,
  6         data_blk#,
  7         substr(sql_redo, 1, 50) as sql_redo,
  8         info,
  9         count(*),
 10         count(distinct row_id)
 11    from v$logmnr_contents
 12   group by xid,
 13            rollback,
 14            operation,
 15            data_obj#,
 16            substr(sql_redo, 1, 50),
 17            abs_file#,
 18            data_blk#,
 19            info
 20   having count(*) > 100 -- отфильтруем незначительные операции
 21  /
 
XID              ROLLBACK OPERATION  DATA_OBJ#  ABS_FILE#  DATA_BLK# SQL_REDO                                           INFO                  COUNT(*) COUNT(DISTINCTROW_ID)
---------------- -------- --------- ---------- ---------- ---------- -------------------------------------------------- ------------------- ---------- ---------------------
0900150070210000        1 DELETE         94082          9      72255 delete from "UNKNOWN"."OBJ# 94082" where ROWID =   Dictionary Mismatch      62190                     1
0900150070210000        0 INSERT         94082          9      72255 insert into "UNKNOWN"."OBJ# 94082"("COL 1","COL 2" Dictionary Mismatch      62191                     1

— на каждую из неудачно вставляемых дублирующих строк приходится вставка/удаление лишь одной строки, при этом, судя по повторяющемуся ROW_ID — одной и той же. Аналогичная опережающая «оптимизированная» запись, но в заметно меньших объёмах ;)

При этом, наблюдаемое при использовании IGNORE_ROW_ON_DUPKEY_INDEX поведение (типа «оптимизации») не зависит от выбранного способа управления местом в табличном пространстве, т.е. создание тестовой таблицы в ТС SYSTEM с «ручным» управлением никак не влияет на скорость вставки / объём генерируемого redo:

SQL> insert /*+ IGNORE_ROW_ON_DUPKEY_INDEX(tig_mssm tig_mssm_pk)*/
  2  into tig_mssm
  3    select level, rpad('*', 200, '*') from dual connect by level <= 1e5
  4  /

0 rows created.

Elapsed: 00:00:59.96         -- то же неоптимальное время

Statistics
----------------------------------------------------------
     800027  recursive calls
    1304946  db block gets
     949935  consistent gets
          0  physical reads
  945743920  redo size       -- при том же объёме REDO
...

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

  1. Есть еще разница — в случае использования хинта, можно узнать, сколько записей было реально вставлено, а вот в случае view — нет. Тем не менее, идея с VIEW интересна своей неожиданностью. Я бы до этого стал использовать INSERT в блоке begin .. exception, либо forall insert exceptions into либо insert into X as select from Y minus select X. Последнее должно быть самое интересное

    комментарий от Sergey Golikov — 10.01.2014 @ 16:45 | Ответить

    • insert /*+ IGNORE_ROW_ON_DUPKEY_INDEX(tig tig_pk)*/ into tig
      select x,y from (select level x, rpad(‘*’, 200, ‘*’) y from dual connect by level<=1e5)
      minus
      select x,y from tig

      0 rows created.
      Elapsed: 00:00:02.71

      комментарий от Sergey Golikov — 10.01.2014 @ 17:01 | Ответить

    • при вставке как LOAD TABLE сдвигается HWM. Если вставлять пачку записей, а затем откатывать изменения, HWM все равно будет сдвигаться и таблица расти. Интересно, что же сделали в 12.1 ?

      комментарий от Sergey Golikov — 10.01.2014 @ 17:17 | Ответить

      • HWM в обязательном порядке сдвигается при direct-path вставке, а здесь используется LOAD TABLE CONVENTIONAL — я в пост добавил план — т.е. это какой-то третий тип «оптимизации» при массовом добавлении строк с подсказкой IGNORE_ROW_ON_DUPKEY_INDEX
        В 11.2 при этом ошибочно и многократно двигался HWM, а в 12.1 «холостой» сдвиг HWM отключили, но redo по-прежнему генерируется опережающими темпами, насколько я понимаю

        комментарий от Igor Usoltsev — 10.01.2014 @ 21:22 | Ответить


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