在10g中，Oracle新增了DBMS_MONITOR包，使得用户可以更加方便的设置TRACE和统计信息。
这一篇介绍TRACE相关的过程。
DBMS_MONITOR包中提供了多种方法来开启、关闭会话或整个实例的TRACE。
除了最常用的通过会话的SID和SERIAL#进行设置的SESSION_TRACE_ENABLE/SESSION_TRACE_DISABLE外，还包括设置数据库实例上所有会话的DATABASE_TRACE_ENABLE/DATABASE_TRACE_DISABLE过程，通过客户端ID表示设置会话TRACE的CLIENT_ID_TRACE_ENABLE/CLIENT_ID_TRACE_DISABLE、通过SERVICE_NAME, MODULE_NAME和ACTION_NAME进行设置的SERV_MOD_ACT_TRACE_ENABLE/SERV_MOD_ACT_TRACE_DISABLE。
看一个简单的例子：
SQL> SELECT SID, SERIAL#, SQL_TRACE, SQL_TRACE_WAITS, SQL_TRACE_BINDS
2 FROM V$SESSION
3 WHERE SID IN
4 (SELECT SID
5 FROM V$MYSTAT
6 WHERE ROWNUM = 1);
SID SERIAL# SQL_TRAC SQL_T SQL_T
---------- ---------- -------- ----- -----
294 45413 DISABLED FALSE FALSE
在另外的会话设置当前会话的TRACE信息：
SQL> SET SQLP 'SQL2> '
SQL2> CONN / AS SYSDBA
已连接。
SQL2> EXEC DBMS_MONITOR.SESSION_TRACE_ENABLE(294, 45413)
PL/SQL过程已成功完成。
返回刚才的会话检查TRACE状态：
SQL> SELECT SID, SERIAL#, SQL_TRACE, SQL_TRACE_WAITS, SQL_TRACE_BINDS
2 FROM V$SESSION
3 WHERE SID = 294;
SID SERIAL# SQL_TRAC SQL_T SQL_T
---------- ---------- -------- ----- -----
294 45413 ENABLED TRUE FALSE
可以看到，默认情况下，设置等待事件，而不设置绑定变量。
SQL2> EXEC DBMS_MONITOR.SESSION_TRACE_DISABLE(294, 45413)
PL/SQL过程已成功完成。
关闭后，再次检查会话状态：
SQL> SELECT SID, CLIENT_IDENTIFIER, SQL_TRACE, SQL_TRACE_WAITS, SQL_TRACE_BINDS
2 FROM V$SESSION
3 WHERE SID = 294;
SID CLIENT_IDE SQL_TRAC SQL_T SQL_T
---------- ---------- -------- ----- -----
294 DISABLED FALSE FALSE
SQL> EXEC DBMS_SESSION.SET_IDENTIFIER('MY_CLIENT')
PL/SQL过程已成功完成。
SQL> SELECT SID, CLIENT_IDENTIFIER, SQL_TRACE, SQL_TRACE_WAITS, SQL_TRACE_BINDS
2 FROM V$SESSION
3 WHERE SID = 294;
SID CLIENT_IDE SQL_TRAC SQL_T SQL_T
---------- ---------- -------- ----- -----
294 MY_CLIENT DISABLED FALSE FALSE
下面在另一个会话中设置客户端标识为MY_CLIENT的会话进行TRACE：
SQL2> EXEC DBMS_MONITOR.CLIENT_ID_TRACE_ENABLE('MY_CLIENT', TRUE, TRUE)
PL/SQL过程已成功完成。
检查会话TRACE设置状态：
SQL> SELECT SID, CLIENT_IDENTIFIER, SQL_TRACE, SQL_TRACE_WAITS, SQL_TRACE_BINDS
2 FROM V$SESSION
3 WHERE SID = 294;
SID CLIENT_IDE SQL_TRAC SQL_T SQL_T
---------- ---------- -------- ----- -----
294 MY_CLIENT DISABLED FALSE FALSE
SQL> EXEC DBMS_SESSION.SET_IDENTIFIER('MY_CLIENT')
PL/SQL过程已成功完成。
SQL> SELECT SID, CLIENT_IDENTIFIER, SQL_TRACE, SQL_TRACE_WAITS, SQL_TRACE_BINDS
2 FROM V$SESSION
3 WHERE SID = 294;
SID CLIENT_IDE SQL_TRAC SQL_T SQL_T
---------- ---------- -------- ----- -----
294 MY_CLIENT DISABLED FALSE FALSE
SQL> SELECT SPID FROM V$PROCESS
2 WHERE ADDR IN
3 (SELECT PADDR
4 FROM V$SESSION
5 WHERE SID = 294);
SPID
------------
11420
似乎设置SQL_TRACE并没有生效，但是如果检查TRACE文件，就会发现事实并非如此：
bash-2.03$ tkprof testrac1_ora_11420.trc /export/home/oracle/output.log sys=no
TKPROF: Release10.2.0.3.0 - Production on星期日4月4 00:53:42 2010
Copyright (c) 1982, 2005, Oracle. All rights reserved.
bash-2.03$ more /export/home/oracle/output.log
TKPROF: Release10.2.0.3.0 - Production on星期日4月4 00:53:42 2010
Copyright (c) 1982, 2005, Oracle. All rights reserved.
Trace file: testrac1_ora_11420.trc
Sort options: default
********************************************************************************
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
********************************************************************************
SELECT SID, SERIAL#, SQL_TRACE, SQL_TRACE_WAITS, SQL_TRACE_BINDS
FROM V$SESSION
WHERE SID = 294
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.01 0.01 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 2 0.00 0.00 0 0 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 4 0.01 0.01 0 0 0 1
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 76
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 2 0.00 0.00
SQL*Net message from client 2 165.67 165.68
********************************************************************************
SELECT SID, CLIENT_IDENTIFIER, SQL_TRACE, SQL_TRACE_WAITS, SQL_TRACE_BINDS
FROM V$SESSION
WHERE SID = 294
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 4 0.02 0.01 0 0 0 0
Execute 4 0.00 0.00 0 0 0 0
Fetch 8 0.00 0.00 0 0 0 4
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 16 0.02 0.01 0 0 0 4
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 76
Rows Row Source Operation
------- ---------------------------------------------------
1 NESTED LOOPS (cr=0 pr=0 pw=0 time=94 us)
1 FIXED TABLE FIXED INDEX X$KSUSE (ind:1) (cr=0 pr=0 pw=0 time=76 us)
1 FIXED TABLE FIXED INDEX X$KSLED (ind:2) (cr=0 pr=0 pw=0 time=7 us)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 8 0.00 0.00
SQL*Net message from client 8 486.22 653.34
********************************************************************************
SELECT SPID FROM V$PROCESS
WHERE ADDR IN
(SELECT PADDR
FROM V$SESSION
WHERE SID = 294)
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.05 0.05 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 2 0.01 0.00 0 0 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 4 0.06 0.05 0 0 0 1
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 76
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 2 0.00 0.00
SQL*Net message from client 1 0.00 0.00
********************************************************************************
.
.
.
********************************************************************************
Trace file: testrac1_ora_11420.trc
Trace file compatibility:10.01.00
Sort options: default
1 session in tracefile.
7 user SQL statements in trace file.
178 internal SQL statements in trace file.
185 SQL statements in trace file.
33 unique SQL statements in trace file.
4000 lines in trace file.
1129 elapsed seconds in trace file.
可以看到，事实上当前会话的TRACE已经被启用，最后执行的查询SPID的语句已经出现在TRACE文件中。
不过由于是通过CLIENT_ID方式设置的，因此无法从当前会话的状态中看到。
SQL2> EXEC DBMS_MONITOR.CLIENT_ID_TRACE_DISABLE('MY_CLIENT')
PL/SQL过程已成功完成。
另外两种过程分别是设置整个数据库中所有会话的TRACE状态，以及通过SERVICE_NAME、MODULE_NAME和ACTION_NAME设置会话的TRACE状态，其实和上面介绍的两种方法十分类似，这里就不再重复描述了。
除了提供TRACE的开启和关闭外，DBMS_MONITOR包还可以开启关闭对指定会话的统计功能。
SQL> SELECT SID, SERIAL#, CLIENT_IDENTIFIER
2 FROM V$SESSION
3 WHERE SID IN
4 (SELECT SID
5 FROM V$MYSTAT
6 WHERE ROWNUM = 1);
SID SERIAL# CLIENT_IDENTIFIER
---------- ---------- ------------------------------
308 58723
SQL> SELECT * FROM V$CLIENT_STATS;
未选定行
SQL> EXEC DBMS_SESSION.SET_IDENTIFIER('MY_CLIENT')
PL/SQL过程已成功完成。
SQL> SELECT * FROM V$CLIENT_STATS;
未选定行
下面在另外的会话启动CLIENT_ID为MY_CLIENT客户端标识的统计功能：
SQL> SET SQLP 'SQL2> '
SQL2> EXEC DBMS_MONITOR.CLIENT_ID_STAT_ENABLE('MY_CLIENT')
PL/SQL过程已成功完成。
这是回到刚才的会话检查统计信息：
SQL> SELECT * FROM V$CLIENT_STATS;
CLIENT_IDENTIFIER STAT_ID STAT_NAME VALUE
------------------------------ ---------- -------------------------------- ----------
MY_CLIENT 2882015696 user calls 1
MY_CLIENT 3649082374 DB time 777
MY_CLIENT 2748282437 DB CPU 777
MY_CLIENT 63887964 parse count (total) 1
MY_CLIENT 1431595225 parse time elapsed 151
MY_CLIENT 2453370665 execute count 2
MY_CLIENT 2821698184 sql execute elapsed time 277
MY_CLIENT 85052502 opened cursors cumulative 1
MY_CLIENT 3143187968 session logical reads 0
MY_CLIENT 2263124246 physical reads 0
MY_CLIENT 1190468109 physical writes 0
MY_CLIENT 1236385760 redo size 0
MY_CLIENT 582481098 user commits 0
MY_CLIENT 3211650785 workarea executions - optimal 0
MY_CLIENT 798730793 workarea executions - onepass 0
MY_CLIENT 3804491469 workarea executions - multipass 0
MY_CLIENT 3678609077 session cursor cache hits 0
MY_CLIENT 3671147913 user rollbacks 0
MY_CLIENT 916801489 db block changes 0
MY_CLIENT 2877738702 gc cr blocks received 0
MY_CLIENT 1759426133 gc cr block receive time 0
MY_CLIENT 326482564 gc current blocks received 0
MY_CLIENT 1388758753 gc current block receive time 0
MY_CLIENT 2432034337 cluster wait time 0
MY_CLIENT 3868577743 concurrency wait time 0
MY_CLIENT 1099569955 application wait time 0
MY_CLIENT 3332107451 user I/O wait time 0
已选择27行。
SQL> SELECT * FROM V$CLIENT_STATS;
CLIENT_IDENTIFIER STAT_ID STAT_NAME VALUE
------------------------------ ---------- -------------------------------- ----------
MY_CLIENT 2882015696 user calls 5
MY_CLIENT 3649082374 DB time 2837
MY_CLIENT 2748282437 DB CPU 2837
MY_CLIENT 63887964 parse count (total) 2
MY_CLIENT 1431595225 parse time elapsed 251
MY_CLIENT 2453370665 execute count 6
MY_CLIENT 2821698184 sql execute elapsed time 1801
MY_CLIENT 85052502 opened cursors cumulative 2
MY_CLIENT 3143187968 session logical reads 0
MY_CLIENT 2263124246 physical reads 0
MY_CLIENT 1190468109 physical writes 0
MY_CLIENT 1236385760 redo size 0
MY_CLIENT 582481098 user commits 0
MY_CLIENT 3211650785 workarea executions - optimal 0
MY_CLIENT 798730793 workarea executions - onepass 0
MY_CLIENT 3804491469 workarea executions - multipass 0
MY_CLIENT 3678609077 session cursor cache hits 1
MY_CLIENT 3671147913 user rollbacks 0
MY_CLIENT 916801489 db block changes 0
MY_CLIENT 2877738702 gc cr blocks received 0
MY_CLIENT 1759426133 gc cr block receive time 0
MY_CLIENT 326482564 gc current blocks received 0
MY_CLIENT 1388758753 gc current block receive time 0
MY_CLIENT 2432034337 cluster wait time 0
MY_CLIENT 3868577743 concurrency wait time 0
MY_CLIENT 1099569955 application wait time 0
MY_CLIENT 3332107451 user I/O wait time 0
已选择27行。
可以看到，会话的统计信息根据用户的操作而不断的更新。
会话的统计信息可以通过CLIENT_ID_STAT_DISABLE过程关闭：
SQL2> EXEC DBMS_MONITOR.CLIENT_ID_STAT_DISABLE('MY_CLIENT')
PL/SQL过程已成功完成。
这时，V$CLIENT_STAT视图中的统计信息消失：
SQL> SELECT * FROM V$CLIENT_STATS;
未选定行
那么DBMS_MONITOR包提供的这种统计功能和V$MYSTAT提供的有何不同之处，V$MYSTAT或者V$SESSTAT提供的是会话级别的统计，而CLIENT_ID_STAT_ENABLE提供的是指定客户端标识符的统计功能，任何会话只要设置了指定统计的标识符，都会被累计到统计值之中。而只要更改了CLIENT_IDENTIFIER，这个会话的统计信息就不会再被统计。
下面看看SERV_MOD_ACT_STAT_ENABLE过程：
SQL> CONN TEST/TEST@TESTRAC1
已连接。
SQL> SELECT SID, SERIAL#, SERVICE_NAME, MODULE
2 FROM V$SESSION
3 WHERE SID IN
4 (SELECT SID
5 FROM V$MYSTAT
6 WHERE ROWNUM = 1);
SID SERIAL# SERVICE_NAME MODULE
---------- ---------- -------------------- ------------------------------
308 58725 testrac SQL*Plus
SQL> SELECT * FROM V$SERV_MOD_ACT_STATS;
未选定行
执行SERV_MOD_ACT_STAT_ENABLE过程，对使用testrac为服务名的SQLPLUS连接设置统计信息：
SQL2> EXEC DBMS_MONITOR.SERV_MOD_ACT_STAT_ENABLE('testrac', 'SQL*Plus')
PL/SQL过程已成功完成。
再次检查对应的视图：
SQL> SELECT * FROM V$SERV_MOD_ACT_STATS;
AGGREGATION_TYPE SERVICE_NAME MODULE ACTION STAT_ID STAT_NAME VALUE
---------------- ------------ -------- ------ ---------- ------------------------------- -----
SERVICE_MODULE testrac SQL*Plus 2882015696 user calls 9
SERVICE_MODULE testrac SQL*Plus 3649082374 DB time 8740
SERVICE_MODULE testrac SQL*Plus 2748282437 DB CPU 8740
SERVICE_MODULE testrac SQL*Plus 63887964 parse count (total) 3
SERVICE_MODULE testrac SQL*Plus 1431595225 parse time elapsed 2329
SERVICE_MODULE testrac SQL*Plus 2453370665 execute count 10
SERVICE_MODULE testrac SQL*Plus 2821698184 sql execute elapsed time 5137
SERVICE_MODULE testrac SQL*Plus 85052502 opened cursors cumulative 3
SERVICE_MODULE testrac SQL*Plus 3143187968 session logical reads 0
SERVICE_MODULE testrac SQL*Plus 2263124246 physical reads 0
SERVICE_MODULE testrac SQL*Plus 1190468109 physical writes 0
SERVICE_MODULE testrac SQL*Plus 1236385760 redo size 0
SERVICE_MODULE testrac SQL*Plus 582481098 user commits 0
SERVICE_MODULE testrac SQL*Plus 3211650785 workarea executions - optimal 0
SERVICE_MODULE testrac SQL*Plus 798730793 workarea executions - onepass 0
SERVICE_MODULE testrac SQL*Plus 3804491469 workarea executions - multipass 0
SERVICE_MODULE testrac SQL*Plus 3678609077 session cursor cache hits 1
SERVICE_MODULE testrac SQL*Plus 3671147913 user rollbacks 0
SERVICE_MODULE testrac SQL*Plus 916801489 db block changes 0
SERVICE_MODULE testrac SQL*Plus 2877738702 gc cr blocks received 0
SERVICE_MODULE testrac SQL*Plus 1759426133 gc cr block receive time 0
SERVICE_MODULE testrac SQL*Plus 326482564 gc current blocks received 0
SERVICE_MODULE testrac SQL*Plus 1388758753 gc current block receive time 0
SERVICE_MODULE testrac SQL*Plus 2432034337 cluster wait time 0
SERVICE_MODULE testrac SQL*Plus 3868577743 concurrency wait time 1122
SERVICE_MODULE testrac SQL*Plus 1099569955 application wait time 0
SERVICE_MODULE testrac SQL*Plus 3332107451 user I/O wait time 0
已选择27行。
利用SERV_MOD_ACT_STAT_DISABLE过程进行统计信息的关闭：
SQL2> EXEC DBMS_MONITOR.SERV_MOD_ACT_STAT_DISABLE('testrac', 'SQL*Plus')
PL/SQL过程已成功完成。
这时统计信息被关闭：
SQL> SELECT * FROM V$SERV_MOD_ACT_STATS;
未选定行
和CLIENT_ID方式一样，这种统计信息是对应所有通过指定服务名登陆，且MODULE_NAME与指定的MODULE一致的会话的。因此DBMS_MONITOR包提供的两种设置统计信息的方法，都是针对具有相同类型的一组会话，这使得检查或诊断一类用户的行为时，更加的方便，更有针对性。
|
|
京ICP备12024223-8号
不良信息举报电话：13718043309
转播
分享
淘帖
