В Oracle 11.2 появилась возможность получать трейс CBO без необходимости заново выполнять запрос с установленным 10053 event при условии наличия соответствующего курсора в shared pool – факт извесный и добротно описанный в блоге Greg Rahn. Creating Optimizer Trace Files, где указывается, что при вызове процедуры DBMS_SQLDIAG.DUMP_TRACE Oracle выполняет новый разбор нового курсора с добавленным к оригинальному запросу комментарием типа /* SQL Analyze(12,0) */ и, следовательно, с новым SQL_ID:
При этом совершенно непонятна роль параметра CHILD NUMBER:
-- dump_trace - Dump Optimizer Trace -- -- DESCRIPTION: -- This procedure dumps the optimizer or compiler trace for a give SQL -- statement identified by a SQL ID and an optional child number. -- -- PARAMETERS: -- p_sql_id (IN) - identifier of the statement in the cursor -- cache -- p_child_number (IN) - child number
И, соответственно, не вполне ясно можно ли с помощью процедуры сгенерировать трейсы с различными планами выполнения, которые могут присутствовать в shared pool для разных дочерних курсоров?
Например, при наличии 3-х курсоров с разными планами:
11.2.0.2.@SQL> select s.sql_text, <pre> 2 s.child_number, 3 s.plan_hash_value, 4 s.optimizer_cost, 5 round(s.elapsed_time / executions) as ELAPSED_BY_EXEC, 6 b.last_captured bind_last_captured, 7 b.value_string bind_value 8 from v$sql_bind_capture b, v$sql s 9 where b.sql_id = '7h32p3yhunfaj' 10 and b.sql_id = s.sql_id 11 and b.child_number = s.child_number 12 / SQL_TEXT CHILD_NUMBER PLAN_HASH_VALUE OPTIMIZER_COST ELAPSED_BY_EXEC BIND_LAST_CAPTURED BIND_VALUE --------------------------------------------------------------------- ------------ --------------- -------------- --------------- ------------------- ---------- SELECT COUNT (*) FROM SOME_COMPLICATED_VIEW WHERE HEADER_ID = :b1 0 3023217270 2171894 166895 17.02.2012 14:10:26 544745 SELECT COUNT (*) FROM SOME_COMPLICATED_VIEW WHERE HEADER_ID = :b1 1 921676850 3980336 141899 15.02.2012 09:10:27 426282 SELECT COUNT (*) FROM SOME_COMPLICATED_VIEW WHERE HEADER_ID = :b1 2 2690279671 76473687 556619257 17.02.2012 15:05:12 338893
*) в запросе используется не слишком корректное соединение с V$SQL_BIND_CAPTURE, в котором по счастливой случайности было ровно по одному значению связанной переменной на курсор
при попытке выполненить процедуру для наиболее проблемного курсора с child_number=2
11.2.0.2.@SQL> exec dbms_sqldiag.dump_trace('7h32p3yhunfaj',2,'Optimizer','My_CBO_Trace');
PL/SQL procedure successfully completed.
в трейсе отражается условно хороший план стоимостью 2121K курсора с child_number=0:
Starting SQL statement dump user_id=173 user_name=APPS module=SQL*Plus action= sql_id=59450vqutpqca plan_hash_value=-1271750026 problem_type=3 ----- Current SQL Statement for this session (sql_id=59450vqutpqca) ----- /* SQL Analyze(12,0) */ SELECT COUNT (*) FROM SOME_COMPLICATED_VIEW WHERE HEADER_ID = :b1 ----- PL/SQL Stack ----- ... ----- Explain Plan Dump ----- ----- Plan Table ----- ============ Plan Table ============ ----------------------------------------------------------------------------+-----------------------------------+ | Id | Operation | Name | Rows | Bytes | Cost | Time | ----------------------------------------------------------------------------+-----------------------------------+ | 0 | SELECT STATEMENT | | | | 2121K | |
- что естественно для свежего разбора курсора, однако тот же трейс показывает оригинальное значение связанной переменной, которое оптимизатор использовал для калькуляций, и недоступное через обзор V$SQL_BIND_CAPTURE:
******************************************* Peeked values of the binds in SQL statement ******************************************* ----- Bind Info (kkscoacd) ----- Bind#0 oacdty=02 mxl=22(04) mxlc=00 mal=00 scl=00 pre=00 oacflg=11 fl2=0000 frm=00 csi=00 siz=24 off=0 kxsbbbfp=7ff8961039c0 bln=22 avl=04 flg=05 value=352265
В то же время реально используемый план проблемного курсора (child_number=2) находится в памяти:
11.2.0.2.@SQL> SELECT * FROM TABLE(dbms_xplan.display_cursor( '7h32p3yhunfaj','2','basic advanced last')); PLAN_TABLE_OUTPUT ----------------------------------------------------------------------------------------------------------------------------------------------- SQL_ID 7h32p3yhunfaj, child number 2 ------------------------------------- SELECT COUNT (*) FROM SOME_COMPLICATED_VIEW WHERE HEADER_ID = :b1 Plan hash value: 2690279671 ----------------------------------------------------------------------------------------------------------------------------------------------- | Id | Operation | Name | E-Rows |E-Bytes| Cost (%CPU)| E-Time | OMem | 1Mem | Used-Mem | ----------------------------------------------------------------------------------------------------------------------------------------------- | 0 | SELECT STATEMENT | | | | 76M(100)| | | | | ... Peeked Binds (identified by position): -------------------------------------- 1 - (NUMBER): 426282 ... Note ----- - cardinality feedback used for this statement
, использует при построении технологию Cardinality Feedback, т.е. данные статистики выполнения запроса (rowsource statistics). При этом и проблемный план, и статистика выполнения доступны процедуре DBMS_SQLDIAG.DUMP_TRACE для построение трейса реального плана – всё находится в памяти, однако, увы
Единственное преимущество использования процедуры при попытке воспроизвести нестандартные планы выполнения может быть – в получении недоступных иным способом значений связанных переменных

Игорь, а кто еще добавляет такие комментарии типа “/* SQL Analyze(XXXX,XXX) */”? Дело в том, что обнаружили что такие запросы выполнялись во время сбора статистики во время теста, а по v$active_session_history не смогли понять кем они запускались. Было подозрение на включение dynamic sampling’a из-за сбора статистики, но с ним обычно такого комментария же нет.
комментарий от Sayan Malakshinov — 21.03.2012 @ 11:31 |
Привет, Саян
Посмотреть можно в истории AWR:
- комментарии – по характерным префиксам поля ACTION
Сравните с названиями групп scheduler’а, точнее с окончаниями:
комментарий от Igor Usoltsev — 22.03.2012 @ 18:32 |
Добрый вечер, Игорь, и спасибо :) а то я хоть и поглядел и в awr и в ash, но, т.к. времени было мало, акцентировался на статистиках и проглядел module и action. Первый-то параметр понял – это sid сессии, в которой анализ проводился, а в ash у этой сессии был userid=0. Теперь завтра разберусь
комментарий от xtender — 22.03.2012 @ 19:09 |