Oracle mechanics

Trace events

Трейсы, дампы, сигналы

Список ошибок Oracle, включая номера событий (Oracle events) на Unix/Linux платформах можно найти в файле $ORACLE_HOME/rdbms/mesg/oraus.msg.

218105.1 Introduction to ORACLE Diagnostic EVENTS

Diagnostic Events in 10g and 11g [VIDEO] [ID 1402625.1]

Event Reference описание недостаточно документированных событий от Julian Dyke

Описание события Oracle 11g с использованием функции sqlerrm

SQL> set serveroutput on
SQL> declare
 2   v_errm VARCHAR2(256);
 3  begin
 4  v_errm := SUBSTR(SQLERRM(-10046),1,256);
 5  DBMS_OUTPUT.PUT_LINE( v_errm);
 6  end;
 7  /
ORA-10046: enable SQL statement timing
SQL> -- или списком:
SQL> set serveroutput on
SQL> exec for event in 10000..10999 loop dbms_output.put_line( sqlerrm(-event) ); end loop;

Список событий, установленных для текущей сессии:

SQL> alter session set events '10053 trace name context forever, level 1';

Session altered.

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

Session altered.

SQL> oradebug setmypid
Statement processed.
SQL> oradebug eventdump session                   -- показывает все события
sql_trace level=4
trace [RDBMS.SQL_OPTIMIZER]
trace [RDBMS.SQL_Transform]
trace [RDBMS.SQL_MVRW]
trace [RDBMS.SQL_VMerge]
trace [RDBMS.SQL_Virtual]
trace [RDBMS.SQL_APA]
trace [RDBMS.SQL_Costing]
trace [RDBMS.SQL_Parallel_Optimization]
trace [RDBMS.SQL_Plan_Management]
10721 trace name context forever, level 3

11.2@ SQL> set serveroutput on
11.2@SQL> declare
  2    event_level number;
  3    counter     number;
  4  begin
  5    counter := 0;
  6    for i in 10000 .. 10999 loop
  7      sys.dbms_system.read_ev(i, event_level); -- начиная с Oracle 11g показывает только цифровые события, соответствующие кодам ORA-10NNN
  8      if (event_level > 0) then
  9        dbms_output.put_line('Event ' || to_char(i) || ' set at level ' || to_char(event_level));
 10        counter := counter + 1;
 11      end if;
 12    end loop;
 13    if (counter = 0) then
 14      dbms_output.put_line('No events set for this session');
 15    end if;
 16  end;
 17  /
Event 10721 set at level 3

PL/SQL procedure successfully completed.
Трейс выполнения запроса / SQL trace/ 10046 event

«стандартный» Oracle SQL Trace, в зависимости от уровня может включать значения связанных переменных (binds) и информацию по статистике событий ожиданий (waits). «Уровни трейса (EVENT) 10046:

1  — стандартный уровень SQL_TRACE (Default)
4  — уровень 1 + трейс значений связанных переменных (binds)
8  — уровень 1 + трейс событий ожидания (waits)…
12 = 4+8 уровень 1 + трейсы значений связанных переменных (binds) и событий ожидания (waits)
«

начиная с Oracle 11 список базовых уровней дополнен статистикой плана выполнения plan_statChristian Antognini. Event 10046 – Full List of Levels

Level Description sql_trace
0 The debugging event is disabled.
1 The debugging event is enabled. For each processed database call, the following information is given: SQL statement, response time, service time, number of processed rows, number of logical reads, number of physical reads and writes, execution plan, and little additional information.
Up to 10.2 an execution plan is written to the trace file only when the cursor it is associated with is closed. The execution statistics associated to it are values aggregated over all executions.
As of 11.1 an execution plan is written to the trace file only after the first execution of every cursor. The execution statistics associated to it are the ones of the first execution only.
waits=FALSE, binds=FALSE, plan_stat=’first_execution’
4 As in level 1, with additional information about bind variables. Mainly, the data type, its precision, and the value used for each execution. waits=FALSE, binds=TRUE, plan_stat=’first_execution’
8 As in level 1, plus detailed information about wait time. For each wait experienced during the processing, the following information is given: the name of the wait event, the duration, and a few additional parameters identifying the resource that has been waited for. waits=TRUE, binds=FALSE, plan_stat=’first_execution’
16 As in level 1, plus the execution plans information is written to the trace file for each execution. Available as of 11.1 only. waits=FALSE, binds=FALSE, plan_stat=’all_executions’
32 As in level 1, but without the execution plans information. Available as of 11.1 only. waits=FALSE, binds=FALSE, plan_stat=never’
64 As in level 1, plus the execution plans information might be written for executions following the first one. The condition is that, since the last write of execution plans information, a particular cursor consumed at least one additional minute of DB time. This level is interesting in two cases. First, when the information about the first execution is not enough for analysing a specific issue. Second, when the overhead of writing the information about every execution (level 16) is too high. Generally available as of 11.2.0.2 only. waits=FALSE, binds=FALSE, plan_stat=’adaptive’ — not available yet

Включить/выключить стандартные трейс в текущей сессии

SQL> alter session set SQL_TRACE= TRUE|FALSE;

или с указанием уровня трейса

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

Включить/выключить трейс в любой сессии, используя пакет DBMS_SUPPORT:

SQL> exec sys.dbms_support.start_trace_in_session( &sid, &serial, waits=>TRUE, binds=>TRUE );
SQL> exec sys.dbms_support.stop_trace_in_session( &sid, &serial );

То же с использованием утилиты ORADEBUG:

SQL> select s.sid, s.serial#, p.spid ospid, p.pid orapid, s.username, s.osuser
 2    from v$session s, v$process p
 3   where s.paddr = p.addr
 4  /

 SID    SERIAL#    OSPID    ORAPID    USERNAME    OSUSER
------- ---------- -------- --------- ----------- ------------

- определить/установить сессию по orapid

SQL> oradebug setorapid &orapid

или по ospid

SQL> oradebug setospid &ospid

включить / проверить состояние / выключить трейс:

SQL> oradebug event 10046 trace name context forever , level 12
Statement processed.
SQL> oradebug eventdump session
sql_trace level=12
SQL> oradebug event 10046 trace name context off

1058210.6 How to Enable SQL_TRACE for Another Session or in MTS Using Oradebug

Включить/выключить трейс на уровне системы:

SQL> alter system set events '10046 trace name context forever[, level L]';
SQL> alter system set events '10046 trace name context off';

или с использованием параметра системы:

event='10046 trace name context forever[,  level 12]'

Выключить все события для всех инстансов бд:

SQL> ALTER SYSTEM RESET EVENT SCOPE=SPFILE SID='*' ;

160178.1 How to set EVENTS in the SPFILE

all possible methods for sql trace / 10046 trace setup [ID 1274511.1] — специалисты Oracle сами всё описывают

с Oracle 10.2 можно определить наличие и уровень SQL_TRACE для сессии по значениям SQL_TRACE, SQL_TRACE_WAITS, SQL_TRACE_BINDS в V$SESSION

с Oracle 10g можно включить SQL трейс на уровне SERVICE [ MODULE [ ACTION ] ], устанавливаемых пакетом DBMS_APPLICATION_INFO, с помощью DBMS_MONITOR.SERV_MOD_ACT_TRACE_ENABLE или по CLIENT_ID с помощью DBMS_MONITOR.CLIENT_ID_TRACE_ENABLE:

11.@SQL> EXECUTE DBMS_MONITOR.SERV_MOD_ACT_TRACE_ENABLE( service_name  => 'SERV'-
>                                                      , module_name   => 'MOD' -
>                                                      , action_name   => 'ACT' -
>                                                      , waits         => FALSE -
>                                                      , binds         => TRUE  -
>                                                      , instance_name => 'ORCL'-
>                                                      , plan_stat     => 'ALL_EXECUTIONS') /*'NEVER', 'FIRST_EXECUTION' (equivalent to NULL) or 'ALL_EXECUTIONS'*/

PL/SQL procedure successfully completed.

SQL> select * from DBA_ENABLED_TRACES;

TRACE_TYPE            PRIMARY_ID  QUALIFIER_ID1  QUALIFIER_ID2  WAITS BINDS PLAN_STATS INSTANCE_NAME
--------------------- ----------- -------------- -------------- ----- ----- ---------- -------------
SERVICE_MODULE_ACTION SERV        MOD            ACT            FALSE TRUE  ALL_EXEC   ORCL

1 row selected.

SQL> select * from SYS.WRI$_TRACING_ENABLED;

TRACE_TYPE PRIMARY_ID  QUALIFIER_ID1   QUALIFIER_ID2  INSTANCE_NAME FLAGS
---------- ----------- --------------- -------------- ------------- -----
         5 SERV        MOD             ACT            ORCL             20

SQL> EXECUTE DBMS_SESSION.SET_IDENTIFIER ('123');

PL/SQL procedure successfully completed.

SQL> SELECT sid FROM v$session WHERE client_identifier = '123';

       SID
----------
         7

SQL> EXECUTE dbms_monitor.client_id_trace_enable (client_id=>'123');

PL/SQL procedure successfully completed.

SQL> select * from DBA_ENABLED_TRACES;                                                              -- отражает оба типа трейсов

TRACE_TYPE            PRIMARY_ID  QUALIFIER_ID1  QUALIFIER_ID2  WAITS BINDS PLAN_STATS INSTANCE_NAME
--------------------- ----------- -------------- -------------- ----- ----- ---------- -------------
SERVICE_MODULE_ACTION SERV        MOD            ACT            FALSE TRUE  ALL_EXEC   ORCL
CLIENT_ID             123                                       TRUE  FALSE FIRST_EXEC

SQL> EXECUTE dbms_monitor.client_id_trace_disable (client_id=>'123');

PL/SQL procedure successfully completed.

SQL> EXECUTE DBMS_MONITOR.SERV_MOD_ACT_TRACE_DISABLE( service_name  => 'SERV'-
>                                               , module_name   => 'MOD' -
>                                               , action_name   => 'ACT' -
>                                               , instance_name => 'ORCL');

PL/SQL procedure successfully completed.

SQL> select * from DBA_ENABLED_TRACES;

no rows selected

Tracing Enhancements In 10g and 11g Using DBMS_MONITOR [ID 293661.1]

Интерпретация результатов трейса 10046:

39817.1 Interpreting Raw SQL_TRACE and DBMS_SUPPORT.START_TRACE output — структура информации необработанного (raw) трейс файла

На примере трассировке с уровнем 12 (LEVEL 12 = binds + waits) операции вставки массива строк (array insert, реализуемый с использованием FORALL кляузы в PL/SQL или host arrays) Oracle сразу после записи о разборе (PARSING IN CURSOR)  запишет в файл только первый набор значений связанных переменных (первый элемент вставляемого массива строк):

PARSING IN CURSOR #139988089003064 len=227 dep=0 uid=21 oct=2 lid=21 tim=1323439560100077 hv=1512394967 ad='1f578f9c0' sqlid='291quzjd2an6r'
INSERT INTO "MY_TABLE" ("EVENTTIME", "TRANTIME", "BLOCK_ID", ...) VALUES(TO_DATE(:p1, 'YYYY-MM-DD HH24:MI:SS'), TO_DATE(:p2, 'YYYY-MM-DD HH24:MI:SS'), :p3, ...)
END OF STMT
BINDS #139988089003064:                             -- bind-значения для курсора #139988089003064
Bind#0                                              --
oacdty=01 mxl=32(19) mxlc=00 mal=00 scl=00 pre=00   -- св-ва переменной: тип данных [oac]dty; макс.длина mxl;...
oacflg=00 fl2=1000000 frm=01 csi=196 siz=96 off=0
kxsbbbfp=7f5184562ab8  bln=32  avl=19  flg=05       -- bind address [kxsbb]bfp; размер bind буфера bln; актуальный размер переменной avl;...
value="2011-12-09 17:29:03"                         -- значение
...

далее — типичные ожидания (в случае array insert основные дисковые чтения приходятся на блоки индексов):

...
WAIT #139988089003064: nam='db file sequential read' ela= 13105 file#=197 block#=576548 blocks=1 obj#=8483163 tim=1323439560207461
...

и, собственно, выполнение курсора:

...
EXEC #139988089003064:c=245963,e=29695833,p=683,cr=265,cu=3207,mis=0,r=1000,dep=0,og=1,plh=0,tim=1323439589795819
Brevis Description
c CPU time (9i+ microseconds)
e Elapsed time (9i+ microseconds)
p # of Physical reads
cr # of buffers retrieved for CR reads — соответствует статистике consistent gets
cu Number of buffers retrieved in current mode — соответствует статистике db block gets
mis Cursor missed in library cache, если > 0 — при выполнении запроса поребовался разбор курсора — hard parse
r # of rows processed — кол-во обработанных строк, в этом случае 1000
dep Recursive call depth (0 = user SQL, >0 = recursive)
og Optimizer Goal: 1=All_Rows, 2=First_Rows, 3=Rule, 4=Choose
tim Timestamp (9i+ microseconds) — может быть использован для определения времени между операциями в трейс файле, к реальному времени можно привязать через обзор v$timer
plh sql PLan Hash
trcsess

штатная утилита консолидации нескольких трейс-файлов, например, при параллельном выполнении, на основе:

  • Session ID
  • Client ID
  • Service name
  • Action name
  • Module name

What is TRCSESS and How to use it ? [ID 280543.1]

В консолидированном файле записи сгруппированы по курсорам, но могут нарушать хронологический порядок

tkprof

32951.1 Tkprof Interpretation: стандартно поставляемая с Oracle утилита tkprof для обработки и анализа содержимого трейс файлов

Из обработанного tkprof трейса:

********************************************************************************
count    = number of times OCI procedure was executed                    -- кол-во выполнений процедур PARSE, FETCH, EXEC,...
cpu      = cpu time in seconds executing
elapsed  = elapsed time in seconds executing
disk     = number of physical reads of buffers from disk                 -- соответствует статистике physical reads
query    = number of buffers gotten for consistent read                  -- соответствует статистике consistent gets
current  = number of buffers gotten in current mode (usually for update) -- соответствует статистике db block gets
rows     = number of rows processed by the fetch or execute call         -- количество полеченных (SELECT) или вставленных/обновлённых (INSERT/UPDATE) строк
********************************************************************************

Обработанный трейс Array insert из предыдущего примера выглядит так:

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        0      0.00       0.00          0          0          0           0
Execute      7      1.34     136.54       3816       1828      19538        6032  -- за 7 выполнений вставлено 6032 строк, при этом прочитано 1828(query)+19538(current)=21366 блоков бд, из них 3816 блоков - с диска
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        7      1.34     136.54       3816       1828      19538        6032

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

Elapsed times include waiting on following events:
Event waited on                             Times   Max. Wait  Total Waited
----------------------------------------   Waited  ----------  ------------
db file sequential read                      3816        0.49        130.10 -- 3816 одноблочных чтений с диска были выполнены за 130 секунд
SQL*Net more data from client                  24        0.00          0.00
log file switch completion                      1        0.41          0.41
SQL*Net message to client                       7        0.00          0.00
SQL*Net message from client                     7        0.01          0.08
read by other session                           2        0.07          0.09
latch: object queue header operation            2        0.00          0.00
latch: cache buffers chains                     1        0.00          0.00
********************************************************************************

По крайней мере, начиная с версии 11g, tkprof пишет статистику плана выполнения (row source statistics):

Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 173
Number of plan statistics captured: 1

Rows (1st) Rows (avg) Rows (max)  Row Source Operation
---------- ---------- ----------  ---------------------------------------------------
      2628       2628       2628  SORT AGGREGATE (cr=9913 pr=1028 pw=0 time=7379389 us) -- 1028 Physical Reads; 7.379389 seconds
      2628       2628       2628   TABLE ACCESS BY INDEX ROWID CUSTOMER_TRX_ALL (cr=9913 pr=1028 pw=0 time=7373736 us cost=5 size=13 card=1)
      2628       2628       2628    INDEX RANGE SCAN CUSTOMER_TRX_IDX3 (cr=7847 pr=1028 pw=0 time=7359145 us cost=4 size=0 card=1)(object id 29159)
TRCANLZR

224270.1 TRCANLZR «…reads a raw SQL Trace generated by standard SQL Trace or by EVENT 10046 (Level 4, 8 or 12), and generates a comprehensive HTML report with performance related details: time summary, call summary (parse, execute, fetch), identification of top SQL, row source plan, explain plan, CBO statistics, wait events, values of bind variables, I/O summary per schema object, latches, hot blocks, etc.» . Инструмент реализован в виде схемы БД, считывает трейс файл 10046 и генертрует подробный отчёт в формате HTML. Во время обработки данные загружаются в global temporary table и доступны из SQL, например, для создания на основе активности сессии тестового повторного сценария (Oracle session activity Replay)

events sql_trace

Начиная с Oracle 11g появилась возможность устанавливать SQL trace на уровнях отдельных запросов, процессов — см.описание в блоге Miladin Modrakovich:

SQL> alter session/system set events 'sql_trace [sql:|] wait=true | false, bind=true | false, planstat=never | first_execution | all_executionss | level = 12';
SQL> alter session/system set events 'sql_trace {process : pid = , pname = , orapid = } ...';
SQL> alter system set events 'sql_trace  {process: pname = p000 | p005}';

например для конкретного SQL_ID на уровне системы:

11.@SYS SQL> alter system set events 'sql_trace [sql:b9wj15rg7qhv1] level 12';

System altered.

11.@SYS SQL> oradebug setmypid
Statement processed.

11.@SYS SQL> oradebug eventdump system
sql_trace [sql:b9wj15rg7qhv1] level 12

11.@SYS SQL> alter system set events 'sql_trace [sql:b9wj15rg7qhv1] off';

System altered.

11.@SYS SQL> oradebug eventdump system
Statement processed.

, более подробно в Tanel Poder: The full power of Oracle’s diagnostic events, part 2: ORADEBUG DOC and 11g improvements

SQL> alter session set events ‘sql_trace [sql: &sql_id] crash’; — особый вариант использования события, использовать только с одобрения поддержки Oracle

10053 event / 10132 event

Трассировка действий оптимизатора (Cost-Based Optimizer) по выбору плана выполнения запроса, включая используемые параметры, статистику объектов (изпользуемых таблиц и индексов), использование правил,…

SQL> alter session set events '10053 trace name context forever';
SQL> select count(*) from emp ...;
SQL> alter session set events '10053 trace name context off';

Событие 10132 — облегчённый вариант предыдущего события(?), без математики

SQL> alter session set events '10132 trace name context forever, level 12';
SQL> select ...
SQL> alter session set events '10053 trace name context off';

В конце трейсов в случае применения в запросе подсказок можно найти отчёт об использовании подсказок (used=0/1 — неиспользована/использована):

Dumping Hints
=============
atom_hint=(@=0x7ff72a34fce8 err=6 resol=1 used=0 token=453 org=1 lvl=2 txt=FIRST_ROWS )
atom_hint=(@=0x7ff72a348b18 err=6 resol=1 used=0 token=454 org=1 lvl=2 txt=ALL_ROWS )
********** WARNING: SOME HINTS HAVE ERRORS *********

Wolfgang Breitling A LOOK UNDER THE HOOD OF CBO: THE 10053 EVENT

CASE STUDY: Analyzing 10053 Trace Files [ID 338137.1]

Optimizer Trace

Greg Rahn «Creating Optimizer Trace Files» — начиная с Oracle 11g:

SQL> oradebug doc component SQL_Compiler

  SQL_Compiler                    SQL Compiler
    SQL_Parser                    SQL Parser (qcs)
    SQL_Semantic                  SQL Semantic Analysis (kkm)
    SQL_Optimizer                 SQL Optimizer
      SQL_Transform               SQL Transformation (kkq, vop, nso)
        SQL_MVRW                  SQL Materialized View Rewrite
        SQL_VMerge                SQL View Merging (kkqvm)
        SQL_Virtual               SQL Virtual Column (qksvc, kkfi)
      SQL_APA                     SQL Access Path Analysis (apa)
      SQL_Costing                 SQL Cost-based Analysis (kko, kke)
        SQL_Parallel_Optimization SQL Parallel Optimization (kkopq)
    SQL_Code_Generator            SQL Code Generator (qka, qkn, qke, kkfd, qkx)
      SQL_Parallel_Compilation    SQL Parallel Compilation (kkfd)
      SQL_Expression_Analysis     SQL Expression Analysis (qke)
      SQL_Plan_Management         SQL Plan Managment (kkopm)
    MPGE                          MPGE (qksctx)

SQL> alter session set events 'trace [SQL_Compiler.*]';
SQL> select * from scott.emp where ename = 'SCOTT';
SQL> alter session set events 'trace [SQL_Compiler.*] off';

Начиная с Oracle 11.2 можно получить трейс оптимизатора для запроса, находящегося в shared pool (v$sql), без повторного выполнения запроса:

begin
dbms_sqldiag.dump_trace(
   p_sql_id=>'d9m84krtg4yg1',
   p_child_number => 2,
   p_component=>'Optimizer',    --Valid values are "Optimizer" and "Compiler"
   p_file_id=>'My_CBO_Trace');
end;

При выполнениии процедуры dbms_sqldiag.dump_trace для формирования трейса будет выполнен повторный разбор запроса, в текст которого добавляется соответствующий комментарий:

sql=/* SQL Analyze(129,0) */ SELECT "A1"."C" FROM "TEST" "A1"

, т.е. указание в качестве параметра процедуры p_child_number не позволяет получать трейс формирования конкретного дочернего курсора — Параметр CHILD NUMBER в процедуре DBMS_SQLDIAG.DUMP_TRACE по крайней мере в 11.2

Для трассировки разбора определённого запроса по SQL_ID, например, вызываемого из PL/SQL, или изменяющего план выполнения под влиянием Cardinality Feedback или рекурсивного запроса при удалённом выполнении, удобно выставлять трейс таким образом — How do I capture a 10053 trace for a SQL statement called in a PL/SQL package:

11.2.0.2.@SQL> alter system set events 'trace [rdbms.SQL_Compiler.*][sql:dvhxps45r7j8s]';

System altered.

-- Полезная работа

SQL> alter system set events 'trace [rdbms.SQL_Compiler.*] off';

System altered.

*) начиная с Oracle 11.1.0.6 при установленном параметре trace_enabled=false файлы любых трейсов оптимизатора (вкл. 10053 event) могут не генерироваться — Bug 7304656: TRACE_ENABLED=FALSE DISABLES EVENT 10053 TRACE IN 11G, при этом файлы обычного SQL_TRACE (10046 event) генерируются без проблем

SQL> alter system set trace_enabled=true;

System altered.

SQL> connect scott/tiger                                -- для последующих соединений проблем нет
Connected.

та же проблема в 11.2.0.*

SQL PLAN MANAGEMENT trace

SQL PLAN MANAGEMENT TRACING [ID 789520.1]

SQL> exec dbms_spm.configure('spm_tracing',1);

PL/SQL procedure successfully completed

SQL> select parameter_value from SYS.SMB$CONFIG where parameter_name = 'SPM_TRACING';

PARAMETER_VALUE
---------------
1

SQL> exec dbms_spm.configure('spm_tracing',0);

PL/SQL procedure successfully completed

SQL> select parameter_value from SYS.SMB$CONFIG where parameter_name = 'SPM_TRACING';

PARAMETER_VALUE
---------------
0

или на уровне сессии:

11.1.@ SQL> alter session set events 'trace [sql_planmanagement.*]';

11.2.@ SQL> alter system set events 'trace [SQL_Plan_Management.*][sql:g1jratsw6ujcz]';

System altered.

SQL> oradebug setmypid
Statement processed.
SQL> oradebug eventdump system
trace [RDBMS.SQL_PLAN_MANAGEMENT] [sql:g1jratsw6ujcz]
SQL> alter system set events 'trace [RDBMS.SQL_PLAN_MANAGEMENT] [sql:g1jratsw6ujcz] off';

System altered.

SQL> oradebug eventdump system
Statement processed.
cursortrace event

событие для анализа причин повторного неиспользования курсоров, упоминается в «296377.1 Handling and resolving unshared cursors/large version_counts«

Включить трейс

SQL> alter system set events 'immediate trace name cursortrace level 577,  address &hash_value';
SQL> alter system set events 'immediate trace name cursortrace level 612,  address &hashvalue';

Отключить

SQL> alter system set events 'immediate trace name cursortrace level 128,  address &hashvalue';

&hashvalue — значение hash_value курсора из обзора v$sql — тесты события описаны в блоге Tanya Hardy — Cursortrace event

drop_segments event
SQL> alter session set events 'immediate trace name DROP_SEGMENTS level TS#+1';

Событие для удаления временных сегментов, которые по каким-либо причинам не были удалены SMON. На практике бывает необходимо для очистки временных сегментов, оставшихся от прерванной операции создания индекса, например. Наличие таких «неочищенных» SMON’ом сегментов затрудняет создание новых объектов в ТС.

61997.1 SMON — Temporary Segment Cleanup and Free Space Coalescing
47400.1 EVENT: DROP_SEGMENTS — Forcing cleanup of TEMPORARY segments

10949 event
#  "Disable autotune direct path read for full table scan"
# // *Cause:
# // *Action:  Disable autotune direct path read for serial full table scan.
# //

Начиная с Oracle 11g, позволяет отключить автоматический выбор механизма многоблочного чтения между [обычным] чтением данных через buffer cache SGA (ожидания db file scattered read) и чтением блоков через PGA — serial direct path read (ожидания direct path read), отключая direct path read:

SQL> alter session set events '10949 trace name context forever, level 1';
trace name treedump

Выводит внутреннюю структуру индекса по id объекта

SQL> alter session set events 'immediate trace name treedump level &object_id';

Jonathan Lewis blog: treedump

Richard Foote. Oracle B-Tree Index Internals: Rebuilding The Truth

10231 event

позволяет на уровне сессии пропускать битые блоки (corrupted blocks), выдающие ORA-01578, ORA-08103 при сканировании таблиц. Удобно для переноса уцелевших данных (в случае отсутствия бэкапа) — EVENT: 10231 «skip corrupted blocks on _table_scans_» [ID 21205.1]

SQL> ALTER SESSION SET EVENTS '10231 TRACE NAME CONTEXT FOREVER, LEVEL 10';

SQL> ALTER TABLE ... MOVE;

$ oerr ORA 10231
10231, 00000, "skip corrupted blocks on _table_scans_"
// *Cause:
// *Action: such blocks are skipped in table scans, and listed in trace files

установить режим пропуска «плохих» блоков (skip corrupted blocks) на уровне объекта бд:

EXEC DBMS_REPAIR.SKIP_CORRUPT_BLOCKS (
SCHEMA_NAME => '&OWNER',
OBJECT_NAME => '&TABLE_NAME',
OBJECT_TYPE => dbms_repair.table_object,
FLAGS => dbms_repair.SKIP_FLAG);
event 43905

трассировка Result Cache — Julian Dyke «Result Cache Internals»:

SQL> ALTER SESSION SET EVENTS '43905 trace name context forever, level 1';

 

$ oerr ora 43905
 43905, 0000, "result cache tracing event"
 // *Document: NO
 // *Cause:    This is an internal event.
 // *Action:   N/A
heapdump / memory heaps dump
SQL> ALTER SESSION SET EVENTS 'immediate trace name heapdump level &level';

SQL> oradebug dump heapdump &level

Уровни для Oracle 10.2.0.1:

Level Description
1 PGA summary
2 SGA summary
4 UGA summary
8 Callheap (Current)
16 Callheap (User)
32 Large pool
64 Streams pool
128 Java pool
1025 PGA with contents
2050 SGA with contents
4100 UGA with contents
8200 Callheap with contents (Current)
16400 Callheap with contents (User)
32800 Large pool with contents
65600 Streams pool with contents
131200 Java pool with contents

shared pool heap dump / X$KSMSP — Oracle 11g

_px_trace

Трейс паралельного выполнения, как запускать и что и как нужно читать описано в Tracing Parallel Execution with _px_trace. Part I [ID 444164.1]:

SQL> alter session set «_px_trace»=[[Verbosity,]area],[[Verbosity,]area],..,[time];

примеры:

SQL> alter session set "_px_trace"=high,execution,medium,execution,time;
SQL> alter session set "_px_trace"="compilation","execution","messaging";
SQL> alter session set "_px_trace"="high","execution","medium","buffer","time";
SQL> alter session set "_px_trace"="all";

параметры:

Verbosity:

high
medium
low

Area:

scheduling — ( equivalent to some of event 10384 and some of 10390)
execution — (equivalent to some of event 10390)
granule — (equivalent to some of event 10390 and some of 10391)
messaging — (equivalent to event 10392 and event 10393)
buffer — (equivalent to event 10399)
compilation — ( no equivalent event)
all — all of the above
none — none of the above.

Timing

time

events 10384

Предназначен для выполнения запроса с использованием параллельного плана выполнения в непараллельном (serial) режиме — одним процессом без использования PX slave процессов. Может быть полезен для получения консолидированной статистики / трейса выполнения запроса

Доступен, начиная с Oracle 10.2 — How to force that a Parallel Query runs in serial with the Parallel Execution Plan [ID 1114405.1]:

alter session set events '10384 trace name context forever , level 16384';

alter session set events '10384 trace name context off';
dbms_space_admin.segment_dump(&tablespace_name, &relative_fno, &header_block)

дамп блоков заголовка сегмента и bitmap-карты в USER_DUMP_DEST

 dump of datafile block[s]

How to dump a block within ASM [ID 280636.1] — дамп блоков бд по имени файла, по 1 блоку:

SQL> alter system dump datafile 'C:\ORADATA\ORCL112\SYSTEM01.DBF' block 288;

System altered.

SQL> alter system dump datafile '+DATA/orcl112/datafile/idx.259.765724117' block 2971572;

System altered.

по номерам файлов бд, и по диапазонам блоков:

SQL> alter system dump datafile 85 block min 1956115 block max 1956118;

System altered.

Формат дампа листового блока индекса (index leaf block) — Richard Foote: Index Block Dump

dump of datafile headers
SQL> Alter Session Set Events 'immediate trace name file_hdrs level 10';
dump of logfile

header или содержимое redo log

How to Dump Redo Log File Information [ID 1031381.6]

Graham Thornton. Dissassembling the Oracle Redolog

dump of controlfile

MOS ID 269352.1

SQL> Alter Session Set Events 'immediate trace name controlf level 4';
events 1652

может быть полезно для трассировки условий возникновения ORA-1652: unable to extend temp segment by 16 in tablespace TEMP

How Can Temporary Segment Usage Be Monitored Over Time? [ID 364417.1]

Trace «ORA-01652: unable to extend temp segment»

SQL> alter system set events '1652 trace name errorstack level 3';
SQL> alter system set events '1652 trace name errorstack level 12';

System altered.

SQL> alter system set events '1652 trace name errorstack off';
events 10704

информация о блокировках (locks/enqueues), используемых сессией, включая время ожидания

SQL> alter session set events '10704 trace name context forever, level 10';

$ oerr ora 10704
10704, 00000, "Print out information about what enqueues are being obtained"
// *Cause:  When enabled, prints out arguments to calls to ksqcmi and
//          ksqlrl and the return values.
// *Action: Level indicates details:
//   Level: 1-4: print out basic info for ksqlrl, ksqcmi
//          5-9: also print out stuff in callbacks:  ksqlac, ksqlop
//          10+: also print out time for each line
events 10104

детали выполнения операций HASH JOIN

$ oerr ora 10104
10104, 00000, "dump hash join statistics to trace file"

SQL> ALTER SESSION SET EVENTS '10104 trace name context forever, level 1';

Session altered

SQL> ALTER SESSION SET EVENTS '10104 trace name context off';

уровни 1-10, к более подробному

events 10730

трассировка предикатов, добавляемых политиками VPD | RLS | FGAC, в Tracing VPD Predicates описан для диагностики ошибок типа ORA-28113: policy predicate has error

$ oerr ora 10730
10730, 00000, "trace row level security policy predicates"
// *Document: NO

SQL> ALTER SESSION SET events '10730 trace name context forever, level 1';

Session altered.

в трейс-файле — описание RLS view, в который преобразуется запрос к таблице/синониму:

-------------------------------------------------------------
Logon user     : SCOTT
Synonym        : SCOTT.SOME_SYN_NAME
Policy name    : MY_SEC
Policy function: SCOTT.MY_SECURITY
RLS view :
SELECT  ... FROM "SCOTT"."SOME_SYN_NAME" WHERE (sec_id = sys_context(...
-------------------------------------------------------------
10513 event

в редких случаях рекомендуется для временного отключения SMON transaction recovery -  автоматического восстановления незавершённых транзакций:

SQL> select pid, program from v$process where program like '%SMON%';

PID  PROGRAM
---- -----------------
 22  oracle@... (SMON)                                                      -- определение PID

SQL> oradebug setorapid 22
Oracle pid: 22, Unix process pid: 21214, image: oracle@stbyins2...ru (SMON)
SQL> oradebug eventdump session
Statement processed.                                                        -- список events сессии пуст
SQL> oradebug event 10513 trace name context forever, level 2;
Statement processed.SQL> oradebug eventdump session
10513 trace name context forever, level 2                                   -- список events сессии

обязательное последующее включение:

SQL> oradebug event 10513 trace name context off
Statement processed.
SQL> oradebug eventdump session
Statement processed.

Database Hangs Because SMON Is Taking 100% CPU Doing Transaction Recovery [ID 414242.1]

ORADEBUG утилита

ORADEBUG — UNDOCUMENTED ORACLE UTILITY — подробное описание некоторых возможностей от Miladin Modrakovic’а

_swrf_test_action

трассировка процессов MMON:

SQL> alter session set "_swrf_test_action" = 28;-- включение трейса
Session altered.
SQL> alter session set "_swrf_test_action" = 29;-- выключение

и snapshot flush trace (M00x процессов):

SQL> alter session set "_swrf_test_action" = 10;-- включение
Session altered.
SQL> alter session set "_swrf_test_action" = 11;-- выключение

Могут быть полезны, в частности, для выявления проблем с генерацией AWR снапшотов — Troubleshooting: AWR Snapshot Collection issues [ID 1301503.1]

ashdump

запись данных Active Session History системы (v$active_session_history) в файл

SQL> alter session set events 'immediate trace name ashdump level 10';
--or
SQL> alter system set events 'immediate trace name ashdump level 10';
--or
SQL> oradebug setmypid
SQL> oradebug dump ashdump 10;

10 => кол-во минут истории для дампа

10g and above Active Session History (Ash) And Analysis Of Ash Online And Offline [ID 243132.1]

ashdump* scripts and post-load processing of MMNL traces (Doc ID 555303.1)

event 16000
event 604

Для поиска причин ORA-16000 ORA-604 на Read Only Standby / Active Data Guard db:

11.@SQL> alter system set events '604 trace name errorstack level 10';
SQL> alter system set events '16000 trace name errorstack level 3';
--
SQL> alter system set events '604 trace name errorstack off';
SQL> alter system set events '16000 trace name errorstack off';

PHYSICAL: ORA-604 ORA-16000 on Standby Opened Read Only [ID 730659.1]

event 10442

Событие для трассировки ORA-1555, принимается в MOS

SQL> Alter system set events '10442 trace name context forever , level 10';
CURSORTRACE event
CURSORDUMP event

Трассировка информации о причинах повторного неиспользования курсоров

10G@ SQL> alter system set events 'immediate trace name cursortrace level 577, address hash_value'; -- v$sqlarea.hash_value
11.2@ SQL> alter system set events 'immediate trace name cursordump level 16';

Troubleshooting: High Version Count Issues [ID 296377.1]

10237 event

Тестовое событие, позволяет прервать выполнение запроса в другой сессии

$ oerr ora 10237
10237, 00000, "simulate ^C (for testing purposes)"

SQL> exec dbms_system.set_ev(489, 21321, 10237, 1, '')

PL/SQL procedure successfully completed

      SID#489@ SQL> select
      ...
      529  /

      ERROR at line 346:
      ORA-01013: user requested cancel of current operation

      Elapsed: 00:53:50.19

      SID#489@ SQL> select
      ...
      529  /

      ERROR at line 1:
      ORA-01013: user requested cancel of current operation

      Elapsed: 00:00:00.03                             -- повторное выполнение невозможно

SQL> exec dbms_system.set_ev(489, 21321, 10237, 0, '') -- отключение события для возобновления работы сессии SID 489

PL/SQL procedure successfully completed

How To Cancel A Query Running In Another Session

10157 event

событие, позволяющее блокировать использование операции INLIST ITERATOR с индексным доступом; в документах MOS рекомендуется устанавливать на уровне системы, ввиду нестабильности, см., например, Конкатенация против INLIST ITERATOR

10119 event

событие отключения NOSORT опции для операции SORT GROUP BY:

$ oerr ora 10119
10119, 00000, "QKA Disable GBY sort elimination"

пример использования на стандартной схеме SCOTT:

11.2.0.3.ORCL1123@SCOTT SQL> alter table EMP modify deptno not null
  2  /

Table altered.

SQL> create index EMP_DEPTNO_IDX on EMP (DEPTNO)
  2  /

Index created.

SQL> select *
  2   from (select max(sal) as top_salary from emp group by deptno)
  3  where rownum < 2
  4  /

-------------------------------------------------------------------------------------------------
| Id  | Operation                      | Name           | Rows  | Bytes | Cost (%CPU)| Time     |
-------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT               |                |     1 |    13 |     2   (0)| 00:00:01 |
|*  1 |  COUNT STOPKEY                 |                |       |       |            |          |
|   2 |   VIEW                         |                |     1 |    13 |     2   (0)| 00:00:01 |
|   3 |    SORT GROUP BY NOSORT        |                |     1 |     7 |     2   (0)| 00:00:01 |
|   4 |     TABLE ACCESS BY INDEX ROWID| EMP            |    14 |    98 |     2   (0)| 00:00:01 |
|   5 |      INDEX FULL SCAN           | EMP_DEPTNO_IDX |     1 |       |     1   (0)| 00:00:01 |
-------------------------------------------------------------------------------------------------

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

   1 - filter(ROWNUM<2)

SQL> alter session set events '10119 trace name context forever'
  2  /

Session altered.

SQL> select *
  2   from (select max(sal) as top_salary from emp group by deptno)
  3  where rownum < 2
  4  /

-------------------------------------------------------------------------------------------------
| Id  | Operation                      | Name           | Rows  | Bytes | Cost (%CPU)| Time     |
-------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT               |                |     1 |    13 |     2   (0)| 00:00:01 |
|*  1 |  COUNT STOPKEY                 |                |       |       |            |          |
|   2 |   VIEW                         |                |     1 |    13 |     2   (0)| 00:00:01 |
|*  3 |    SORT GROUP BY STOPKEY       |                |     1 |     7 |     2   (0)| 00:00:01 |
|   4 |     TABLE ACCESS BY INDEX ROWID| EMP            |    14 |    98 |     2   (0)| 00:00:01 |
|   5 |      INDEX FULL SCAN           | EMP_DEPTNO_IDX |     1 |       |     1   (0)| 00:00:01 |
-------------------------------------------------------------------------------------------------

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

   1 - filter(ROWNUM<2)
   3 - filter(ROWNUM<2)
Alexander Anokhin. Dynamic tracing of Oracle logical I/O
10128 event

Трассировка Partition Pruning, впрочем, достаточно бесполезная

$ oerr ora 10128
10128, 00000, "Dump Partition Pruning Information"
// *Cause:
// *Action:  set this event only under the supervision of Oracle development
//
//  LEVEL        ACTION
//---------------------------------------------------------------------------
//  0x0001       dump pruning decriptor for each partitioned object
//  0x0002       dump partition iterators
//  0x0004       dump optimizer decisions about partition-wise join
//  0x0008       dump rowid range scan pruning information
Трассировка PL/SQL

Классическая трассировка с помощью events 10928, 10938, 10940 и параметра _PLSQL_DUMP_BUFFER_EVENTSPL/SQL Tracing Features Available with PL/SQL 2.3.4 in Oracle 7.3.4 (Doc ID 52481.1)

С использованием пакета DBMS_TRACE и таблицы PLSQL_TRACE_EVENTS (@?/rdbms/admin/tracetab.sql) — How to Use DBMS_TRACE (Doc ID 104239.1)

Пример в блоге Саяна Малакшинова

Как найти название трейс файла процесса Oracle?

Для собственной сессии:

SQL> oradebug setmypid
Statement processed.
SQL> oradebug tracefile_name
c:\oracle\diag\rdbms\orcl112\orcl112\trace\orcl112_ora_2076.trc

Несколько способов для любого (включая системные) процесса — из блога Laurent Schneider

1)

SQL> select p.pid from v$session s, v$process p
 2  where s.paddr = p.ADDR
 3  and s.program like '%LGWR%'
 4  /

PID
----------
 11

SQL> oradebug setorapid 11
 Oracle pid: 11, Windows thread id: 5760, image: ORACLE.EXE (LGWR)
SQL> oradebug tracefile_name
c:\oracle\diag\rdbms\orcl112\orcl112\trace\orcl112_lgwr_5760.trc

2)

SQL> SELECT LOWER(d.name)||'_ora_'||p.spid||DECODE(p.value,'','','_'||value) tracefile_name
 2  FROM v$parameter p, v$database d, sys.v_$session s, sys.v_$process p
 3  ,(SELECT sid FROM v$session WHERE program like '%LGWR%') m
 4  WHERE p.name = 'tracefile_identifier'
 5  AND s.paddr = p.addr
 6  AND s.sid = m.sid
 7  /

TRACEFILE_NAME
--------------------------------------------------------------------------------
orcl112_ora_5760

3) начиная с версии Oracle 11g для собственной сессии

SQL> select value from v$diag_info where name='Default Trace File'
 2  /

VALUE
------------------------------------------------------------------
c:\oracle\diag\rdbms\orcl112\orcl112\trace\orcl112_ora_2284.trc

4) с версии Oracle 11g для любого процесса

SQL> select tracefile from v$process where pid=11;

TRACEFILE
----------------------------------------------------------------
c:\oracle\diag\rdbms\orcl112\orcl112\trace\orcl112_lgwr_5760.trc

TBD

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

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

RSS-лента комментариев к этой записи. TrackBack URI

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

Заполните поля или щелкните по значку, чтобы оставить свой комментарий:

Логотип WordPress.com

Для комментария используется ваша учётная запись WordPress.com. Выход / Изменить )

Фотография Twitter

Для комментария используется ваша учётная запись Twitter. Выход / Изменить )

Фотография Facebook

Для комментария используется ваша учётная запись Facebook. Выход / Изменить )

Google+ photo

Для комментария используется ваша учётная запись Google+. Выход / Изменить )

Connecting to %s

Тема: Rubric. Create a free website or blog at WordPress.com.

Отслеживать

Get every new post delivered to your Inbox.

Join 87 other followers

%d bloggers like this: