Oracle 11g下如何捕捉library cache对象执行时产生的lock、pin等信息

197次阅读

共计 7741 个字符，预计需要花费 20 分钟才能阅读完成。

我们知道使用 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 需要具备更高的专业素养

更多 Oracle 相关信息见Oracle 专题页面 http://www.linuxidc.com/topicnews.aspx?tid=12

本文永久更新链接地址：http://www.linuxidc.com/Linux/2016-05/131883.htm

正文完

星哥玩云-微信公众号