转itpub: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 oct=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 oct=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 oct=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 obj=116 op='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 oct=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 oct=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 oct=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 oct=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
oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
oacflg=03 fl2=1000000 frm=00 csi=00 siz=24 off=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 obj=0 op='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 oct=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‘语句。