转载

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需要具备更高的专业素养

正文到此结束