1 什么时候需要获得绑定变量
Oracle数据库一个常用的优化技术是绑定变量,如果使用得到,绑定变量可以大幅度减少物理解析,提高sql语句的执行效率。反过来讲,使用绑定变量又给我们排查总成了一定的困难,使用了绑定变量的sql语句在大部分数据库诊断工具中不再显示sql语句执行时的值,而是显示绑定变量,这使我们难以准确判断到底时那条语句执行时出了问题。
行锁和缓冲区忙等待事件是dba经常遇到的,有一个场景比较常见,就是有个一表有多个应用访问,而对这个表的访问恰恰造成了行锁或缓冲区忙,导致大量会话被阻塞
这时候需要判断是哪个应用的异常导致了会话的阻塞,由于语句是使用了绑定变量,在awr报告或ash报告中看不到sql执行时的具体值,这个时候如果能够看到sql语句执行时的具体值,从这些值就能判断出哪个或哪些应用出了问题,缩小故障范围。
获得绑定变量可以用orace 的10046事件,10046是Oracle的内部事件(event),通过设置这个事件可以获得Oracle内部执行系统解析、调用、等待、绑定变量等详细的trace信息,在数据库性能分析方面有着重要的作用。10046 我们常用到1,4,8,12 四个不同的等级,1 相当于打开sql_trace,4在1的基础上增加了绑定变量,8在1的基础上增加了等待事件,12 在1级的输出基础上增加了绑定变量和等待事件,获得绑定变量的信息,用等级4就可以。
监控当前会话直接设置10046事件即可,想要获得其它会话的绑定变量信息,可以用oradebug,或者dbms.dbms_monitor、DBMS_SYSTEM 包设置10046 事件,具体的步骤如下所述。
2 使用dbms_monitor包获得sql语句执行时的绑定变量
使用dbms_monitor包跟踪其它会话,首先要获得要跟踪会话的sid(会话id)和serial#,当数据库中有大量被阻塞会话使,可以从v$session视图中查询到阻塞会话(blocking session)的sid,然后在v$session中查询这个会话的serial#。在实验的时候,在被跟踪的会话中运行下面的命令获得会话sid。
SQL> select userenv('sid') from dual;
USERENV('SID')
--------------
440
获得要跟踪会话的sid之后,就要取得这个会话的查询的serial#及tracefile,虽然我们使用dbms_monitor包跟踪其它会话,跟踪产生的trace文件是被跟踪会话的tracefile,而不是我们运行dbms_monitor包的这个会话,这个如果弄错了,会查不到跟踪的内容。
serial#可以在v$session中获得,tracefile需要从v$process中获得,join这两个视图,可以查询到会话的serial#和tracefile。
SQL> select a.sid,a.serial#, b.spid, b.TRACEFILE from v$session a , v$process b where a.paddr=b.ADDR and a.sid=440;
SID SERIAL# SPID
---------- ---------- ------------------------
TRACEFILE
--------------------------------------------------------------------------------
440 56821 4093
/opt/oracle/diag/rdbms/orclcdb/ORCLCDB/trace/ORCLCDB_ora_4093.trc
exec
取得必要的信息后,就可以使用dbms_monitor包激活这个会话的10046事件了,使用下面这个语句:
dbms_monitor.session_trace_enable(session_id=>440,serial_num=>56821,waits=>true,binds=>true);
上面的语句中第一个参数是sid,第二个参数是serial#,这两个参数的值也可以用''包括起来,如果用双引号就会报错。waits和binds都是true,在跟踪信息中包括等待事件和绑定变量。
在被跟踪的会话中执行一条语句
SQL> update test set salary=2000 where id=2;
1 row updated.
在跟踪会话中运行下面语句,关闭会话跟踪。
exec dbms_monitor.session_trace_disable(session_id=>440,serial_num=>56821);
查询一下跟踪文件
SQL> !more /opt/oracle/diag/rdbms/orclcdb/ORCLCDB/trace/ORCLCDB_ora_4093.trc
PARSING IN CURSOR #140411130438576 len=332 dep=1 uid=0 oct=3 lid=0 tim=64183077659 hv=2698389488 ad='68d79de8' sqlid='ac
mvv4fhdc9zh'
select obj#,type#,ctime,mtime,stime, status, dataobj#, flags, oid$, spare1, spare2, spare3, signature, spare7, spare8, s
pare9, nvl(dflcollid, 16382), creappid, creverid, modappid, modverid, crepatchid, modpatchid from obj$ where owner#=:1 a
nd name=:2 and namespace=:3 and remoteowner is null and linkname is null and subname is null
END OF STMT
PARSE #140411130438576:c=173,e=173,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=4,plh=813480514,tim=64183077658
BINDS #140411130438576:
Bind#0
oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
oacflg=00 fl2=1000001 frm=00 csi=00 siz=176 off=0
kxsbbbfp=7fb4038d01e0 bln=22 avl=03 flg=05
value=109
Bind#1
oacdty=01 mxl=128(04) mxlc=00 mal=00 scl=00 pre=00
oacflg=10 fl2=0001 frm=01 csi=873 siz=0 off=24
kxsbbbfp=7fb4038d01f8 bln=128 avl=04 flg=01
value="TEST"
Bind#2
oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
oacflg=00 fl2=1000001 frm=00 csi=00 siz=0 off=152
kxsbbbfp=7fb4038d0278 bln=22 avl=02 flg=01
value=1
上面截取的是跟踪文件的一部分,由于是第一运行这个语句,需要对这个语句及逆行硬解析,上面的语句是运行硬解析时运行的一条语句,在obj$视图中查询要对象信息,这条语句有三个绑定变量,在语句中分别用:1,:2,:3来表示,它们的实际值在bind#0,bind#1,bind#2中,
绑定变量1 是owner#,这个值是数值类型,值是109,查一下这个owner下的对象
SQL> l
1* select obj#, owner#,name from obj$
SQL> a where owner#=109;
1* select obj#, owner#,name from obj$ where owner#=109
SQL> /
OBJ# OWNER# NAME
---------- ---------- ---------
76281 109 SYS_C008220
76280 109 TEST
76290 109 TEST2
再查一下这个owner的name
SQL> select username from dba_users where user_id=109;
USERNAME
--------------------------------------------------------------------------------
TEST
正式我们被跟踪会话登录数据库时的用户名。
第二个绑定变量是名字,从obj$的定义从我们可以知道这个名字是对象名,它的值是TEST,正好是更新语句的表名。
3 使用oradebug跟踪其它会话
使用oradebug跟踪其它会话要获得被跟踪会话的oracle pid后os pid,这里我们获得会话的oacle pid。
同样,先获得要跟踪会话的sid,在被跟踪会话中运行下面的查询语句。
SQL> select userenv('sid') from dual;
查询进程的oracle pid
SQL> select a.sid, b.pid from v$session a ,v$process b where a.paddr=b.addr and a.sid=30;
SID PID
---------- ----------
30 66
设置oradebug会话为跟踪会话
SQL> oradebug setorapid 66
Oracle pid: 66, Unix process pid: 4134, NID: 4026531836, image:
从命令的输出可以看到会话的oracle pid是66,os pid是4134.
oracle@iZ2ze0t8khaprrpfvmevjiZ
检查一下当前的tracefile命名
SQL> oradebug tracefile_name
/opt/oracle/diag/rdbms/orclcdb/ORCLCDB/trace/ORCLCDB_ora_4134.trc
tracefile名字中包含被跟踪会话的os pid。
如果需要更改一下trace file的名字,便于查找,可以在被跟踪的会话内更改tracefile标识符
SQL> alter session set tracefile_identifier=test;
回到监控会话,tracefile_name已经改变
SQL> oradebug tracefile_name
/opt/oracle/diag/rdbms/orclcdb/ORCLCDB/trace/ORCLCDB_ora_4134_TEST.trc
设置oradebug的会话后,就可以打开会话的10046 事件了,用下面的命令,打开10046 4级事件。
SQL> oradebug event 10046 trace name context forever,level 4;
Statement processed.
等一段时间后,用下面命令关闭打开的事件
SQL> oradebug event 10046 trace name context off;
Statement processed.
看一下跟踪文件
SQL> !more /opt/oracle/diag/rdbms/orclcdb/ORCLCDB/trace/ORCLCDB_ora_4134_TEST.trc
PARSING IN CURSOR #139953117550368 len=39 dep=0 uid=109 oct=6 lid=109 tim=66133499254 hv=3517068083 ad='664ffb90' sqlid=
'54b1ft78u4ctm'
update test2 set salary=1500 where id=3
END OF STMT
PARSE #139953117550368:c=61181,e=63361,p=0,cr=599,cu=0,mis=1,r=0,dep=0,og=1,plh=1989979325,tim=66133499254
EXEC #139953117550368:c=243,e=243,p=0,cr=2,cu=3,mis=0,r=1,dep=0,og=1,plh=1989979325,tim=66133499544
STAT #139953117550368 id=1 cnt=0 pid=0 pos=1 obj=76290 op='UPDATE TEST2 (cr=2 pr=0 pw=0 str=1 time=178 us)'
STAT #139953117550368 id=2 cnt=1 pid=1 pos=1 obj=76290 op='TABLE ACCESS FULL TEST2 (cr=2 pr=0 pw=0 str=1 time=47 us cost
=3 size=7 card=1)'
可以看到跟踪的结果,绑定变量已在前面介绍,这里就不再重述了。
4 DBMS_SYSTEM包
DBMS_SYSTEM包的用法和dbms_monitor包类似,只是语法上稍有不同,这里不再介绍。