Oracle 11g下如何捕捉library cache对象执行时产生的lock、pin等
我们知道使用10049 event可以跟踪语句执行过程中在library cache对象上产生的lock和pin的动作,但此方法仅在Oracle 10g版本下有效,11g下另有他法。
先来回顾一下10g里是怎么做的
//////////////////////////
// ORACLE 10gR2 下的测试
//////////////////////////
###创建测试表,执行测试SQL语句
drop table t2;
create table system.t2 as select * from all_users;
select * from system.t2 where user_id<50;
###获取语句hash value,转成16进制
select to_char(hash_value,'xxxxxxxxxx') from v$sql where sql_text like 'select * from system.t2 where user_id<%';
TO_CHAR(HAS
-----------
200eeb23
0xEB23|(0x2000+0x0010+0x0020)=0xEB232030=3944947760
注:
0xEB23是sql语句hash value转换成16进制以后的低4位数
0x2000表示"DUMP BY HASH VALUE"
0x0010表示"trace lock operations"
0x0020表示"trace pin operations"
###使用10049对语句进行trace
oradebug setmypid
oradebug event 10049 trace name context forever,level 3944947760;
Session altered.
select * from system.t2 where user_id<50;
oradebug tracefile_name
/oracle/app/oracle/admin/pboss/udump/pboss1_ora_2093188.trc
### .trc文件输出
cat /oracle/app/oracle/admin/pboss/udump/pboss1_ora_2093188.trc
*** 2016-04-26 10:53:00.346
*** ACTION NAME:() 2016-04-26 10:53:00.339
*** MODULE NAME:(sqlplus@qb550135 (TNS V1-V3)) 2016-04-26 10:53:00.339
*** SERVICE NAME:(SYS$USERS) 2016-04-26 10:53:00.339
*** SESSION ID:(1713.37581) 2016-04-26 10:53:00.339
KGLTRCLCK kglget hd = 0x7000001a3c2c860 KGL Lock addr = 0x7000001b2ad5800 mode = N <---因为本次是软解析所以输出较少我们再看一下硬解析的情况
###清空shared_pool后再次进行10049 trace
alter system flush shared_pool;
oradebug setmypid
oradebug event 10049 trace name context forever,level 3944947760;
Session altered.
select * from system.t2 where user_id<50;
oradebug tracefile_name
/oracle/app/oracle/admin/pboss/udump/pboss2_ora_2445438.trc
### .trc文件输出
cat /oracle/app/oracle/admin/pboss/udump/pboss2_ora_2445438.trc
*** SESSION ID:(2137.39198) 2016-04-26 11:12:04.699
KGLTRCLCK kglget hd = 0x7000001996e6eb8 KGL Lock addr = 0x7000001b00d2b38 mode = N
KGLTRCPIN kglpin hd = 0x7000001996e6eb8 KGL Pin addr = 0x7000001c0b81780 mode = X
KGLTRCPIN kglpndl hd = 0x7000001996e6eb8 KGL Pin addr = 0x7000001c0b81780 mode = X
KGLTRCLCK kglget hd = 0x700000153b8b5f8 KGL Lock addr = 0x7000001be110888 mode = N
KGLTRCPIN kglpin hd = 0x700000153b8b5f8 KGL Pin addr = 0x7000001b1204900 mode = X
KGLTRCPIN kglpndl hd = 0x700000153b8b5f8 KGL Pin addr = 0x7000001b1204900 mode = X
KGLTRCLCK kgllkdl hd = 0x700000153b8b5f8 KGL Lock addr = 0x7000001be110888 mode = N
KGLTRCLCK kgllkdl hd = 0x7000001996e6eb8 KGL Lock addr = 0x7000001b00d2b38 mode = N
###在x$kglob里查看上述handle address所代表的library cache里的对象
col KGLNAOWN format a10
col KGLNAOBJ format a58
col KGLHDOBJ format a25
set linesize 160
select kglhdadr,KGLHDPAR,KGLNAOWN,KGLNAOBJ,KGLNAHSH,KGLHDOBJ from x$kglob where kglhdadr=hextoraw(upper('7000001996e6eb8'));
KGLHDADR KGLHDPAR KGLNAOWN KGLNAOBJ KGLNAHSH KGLHDOBJ
---------------- ---------------- ---------- ---------------------------------------------------------- ---------- -------------------------
07000001996E6EB8 07000001996E6EB8 select * from system.t2 where user_id<:"SYS_B_0" 537848611 07000001B16EE9C8
select kglhdadr,KGLHDPAR,KGLNAOWN,KGLNAOBJ,KGLNAHSH,KGLHDOBJ from x$kglob where kglhdadr=hextoraw(upper('700000153b8b5f8'));
KGLHDADR KGLHDPAR KGLNAOWN KGLNAOBJ KGLNAHSH KGLHDOBJ
---------------- ---------------- ---------- ---------------------------------------------------------- ---------- -------------------------
0700000153B8B5F8 07000001996E6EB8 select * from system.t2 where user_id<:"SYS_B_0" 537848611 07000001A2B80210
其中07000001996E6EB8是父游标的handle address、0700000153B8B5F8是子游标的handle address
###对Trace得到的内容作一下总结
(1) 在父游标上获取Null模式的lock
(2) 在父游标上获取Exclusive模式的pin
(3) 释放父游标上Exclusive模式的pin
(4) 在子游标上获取Null模式的lock
(5) 在子游标上获取Exclusive模式的pin
(6) 释放子游标上Exclusive模式的pin
(7) 释放子游标上Null模式的lock
(8) 释放父游标上Null模式的lock
oracle 11g里该如何实现跟踪?
如果要在11g Trace出这些内容,使用10049 event时无效的,因为在11g里功能更强大的隐含参数_kgl_debug替代了原先的10049 event。
_kgl_debug参数可以在系统或者会话级别灵活设定跟踪对象,这个对象可以是table、index等object,也可以library cache里的一条语句
跟踪scott.t2这个对象:
alter session set "_kgl_debug"="name='T2' schema='SCOTT' namespace=1 debug=96"
其中namespace为1时表示:table/view/sequence/synonym等类型的object
其中namespace为2时表示:package body/type body等类型的object
debug=96表示仅针对lock和pin执行trace操作:
Trace Locks:0x20
Trace Pins:0x40
Trace Locks + Trace Pins=0x60=96
跟踪full hash value为0c3fd8f8071f22064d99be791649a55f的语句:
alter session set "_kgl_debug"="hash='0c3fd8f8071f22064d99be791649a55f' debug=96";
注意这里的full hash_value来自于X$KGLOB.KGLNAHSV,如何得到这个值,后面会有详细介绍。
下面就来演示一下11g里Trace lock/pin的过程
//////////////////////////
// ORACLE 11gR2 下的测试
//////////////////////////
###创建测试表
create table scott.t0517_2 as select * from all_users;
select * from scott.t0517_2;
###获取SQL的hash_value
set linesize 150
select address,child_address,sql_id,hash_value from v$sql where sql_text like 'select * from scott.t0517_2';
ADDRESS CHILD_ADDRESS SQL_ID HASH_VALUE
---------------- ---------------- ------------- ----------
07000000BD3AEF00 07000000BD3AECB0 3ywd5md8ay2q0 1353648832
###根据hash_value找到KGLNAHSV
col KGLNAOWN format a30
col KGLNAOBJ format a30
set linesize 190
select kglhdadr,kglhdpar,kglnaown,kglnaobj,KGLNAHSH,KGLNAHSV from x$kglob where KGLNAHSH=1353648832;
KGLHDADR KGLHDPAR KGLNAOWN KGLNAOBJ KGLNAHSH KGLNAHSV
---------------- ---------------- ------------------------------ ------------------------------ ---------- --------------------------------
07000000BD3AECB0 07000000BD3AEF00 select * from scott.t0517_2 1353648832 45ecd74da55e32363f71a59b50af0ac0
07000000BD3AEF00 07000000BD3AEF00 select * from scott.t0517_2 1353648832 45ecd74da55e32363f71a59b50af0ac0
###session的Trace File名称
SQL> select value from v$diag_info where name='Default Trace File';
VALUE
------------------------------------------------------------------------------------------------------------------------------------------------------
/oradata06/tstdb1_diag/diag/rdbms/tstdb1/tstdb1/trace/tstdb1_ora_8193016.trc
###设置_kgl_debug同时跟踪表对象和SQL语句
alter system flush shared_pool;
alter session set "_kgl_debug"="name='T0517_2' schema='SCOTT' namespace=1 debug=96,hash='45ecd74da55e32363f71a59b50af0ac0' debug=96"; <---中间以逗号分隔
###执行语句
select * from scott.t0517_2;
###最后关闭_kgl_debug(将debug值设为0)
alter session set "_kgl_debug"="name='T0517_2' schema='SCOTT' namespace=1 debug=0,hash='45ecd74da55e32363f71a59b50af0ac0' debug=0"; <---中间以逗号分隔
因为我们设置_kgl_debug参数时指定了Scott.t0517_2表和"select * from scott.t0517_2"语句的作为Trace的对象,中间以逗号分隔,所以生成的TraceFile里既包含了Scott.t0517_2表上的
library cache lock/pin操作,也包含了"select * from scott.t0517_2"这条语句上的library cache lock/pin,Trace文件是按照xml格式组织的,以下是摘录的部分片段(来自于sql语句的跟踪):
<KGLTRACE>
<Timestamp>2016-05-18 12:50:01.066</Timestamp>
<SID>266</SID>
<Function>kgllkal</Function>
<Reason>TRACELOCK</Reason>
<Param1>7000000bda28ef8</Param1>
<Param2>0</Param2>
<LibraryHandle>
<Address>7000000bd9ef918</Address>
<Hash>50af0ac0</Hash>
<LockMode>N</LockMode>
<PinMode>0</PinMode>
<LoadLockMode>0</LoadLockMode>
<Status>VALD</Status>
<ObjectName>
<Name>select * from scott.t0517_2</Name>
<FullHashValue>45ecd74da55e32363f71a59b50af0ac0</FullHashValue>
<Namespace>SQL AREA(00)</Namespace> <---<Namespace>SQL AREA(00)</Namespace>表示对SQL的跟踪,如果是<Type>TABLE(02)</Type>则表示对
表的跟踪
<Type>CURSOR(00)</Type>
<Identifier>1353648832</Identifier>
<OwnerIdn>0</OwnerIdn>
</ObjectName>
</LibraryHandle>
<LibraryObjectLock>
<Address>7000000bda28ef8</Address>
<Handle>7000000bd9ef918</Handle>
<Mode>N</Mode>
</LibraryObjectLock>
</KGLTRACE>
针对"select * from scott.t0517_2"语句句柄的lock/pin相关操作所调用到的内核函数,从trace结果中按照调用先后顺序输出如下:
kglLock
kglHandleInitialize
kgllkal
kglLock
kglpin
kglobld
kglHandleInitialize
kglPin
kglUnPin
kglpndl
按我个人的理解kglHandleInitialize是在硬解析的时候构造存放SQL的handle address、kgllkal应该是用于分配lock address,kglobld用于将object装载进内存
与此类似对于表Scott.t0517_2也有这么一组内核函数完成加锁解锁的过程。
无论是lock还是pin都有三个模式属性LockMode、PinMode、LoadLockMode,每个模式属性都有N,S,X,0四种取值的可能性。
完整的Trace文件可以参考附件"tstdb1_ora_8193016.trc"
通过以上对比不难发现相比10g仅能输出游标的trace信息,11g引入了_kgl_debug参数后所能提供的library cache lock/pin信息跟踪选项更为全面,能对游标进行Trace也能对各object输出Trace信息,信息量更为丰富,当然读懂这些Trace需要具备更高的专业素养