启用 Oracle 10046 调试事件

Oracle 10046是一个Oracle内部事件。最常用的是在Session级别设置sql_trace(alter session set sql_trace=true)即是开启了级别为1

的10046调试事件。当设置了10046事件之后，Oracle 将产生一个dump文件。通过得到的dump文件进行进一步分析，可以得到Oracle 内部执行系

统解析、调用、等待、绑定变量等详细的trace信息，对于分析系统的性能有着举足轻重的作用。

一、10046事件的相关参数

该事件需要设置一些参数以控制dump文件的输出：

TIMED_STATISTICS

用于控制计时信息，可以设定为true和false。当设定为true时，计时信息将会被添加到trace文件中。

MAX_DUMP_FILE_SIZE

用于控制trace文件的最大尺寸。当使用10046事件时，建议将该参数设定为unlimited。

USER_DUMP_DEST

用于设定trace文件写入到哪个文件目录

STATISTICS_LEVEL

用于控制统计信息的收集度。此参数有3个选择，baisc，typical，all。

basic:仅收集满足trace所需的最基本的信息，象Timed statistics，Object level statistics，以及一些advisory会被忽略。

typical:此为缺省值。此设置将在basic的基础上增加一些额外的统计信息，象操作系统耗用时间的统计信息，执行计划的统计信息都会被收集

all:当设置为all时，所有与该session相关的信息全部会被收集。

TRACEFILE_IDENTIFIER

用于设置识别Trace文件的字符串，便于更快捷的找到生成的Trace文件。

以上参数可以基于系统级别以及会话级别进行修改。

ALTER SESSION/SYSTEM SET timed_statistics=true

ALTER SESSION/SYSTEM SET max_dump_file_size=unlimited

ALTER SESSION SET tracefile_identifier='trace_sql_example' -->仅session级别

为特定的session动态设定trace相关参数，借助DBMS_SYSTEM包

sys.DBMS_SYSTEM.set_bool_param_in_session( &sid

, &serial

, 'timed_statistics'

, TRUE );

sys.DBMS_SYSTEM.set_int_param_in_session( &sid

, &serial

, 'max_dump_file_size'

, 2147483647 );

二、10046调试事件的等级

10046调试事件可以分为多个不同的等级，不同的等级输出不同的trace信息。

等级 作用

0 禁止调试事件

1 调试事件处于激活状态。针对每个被处理的数据库调用，输出SQL语句,APPNAME（应用程序名）,PARSING IN CURSOR,PARSE ERROR（SQL解析）

,EXEC（执行）,FETCH（获取数据）,UNMAP,SORT UNMAP（排序，临时段）,ERROR,STAT（执行计划）,XCTEND（事务）等行。

4 包括等级1的输出，加上BIND行（绑定变量信息）

8 包括等级1的输出，加上WAIT行（等待事件信息）。对于处理过程中的每个等待，提供如下信息：等待时间的名字，持续时间，以及一些额外

的参数，可表明所等待的资源。

12 输出等级4以及等级8的所有信息

三、激活10046调试事件

[sql]
view plaincopyprint?

1.针对当前会话启用10046事件(常用set event)
-- 开启当前会话级别为12的Trace，level后面的数字用于设定Trace的级别，取值为0,1,4,8,12

ALTER SESSION SET EVENTS '10046 trace name context forever, level 12'
-- 关闭当前会话任意级别的Trace

ALTER SESSION SET EVENTS '10046 trace name context off'

2. 针对非当前会话启用10046事件
sys@MMBOTST> desc dbms_system
PROCEDURE SET_EV
Argument Name Type In/Out Default?
------------------------------ ----------------------- ------ --------

SI BINARY_INTEGER IN
SE BINARY_INTEGER IN
EV BINARY_INTEGER IN
LE BINARY_INTEGER IN
NM VARCHAR2 IN

-->使用包来实现其他session的10046事件

sys.DBMS_SYSTEM.set_ev( &input_sid
, &input_serial
, 10046
, &input_level
, NULL );
sys.DBMS_SYSTEM.set_ev( &input_sid
, &input_serial
, 10046
, 0
, NULL );

-->使用触发器来实现其它用户登录之后即开启10046事件

-->为避免针对所有用户开启跟踪，建议创建一个角色，假定为sql_trace，然后将该角色授予需要进行trace的用户(create role sql_trace)

CREATE OR REPLACE TRIGGER enable_sql_trace
AFTER LOGON
ON DATABASE
BEGIN
IF ( DBMS_SESSION.is_role_enabled( 'SQL_TRACE' ) ) THEN
EXECUTE IMMEDIATE 'ALTER SESSION SET timed_statistics=true';

EXECUTE IMMEDIATE 'ALTER SESSION SET max_dump_file_size=unlimited';

EXECUTE IMMEDIATE 'ALTER SESSION SET EVENTS ''10046 trace name context forever, level 8'' ';
END IF;
END;
/

3.根据client identifier来trace 多个不同的会话
sys.DBMS_MONITOR.CLIENT_ID_TRACE_ENABLE ( client_id=>'&input_client_identifier', waits=>TRUE, binds=>FALSE );
sys.DBMS_MONITOR.CLIENT_ID_TRACE_DISABLE ( client_id=>'&input_client_identifier' );

使用系统自带的包来设置client identifier
BEGIN
dbms_session.set_identifier(client_id=>'robinson.cheng');
dbms_application_info.set_client_info(client_info=>'Linux x86_64');
dbms_application_info.set_module(module_name=>'test.module',
action_name=>'test session');
END;
/

scott@CNMMBO> SELECT client_identifier,
2 client_info,
3 module AS module_name,
4 action AS action_name
5 FROM v$session
6 WHERE sid = sys_context('userenv','sid');

CLIENT_IDENTIFIER CLIENT_INFO MODULE_NAME ACTION_NAME
------------------------- ------------- ----------------- -------------------------

robinson.cheng Linux x86_64 test.module test session

-->使用下面的procedure来清除当前session的client identifier

scott@CNMMBO> exec dbms_session.CLEAR_IDENTIFIER;

PL/SQL procedure successfully completed.

-->也可以使用下面的trigger来生成client identifier

-->下面针对sql_trace角色下的用户登录之后设置client identifier

CREATE OR REPLACE TRIGGER logon_set_identifier
AFTER LOGON
ON DATABASE
DECLARE
UID VARCHAR2( 64 );
BEGIN
IF ( DBMS_SESSION.is_role_enabled( 'SQL_TRACE' ) ) THEN
SELECT ora_login_user
|| ':'
|| SYS_CONTEXT( 'USERENV', 'OS_USER' )
INTO UID
FROM dual;

DBMS_SESSION.set_identifier( UID );
ELSE
NULL;
END IF;
END logon_set_identifier;

[sql]
view plaincopyprint?

1.创建演示环境

CREATE TABLE sql_trace_test

(

id            NUMBER

, description   VARCHAR2( 50 )

);

EXEC DBMS_STATS.gather_table_stats('SCOTT', 'SQL_TRACE_TEST');

CREATE OR REPLACE PROCEDURE populate_sql_trace_test( p_loops IN NUMBER ) AS

l_number   NUMBER;

BEGIN

FOR i IN 1 .. p_loops

LOOP

INSERT INTO sql_trace_test( id, description )

VALUES ( i

, 'Description for '

|| i );

END LOOP;

SELECT COUNT( * ) INTO l_number FROM sql_trace_test;

COMMIT;

DBMS_OUTPUT.put_line( l_number

|| ' rows inserted.' );

END;

/

SHOW ERRORS

2.使用10046事件开启8级跟踪

scott@CNMMBO> ALTER SESSION SET EVENTS '10046 trace name context forever, level 8';

Session altered.

scott@CNMMBO> EXEC populate_sql_trace_test(p_loops => 10);

10 rows inserted.

PL/SQL procedure successfully completed.

scott@CNMMBO> ALTER SESSION SET EVENTS '10046 trace name context off';

Session altered.

scott@CNMMBO> ho ls -hltr /u02/database/CNMMBO/udump/*example*

-rw-r----- 1 oracle oinstall 9.1K 2012-02-24 10:24 /u02/database/CNMMBO/udump/cnmmbo_ora_6667_trace_sql_example.trc

3.使用tkprof工具格式化trace file

scott@CNMMBO> host

oracle@SZDB:~/robinson/scripts/dba_scripts/custom/sql> cd /u02/database/CNMMBO/udump/

oracle@SZDB:/u02/database/CNMMBO/udump> tkprof cnmmbo_ora_6667_trace_sql_example.trc sql_example.txt \

> explain=scott/tiger sys=no sort=prsela,exeela,fchela

TKPROF: Release 10.2.0.3.0 - Production on Fri Feb 24 10:33:16 2012

Copyright (c) 1982, 2005, Oracle.  All rights reserved.

oracle@SZDB:/u02/database/CNMMBO/udump> more sql_example.txt

TKPROF: Release 10.2.0.3.0 - Production on Fri Feb 24 10:33:16 2012

Copyright (c) 1982, 2005, Oracle.  All rights reserved.

Trace file: cnmmbo_ora_6667_trace_sql_example.trc

Sort options: prsela  exeela  fchela

********************************************************************************

count    = number of times OCI procedure was executed

cpu      = cpu time in seconds executing

elapsed  = elapsed time in seconds executing

disk     = number of physical reads of buffers from disk

query    = number of buffers gotten for consistent read

current  = number of buffers gotten in current mode (usually for update)

rows     = number of rows processed by the fetch or execute call

********************************************************************************

BEGIN populate_sql_trace_test(p_loops => 10); END;

call     count       cpu    elapsed       disk      query    current        rows

------- ------  -------- ---------- ---------- ---------- ----------  ----------

Parse        1      0.00       0.00          0          0          0           0

Execute      1      0.00       0.00          0          0          0           1

Fetch        0      0.00       0.00          0          0          0           0

------- ------  -------- ---------- ---------- ---------- ----------  ----------

total        2      0.01       0.00          0          0          0           1

Misses in library cache during parse: 1

Optimizer mode: ALL_ROWS

Parsing user id: 66  (SCOTT)

Elapsed times include waiting on following events:

Event waited on                             Times   Max. Wait  Total Waited

----------------------------------------   Waited  ----------  ------------

log file sync                                   1        0.09          0.09

SQL*Net message to client                       1        0.00          0.00

SQL*Net message from client                     1        0.00          0.00

********************************************************************************

INSERT INTO SQL_TRACE_TEST( ID, DESCRIPTION )

VALUES

( :B1 , 'Description for ' || :B1 )

call     count       cpu    elapsed       disk      query    current        rows

------- ------  -------- ---------- ---------- ---------- ----------  ----------

Parse        1      0.00       0.00          0          0          0           0

Execute     10      0.00       0.00          0          1         31          10

Fetch        0      0.00       0.00          0          0          0           0

------- ------  -------- ---------- ---------- ---------- ----------  ----------

total       11      0.00       0.00          0          1         31          10

Misses in library cache during parse: 1

Misses in library cache during execute: 1

Optimizer mode: ALL_ROWS

Parsing user id: 66  (SCOTT)   (recursive depth: 1)

/**************************************************/

/* Author: Robinson Cheng                         */

/* Blog:   http://blog.csdn.net/robinson_0612     */

/* MSN:    robinson_0612@hotmail.com              */

/* QQ:     645746311                              */

/**************************************************/

4.演示应用程序上的跟踪(使用client identifier)

-->根据前面的描述创建角色并授予需要跟踪的用户以及添加client identifier的触发器，并启动应用程序

oracle@2go-devDB01uv:/u02/database/SYBO2/udump> ls -hltr    -->移出不必要的trace文件以清除判断其产生的跟踪文件

total 8.5K

drwxr-xr-x 2 oracle oinstall 8.5K 2012-02-24 11:52 old

oex_admin@SYBO2> create role sql_trace;                    -->创建角色

Role created.

goex_admin@SYBO2> grant sql_trace to goex_webuser;         -->将角色授予用户。注：触发器logon_set_identifier已经创建

Grant succeeded.

-->启动应用程序后，session的信息如下

goex_admin@SYBO2> SELECT sid , serial#, username , client_identifier, client_info , module AS module_name

2  FROM   v$session WHERE username is not null;

SID    SERIAL# USERNAME             CLIENT_IDENTIFIER              CLIENT_INFO   MODULE_NAME

---------- ---------- -------------------- ------------------------------ ------------- -----------------

1068       6250 GOEX_WEBUSER         GOEX_WEBUSER:Robinson.Cheng                  mBO.exe

1073       7201 GOEX_ADMIN                                                        SQL*Plus

1075       9115 GOEX_ADMIN                                                        SQL*Plus

1086      60120 GOEX_ADMIN                                                        TOAD 10.5.0.41

-->开启基于client identifier的trace

goex_admin@SYBO2> exec DBMS_MONITOR.CLIENT_ID_TRACE_ENABLE('GOEX_WEBUSER:Robinson.Cheng',waits=>TRUE, binds=>FALSE );

PL/SQL procedure successfully completed.

-->调用应用程序的report 模块并生成report，此时可以看到应用程序多产生了一个session,其sid,serial分别为1078,34788

goex_admin@SYBO2> SELECT sid , serial#, username , client_identifier, client_info , module AS module_name

2  FROM   v$session WHERE username is not null;

SID    SERIAL# USERNAME             CLIENT_IDENTIFIER              CLIENT_INFO   MODULE_NAME

---------- ---------- -------------------- ------------------------------ ------------- -----------------

1068       6250 GOEX_WEBUSER         GOEX_WEBUSER:Robinson.Cheng                  mBO.exe

1073       7201 GOEX_ADMIN                                                        SQL*Plus

1075       9115 GOEX_ADMIN                                                        SQL*Plus

1078      34788 GOEX_WEBUSER         GOEX_WEBUSER:Robinson.Cheng                  mBO.exe

1086      60120 GOEX_ADMIN                                                        TOAD 10.5.0.41

-->report产生后关闭基于client identifier的trace

goex_admin@SYBO2> exec DBMS_MONITOR.CLIENT_ID_TRACE_DISABLE('GOEX_WEBUSER:Robinson.Cheng');

PL/SQL procedure successfully completed.

oracle@2go-devDB01uv:/u02/database/SYBO2/udump> ls -hltr     -->此时的udump目录下产生了两个trace文件

total 409K

drwxr-xr-x 2 oracle oinstall 8.5K 2012-02-24 11:52 old

-rw-r----- 1 oracle oinstall 4.9K 2012-02-24 11:56 sybo2_ora_6419.trc

-rw-r----- 1 oracle oinstall 391K 2012-02-24 11:56 sybo2_ora_6422.trc

oracle@2go-devDB01uv:/u02/database/SYBO2/udump> cat sybo2_ora_6419.trc | grep SESSION

*** SESSION ID:(1068.6250) 2012-02-24 11:56:19.617

oracle@2go-devDB01uv:/u02/database/SYBO2/udump> cat sybo2_ora_6422.trc | grep SESSION

*** SESSION ID:(1078.34788) 2012-02-24 11:56:20.650

IF ( DBMS_SESSION.is_role_enabled( 'SQL_TRACE' ) ) THEN

DBMS_SESSION.set_identifier( UID );

ALTER SESSION  SET NLS_CALENDAR = 'GREGORIAN'  NLS_DATE_FORMAT = 'YYYY-MM-DD HH24:MI:SS' NLS_NUMERIC_CHARACTERS = '.,'

-->可以看到对于由应用程序衍生出来的另外一个session 也被trace，而衍生的session正是由SQL语句产生的。

1.创建演示环境
CREATE TABLE sql_trace_test
(
id            NUMBER
, description   VARCHAR2( 50 )
);

EXEC DBMS_STATS.gather_table_stats('SCOTT', 'SQL_TRACE_TEST');

CREATE OR REPLACE PROCEDURE populate_sql_trace_test( p_loops IN NUMBER ) AS
l_number   NUMBER;
BEGIN
FOR i IN 1 .. p_loops
LOOP
INSERT INTO sql_trace_test( id, description )
VALUES ( i
, 'Description for '
|| i );
END LOOP;

SELECT COUNT( * ) INTO l_number FROM sql_trace_test;

COMMIT;
DBMS_OUTPUT.put_line( l_number
|| ' rows inserted.' );
END;
/

SHOW ERRORS

2.使用10046事件开启8级跟踪
scott@CNMMBO> ALTER SESSION SET EVENTS '10046 trace name context forever, level 8';

Session altered.

scott@CNMMBO> EXEC populate_sql_trace_test(p_loops => 10);
10 rows inserted.

PL/SQL procedure successfully completed.

scott@CNMMBO> ALTER SESSION SET EVENTS '10046 trace name context off';

Session altered.

scott@CNMMBO> ho ls -hltr /u02/database/CNMMBO/udump/*example*
-rw-r----- 1 oracle oinstall 9.1K 2012-02-24 10:24 /u02/database/CNMMBO/udump/cnmmbo_ora_6667_trace_sql_example.trc

3.使用tkprof工具格式化trace file
scott@CNMMBO> host
oracle@SZDB:~/robinson/scripts/dba_scripts/custom/sql> cd /u02/database/CNMMBO/udump/
oracle@SZDB:/u02/database/CNMMBO/udump> tkprof cnmmbo_ora_6667_trace_sql_example.trc sql_example.txt \
> explain=scott/tiger sys=no sort=prsela,exeela,fchela

TKPROF: Release 10.2.0.3.0 - Production on Fri Feb 24 10:33:16 2012

Copyright (c) 1982, 2005, Oracle.  All rights reserved.

oracle@SZDB:/u02/database/CNMMBO/udump> more sql_example.txt

TKPROF: Release 10.2.0.3.0 - Production on Fri Feb 24 10:33:16 2012

Copyright (c) 1982, 2005, Oracle.  All rights reserved.

Trace file: cnmmbo_ora_6667_trace_sql_example.trc
Sort options: prsela  exeela  fchela
********************************************************************************
count    = number of times OCI procedure was executed
cpu      = cpu time in seconds executing
elapsed  = elapsed time in seconds executing
disk     = number of physical reads of buffers from disk
query    = number of buffers gotten for consistent read
current  = number of buffers gotten in current mode (usually for update)
rows     = number of rows processed by the fetch or execute call
********************************************************************************

BEGIN populate_sql_trace_test(p_loops => 10); END;

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

Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 66  (SCOTT)

Elapsed times include waiting on following events:
Event waited on                             Times   Max. Wait  Total Waited
----------------------------------------   Waited  ----------  ------------
log file sync                                   1        0.09          0.09
SQL*Net message to client                       1        0.00          0.00
SQL*Net message from client                     1        0.00          0.00
********************************************************************************

INSERT INTO SQL_TRACE_TEST( ID, DESCRIPTION )
VALUES
( :B1 , 'Description for ' || :B1 )

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute     10      0.00       0.00          0          1         31          10
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total       11      0.00       0.00          0          1         31          10

Misses in library cache during parse: 1
Misses in library cache during execute: 1
Optimizer mode: ALL_ROWS
Parsing user id: 66  (SCOTT)   (recursive depth: 1)

/**************************************************/
/* Author: Robinson Cheng                         */
/* Blog:   http://blog.csdn.net/robinson_0612     */
/* MSN:    robinson_0612@hotmail.com              */
/* QQ:     645746311                              */
/**************************************************/

4.演示应用程序上的跟踪(使用client identifier)
-->根据前面的描述创建角色并授予需要跟踪的用户以及添加client identifier的触发器，并启动应用程序
oracle@2go-devDB01uv:/u02/database/SYBO2/udump> ls -hltr    -->移出不必要的trace文件以清除判断其产生的跟踪文件
total 8.5K
drwxr-xr-x 2 oracle oinstall 8.5K 2012-02-24 11:52 old

oex_admin@SYBO2> create role sql_trace;                    -->创建角色

Role created.

goex_admin@SYBO2> grant sql_trace to goex_webuser;         -->将角色授予用户。注：触发器logon_set_identifier已经创建

Grant succeeded.

-->启动应用程序后，session的信息如下
goex_admin@SYBO2> SELECT sid , serial#, username , client_identifier, client_info , module AS module_name
2  FROM   v$session WHERE username is not null;

SID    SERIAL# USERNAME             CLIENT_IDENTIFIER              CLIENT_INFO   MODULE_NAME
---------- ---------- -------------------- ------------------------------ ------------- -----------------
1068       6250 GOEX_WEBUSER         GOEX_WEBUSER:Robinson.Cheng                  mBO.exe
1073       7201 GOEX_ADMIN                                                        SQL*Plus
1075       9115 GOEX_ADMIN                                                        SQL*Plus
1086      60120 GOEX_ADMIN                                                        TOAD 10.5.0.41

-->开启基于client identifier的trace
goex_admin@SYBO2> exec DBMS_MONITOR.CLIENT_ID_TRACE_ENABLE('GOEX_WEBUSER:Robinson.Cheng',waits=>TRUE, binds=>FALSE );

PL/SQL procedure successfully completed.

-->调用应用程序的report 模块并生成report，此时可以看到应用程序多产生了一个session,其sid,serial分别为1078,34788
goex_admin@SYBO2> SELECT sid , serial#, username , client_identifier, client_info , module AS module_name
2  FROM   v$session WHERE username is not null;

SID    SERIAL# USERNAME             CLIENT_IDENTIFIER              CLIENT_INFO   MODULE_NAME
---------- ---------- -------------------- ------------------------------ ------------- -----------------
1068       6250 GOEX_WEBUSER         GOEX_WEBUSER:Robinson.Cheng                  mBO.exe
1073       7201 GOEX_ADMIN                                                        SQL*Plus
1075       9115 GOEX_ADMIN                                                        SQL*Plus
1078      34788 GOEX_WEBUSER         GOEX_WEBUSER:Robinson.Cheng                  mBO.exe
1086      60120 GOEX_ADMIN                                                        TOAD 10.5.0.41

-->report产生后关闭基于client identifier的trace
goex_admin@SYBO2> exec DBMS_MONITOR.CLIENT_ID_TRACE_DISABLE('GOEX_WEBUSER:Robinson.Cheng');

PL/SQL procedure successfully completed.

oracle@2go-devDB01uv:/u02/database/SYBO2/udump> ls -hltr     -->此时的udump目录下产生了两个trace文件
total 409K
drwxr-xr-x 2 oracle oinstall 8.5K 2012-02-24 11:52 old
-rw-r----- 1 oracle oinstall 4.9K 2012-02-24 11:56 sybo2_ora_6419.trc
-rw-r----- 1 oracle oinstall 391K 2012-02-24 11:56 sybo2_ora_6422.trc

oracle@2go-devDB01uv:/u02/database/SYBO2/udump> cat sybo2_ora_6419.trc | grep SESSION
*** SESSION ID:(1068.6250) 2012-02-24 11:56:19.617
oracle@2go-devDB01uv:/u02/database/SYBO2/udump> cat sybo2_ora_6422.trc | grep SESSION
*** SESSION ID:(1078.34788) 2012-02-24 11:56:20.650
IF ( DBMS_SESSION.is_role_enabled( 'SQL_TRACE' ) ) THEN
DBMS_SESSION.set_identifier( UID );
ALTER SESSION  SET NLS_CALENDAR = 'GREGORIAN'  NLS_DATE_FORMAT = 'YYYY-MM-DD HH24:MI:SS' NLS_NUMERIC_CHARACTERS = '.,'

-->可以看到对于由应用程序衍生出来的另外一个session 也被trace，而衍生的session正是由SQL语句产生的。