DBMS_SESSION包小議（五）

除了使用ALTER SESSION設定會話的狀態，利用V$SESSION查詢會話狀態，Oracle還提供了PL/SQL介面DBMS_SESSION來查詢和設定會話相關的狀態。

描述用來設定TRACE的SET_SQL_TRACE、SESSION_TRACE_ENABLE和SESSION_TRACE_DISABLE過程。

DBMS_SESSION包小議（一）：http://yangtingkun.itpub.net/post/468/498365

DBMS_SESSION包小議（二）：http://yangtingkun.itpub.net/post/468/498408

DBMS_SESSION包小議（三）：http://yangtingkun.itpub.net/post/468/498451

DBMS_SESSION包小議（四）：http://yangtingkun.itpub.net/post/468/498475

一般來說設定會話級的狀態都是透過ALTER SESSION語句，也有個別的例外，比如角色的設定是透過SET語句實現的。Oracle除了提供SQL的方法外，還提供了PL/SQL的介面，DBMS_SESSION包，將會話狀態的設定和查詢整合在這個包中。

設定當前會話的TRACE的方法很多，會話級修改的方法包括ALTER SESSION SET SQL_TRACE = TRUE以及ALTER SESSION SET EVENTS ‘10046 TRACE NAME CONTEXT FOREVER, LEVEL 12’。

而在DBMS_SESSION中分別提供了不過的過程實現對兩種情況的設定：

SQL> EXEC DBMS_SESSION.SET_SQL_TRACE(TRUE)

PL/SQL 過程已成功完成。

SQL> SELECT * FROM DUAL;

D
-
X

SQL> EXEC DBMS_SESSION.SET_SQL_TRACE(FALSE)

PL/SQL 過程已成功完成。

這種方法等價於SET SQL_TRACE = TRUE，檢查生成的日誌資訊：

SQL> SELECT SPID                
  2  FROM V$PROCESS
  3  WHERE ADDR IN
  4  (SELECT PADDR
  5  FROM V$SESSION
  6  WHERE SID IN
  7  (SELECT SID
  8  FROM V$MYSTAT
  9  WHERE ROWNUM = 1));

SPID
------------------------
13879

                                                 2/test112/trace
SQL> SHOW PARAMETER USER_DUMP

NAME                      TYPE        VALUE
------------------------- ----------- ----------------------------------------------
user_dump_dest            string      /data/oracle/diag/rdbms/test112/test112/trace

檢查對應的日誌：

[oracle@bjtest ~]$ more /data/oracle/diag/rdbms/test112/test112/trace/test112_ora_13879.trc
Trace file /data/oracle/diag/rdbms/test112/test112/trace/test112_ora_13879.trc
Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - 64bit Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options
ORACLE_HOME = /data/oracle/product/11.2
System name:    Linux
Node name:      bjtest
Release:        2.6.18-8.el5xen
Version:        #1 SMP Tue Jun 5 23:53:34 EDT 2007
Machine:        x86_64
Instance name: test112
Redo thread mounted by this instance: 1
Oracle process number: 25
Unix process pid: 13879, image: oracle@bjtest (TNS V1-V3)

*** 2010-03-24 01:14:27.986
*** SESSION ID:(146.4115) 2010-03-24 01:14:27.986
*** CLIENT ID:() 2010-03-24 01:14:27.986
*** SERVICE NAME:(SYS$USERS) 2010-03-24 01:14:27.986
*** MODULE NAME:(SQL*Plus) 2010-03-24 01:14:27.986
*** ACTION NAME:() 2010-03-24 01:14:27.986
 
=====================
PARSING IN CURSOR #3 len=32 dep=1 uid=85 ct=42 lid=85 tim=1269364467986105 hv=1569151342 ad='2aaaac8269a8' sqlid='4tk6t8tfsfqbf'
alter session set sql_trace=true
END OF STMT
EXEC #3:c=0,e=8047,p=0,cr=0,cu=0,mis=1,r=0,dep=1,og=1,plh=0,tim=1269364467986086
CLOSE #3:c=0,e=11,dep=1,type=0,tim=1269364467987068
=====================
PARSING IN CURSOR #2 len=46 dep=0 uid=85 ct=47 lid=85 tim=1269364467987120 hv=3357771837 ad='1eb524df0' sqlid='dnjg30v42721x'
BEGIN DBMS_SESSION.SET_SQL_TRACE(TRUE); END;
END OF STMT
EXEC #2:c=0,e=10318,p=0,cr=0,cu=0,mis=1,r=1,dep=0,og=1,plh=0,tim=1269364467987116

*** 2010-03-24 01:14:33.734
CLOSE #2:c=0,e=34,dep=0,type=0,tim=1269364473734599
=====================
PARSING IN CURSOR #3 len=18 dep=0 uid=85 ct=3 lid=85 tim=1269364473751551 hv=3991932091 ad='1f3d67e80' sqlid='9g6pyx7qz035v'
SELECT * FROM DUAL
END OF STMT
PARSE #3:c=0,e=16825,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=272002086,tim=1269364473751545
EXEC #3:c=0,e=108,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=272002086,tim=1269364473751847
FETCH #3:c=0,e=89,p=0,cr=3,cu=0,mis=0,r=1,dep=0,og=1,plh=272002086,tim=1269364473752092
STAT #3 id=1 cnt=1 pid=0 pos=1 bj=116 p='TABLE ACCESS FULL DUAL (cr=3 pr=0 pw=0 time=0 us cost=2 size=2 card=1)'
FETCH #3:c=0,e=5,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,plh=272002086,tim=1269364473752649

*** 2010-03-24 01:14:39.512
CLOSE #3:c=0,e=27,dep=0,type=0,tim=1269364479512173
=====================
PARSING IN CURSOR #2 len=47 dep=0 uid=85 ct=47 lid=85 tim=1269364479514794 hv=2241307378 ad='1e7f7c9b8' sqlid='568s3wq2tg8rk'
BEGIN DBMS_SESSION.SET_SQL_TRACE(FALSE); END;
END OF STMT
PARSE #2:c=0,e=2483,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=0,tim=1269364479514788
=====================
PARSING IN CURSOR #3 len=33 dep=1 uid=85 ct=42 lid=85 tim=1269364479515649 hv=525901419 ad='2aaaac8269a8' sqlid='aam2chsgpj7mb'
alter session set sql_trace=false
END OF STMT
PARSE #3:c=0,e=522,p=0,cr=0,cu=0,mis=1,r=0,dep=1,og=1,plh=0,tim=1269364479515644
EXEC #3:c=0,e=71,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,plh=0,tim=1269364479515840
EXEC #2:c=0,e=1017,p=0,cr=0,cu=0,mis=0,r=1,dep=0,og=1,plh=0,tim=1269364479515949

可以在TRACE檔案中明確的看到alter session set sql_trace=true和alter session set sql_trace=false語句。

下面看看SET_TRACE_ENABLE過程：

SQL> VAR BIND_NUM NUMBER
SQL> EXEC :BIND_NUM := 1

PL/SQL 過程已成功完成。

SQL> CONN TEST/TEST
已連線。
SQL> EXEC DBMS_SESSION.SESSION_TRACE_ENABLE(TRUE, TRUE)

PL/SQL 過程已成功完成。

SQL> SELECT * FROM DUAL;

D
-
X

SQL> EXEC DBMS_SESSION.SESSION_TRACE_DISABLE

PL/SQL 過程已成功完成。

SQL> SELECT SPID
  2  FROM V$PROCESS
  3  WHERE ADDR IN
  4  (SELECT PADDR
  5  FROM V$SESSION
  6  WHERE SID IN
  7  (SELECT SID
  8  FROM V$MYSTAT
  9  WHERE ROWNUM = 1));

SPID
------------------------
13943

為了避免生成的TRACE寫到同一個檔案中，這裡重新連線，下面檢查對應的TRACE資訊：

Trace file /data/oracle/diag/rdbms/test112/test112/trace/test112_ora_13988.trc
Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - 64bit Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options
ORACLE_HOME = /data/oracle/product/11.2
System name:    Linux
Node name:      bjtest
Release:        2.6.18-8.el5xen
Version:        #1 SMP Tue Jun 5 23:53:34 EDT 2007
Machine:        x86_64
Instance name: test112
Redo thread mounted by this instance: 1
Oracle process number: 25
Unix process pid: 13988, image: oracle@bjtest (TNS V1-V3)

*** 2010-03-24 01:31:46.471
*** SESSION ID:(146.4123) 2010-03-24 01:31:46.471
*** CLIENT ID:() 2010-03-24 01:31:46.471
*** SERVICE NAME:(SYS$USERS) 2010-03-24 01:31:46.471
*** MODULE NAME:(SQL*Plus) 2010-03-24 01:31:46.471
*** ACTION NAME:() 2010-03-24 01:31:46.471
 
=====================
PARSING IN CURSOR #2 len=77 dep=0 uid=85 ct=47 lid=85 tim=1269365506470534 hv=1574321247 ad='1f3ea9108' sqlid='20wpgb5fxcg2z'
BEGIN DBMS_SESSION.SESSION_TRACE_ENABLE(TRUE, TRUE, 'ALL_EXECUTIONS'); END;
END OF STMT
EXEC #2:c=0,e=1478,p=0,cr=0,cu=0,mis=0,r=1,dep=0,og=1,plh=0,tim=1269365506470523
WAIT #2: nam='SQL*Net message to client' ela= 10 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1269365506471439

*** 2010-03-24 01:31:57.144
WAIT #2: nam='SQL*Net message from client' ela= 10672879 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1269365517144366
CLOSE #2:c=0,e=71,dep=0,type=0,tim=1269365517144605
=====================
PARSING IN CURSOR #3 len=26 dep=0 uid=85 ct=3 lid=85 tim=1269365517153876 hv=1790055047 ad='1f3ea2558' sqlid='8s90f65pb44n7'
SELECT :BIND_NUM FROM DUAL
END OF STMT
PARSE #3:c=0,e=9185,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=0,tim=1269365517153870
BINDS #3:
 Bind#0
  acdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
  acflg=03 fl2=1000000 frm=00 csi=00 siz=24 ff=0
  kxsbbbfp=2aaaac8686c8  bln=22  avl=02  flg=05
  value=1
EXEC #3:c=0,e=3602,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=1388734953,tim=1269365517157634
WAIT #3: nam='SQL*Net message to client' ela= 11 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1269365517157742
FETCH #3:c=0,e=135,p=0,cr=0,cu=0,mis=0,r=1,dep=0,og=1,plh=1388734953,tim=1269365517157929
STAT #3 id=1 cnt=1 pid=0 pos=1 bj=0 p='FAST DUAL  (cr=0 pr=0 pw=0 time=0 us cost=2 size=0 card=1)'
WAIT #3: nam='SQL*Net message from client' ela= 274 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1269365517158378
FETCH #3:c=0,e=5,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,plh=1388734953,tim=1269365517158434
WAIT #3: nam='SQL*Net message to client' ela= 4 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1269365517158484

*** 2010-03-24 01:32:01.297
WAIT #3: nam='SQL*Net message from client' ela= 4138626 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1269365521297140
CLOSE #3:c=0,e=32,dep=0,type=0,tim=1269365521297316
=====================
PARSING IN CURSOR #2 len=48 dep=0 uid=85 ct=47 lid=85 tim=1269365521297589 hv=2592126054 ad='1e7f841a0' sqlid='9wuhwhad81d36'
BEGIN DBMS_SESSION.SESSION_TRACE_DISABLE; END;
END OF STMT
PARSE #2:c=0,e=191,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=0,tim=1269365521297584
EXEC #2:c=0,e=644,p=0,cr=0,cu=0,mis=0,r=1,dep=0,og=1,plh=0,tim=1269365521298353

使用SESSION_TRACE_ENABLE過程，不僅可以看到等待時間資訊還可以看到繫結變數資訊，相當於SET EVENTS ‘10046 TRACE NAME CONTEXT FOREVER, LEVEL 12‘語句。