逻辑读时的cbc latch(二)

继续验证，使用solaris中的dtrace

session1:编写dtrace脚本

more test.d#!/usr/sbin/dtrace -s -ndtrace:::BEGIN{        i=1;}pid$1:::entry{        printf("i=%d PID::entry:==%s:%s:%s:%s %x %x %x %x %x %x",i, probeprov, probemod, probefunc, probename,arg0,arg1,arg2,arg3,arg4,arg5);        i=i+1;}

session2:多执行几次rowid查询，使查询走逻辑读

create table a as select * from scott.emp;create index ind_a on a(empno);select c.sid,spid,pid,a.SERIAL# from (select sid from v$mystat where rownum<=1) c,v$session a,v$process b where c.sid=a.sid and a.paddr=b.addr;       SID SPID                PID    SERIAL#---------- ------------ ---------- ----------       159 1154                 15          3       select * from a where rowid='AAAMjsAABAAAOs6AAA';

session1:运行dtrace脚本，并输出到日志

./test.d 1154 > logic_read1.log

session2:再次执行一次，此时为逻辑读

select * from a where rowid='AAAMjsAABAAAOs6AAA';

session1:查询文件，文件内容为语句执行期间做的跟踪

cat logic_read1.log|wc -l1393

session2:

select dbms_rowid.ROWID_RELATIVE_FNO('AAAMjsAABAAAOs6AAA'),dbms_rowid.rowid_block_number('AAAMjsAABAAAOs6AAA') from dual;1 60218select file#,dbablk,tch,lower(HLADDR) from x$bh where file#=1 and dbablk=60218;     FILE#     DBABLK        TCH LOWER(HL---------- ---------- ---------- --------         1      60218          8 5f0f596c

1号文件60218号块，是受地址为5f0f596c的Latch保护

session1:

cat logic_read1.log|grep 5f0f596c  1 113271                  sskgslcas:entry i=637 PID::entry:==pid1154:oracle:sskgslcas:entry 5f0f596c 0 2000000f fdc1a128 fdc1a0d0 fdc1a128  1 113274                 sskgsldecr:entry i=646 PID::entry:==pid1154:oracle:sskgsldecr:entry 5f0f596c 2000000f fdc1a128 fdc1a0d0 fdc1a128 804534c  1 113271                  sskgslcas:entry i=687 PID::entry:==pid1154:oracle:sskgslcas:entry 5f0f596c 0 2000000f 1 fdc1a0c0 5854e074  1  59436                     kcbzar:entry i=692 PID::entry:==pid1154:oracle:kcbzar:entry 5f181bcc 5f0f596c 108000 8045268 1 fdc1a0c0  1 103456                   slmxnoop:entry i=693 PID::entry:==pid1154:oracle:slmxnoop:entry 587ed578 fdc1a130 5f0f596c 8045238 a9ef965 c4a88d0  1 103456                   slmxnoop:entry i=694 PID::entry:==pid1154:oracle:slmxnoop:entry 587ed578 fdc1a130 5f0f596c 8045238 a9ef965 c4a88d0  1 103456                   slmxnoop:entry i=695 PID::entry:==pid1154:oracle:slmxnoop:entry 587ed578 fdc1a130 5f0f596c 8045238 a9ef965 c4a88d0  1 103456                   slmxnoop:entry i=696 PID::entry:==pid1154:oracle:slmxnoop:entry 587ed578 fdc1a130 5f0f596c 8045238 a9ef965 c4a88d0  1 103456                   slmxnoop:entry i=697 PID::entry:==pid1154:oracle:slmxnoop:entry 587ed578 fdc1a130 5f0f596c 8045238 a9ef965 c4a88d0  1 103456                   slmxnoop:entry i=699 PID::entry:==pid1154:oracle:slmxnoop:entry 587ed578 fdc1a130 5f0f596c 8045238 a9ef965 c4a88d0  1 113274                 sskgsldecr:entry i=701 PID::entry:==pid1154:oracle:sskgsldecr:entry 5f0f596c 2000000f 1 fdc1a0c0 5854e074 8045410  1  54264                     k***mf:entry i=703 PID::entry:==pid1154:oracle:k***mf:entry 5f181ba8 5f0bcc2c 587ed578 2000000f 5f0f596c 5f181bcc

和这个地址(5f0f596c)相关的有这十几行。在这里，有一点编程习惯再说一下，要申请某一个地址处的Latch，这个Latch的地址，是这个函数的最重要的参数，

因此，Oracle会把它排在第一位，也就是说，以上这十几行中，第一个参数不是8ea1d750的，基本可以排除掉了。

所以，我们只剩这些行需要关注:

  1 113271                  sskgslcas:entry i=637 PID::entry:==pid1154:oracle:sskgslcas:entry 5f0f596c 0 2000000f fdc1a128 fdc1a0d0 fdc1a128  1 113274                 sskgsldecr:entry i=646 PID::entry:==pid1154:oracle:sskgsldecr:entry 5f0f596c 2000000f fdc1a128 fdc1a0d0 fdc1a128 804534c  1 113271                  sskgslcas:entry i=687 PID::entry:==pid1154:oracle:sskgslcas:entry 5f0f596c 0 2000000f 1 fdc1a0c0 5854e074  1 113274                 sskgsldecr:entry i=701 PID::entry:==pid1154:oracle:sskgsldecr:entry 5f0f596c 2000000f 1 fdc1a0c0 5854e074 8045410

这四行，两个函数调用，sskgslcas、sskgsldecr，

第一个参数都是Latch的地址：5f0f596c 我相信这不是巧合，它们肯定是申请、释放Latch的函数。

i=637这行，Oracle调用sskgslcas持有Latch，在i=646这行，调用sskgsldecr释放，

接下来在i=687又一次调用sskgslcas持有Latch，在i=701处调用sskgsldecr释放。

一次逻辑读对应两次Latch调用。

结果是这样吗，让我们继续验证，Oracle的Oradebug可以调用某个Oracle自身的函数，就有它来验证吧：

session2:

SQL> oradebug setmypidStatement processed.SQL> oradebug call sskgslcas 0x5f0f596c 0 0x2000000f 0xfdc1a128Function returned 1SQL>select * from a where rowid='AAAMjsAABAAAOs6AAA';Hang住了

session3:查看等等事件，并释放latch

SQL> select sid,event,p1raw,p2 from v$session where sid=159;       SID EVENT---------- ----------------------------------------------------------------P1RAW            P2-------- ----------       159 latch: cache buffers chains5F0F596C        122SQL> oradebug setospid 1154Oracle pid: 15, Unix process pid: 1154, p_w_picpath: oracle@sol (TNS V1-V3)SQL> oradebug call sskgsldecr 0x5f0f596c 0x2000000fFunction returned 2000000F

在session2中查看，此时结果出来了。说明被Hang的会话，已经可以顺利执行下去了。说明Latch已经被释放。

结论：一次逻辑读，两次cbc latch，cbc latch的申请函数为sskgslcas，释放函数为sskgsldecr

逻辑读时的cbc latch(一)：http://qhd2004.blog.51cto.com/629417/1576554

逻辑读时的cbc latch(三): http://qhd2004.blog.51cto.com/629417/1577532

参考：http://blog.itpub.net/321157/viewspace-730936/