Oracle diagnostic events - это очень мощное средство, но, к сожалению, слабо документированное, поэтому я решил перечислить и свести воедино несколько неизвестных или малоизвестных способов его использования.
Единственная его документация - это очень краткая встроенная документация, доступная по команде oradebug doc в SQL*Plus, и она отсутствует в официальной документации. Вы можете встретить только отрывки из нее в разных блогах, что не очень удобно, поэтому я скомпилировал ее полностью: http://orasql.org/files/events/
Современный синтаксис и несколько простых примеров приведены в oradebug doc event. Я их здесь приводить не буду и начну сразу с примеров.
alter system set events
'kg_event[1476]
{occurence: start_after 1, end_after 3}
trace("stack is: %\n", shortstack())
errorstack(2)
';kg_event[errno] - это Kernel Generic event из библиотеки Generic, инструктирующее сработать на ошибку с номером
errno;{occurence: start_after X, end_after Y} - это один из фильтров , инструктирующий пропустить X срабатываний данного event и выполниться Y раз;
trace(format, str1, str2, ..., str15) - это функция из ACTIONS для вывода в трейс-файл своих сообщений;
shortstack() - это функция из ACTIONS , возвращающая call stack в кратком виде;
errorstack(level) - это функция из ACTIONS, выводящая в трейс-файл расширенную информацию (level: 0 - только errorstack, 1 - errorstack + call stack, 2 - как level=1 + processtate, 3 - как level=2 + context area). Еще более расширенную информацию можно получить с помощью PROCESSSTATE или SYSTEMSTATE. Если нужен только call stack можно воспользоваться CALLSTACK(level) - при level>1 запишет и аргументы.
alter system set events
'trace[SQL_Compiler.* | SQL_Execution.*]
[SQL: ...]
{process: ospid = ...}
{occurence:end_after 3}
controlc_signal()';trace[component] - это основной диагностический event, позволяющий указать компоненты, внутри которых надо срабатывать. В данном случае, я указал срабатывать внутри всех дочерних функций в SQL_Compiler и SQL_Execution. Например,
RDBMS.SQL_Compiler.SQL_Optimizer.SQL_Transform.*указало бы срабатывать только в функциях трансформации запросов.SQL[SQL: sqlid ] - это единственный SCOPE в библиотеке RDBMS, позволяющий отфильтровать все события, связанные с указанными запросами, включая события его рекурсивных запросов(например, если это sql_id PL/SQL вызова, то будут оттрассированы все запросы внутри него, или для запроса - все его внутренние запросы во время парсинга и оптимизации, внутренних запросов PL/SQL функций и тд.);
{process: ...} - это фильтр, позволяющий указать процессы для которых данный event будет включен.
controlc_signal - это ACTION, вызывающий ошибку "ORA-01013: user requested cancel of current operation", т.е. сессия запустившая этот запрос получит эту ошибку, как будто она сама прервала выполнение запроса.
Конкретно, данным примером я воспользовался, когда в ходе нагрузочного тестирования большого веб-приложения на hibernate, были обнаружены очень плохие фактически ненужные запросы и нужно было помочь разработчикам быстро найти откуда в их коде они выполняются.
alter system set events
'sql_trace {process: ospid = ...}
trace("sqlid(%): %\n", sqlid(), evfunc())
';sql_trace - это старый добрый event 10046, а целиком команда предписывает при каждом событии инструментированным этим event 10046, вывести функцию, его вызвавшую(evfunc) и sqlid запроса (ACTION sqlid).
Пример:
Как видите, при "_rowsource_statistics_sampfreq" =1 инструментировано намного больше событий: 26 против 12! Подробнее тут.
alter system set events
'wait_event["enq: TM - contention"]
{wait: minwait=1000}
errorstack(1)
trace("event=[%] sqlid=%, ela=% p1=% p2=% p3=%\n",
evargs(5), sqlid(), evargn(1), evargn(2), evargn(3), evargn(4))
';wait_event[name] - event, срабатывающий по имени событий ожидания (wait events), имена и их параметры вы можете посмотреть в v$event_name:
select wait_class,name,parameter1,parameter2,parameter3 ,display_name from v$event_name{wait: ... } - фильтр позволяющий отфильтровать как по долготе ожидания(в мс), так и по параметрам P1, P2, P3. Например, для указанного ожидания "TM-contention", P2 - это object #, и можно указать {wait: minwait=1000; p2=12345}, т.е. только ожидания табличной блокировки на таблице с object_id=12345 и длившиеся дольше 1 сек.
evargX() - это функции из ACTION, возвращающие аргументы event-check события, где 1-й аргумент это elapsed time(ms), 2-4 - p1-p3, 5-й - имя ожидания. Соответствующие функции имеет и kg_event: errargX.
Или еще пример, когда вам надо узнать какие сессионные переменные были изменены. Допустим, кто-то забыл указать nls-параметры в to_number, on conversion error не указан, и какие-то сессии периодически получают ORA-01722: invalid number:
-- допустим, изначально должны стоять следующие параметры:
SQL> alter session set nls_numeric_characters='.,';
Session altered.
-- и все работает нормально
SQL> select to_number('1,200.3','999g999d999') + 10 from dual;
TO_NUMBER('1,200.3','999G999D999')+10
-------------------------------------
1210.3
-- до тех пор, пока в какой-то момент они не меняются:
SQL> alter session set nls_numeric_characters=q'[.']';
'Session altered.
-- соответственно вылетает ошибка:
SQL> select to_number('1,200.3','999g999d999') + 10 from dual;
select to_number('1,200.3','999g999d999') + 10 from dual
*
ERROR at line 1:
ORA-01722: invalid numberХотя нет никакой вьюхи для получения параметров чужой сессии, не входящих в v$ses_optimizer_env, мы можем легко их получить с помощью MODIFIED_PARAMETERS():
alter system set events
'kg_event[1722]
{process: ospid=27556}
{occurence:end_after 1}
MODIFIED_PARAMETERS()';И благодаря тому, что сейчас есть удобные v$diag_alert_ext - для доступа к alert.log, v$diag_trace_file_contents - для доступа к трейс-файлам, мы можем все получить простым запросом:
select c.payload
from v$diag_trace_file_contents c
where 1=1
and c.session_id = ... -- sid сессии
and c.serial# = ... -- serial#
and c.section_name = 'Error Stack' -- параметры будут в секции Error Stack
-- and c.payload like '%nls_numeric%' -- можно отфильтровать именно
and c.timestamp>systimestamp-interval'15'minute;
-- результат:
DYNAMICALLY MODIFIED PARAMETERS:
nls_language = "AMERICAN"
nls_territory = "AMERICA"
nls_sort = "BINARY"
nls_date_language = "AMERICAN"
nls_date_format = "yyyy-mm-dd hh24:mi:ss"
nls_currency = "$"
nls_numeric_characters = ".'"
nls_iso_currency = "AMERICA"
nls_calendar = "GREGORIAN"
nls_time_format = "hh24:mi:ssxff"
nls_timestamp_format = "yyyy-mm-dd hh24:mi:ssxff"
nls_time_tz_format = "hh24:mi:ssxff TZR"
nls_timestamp_tz_format = "yyyy-mm-dd hh24:mi:ssxff TZR"
nls_dual_currency = "$"
nls_comp = "BINARY"
local_listener = ""Update: В телеграм канале RuOUG спросили:
В качестве примера, у нас используется код расширения статистики оптимизатора, периодически падающий с ошибкой ORA-06550 PL/SQL compile error, т.е. этот код вызывает сам оптимизатор Oracle.
Возможно ли в Oracle diagnostic events одновременно задать kg_event и sql_id, чтобы в alert.log появились ошибки ORA-06550 и имена соответствующих trace файлов, например так:
alter system set events 'kg_event[6550]
{occurence: start_after 1, end_after 3}
[sql: 7ujay4u33g337]
errorstack(3)
';
И я вспомнил, что хотел описать и еще один крайне полезный ACTION - incident(). Пример:
alter system set events
'kg_event[6550]
[sql: 5cmnpq8t0g7pd]
{occurence: start_after 1, end_after 3}
errorstack(3)
incident(plserrors)
';kg_event[6550] - трассировать ошибки "ORA-06550: line %, column %" и incident(plserrors) - создать инцидент-файл (при необходимости его можно легко упаковать через adrci и отправить для разбора консультантам или в Oracle Support)
PS. Дополнительные детали вы можете узнать в статьях Tanel Poder:
1. The full power of Oracle’s diagnostic events, part 1: Syntax for KSD debug event handling
2. The full power of Oracle’s diagnostic events, part 2: ORADEBUG DOC and 11g improvements
3. What Caused This Wait Event: Using Oracle's wait_event[] tracing
4. http://tech.e2sn.com/oracle/troubleshooting/oradebug-doc
О внутренних функциях у Frits Hoogland: http://orafun.info/
Полная внутренняя документация по oradebug/diagnostic events: http://orasql.org/files/events
