在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: Release 10.2.0.3.0 - Production on 星期日 4月 4 00:53:42 2010

bash-2.03$ more /export/home/oracle/output.log

TKPROF: Release 10.2.0.3.0 - Production on 星期日 4月 4 00:53:42 2010

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狀態，其實和上面介紹的兩種方法十分類似，這裡就不再重複描述了。

Oracle10g新增DBMS_MONITOR包（一）

相關文章