29 Май 2009 г.

Представления словаря данных

Преамбула: когда-то давно, лет пять назад, я стоял у истоков одной большой информационной системы, был ее архитектором. Сейчас занимаюсь поддержкой и развитем этой системы. В основе выбранной мною архитектуры лежало понятие изолированных подсистем, каждая подсистема находится в отдельной схеме базы данных. Экземпляр системы состоит из набора схем, имеющих дозированный доступ друг к другу. Кроме того, информационная система является распределенной, т. е. происходит репликация данных между узлами. При тестировании, чтобы иметь возможность развернуть несколько экземпляров системы в одной физической базе, было принято решение использовать для имен схем префиксы, а для обращения подсистем друг к другу - приватные синонимы. Система пошла в "production", и вот, уже более чем через 5 лет эксплуатации, в центральном ее узле назрела проблема - количество синонимов приближается к 100 тысячам. Таже проблема, кстати, и в девелоперской базе.
Амбула: недавно устанавливал обновления приложений центральной базы. Процесс очень затянулся. Одним из основных потребителей времени оказался SQL*Loader. Дело в том, что в процессе обновления грузилось очень много мелких файлов с помощью указанной утилиты. Собственно сама загрузка происходила быстро, но перед загрузкой, SQL*Loader обращался к представлению ALL_SYNONYMS. На это, в моем случае, уходило порядка 30 секунд.

План соответствующего запроса имеет угрожающий вид:


SQL_ID 41zw01wh8s59a, child number 0
SELECT TABLE_NAME, NVL(TABLE_OWNER, ''), NVL(DB_LINK, '') FROM SYS.ALL_SYNONYMS WHERE SYNONYM_NAME = :1 AND OWNER = :2
Plan hash value: 3788280054

---------------------------------------------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows | A-Rows | A-Time | Buffers | OMem | 1Mem | Used-Mem |
---------------------------------------------------------------------------------------------------------------------------------------------------
| 1 | VIEW | ALL_SYNONYMS | 1 | 2 | 1 |00:00:30.26 | 4601 | | | |
| 2 | SORT UNIQUE | | 1 | 2 | 1 |00:00:30.26 | 4601 | 2048 | 2048 | 2048 (0)|
| 3 | UNION-ALL | | 1 | | 1 |00:00:30.26 | 4601 | | | |
|* 4 | FILTER | | 1 | | 1 |00:00:00.01 | 8 | | | |
| 5 | NESTED LOOPS | | 1 | 1 | 1 |00:00:00.01 | 8 | | | |
| 6 | NESTED LOOPS | | 1 | 1 | 1 |00:00:00.01 | 5 | | | |
| 7 | TABLE ACCESS BY INDEX ROWID | USER$ | 1 | 1 | 1 |00:00:00.01 | 2 | | | |
|* 8 | INDEX UNIQUE SCAN | I_USER1 | 1 | 1 | 1 |00:00:00.01 | 1 | | | |
|* 9 | TABLE ACCESS BY INDEX ROWID | OBJ$ | 1 | 1 | 1 |00:00:00.01 | 3 | | | |
|* 10 | INDEX RANGE SCAN | I_OBJ2 | 1 | 1 | 1 |00:00:00.01 | 2 | | | |
| 11 | TABLE ACCESS BY INDEX ROWID | SYN$ | 1 | 1 | 1 |00:00:00.01 | 3 | | | |
|* 12 | INDEX UNIQUE SCAN | I_SYN1 | 1 | 1 | 1 |00:00:00.01 | 2 | | | |
|* 13 | FILTER | | 0 | | 0 |00:00:00.01 | 0 | | | |
|* 14 | FILTER | | 0 | | 0 |00:00:00.01 | 0 | | | |
| 15 | NESTED LOOPS | | 0 | 1 | 0 |00:00:00.01 | 0 | | | |
| 16 | NESTED LOOPS | | 0 | 1 | 0 |00:00:00.01 | 0 | | | |
| 17 | TABLE ACCESS BY INDEX ROWID | USER$ | 0 | 1 | 0 |00:00:00.01 | 0 | | | |
|* 18 | INDEX UNIQUE SCAN | I_USER1 | 0 | 1 | 0 |00:00:00.01 | 0 | | | |
| 19 | TABLE ACCESS BY INDEX ROWID | OBJ$ | 0 | 1 | 0 |00:00:00.01 | 0 | | | |
|* 20 | INDEX RANGE SCAN | I_OBJ2 | 0 | 1 | 0 |00:00:00.01 | 0 | | | |
|* 21 | INDEX RANGE SCAN | I_OBJAUTH1 | 0 | 1 | 0 |00:00:00.01 | 0 | | | |
|* 22 | FIXED TABLE FULL | X$KZSRO | 0 | 1 | 0 |00:00:00.01 | 0 | | | |
|* 23 | FIXED TABLE FULL | X$KZSPR | 0 | 1 | 0 |00:00:00.01 | 0 | | | |
| 24 | NESTED LOOPS | | 1 | 1 | 0 |00:00:30.26 | 4593 | | | |
|* 25 | HASH JOIN | | 1 | 1 | 0 |00:00:30.26 | 4593 | 700K| 700K| |
| 26 | NESTED LOOPS | | 1 | 1 | 1 |00:00:00.01 | 5 | | | |
| 27 | TABLE ACCESS BY INDEX ROWID | USER$ | 1 | 1 | 1 |00:00:00.01 | 2 | | | |
|* 28 | INDEX UNIQUE SCAN | I_USER1 | 1 | 1 | 1 |00:00:00.01 | 1 | | | |
|* 29 | TABLE ACCESS BY INDEX ROWID | OBJ$ | 1 | 1 | 1 |00:00:00.01 | 3 | | | |
|* 30 | INDEX RANGE SCAN | I_OBJ2 | 1 | 1 | 1 |00:00:00.01 | 2 | | | |
| 31 | VIEW | _ALL_SYNONYMS_TREE | 1 | 4098 | 32 |00:00:30.26 | 4588 | | | |
|* 32 | CONNECT BY WITH FILTERING | | 1 | | 32 |00:00:30.26 | 4588 | 6144 | 6144 | 6144 (0)|
|* 33 | FILTER | | 1 | | 32 |00:00:15.28 | 2544 | | | |
| 34 | COUNT | | 1 | | 38 |00:00:15.28 | 2044 | | | |
|* 35 | HASH JOIN | | 1 | 4098 | 38 |00:00:15.28 | 2044 | 1034K| 1034K| |
| 36 | TABLE ACCESS FULL | USER$ | 1 | 335 | 335 |00:00:00.01 | 14 | | | |
|* 37 | HASH JOIN | | 1 | 4103 | 38 |00:00:15.28 | 2030 | 1033K| 870K| |
|* 38 | HASH JOIN | | 1 | 4103 | 38 |00:00:14.67 | 1154 | 819K| 819K| |
| 39 | TABLE ACCESS FULL | USER$ | 1 | 335 | 335 |00:00:00.01 | 14 | | | |
|* 40 | HASH JOIN | | 1 | 1376K| 3378K|00:00:03.80 | 1140 | 6425K| 2078K| 9700K (0)|
| 41 | TABLE ACCESS FULL | SYN$ | 1 | 94997 | 95067 |00:00:00.10 | 264 | | | |
|* 42 | TABLE ACCESS FULL | OBJ$ | 1 | 95290 | 95069 |00:00:00.19 | 876 | | | |
| 43 | TABLE ACCESS FULL | OBJ$ | 1 | 143K| 143K|00:00:00.14 | 876 | | | |
|* 44 | FILTER | | 37 | | 32 |00:00:00.01 | 500 | | | |
| 45 | NESTED LOOPS | | 37 | 1 | 61 |00:00:00.01 | 500 | | | |
| 46 | NESTED LOOPS | | 37 | 1 | 169 |00:00:00.01 | 295 | | | |
| 47 | NESTED LOOPS | | 37 | 1 | 36 |00:00:00.01 | 182 | | | |
|* 48 | TABLE ACCESS BY INDEX ROWID| SYN$ | 37 | 1 | 36 |00:00:00.01 | 110 | | | |
|* 49 | INDEX UNIQUE SCAN | I_SYN1 | 37 | 1 | 36 |00:00:00.01 | 74 | | | |
| 50 | TABLE ACCESS BY INDEX ROWID| USER$ | 36 | 335 | 36 |00:00:00.01 | 72 | | | |
|* 51 | INDEX UNIQUE SCAN | I_USER1 | 36 | 1 | 36 |00:00:00.01 | 36 | | | |
| 52 | TABLE ACCESS BY INDEX ROWID | OBJ$ | 36 | 1 | 169 |00:00:00.01 | 113 | | | |
|* 53 | INDEX RANGE SCAN | I_OBJ2 | 36 | 1 | 169 |00:00:00.01 | 73 | | | |
|* 54 | INDEX RANGE SCAN | I_OBJAUTH1 | 169 | 1 | 61 |00:00:00.01 | 205 | | | |
|* 55 | FIXED TABLE FULL | X$KZSRO | 24 | 1 | 1 |00:00:00.01 | 0 | | | |
|* 56 | HASH JOIN | | 1 | | 0 |00:00:14.97 | 2044 | 1035K| 872K| |
| 57 | CONNECT BY PUMP | | 1 | | 32 |00:00:00.01 | 0 | | | |
| 58 | COUNT | | 1 | | 38 |00:00:14.97 | 2044 | | | |
|* 59 | HASH JOIN | | 1 | 4098 | 38 |00:00:14.97 | 2044 | 1034K| 1034K| |
| 60 | TABLE ACCESS FULL | USER$ | 1 | 335 | 335 |00:00:00.01 | 14 | | | |
|* 61 | HASH JOIN | | 1 | 4103 | 38 |00:00:14.97 | 2030 | 1033K| 870K| |
|* 62 | HASH JOIN | | 1 | 4103 | 38 |00:00:14.41 | 1154 | 819K| 819K| |
| 63 | TABLE ACCESS FULL | USER$ | 1 | 335 | 335 |00:00:00.01 | 14 | | | |
|* 64 | HASH JOIN | | 1 | 1376K| 3378K|00:00:03.77 | 1140 | 6425K| 2078K| 9700K (0)|
| 65 | TABLE ACCESS FULL | SYN$ | 1 | 94997 | 95067 |00:00:00.10 | 264 | | | |
|* 66 | TABLE ACCESS FULL | OBJ$ | 1 | 95290 | 95069 |00:00:00.10 | 876 | | | |
| 67 | TABLE ACCESS FULL | OBJ$ | 1 | 143K| 143K|00:00:00.14 | 876 | | | |
| 68 | TABLE ACCESS BY INDEX ROWID | SYN$ | 0 | 1 | 0 |00:00:00.01 | 0 | | | |
|* 69 | INDEX UNIQUE SCAN | I_SYN1 | 0 | 1 | 0 |00:00:00.01 | 0 | | | |
---------------------------------------------------------------------------------------------------------------------------------------------------



Тяжелый случай, тем более, что выбор средств для настройки запросов к представлениям словаря данных весьма узок.
Решением, достаточно эффективным, стало следующее: поскольку процесс обновления эксклюзивно использовал базу данных, у меня была возможность совершенно безопасно выполнить следующие команды:

alter system set sort_area_size=10000000 deferred;
alter system set workarea_size_policy=manual;

Моей целью было воздействовать на выделение ресурсов для частей плана: строки 35-43 и строки 59-67. Указанные части плана являются примерами так называемых "right-deep tree" [1], особенностью которых является то, что в отличие от "left-deep tree", где используется не более двух active work areas, для "правых деревьев" на протяжении практически всего исполнения количество work areas, которые выделяются и участвуют в "probe", равно количеству соединений.
Таким образом, я достаточно сильно ускорил процесс обновления. Для будущих обновлений, включу в скрипты переключение в manual режим параметра workarea_size_policy в начале установки и переключения обратно в конце установки.

Тестирование на девелоперской базе аналогичного запроса показывает следующие результаты:

devdb> sho parameter workarea

NAME TYPE VALUE
------------------------------------ ----------- ------------------------------
workarea_size_policy string AUTO

devdb> variable a1 varchar2(30)
devdb> exec :a1:='...'

PL/SQL procedure successfully completed.

Elapsed: 00:00:00.03
devdb> variable a2 varchar2(30)
devdb> exec :a2:='...'

PL/SQL procedure successfully completed.

Elapsed: 00:00:00.01

devdb> SELECT TABLE_NAME, NVL(TABLE_OWNER, ''), NVL(DB_LINK, '') FROM SYS.ALL_SYNONYMS WHERE SYNONYM_NAME = :a1 AND OWNER = :a2;


...
1 row selected.

Elapsed: 00:00:26.37

devdb> alter session set workarea_size_policy=manual;

System altered.

Elapsed: 00:00:00.26

devdb> alter session set sort_area_size=1000000;

Session altered.

Elapsed: 00:00:00.00
devdb> SELECT TABLE_NAME, ... FROM SYS.ALL_SYNONYMS WHERE SYNONYM_NAME = :a1 AND OWNER = :a2;

...
1 row selected.

Elapsed: 00:00:27.17


devdb> alter session set sort_area_size=5000000;

Session altered.

Elapsed: 00:00:00.00
devdb> SELECT TABLE_NAME, ... FROM SYS.ALL_SYNONYMS WHERE SYNONYM_NAME = :a1 AND OWNER = :a2;


...
1 row selected.

Elapsed: 00:00:03.54


И наверное, уже назрело время переходить на публичные синонимы.


Литература:
1. Christian Antognini "Troubleshooting Oracle Performance".

1 Январь 2009 г.

The use of statistically incorrect assumptions when using this feature can lead to incorrect or undesirable results

В описании sample_clause для select statement имеется такое предупреждение:


Caution:

The use of statistically incorrect assumptions when using this feature can lead to incorrect or undesirable results.

Чем это может "грозить"?
Всем известный dbms_stats широко использует sample_clause при вычислении статистических показателей. При использовании параметров сбора статистики по умолчанию возможны аномалии:


SQL> set serveroutput on
SQL> begin
2 dbms_output.put_line(DBMS_STATS.GET_PARAM('ESTIMATE_PERCENT'));
3 end;
4 /
DBMS_STATS.AUTO_SAMPLE_SIZE

PL/SQL procedure successfully completed.

SQL> exec DBMS_STATS.DELETE_TABLE_STATS('CS','WK_REQUEST_PARS')

PL/SQL procedure successfully completed.


Вот например, собранные в таких условиях некоторые показатели:

SQL> select COLUMN_NAME,NUM_DISTINCT,NUM_NULLS from ALL_TAB_COL_STATISTICS where
2 owner='CS' and table_name='WK_REQUEST_PARS' and COLUMN_NAME='WOP_NUMID';

COLUMN_NAME NUM_DISTINCT NUM_NULLS
------------------------------ ------------ ----------
WOP_NUMID 1633 0

Как выяснилось, такое значение для NUM_DISTINCT - крайне нереалистично. И соответственно, план одного из популярных запросов далек от совершенства:

------------------------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows | A-Rows | A-Time | Buffers | Reads |
------------------------------------------------------------------------------------------------------------------------------
|* 1 | TABLE ACCESS BY INDEX ROWID | WK_REQUEST_PARS | 1 | 1 | 0 |00:00:55.75 | 99643 | 11607 |
| 2 | NESTED LOOPS | | 1 | 1 | 63144 |00:00:30.33 | 92490 | 6769 |
| 3 | NESTED LOOPS | | 1 | 1 | 31572 |00:00:08.30 | 29242 | 2455 |
| 4 | MERGE JOIN CARTESIAN | | 1 | 1 | 6 |00:00:00.01 | 12 | 0 |
| 5 | NESTED LOOPS | | 1 | 1 | 1 |00:00:00.01 | 7 | 0 |
| 6 | TABLE ACCESS BY INDEX ROWID| OORG | 1 | 1 | 1 |00:00:00.01 | 2 | 0 |
|* 7 | INDEX UNIQUE SCAN | XPK_ORG_ID | 1 | 1 | 1 |00:00:00.01 | 1 | 0 |
|* 8 | TABLE ACCESS BY INDEX ROWID| DOCF_DV | 1 | 1 | 1 |00:00:00.01 | 5 | 0 |
|* 9 | INDEX RANGE SCAN | XI_DIC_DIDI | 1 | 6 | 6 |00:00:00.01 | 3 | 0 |
| 10 | BUFFER SORT | | 1 | 1 | 6 |00:00:00.01 | 5 | 0 |
|* 11 | TABLE ACCESS BY INDEX ROWID| DOCF_DV | 1 | 1 | 6 |00:00:00.01 | 5 | 0 |
|* 12 | INDEX RANGE SCAN | XI_DIC_DIDI | 1 | 6 | 6 |00:00:00.01 | 2 | 0 |
|* 13 | TABLE ACCESS BY INDEX ROWID | WK_REQUESTS | 6 | 29 | 31572 |00:00:08.25 | 29230 | 2455 |
|* 14 | INDEX RANGE SCAN | XIF1122_WK_REQUESTS | 6 | 3428 | 191K|00:00:01.02 | 388 | 62 |
|* 15 | INDEX RANGE SCAN | IDX_WOP_WOR | 31572 | 8 | 31571 |00:00:21.83 | 63248 | 4314 |
------------------------------------------------------------------------------------------------------------------------------

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

1 - filter(("WK_REQUEST_PARS"."WOP_NUMID"='6453768762' AND "WK_REQUEST_PARS"."WOP_ST"='R' AND
"WK_REQUEST_PARS"."WOP_IS_SPECIAL"='T'))

7 - access("ORG_ID"=768590)
8 - filter("DIC_VALUE"='R')
9 - access("DIC_DIDI"=12002)
11 - filter(("DIC_VALUE"='A' OR "DIC_VALUE"='C' OR "DIC_VALUE"='F' OR "DIC_VALUE"='H' OR "DIC_VALUE"='I' OR "DIC_VALUE"='K' OR
"DIC_VALUE"='P'))
12 - access("DIC_DIDI"=12001)
13 - filter("WK_REQUESTS"."WOR_REQ_TP"="DIC_VALUE")
14 - access("WK_REQUESTS"."WOR_ORG"=768590)
15 - access("WK_REQUEST_PARS"."WOP_WOR"="WK_REQUESTS"."WOR_ID")

Однако, если сделать так:

exec dbms_stats.gather_table_stats('CS','WK_REQUEST_PARS',cascade=>true,estimate_percent=>100)

то в результате:

SQL> select COLUMN_NAME,NUM_DISTINCT,NUM_NULLS from ALL_TAB_COL_STATISTICS where
2 owner='CS' and table_name='WK_REQUEST_PARS' and COLUMN_NAME='WOP_NUMID';

COLUMN_NAME NUM_DISTINCT NUM_NULLS
------------------------------ ------------ ----------
WOP_NUMID 628654 48

и план того же запроса:

----------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows | A-Rows | A-Time | Buffers |
----------------------------------------------------------------------------------------------------------------
| 1 | NESTED LOOPS | | 1 | 1 | 0 |00:00:00.01 | 14 |
| 2 | MERGE JOIN CARTESIAN | | 1 | 1 | 0 |00:00:00.01 | 14 |
| 3 | MERGE JOIN CARTESIAN | | 1 | 1 | 6 |00:00:00.01 | 10 |
| 4 | NESTED LOOPS | | 1 | 1 | 6 |00:00:00.01 | 7 |
| 5 | TABLE ACCESS BY INDEX ROWID| OORG | 1 | 1 | 1 |00:00:00.01 | 2 |
|* 6 | INDEX UNIQUE SCAN | XPK_ORG_ID | 1 | 1 | 1 |00:00:00.01 | 1 |
|* 7 | TABLE ACCESS BY INDEX ROWID| DOCF_DV | 1 | 1 | 6 |00:00:00.01 | 5 |
|* 8 | INDEX RANGE SCAN | XI_DIC_DIDI | 1 | 6 | 6 |00:00:00.01 | 2 |
| 9 | BUFFER SORT | | 6 | 1 | 6 |00:00:00.01 | 3 |
|* 10 | TABLE ACCESS BY INDEX ROWID| DOCF_DV | 1 | 1 | 1 |00:00:00.01 | 3 |
|* 11 | INDEX RANGE SCAN | XI_DIC_DIDI | 1 | 6 | 6 |00:00:00.01 | 2 |
| 12 | BUFFER SORT | | 6 | 1 | 0 |00:00:00.01 | 4 |
|* 13 | TABLE ACCESS BY INDEX ROWID | WK_REQUEST_PARS | 1 | 1 | 0 |00:00:00.01 | 4 |
|* 14 | INDEX RANGE SCAN | IDX_WRP_NUMID | 1 | 22 | 1 |00:00:00.01 | 3 |
|* 15 | TABLE ACCESS BY INDEX ROWID | WK_REQUESTS | 0 | 1 | 0 |00:00:00.01 | 0 |
|* 16 | INDEX UNIQUE SCAN | PK_WK_REQUESTS | 0 | 1 | 0 |00:00:00.01 | 0 |
----------------------------------------------------------------------------------------------------------------

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

6 - access("ORG_ID"=768590)
7 - filter(("DIC_VALUE"='A' OR "DIC_VALUE"='C' OR "DIC_VALUE"='F' OR "DIC_VALUE"='H' OR "DIC_VALUE"='I' OR "DIC_VALUE"='K' OR
"DIC_VALUE"='P'))
8 - access("DIC_DIDI"=12001)
10 - filter("DIC_VALUE"='R')
11 - access("DIC_DIDI"=12002)
13 - filter(("WK_REQUEST_PARS"."WOP_ST"='R' AND "WK_REQUEST_PARS"."WOP_IS_SPECIAL"='T'))
14 - access("WK_REQUEST_PARS"."WOP_NUMID"='6453768762')
15 - filter(("WK_REQUESTS"."WOR_ORG"=768590 AND "WK_REQUESTS"."WOR_REQ_TP"="DIC_VALUE"))
16 - access("WK_REQUEST_PARS"."WOP_WOR"="WK_REQUESTS"."WOR_ID")

Разница разительна!
Как сообщил мне один из разработчиков, на начальных стадиях заполнения таблицы WK_REQUEST_PARS существовала ошибка в прикладном коде, в связи с которой возникло множество дубликатов для значения поля WOP_NUMID. Видимо это оказало фатальное влияние на работу sample_clause.

28 Декабрь 2008 г.

Древовидные справочники в качестве таблиц-размерностей или анализ “что-если” применительно к “TUNING BY CARDINALITY FEEDBACK METHOD”

Недавно консультировал коллегу по настройке запроса. Суть решаемой запросом задачи состояла в следующем: таблица фактов (далее facts) связана с таблицей размерности (далее dic$territory), а та в свою очередь, являлась древовидным справочником административно-территориального устройства. Интересующий моего коллегу запрос должен был выдавать некоторые суммарные значения по таблице facts, отфильтрованной с помощью таблицы dic$territory. Из таблицы facts отбирались строки, ссылающиеся на некоторую часть дерева справочника dic$territory, корень необходимой для фильтрации части дерева указывался параметром :code.
Запрос имеел вид аналогичный приведенному ниже:


select sum(human_cnt) from facts
where territory_id in (select territory_id
from dic$territory
start with territory_code = :code
connect by prior territory_id = territory_parent);

Первый подход к анализу запроса (explain plan) показал - прогнозируемая кардинальность фильтрующего подзапроса (шаг 4) определяется крайне неточно. Следует отметить, что реальная кардинальность подзапроса зависит от значения параметра, указывающего на корневой узел начала перебора дерева, и может изменяться начиная от нескольких единиц для узлов дерева близких к листовым, до нескольких тысяч для узлов дерева близких к корню.

------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | 22 | 39 (3)| 00:00:01 |
| 1 | SORT AGGREGATE | | 1 | 22 | | |
| 2 | TABLE ACCESS BY INDEX ROWID | FACTS | 9 | 81 | 12 (0)| 00:00:01 |
| 3 | NESTED LOOPS | | 27 | 594 | 39 (3)| 00:00:01 |
| 4 | VIEW | VW_NSO_1 | 3 | 39 | 2 (0)| 00:00:01 |
| 5 | HASH UNIQUE | | 3 | 30 | | |
|* 6 | CONNECT BY WITH FILTERING | | | | | |
| 7 | TABLE ACCESS BY INDEX ROWID | DIC$TERRITORY | 1 | 26 | 2 (0)| 00:00:01 |
|* 8 | INDEX RANGE SCAN | IDX_TERR_CODE | 1 | | 1 (0)| 00:00:01 |
| 9 | NESTED LOOPS | | | | | |
| 10 | CONNECT BY PUMP | | | | | |
| 11 | TABLE ACCESS BY INDEX ROWID| DIC$TERRITORY | 3 | 30 | 2 (0)| 00:00:01 |
|* 12 | INDEX RANGE SCAN | IDX_TERR_PARENT | 3 | | 1 (0)| 00:00:01 |
|* 13 | INDEX RANGE SCAN | IDX_FACTS_TERR | 9 | | 2 (0)| 00:00:01 |
------------------------------------------------------------------------------------------------------

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

6 - access("TERRITORY_PARENT"=PRIOR "TERRITORY_ID")
8 - access("TERRITORY_CODE"=:CODE)
12 - access("TERRITORY_PARENT"=PRIOR "TERRITORY_ID")
13 - access("TERRITORY_ID"="$nso_col_1")

Интересно было бы понять, каким образом вычисляется кардинальность фильтрующего подзапроса. В файле трассировки 10053 имеется следующий фрагмент:

-----------------------------------------
BEGIN Single Table Cardinality Estimation
-----------------------------------------
Column (#2): TERRITORY_PARENT(NUMBER)
AvgLen: 5.00 NDV: 12110 Nulls: 23 Density: 8.2576e-005 Min: 0 Max: 42164
Table: DIC$TERRITORY Alias: DIC$TERRITORY
Card: Original: 42188 Rounded: 3 Computed: 3.48 Non Adjusted: 3.48
-----------------------------------------
END Single Table Cardinality Estimation
-----------------------------------------

на основе которого можно сделать вывод, что кардинальность подзапроса есть не что иное как кардинальность выборки из таблицы dic$territory, отфильтрованой предикатом territory_parent=:id.
Статистика времени выполнения этого запроса при значении параметра :code, указывающим на «близкий» к корню дерева узел, подтверждает, некорректность прогноза кардинальности подзапроса (шаг 4):

----------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows | A-Rows | A-Time | Buffers |
----------------------------------------------------------------------------------------------------------------
| 1 | SORT AGGREGATE | | 1 | 1 | 1 |00:00:00.55 | 28858 |
| 2 | TABLE ACCESS BY INDEX ROWID | FACTS | 1 | 9 | 21051 |00:00:00.43 | 28858 |
| 3 | NESTED LOOPS | | 1 | 27 | 21051 |00:00:00.32 | 7807 |
| 4 | VIEW | VW_NSO_1 | 1 | 3 | 2339 |00:00:00.15 | 3081 |
| 5 | HASH UNIQUE | | 1 | 3 | 2339 |00:00:00.14 | 3081 |
|* 6 | CONNECT BY WITH FILTERING | | 1 | | 2339 |00:00:00.13 | 3081 |
| 7 | TABLE ACCESS BY INDEX ROWID | DIC$TERRITORY | 1 | 1 | 1 |00:00:00.01 | 3 |
|* 8 | INDEX RANGE SCAN | IDX_TERR_CODE | 1 | 1 | 1 |00:00:00.01 | 2 |
| 9 | NESTED LOOPS | | 4 | | 2338 |00:00:00.11 | 3078 |
| 10 | CONNECT BY PUMP | | 4 | | 2339 |00:00:00.01 | 0 |
| 11 | TABLE ACCESS BY INDEX ROWID| DIC$TERRITORY | 2339 | 3 | 2338 |00:00:00.07 | 3078 |
|* 12 | INDEX RANGE SCAN | IDX_TERR_PARENT | 2339 | 3 | 2338 |00:00:00.03 | 2353 |
|* 13 | INDEX RANGE SCAN | IDX_FACTS_TERR | 2339 | 9 | 21051 |00:00:00.06 | 4726 |
----------------------------------------------------------------------------------------------------------------

Оценив на глазок, можно сказать, что способ соединения (шаг 3) не очень подходит для такой кардинальности, так же как и способ доступа к таблице facts (шаги 13, 2).
Учитывая тот факт, что кардинальность подзапроса оценивается оптимизатором настолько грубо, не остается ничего другого, как воспользоваться подсказкой cardinality со значением параметра равным значению колонки A-Rows для шага 4.

select /*+gather_plan_statistics cardinality(@qb1 2339)*/
sum(human_cnt) from facts
where territory_id in (select /*+QB_NAME(qb1)*/ territory_id
from dic$territory
start with territory_code = :code
connect by prior territory_id = territory_parent);

Статистика времени выполнения с уточненной кардинальностью (для того же параметра :code):

--------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows | A-Rows | A-Time | Buffers |
--------------------------------------------------------------------------------------------------------------
| 1 | SORT AGGREGATE | | 1 | 1 | 1 |00:00:03.42 | 4064 |
|* 2 | HASH JOIN RIGHT SEMI | | 1 | 21212 | 21051 |00:00:03.38 | 4064 |
| 3 | VIEW | VW_NSO_1 | 1 | 2339 | 2339 |00:00:00.14 | 3081 |
|* 4 | CONNECT BY WITH FILTERING | | 1 | | 2339 |00:00:00.13 | 3081 |
| 5 | TABLE ACCESS BY INDEX ROWID | DIC$TERRITORY | 1 | 1 | 1 |00:00:00.01 | 3 |
|* 6 | INDEX RANGE SCAN | IDX_TERR_CODE | 1 | 1 | 1 |00:00:00.01 | 2 |
| 7 | NESTED LOOPS | | 4 | | 2338 |00:00:00.11 | 3078 |
| 8 | CONNECT BY PUMP | | 4 | | 2339 |00:00:00.01 | 0 |
| 9 | TABLE ACCESS BY INDEX ROWID| DIC$TERRITORY | 2339 | 3 | 2338 |00:00:00.07 | 3078 |
|* 10 | INDEX RANGE SCAN | IDX_TERR_PARENT | 2339 | 3 | 2338 |00:00:00.03 | 2353 |
| 11 | TABLE ACCESS FULL | FACTS | 1 | 381K| 379K|00:00:00.76 | 983 |
--------------------------------------------------------------------------------------------------------------

В результате LIO уменьшился в 7 раз. Для настройки реального запроса такой метод корректирования кардинальности не претендует на универсальность, однако позволяет легко воздействовать на форму плана и оценивать его эффективность.
В моем случае знание формы более эффективного плана позволило найти решение реальной проблемы, а именно, была создана дополнительная таблица, в которой хранилась «развертка» дерева, эта новая таблица была использована в фильтрующем подзапросе вместо первоначальной древовидной. Её использование позволило оптимизатору получать корректные значения прогнозов кардинальности для большинства используемых значений параметра :code.
Кроме того, на основе проведенной работы выкристализовалась идея использовать подсказку cardinality для осуществления «что-если» анализа в рамках метода «...by cardinality feedback...». Алгоритм может быть примерно следующим:
1) выявить шаг плана, с ошибочным прогнозом кардинальности, используя для этого статистику времени исполнения;
2) подсказкой cardinality скорректировать кардинальность;
3) перезапустить запрос, если еще остаются шаги плана с некорректным прогнозом кардинальности, перейти к шагу 1), иначе перейти к следующему шагу;
4) оценить эффективность плана, при положительном ответе — найти способо помочь оптимизатору находить такой же план, но без использования подсказки(ок) cardinality.
Фактически, такая последовательность действий дает возможность понять — какой план можно получить в ситуации, когда оптимизатор имеет точную информацию о кардинальности, станет ли такой план достаточно эффективным. Ведь в результате анализа может также выяснится, что сама задача, которую решает настраиваемый запрос, требует переформулирования. Кстати, окончательным решением моего коллеги по настройке запроса стало именно переформулирование задачи.

16 Ноябрь 2008 г.

Работаем с BLOB

Недавно принимал участие в решении проблемы низкой производительности PL\SQL приложения.
Анализ файла трассировки 10046 навел на мысль о том, что в основном код работает с BLOB-данными. Разработчики подтвердили это предположение. Соответствующий фрагмент отчета tkprof приведен ниже:


declare
a blob;
begin
a:=PrintActiveContragent(7720);
end;

call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 1 0.03 10.50 1521 4766 2600 1
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2 0.03 10.50 1521 4766 2600 1

Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 5

Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
direct path read 1521 0.05 10.38
SQL*Net message to client 1 0.00 0.00
SQL*Net message from client 1 5.86 5.86
********************************************************************************

Остальные рекурсивные вызовы не приводятся ввиду исчезающе малой ресурсоемкости.
Из приведенного видно, что все время потрачено на direct path read, изучение исходного файла трасировки показало, что это были чтения BLOB-поля, причем со слов разработчиков - читалось значение BLOB только из одной строки таблицы. Кроме того, разработчики сообщили, что размер BLOB в той строке примерно 200К.
Очевидно, что происходят множественные чтения BLOB, которые фактически, осущесвтляются непосредственно с диска. Проверив некоторые свойства BLOB этой таблицы, выяснилось среди прочего, что CACHE=NO.
Что ж, напрашивается рекомендация - воспользоваться возможностью кеширования BLOB, используя стейтмент подобный этому: alter table sometable modify lob (blob_field) (cache reads). После такого изменения скорость работы проблемного приложения улучшилась на 3 порядка, в общем можно было бы останоиться, но у некоторых наверняка возникнут сомнения относительно такого включения кеширования, ведь оно фактически может повлиять и на другие приложения, вытесняя из буферного кеша их данные.

Поскольку я достаточно редко имею дело с BLOB-ами, решил их немного поизучать, заодно попытаться сформулировать возможные альтернативные решения вышеприведенной проблемы.

Тестовые данные. Работаю с Oracle 10.2.0.1 (XE), размер блока 8192 байта.
Таблица:
create table t_blob (id number,blob_data blob);

Проверю некоторые ее свойства

SQL> select table_name,column_name,chunk,cache from user_lobs;

TABLE_NAME COLUMN_NAME CHUNK CACHE
------------------------------ -------------------- ---------- ----------
T_BLOB BLOB_DATA 8192 NO

Создаю одну строку со значением в поле BLOB длиной 10000 байт.

SQL> declare
2 l_data blob;
3 l_str raw(1000);
4 begin
5 insert into t_blob values (1,empty_blob());
6 select blob_data into l_data from t_blob where id=1;
7 dbms_lob.open(l_data,dbms_lob.lob_readwrite);
8 for i in 1..10 loop
9 l_str:=utl_raw.CAST_TO_RAW(rpad('z',1000-i,'z')||rpad('x',i,'x'));
10 dbms_lob.writeappend(l_data,1000,l_str);
11 end loop;
12 dbms_lob.close(l_data);
13 commit;
14 end;
15 /

PL/SQL procedure successfully completed.

SQL> select id,dbms_lob.getlength(blob_data) from t_blob;

ID DBMS_LOB.GETLENGTH(BLOB_DATA)
---------- -----------------------------
1 10000

Создаю процедуру, которая читает BLOB поле фрагментами по 1000 байт, в некотором смысле, эмуляция работы кода, который изучался в начале статьи. После каждого чтения проверяется значение статистики с номером 120 для текущей сессии

SQL> select name from v$statname where statistic#=120;

NAME
------------------------------------------------------
physical reads direct (lob)

Процедура:

SQL> create or replace procedure proc2
2 is
3 function GetStat(st# number) return number
4 is
5 l_res number;
6 begin
7 select value into l_res from v$mystat x where x.statistic#=st#;
8 return l_res;
9 end;
10 procedure a1 (p1 in out blob)
11 as
12 l_cnt1 number;
13 l_cnt2 number;
14 ll raw(1000);
15 am binary_integer := 1000;
16 begin
17 dbms_output.put_line('Size: '||dbms_lob.getlength(p1));
18 for i in 1..trunc(dbms_lob.getlength(p1)/1000) loop
19 l_cnt1:=getstat(120);
20 dbms_lob.read(p1,am,1+(i-1)*am,ll);
21 l_cnt2:=getstat(120);
22 dbms_output.put_line('I/O#'||i||' reads: '||(l_cnt2-l_cnt1));
23 end loop;
24 end;
25 begin
26 for i in (select blob_data from t_blob where id=1 order by id) loop
27 a1(i.blob_data);
28 end loop;
29 end;
30 /

Procedure created.

Сравненние работы с полем BLOB, не кешированными (изначально) и кешированным:

SQL> alter session set events '10046 trace name context forever, level 8';

Session altered.

SQL> begin proc2; end;
2 /
Size: 10000
I/O#1 reads: 1
I/O#2 reads: 1
I/O#3 reads: 1
I/O#4 reads: 1
I/O#5 reads: 1
I/O#6 reads: 1
I/O#7 reads: 1
I/O#8 reads: 1
I/O#9 reads: 2
I/O#10 reads: 1

PL/SQL procedure successfully completed.

SQL> alter table t_blob modify lob (blob_data) (cache reads);

Table altered.

SQL> begin PROC2; end;
2 /
Size: 10000
I/O#1 reads: 0
I/O#2 reads: 0
I/O#3 reads: 0
I/O#4 reads: 0
I/O#5 reads: 0
I/O#6 reads: 0
I/O#7 reads: 0
I/O#8 reads: 0
I/O#9 reads: 0
I/O#10 reads: 0

PL/SQL procedure successfully completed.

Исходя из статистик сессии, следуюет, что каждое обращение к некешированному BLOB приводит к запросу на дисковый ввод-вывод. Это же подтверждают данные трассировки сессии. Видно, что значение BLOB хранится в двух блоках, чтение 9-го фрагмента (длиной 1000 байт) фактически затрагивает оба блока.

WAIT #3: nam='direct path read' ela= 23758 file number=1 first dba=55426 block cnt=1 obj#=16099 tim=107520891323
WAIT #3: nam='direct path read' ela= 271 file number=1 first dba=55426 block cnt=1 obj#=16099 tim=107520895284
WAIT #3: nam='direct path read' ela= 249 file number=1 first dba=55426 block cnt=1 obj#=16099 tim=107520897971
WAIT #3: nam='direct path read' ela= 264 file number=1 first dba=55426 block cnt=1 obj#=16099 tim=107520900695
WAIT #3: nam='direct path read' ela= 262 file number=1 first dba=55426 block cnt=1 obj#=16099 tim=107520903592
WAIT #3: nam='direct path read' ela= 235 file number=1 first dba=55426 block cnt=1 obj#=16099 tim=107520906394
WAIT #3: nam='direct path read' ela= 222 file number=1 first dba=55426 block cnt=1 obj#=16099 tim=107520909032
WAIT #3: nam='direct path read' ela= 235 file number=1 first dba=55426 block cnt=1 obj#=16099 tim=107520911710
WAIT #3: nam='direct path read' ela= 205 file number=1 first dba=55426 block cnt=1 obj#=16099 tim=107520914372
WAIT #3: nam='direct path read' ela= 14 file number=1 first dba=55428 block cnt=1 obj#=16099 tim=107520914681
WAIT #3: nam='direct path read' ela= 239 file number=1 first dba=55428 block cnt=1 obj#=16099 tim=107520917641

Некешированный читаестя через "direct path read", кешированный соответственно через "db file sequential read".
Профиль для некешированного BLOB:

begin proc2; end;


call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 1 0.01 0.04 11 11 0 1
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2 0.01 0.04 11 11 0 1

Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 52

Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
direct path read 11 0.02 0.02
SQL*Net message to client 1 0.00 0.00
SQL*Net message from client 1 0.00 0.00
********************************************************************************


Профиль для кешированного BLOB

begin PROC2; end;


call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 1 0.01 0.06 2 11 0 1
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2 0.01 0.06 2 11 0 1

Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 52

Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
db file sequential read 2 0.03 0.05
SQL*Net message to client 1 0.00 0.00
SQL*Net message from client 1 0.00 0.00
********************************************************************************

Первый итог: любое чтение поля BLOB - приводит к LIO, если поле BLOB не кешируется, то еще и к физическому вводу-выводу. Следовательно, при кодировании алгоритмов, читающих BLOB - поля, более выиграшным будет подход, минимизирующий количество чтений, что есть закономерным. Фактически необходимо преследовать те же цели, что и при оптимизации SQL.
Что же делать если по каким-либо причинам изменение alter table ... modify lob (...) (cache reads) является неприемлемым?
Можно попробовать использовать временный BLOB, причем, кешированный. Сравнивать его, естественно, есть смысл с кешированным BLOB-полем таблицы. В качестве измерительного инструмента - runstats.

SQL> declare
2 l_blob blob;
3 l_blob1 blob;
4 procedure a1 (p1 in out blob)
5 as
6 ll raw(1000);
7 am binary_integer := 1000;
8 begin
9 for i in 1..trunc(dbms_lob.getlength(p1)/1000) loop
10 dbms_lob.read(p1,am,1+(i-1)*am,ll);
11 end loop;
12 end;
13 begin
14 dbms_lob.createtemporary(l_blob1,true);
15 select blob_data into l_blob from t_blob where id=1;
16 DBMS_LOB.COPY (l_blob1,l_blob,dbms_lob.getlength(l_blob));
17 runStats_pkg.rs_start;
18 for j in 1..1000 loop a1(l_blob); end loop;
19 runStats_pkg.rs_middle;
20 for j in 1..1000 loop a1(l_blob1); end loop; --Temporary BLOB
21 runStats_pkg.rs_stop;
22 dbms_lob.freetemporary(l_blob1);
23 end;
24 /
Run1 ran in 31 hsecs
Run2 ran in 10 hsecs
run 1 ran in 310% of the time

Name Run1 Run2 Diff
STAT...active txn count during 1 0 -1
STAT...consistent gets - exami 1 0 -1
LATCH.library cache lock alloc 0 1 1
STAT...redo entries 8 9 1
STAT...cleanout - number of kt 1 0 -1
LATCH.redo allocation 10 9 -1
STAT...calls to kcmgcs 4 5 1
LATCH.library cache lock 6 8 2
LATCH.library cache pin 6 8 2
LATCH.resmgr:resource group CP 4 2 -2
LATCH.redo writing 2 0 -2
LATCH.cache buffers lru chain 8 5 -3
LATCH.object queue header oper 8 5 -3
STAT...recursive cpu usage 5 2 -3
LATCH.messages 4 0 -4
STAT...enqueue releases 5 1 -4
STAT...db block changes 45 40 -5
STAT...consistent changes 36 31 -5
STAT...enqueue requests 6 1 -5
STAT...parse time elapsed 8 1 -7
LATCH.channel operations paren 8 0 -8
LATCH.enqueue hash chains 10 2 -8
LATCH.enqueues 10 2 -8
STAT...db block gets from cach 38 27 -11
STAT...db block gets 38 27 -11
STAT...session logical reads 11,044 11,033 -11
STAT...undo change vector size 2,008 2,024 16
LATCH.checkpoint queue latch 16 0 -16
STAT...redo size 2,688 2,672 -16
STAT...CPU used by this sessio 33 11 -22
STAT...workarea memory allocat 33 11 -22
STAT...Elapsed Time 50 21 -29
LATCH.cache buffers chains 22,186 22,136 -50
LATCH.SQL memory manager worka 73 6 -67
LATCH.simulator hash latch 4 9,002 8,998
LATCH.simulator lru latch 1 9,002 9,001
STAT...calls to get snapshot s 33,002 10,001 -23,001
STAT...session uga memory 65,560 15,072 -50,488
STAT...session uga memory max 261,964 65,560 -196,404
STAT...session pga memory max 262,144 65,536 -196,608

Run1 latches total versus runs -- difference and pct
Run1 Run2 Diff Pct
22,380 40,212 17,832 55.66%

Как говорится, 3:1 в пользу временного! Хотя есть странности: например некоторые типы защелок "simulator hash latch" и "simulator lru latch" достаточно активно себя проявили у "победителя". Кроме того, использование памяти сильно отличается. Можно предположить, что для доступа к данным временного BLOB используется другой "code path", признаками которого, возможно, являются защелки типа "simulator...".
Подытоживая, можно сказать следующее: использование временного кешированного BLOB решает с одной стороны проблему вымывания буферного кеша, а с другой стороны является еще и менее ресурсоемким способом обработки.

28 Октябрь 2008 г.

Неудачные значения при bind peeking.

Проводя ежедневный осмотр моей боевой БД, обнаружил долгоиграющий запрос. На 3 запуска более 80000 секунд времени исполняния (по данным v$sql). Естественно, не дожидаясь отклика "благодарных" пользователей начал исследовать это явление.

Промышленная база версии 10.2.0.4.
Для иллюстрации буду использовать вот такие тестовые данные:


create table t1 as select * from all_objects;
create table t2 as select * from all_objects;
create index t1_i1 on t1(owner,object_type);
create index t2_i1 on t2(owner,object_type);
exec dbms_stats.gather_table_stats(null,'t1',cascade=>true,method_opt=>'for all indexed columns size 254')
exec dbms_stats.gather_table_stats(null,'t2',cascade=>true,method_opt=>'for all indexed columns size 254')

переменные:

variable p_owner varchar2(30)
variable p_type varchar2(20)

запрос:

select /*+gather_plan_statistics*/ count(1)
from t1,t2 where t1.owner=t2.owner and t1.object_type=t2.object_type
and t1.owner=:p_owner and t1.object_type=:p_type;

А теперь, собственно, ход исследования. Предполагается, что запрос уже кем-то где-то в приложении запущен, и моя задача найти и проанализировать информацию о нём.
Сначала получаю план из разделяемого пула:

SQL> select * from table(dbms_xplan.display_cursor('gmf7sa93m8tk4',null,'LAST ALLSTATS'));

PLAN_TABLE_OUTPUT
-----------------------------------------------------------------------------
SQL_ID gmf7sa93m8tk4, child number 0
-------------------------------------
select /*+gather_plan_statistics*/ count(1) from t1,t2 where t1.owner=t2.owner and
t1.object_type=t2.object_type and t1.owner=:p_owner and t1.object_type=:p_type

Plan hash value: 1472244417

--------------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows | A-Rows | A-Time | Buffers | OMem | 1Mem | Used-Mem |
--------------------------------------------------------------------------------------------------------------------
| 1 | SORT AGGREGATE | | 1 | 1 | 1 |00:00:04.28 | 8 | | | |
| 2 | MERGE JOIN CARTESIAN| | 1 | 1 | 516K|00:00:03.10 | 8 | | | |
|* 3 | INDEX RANGE SCAN | T2_I1 | 1 | 1 | 719 |00:00:00.01 | 4 | | | |
| 4 | BUFFER SORT | | 719 | 1 | 516K|00:00:01.04 | 4 | 73728 | 73728 | |
|* 5 | INDEX RANGE SCAN | T1_I1 | 1 | 1 | 719 |00:00:00.01 | 4 | | | |
--------------------------------------------------------------------------------------------------------------------

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

3 - access("T2"."OWNER"=:P_OWNER AND "T2"."OBJECT_TYPE"=:P_TYPE)
5 - access("T1"."OWNER"=:P_OWNER AND "T1"."OBJECT_TYPE"=:P_TYPE)

По статистике выполнения видно, что как минимум, тип соединения не подходит для данных, которые обрабатываются (результирующая кардинальность на шаге 2 плана крайне отличается от прогнозируемой).

Первая гипотеза - неужели статистика устарела? Хотя автоматический сбор статистики не отключал...

Пробую получить план "непосредтсвенно от CBO":

SQL> explain plan for
2 select /*+gather_plan_statistics*/ count(1)
3 from t1,t2 where t1.owner=t2.owner and t1.object_type=t2.object_type
4 and t1.owner=:p_owner and t1.object_type=:p_type;

Explained.

SQL> select * from table(dbms_xplan.display);

PLAN_TABLE_OUTPUT
----------------------------------------------------------------------------
Plan hash value: 1849716936

----------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
----------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | 30 | 3 (34)| 00:00:01 |
| 1 | SORT AGGREGATE | | 1 | 30 | | |
|* 2 | HASH JOIN | | 11125 | 325K| 3 (34)| 00:00:01 |
|* 3 | INDEX RANGE SCAN| T2_I1 | 103 | 1545 | 1 (0)| 00:00:01 |
|* 4 | INDEX RANGE SCAN| T1_I1 | 108 | 1620 | 1 (0)| 00:00:01 |
----------------------------------------------------------------------------

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

2 - access("T1"."OWNER"="T2"."OWNER" AND
"T1"."OBJECT_TYPE"="T2"."OBJECT_TYPE")
3 - access("T2"."OWNER"=:P_OWNER AND "T2"."OBJECT_TYPE"=:P_TYPE)
4 - access("T1"."OWNER"=:P_OWNER AND "T1"."OBJECT_TYPE"=:P_TYPE)

Результат несколько озадачивает - совершенно нормальный план (способ доступа и тип соединения). Почему же в разделяемом пуле нечто совершенно другое? В общем, отбрасываю версию об устаревшей статистике.

После недолгих раздумий начинаю вспоминать недавно прочитанное у Джонатана Льюса (см. ссылку внизу). Возникает вторая гипотеза - влияние bind peeking.

Проверяю текущие значения переменных привязки:

SQL> select last_captured,name,datatype_string,value_string from v$sql_bind_capture
2 where sql_id='gmf7sa93m8tk4';

LAST_CAPTURED NAME DATATYPE_STRING
------------------- ------------------------------ ---------------
VALUE_STRING
---------------------------------------------------------------------
28/10/2008 21:27:37 :P_OWNER VARCHAR2(32)
SYS

28/10/2008 21:27:37 :P_TYPE VARCHAR2(32)
TABLE

Строю план, заменяя переменные литералами с соответствующими текущим значениями:

SQL> select * from table(dbms_xplan.display);

PLAN_TABLE_OUTPUT
----------------------------------------------------------------------------
Plan hash value: 1962103783

----------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
----------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | 30 | 11 (46)| 00:00:01 |
| 1 | SORT AGGREGATE | | 1 | 30 | | |
|* 2 | HASH JOIN | | 678K| 19M| 11 (46)| 00:00:01 |
|* 3 | INDEX RANGE SCAN| T1_I1 | 812 | 12180 | 3 (0)| 00:00:01 |
|* 4 | INDEX RANGE SCAN| T2_I1 | 835 | 12525 | 3 (0)| 00:00:01 |
----------------------------------------------------------------------------

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

2 - access("T1"."OWNER"="T2"."OWNER" AND
"T1"."OBJECT_TYPE"="T2"."OBJECT_TYPE")
3 - access("T1"."OWNER"='SYS' AND "T1"."OBJECT_TYPE"='TABLE')
4 - access("T2"."OWNER"='SYS' AND "T2"."OBJECT_TYPE"='TABLE')

Очевидно, что запрос из разделяемого пула разбирался при других значениях переменных. Проверяю что было при разборе (в следующем отчете среди прочего выводятся значения переменных привязки, которые использовались при разборе запроса):

SQL> select * from table(dbms_xplan.display_cursor('gmf7sa93m8tk4',null,'typical +peeked_binds'));

PLAN_TABLE_OUTPUT
-----------------------------------------------------------------------------
SQL_ID gmf7sa93m8tk4, child number 0
-------------------------------------
select /*+gather_plan_statistics*/ count(1) from t1,t2 where
t1.owner=t2.owner and t1.object_type=t2.object_type and
t1.owner=:p_owner and t1.object_type=:p_type

Plan hash value: 1472244417

-------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
-------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | | | 2 (100)| |
| 1 | SORT AGGREGATE | | 1 | 30 | | |
| 2 | MERGE JOIN CARTESIAN| | 1 | 30 | 2 (0)| 00:00:01 |
|* 3 | INDEX RANGE SCAN | T2_I1 | 1 | 15 | 1 (0)| 00:00:01 |
| 4 | BUFFER SORT | | 1 | 15 | 1 (0)| 00:00:01 |
|* 5 | INDEX RANGE SCAN | T1_I1 | 1 | 15 | 1 (0)| 00:00:01 |
-------------------------------------------------------------------------------

Peeked Binds (identified by position):
--------------------------------------

1 - :P_OWNER (VARCHAR2(30), CSID=171): 'SCOTT'
2 - :P_TYPE (VARCHAR2(30), CSID=171): 'TABLE'

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

3 - access("T2"."OWNER"=:P_OWNER AND "T2"."OBJECT_TYPE"=:P_TYPE)
5 - access("T1"."OWNER"=:P_OWNER AND "T1"."OBJECT_TYPE"=:P_TYPE)


Наконец, перепроверяю вторую гипотезу:

SQL> explain plan for
2 select /*+gather_plan_statistics*/ count(1)
3 from t1,t2 where t1.owner=t2.owner and t1.object_type=t2.object_type
4 and t1.owner='SCOTT' and t1.object_type='TABLE';

Explained.

SQL> select * from table(dbms_xplan.display);

PLAN_TABLE_OUTPUT
-------------------------------------------------------------------------------
Plan hash value: 1472244417

-------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
-------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | 30 | 2 (0)| 00:00:01 |
| 1 | SORT AGGREGATE | | 1 | 30 | | |
| 2 | MERGE JOIN CARTESIAN| | 1 | 30 | 2 (0)| 00:00:01 |
|* 3 | INDEX RANGE SCAN | T2_I1 | 1 | 15 | 1 (0)| 00:00:01 |
| 4 | BUFFER SORT | | 1 | 15 | 1 (0)| 00:00:01 |
|* 5 | INDEX RANGE SCAN | T1_I1 | 1 | 15 | 1 (0)| 00:00:01 |
-------------------------------------------------------------------------------

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

3 - access("T2"."OWNER"='SCOTT' AND "T2"."OBJECT_TYPE"='TABLE')
5 - access("T1"."OWNER"='SCOTT' AND "T1"."OBJECT_TYPE"='TABLE')

Так и есть, разбор происходил при не очень удачных значениях переменных привязки.
Возникает законный вопрос: как бороться с этим? Изящное решение проблемы находися в следующей версии - Oracle 11g. Я имею ввиду новшество "Intelligent Cursor Sharing".

Там аналогичная ситуация выглядела бы вот так:

SQL> begin
2 :p_owner:='SCOTT'; :p_type:='SEQUENCE';
3 end;
4 /

PL/SQL procedure successfully completed.

SQL> select /*+gather_plan_statistics*/ count(1)
2 from t1,t2 where t1.owner=t2.owner and t1.object_type=t2.object_type
3 and t1.owner=:p_owner and t1.object_type=:p_type;

COUNT(1)
----------
0

SQL> select * from table(dbms_xplan.display_cursor(null,null,'allstats last'));

PLAN_TABLE_OUTPUT
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
SQL_ID gmf7sa93m8tk4, child number 0
-------------------------------------
select /*+gather_plan_statistics*/ count(1) from t1,t2 where
t1.owner=t2.owner and t1.object_type=t2.object_type and
t1.owner=:p_owner and t1.object_type=:p_type

Plan hash value: 2988039147

--------------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows | A-Rows | A-Time | Buffers | OMem | 1Mem | Used-Mem |
--------------------------------------------------------------------------------------------------------------------
| 1 | SORT AGGREGATE | | 1 | 1 | 1 |00:00:00.01 | 2 | | | |
| 2 | MERGE JOIN CARTESIAN| | 1 | 1 | 0 |00:00:00.01 | 2 | | | |
|* 3 | INDEX RANGE SCAN | T1_I1 | 1 | 1 | 0 |00:00:00.01 | 2 | | | |
| 4 | BUFFER SORT | | 0 | 1 | 0 |00:00:00.01 | 0 | 73728 | 73728 | |
|* 5 | INDEX RANGE SCAN | T2_I1 | 0 | 1 | 0 |00:00:00.01 | 0 | | | |
--------------------------------------------------------------------------------------------------------------------

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

3 - access("T1"."OWNER"=:P_OWNER AND "T1"."OBJECT_TYPE"=:P_TYPE)
5 - access("T2"."OWNER"=:P_OWNER AND "T2"."OBJECT_TYPE"=:P_TYPE)

...

SQL> begin
2 :p_owner:='SYS'; :p_type:='TABLE';
3 end;
4 /

SQL> select /*+gather_plan_statistics*/ count(1)
2 from t1,t2 where t1.owner=t2.owner and t1.object_type=t2.object_type
3 and t1.owner=:p_owner and t1.object_type=:p_type;

COUNT(1)
----------
872356

SQL> select * from table(dbms_xplan.display_cursor(null,null,'allstats last +peeked_binds'));

PLAN_TABLE_OUTPUT
----------------------------------------------------------------------------------
SQL_ID gmf7sa93m8tk4, child number 1
-------------------------------------
select /*+gather_plan_statistics*/ count(1) from t1,t2 where
t1.owner=t2.owner and t1.object_type=t2.object_type and
t1.owner=:p_owner and t1.object_type=:p_type

Plan hash value: 1849716936

-----------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows | A-Rows | A-Time | Buffers | OMem | 1Mem | Used-Mem |
-----------------------------------------------------------------------------------------------------------------
| 1 | SORT AGGREGATE | | 1 | 1 | 1 |00:00:02.43 | 10 | | | |
|* 2 | HASH JOIN | | 1 | 1824K| 872K|00:00:00.88 | 10 | 909K| 909K| 361K (0)|
|* 3 | INDEX RANGE SCAN| T2_I1 | 1 | 1321 | 934 |00:00:00.01 | 5 | | | |
|* 4 | INDEX RANGE SCAN| T1_I1 | 1 | 1381 | 934 |00:00:00.01 | 5 | | | |
-----------------------------------------------------------------------------------------------------------------

Peeked Binds (identified by position):
--------------------------------------

1 - (VARCHAR2(30), CSID=171): 'SYS'
2 - (VARCHAR2(30), CSID=171): 'TABLE'

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

2 - access("T1"."OWNER"="T2"."OWNER" AND "T1"."OBJECT_TYPE"="T2"."OBJECT_TYPE")
3 - access("T2"."OWNER"=:P_OWNER AND "T2"."OBJECT_TYPE"=:P_TYPE)
4 - access("T1"."OWNER"=:P_OWNER AND "T1"."OBJECT_TYPE"=:P_TYPE)

После изменения значений переменных произошел повторный разбор, в итоге новый child cursor и новый, а главное - подходящий план.
А для используемой мною версии Oracle Database 10.2.0.4, простых решений вероятно не существует. Можно например вытеснять из разделяемого пула выбранный разобранный запрос (dbms_shared_pool.purge). Возможно для некоторых случаев подойдет принудительный (не автоматический) периодичесикий сбор статистики без гистограмм, с последующей фиксацией (dbms_stats.lock_table_stats).

Ссылки:
Jonathan Lewis "Bind Capture"
Troubleshooting Oracle Performance by Christian Antognini

25 Июнь 2008 г.

Предикат из чек-констрейнта

Еще одна, очевидно, ошибка, связанная со сгенеренными предикатами.


drop table ch1;
create table ch1 (f1 number(1) constraint ch1_ck_f1 check (f1 in ('1','2','3')));
insert into ch1 values (1);
insert into ch1 values (2);
insert into ch1 values (3);
insert into ch1 values (4);
commit;
exec dbms_stats.gather_table_stats(ownname=>null,tabname=>'ch1')
select * from ch1 where f1=1;
explain plan for
select * from ch1 where f1=1;
select * from table(dbms_xplan.display);


Как то так вышло у моего коллеги, что для поля с типом NUMBER был создан чек-констрейнт ...in ('1','2','3').
Оптимизатор сгенерил фактически лишний и не корректный предикат из чек-констрейнта.
В итоге результат таков:


SQL> select * from ch1 where f1=1;

no rows selected

SQL> explain plan for
2 select * from ch1 where f1=1;

Explained.

SQL> select * from table(dbms_xplan.display);

PLAN_TABLE_OUTPUT
--------------------------------------------------------------------------------
Plan hash value: 3341507894

---------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
---------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | 3 | 0 (0)| |
|* 1 | FILTER | | | | | |
|* 2 | TABLE ACCESS FULL| CH1 | 1 | 3 | 2 (0)| 00:00:01 |
---------------------------------------------------------------------------

Predicate Information (identified by operation id):

PLAN_TABLE_OUTPUT
---------------------------------------------------

1 - filter(NULL IS NOT NULL)
2 - filter("F1"=1)


а ежели еще вот так


alter table ch1 disable constraint ch1_ck_f1;
select * from ch1 where f1=1;
explain plan for
select * from ch1 where f1=1;
select * from table(dbms_xplan.display);


то


SQL> alter table ch1 disable constraint ch1_ck_f1;

Table altered.

SQL> select * from ch1 where f1=1;

F1
----------
1

SQL> delete from plan_table;

3 rows deleted.

SQL> explain plan for
2 select * from ch1 where f1=1;

Explained.

SQL> select * from table(dbms_xplan.display);

PLAN_TABLE_OUTPUT
--------------------------------------------------------------------------------
Plan hash value: 2138608289

--------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
--------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | 3 | 2 (0)| 00:00:01 |
|* 1 | TABLE ACCESS FULL| CH1 | 1 | 3 | 2 (0)| 00:00:01 |
--------------------------------------------------------------------------

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

1 - filter("F1"=1)



Проверял на следующих версиях: 9.2.0.4, 10.2.0.1, 10.2.0.4, 11.1.0.6 - проявлялось только на 10.2.0.1.

Tuning by Cardinality Feedback в действии

В свое время, статья Tuning by Cardinality Feedback произвеля на меня неизгладимое впечатление.
И вот теперь случилось применить ее в одном интересном случае. Вот такой план имел место быть на промышленной площадке.
Сразу же бросается в глаза серъезное расхождение между прогнозом оптимизатора и статистикой времени исполнения. Первая стадия анализа привела к фрагменту плана, в котором, как мне кажется, находится ключевая ошибка оптимизатора в оценке кардинальности:


-------------------------------------------------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows |E-Bytes|E-Temp | Cost (%CPU)| E-Time | A-Rows |
-------------------------------------------------------------------------------------------------------------------------------------------------------
...
|* 17 | HASH JOIN ANTI | | 1 | 1 | 54 | | 7 (15)| 00:00:01 | 18 |
| 18 | NESTED LOOPS | | 1 | 1 | 42 | | 2 (0)| 00:00:01 | 21 |
|* 19 | TABLE ACCESS BY USER ROWID | IKIS_USERS_ATTR | 1 | 1 | 25 | | 1 (0)| 00:00:01 | 1 |
|* 20 | INDEX FULL SCAN | PK_IKIS_ROLE | 1 | 1 | 17 | | 1 (0)| 00:00:01 | 21 |
| 21 | VIEW | VW_NSO_3 | 1 | 12 | 144 | | 4 (0)| 00:00:01 | 3 |
| 22 | NESTED LOOPS | | 1 | 12 | 600 | | 4 (0)| 00:00:01 | 3 |
|* 23 | TABLE ACCESS FULL | IKIS_RESOURCE | 1 | 9 | 162 | | 3 (0)| 00:00:01 | 4 |
|* 24 | INDEX RANGE SCAN | PK_RSRC2ROLE | 4 | 1 | 32 | | 1 (0)| 00:00:01 | 3 |
...


все остальное лавинообразно преумножало ошибку, сделанную на 20 шаге плана.
Интересный предикат был сгенерен для этого 20 шага:


20 - filter(("IKIS_SUBSYS_UTIL"."GETINSTANCEPREF"()||"RS"."IRL_NAME"<>'PUBLIC' AND "IKIS_SUBSYS_UTIL"."GETINSTANCEPREF"()||"RS"."IRL_NAME"<>'_NEXT_USER'))


Собственно, данный предикат сгенерен на основе where clause представления dba_roles, которое участвует в данном запросе.
Далее простой test case, имитирующий данную ситуацию:


drop table r1;
drop table r2;
create table r1 as select rownum id,x.* from all_objects x where rownum<=1000;

update r1 set object_name='SSDR' where mod(id,276)=0;
update r1 set object_name='GSDR' where mod(id,876)=0;

create table r2 as select * from r1 where mod(object_id,2)=0;

update r1 set object_name='XXX'||substr(object_name,1,25);
update r2 set object_name=substr(object_name,1,25);


commit;

exec dbms_stats.gather_table_stats(ownname=>null,tabname=>'r1')
exec dbms_stats.gather_table_stats(ownname=>null,tabname=>'r2')

create or replace view v1
as
select * from r1
where object_name<>'XXXSSDR' and object_name<>'XXXGSDR' and object_type='INDEX';

explain plan for
select count(1)
from v1,r2
where v1.object_name='XXX'||r2.object_name;


и ожидаемый, аналогичный полученному на пром-системе, результат с ошибкой оценки кардинальности для таблицы R2:


----------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
----------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | 40 | 9 (12)| 00:00:01 |
| 1 | SORT AGGREGATE | | 1 | 40 | | |
|* 2 | HASH JOIN | | 1 | 40 | 9 (12)| 00:00:01 |
|* 3 | TABLE ACCESS FULL| R2 | 1 | 15 | 3 (0)| 00:00:01 |
|* 4 | TABLE ACCESS FULL| R1 | 111 | 2775 | 5 (0)| 00:00:01 |
----------------------------------------------------------------------------

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

2 - access("OBJECT_NAME"='XXX'||"R2"."OBJECT_NAME")
3 - filter('XXX'||"R2"."OBJECT_NAME"<>'XXXSSDR' AND
'XXX'||"R2"."OBJECT_NAME"<>'XXXGSDR')
4 - filter("OBJECT_TYPE"='INDEX' AND "OBJECT_NAME"<>'XXXSSDR' AND
"OBJECT_NAME"<>'XXXGSDR')


Очевидно, что ситуация в следующем: оптимизатор генерит предикат и крайне неверно оценивает его селективность.
Собственно workaround:
1) каким-либо образом заставить оптимизатор не генерить предикат, для этого можно использовать хинт NO_MERGE или NO_QUERY_TRANSFORMATION. В таком случае план будет имеет вид:

-----------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
-----------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | 32 | 9 (12)| 00:00:01 |
| 1 | SORT AGGREGATE | | 1 | 32 | | |
|* 2 | HASH JOIN | | 57 | 1824 | 9 (12)| 00:00:01 |
| 3 | VIEW | V1 | 111 | 1887 | 5 (0)| 00:00:01 |
|* 4 | TABLE ACCESS FULL| R1 | 111 | 2775 | 5 (0)| 00:00:01 |
| 5 | TABLE ACCESS FULL | R2 | 501 | 7515 | 3 (0)| 00:00:01 |
-----------------------------------------------------------------------------

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

2 - access("V1"."OBJECT_NAME"='XXX'||"R2"."OBJECT_NAME")
4 - filter("OBJECT_TYPE"='INDEX' AND "OBJECT_NAME"<>'XXXSSDR' AND
"OBJECT_NAME"<>'XXXGSDR')


План исходного запроса с хинтом NO_QUERY_TRANSFORMATION тяжеловат, но по времени исполнения все таки существенно лучше.

2) пока искал другие пути обнаружил, что это явление - ошибка в коде оптимизатора.
Проверял следующие версии 9.2.0.4 SE Linux, 10.2.0.1 SE/EE Linux,
10.2.0.1 SE Windows, 11.1.0.6 EE Windows.
Этот эффект проявился исключиетльно на 10.2.0.1 SE Windows (такая же версия была и в продукционной системе, где собственно проблема и была обнаружена).