讨厌香草冰激凌的汽车与Buffer busy wiats系列之二：揭密Buffer Pin

2020-06-29 00:00:00 会话调用进程阻塞释放

讨厌香草冰激凌的汽车与Buffer busy wiats系列之二：揭密Buffer Pin 本文是上篇文章“讨厌香草冰激凌的汽车与Buffer busy wiats的故事”（可在www.mythdata.com中查看）续篇。在本文中，将深入探索逻辑读的秘密（只是部分）。但是，本文难度系数会有些高，我将使用一些非常规手段，深入到Oracle内部，探索Oracle的秘密。我直接把结论写在前面，如果你Oracle对内部没啥兴趣，看一下结论，扩展一下思路就可以了。如果你对Oracle内部非常感兴趣，而且又有探索的欲望，哪么继续下去吧，我绝不会让你失望的。其实，探索Buffer busy waits的秘密，更多时候是为了满足好奇心。很多时候，探索出来的结果，可能对实际的调优排故，意义并不大。但，探索的过程，会让我们收获很多。我在阿里的后阶段，专门负责处理各种奇怪问题。到我手里的奇怪问题，无论是否重要，我一定会想方设法找到原因。在这一过程中，除了满足好奇心外，同时，我觉得自已也得到了很大的提高。不过，说实话，很多时候客户对于我得到的结果，并不关注。对于客户来说，数据库能跑、他们的应用正常无误，就一切OK了。但，我对自己将来的定位，不允许我马马虎虎。当逐渐失去了探索的欲望时，也正是我们变成熟练操作工的开始。要知道，时间的累积，并不能使你成为某一领域的大师，只能使你成为经验丰富的操作工。好，废话不说了，开始。

部分： Buffer Busy Waits的两个结论

在遇到了“讨厌香草冰激凌的汽车与Buffer busy waits的故事”这个案例之后，我对Buffer Busy Waits进行了次深入的分析，得到结论如下：一、兼容模式： 10G后的Buffer Busy Waits已经和以前大不一样了。不再是以前的读、写互相阻塞，或写、写互相阻塞。也不是有些网友说的读、写不阻塞，只有写、写阻塞。真实的Buffer Busy Waits，有如下两种情况：（1）、两个进程一同写一个Buffer，这是写、写阻塞。（2）、一个进程在写一个Buffer，另一个进程读。读的进程会有等待。这是写阻塞读。现在，Buffer Busy Waits，只有这两种情况了。有人说，如果一个进程先开始读一个Buffer，另一个进程又要写一个Buffer，这种情况下Oracle如何处理？读会阻塞写吗？答案是，不会。写的操作可以不需等待的马上开始，而正在进行的读操作，则会中止开始等待Buffer Busy Waits。这就是为什么在Buffer busy waits升高时，查找SQL语句，等待Buffer busy waits的大多数会话都是Select，很少有DML。因为DML不会被Select阻塞，只有DML间会互相阻塞。关于这一点，做个简单的测试就可以证明：在会话1运行如下脚本： declare j number; begin for i in 1..3000000 loop select id into j from a1 where rowid='AAAChqAAEAAAAAMAAA'; end loop; end; / 反复读取某一行。在会话2运行如下脚本： begin for i in 1..300 loop update a1 set id=id+0 where rowid='AAAChqAAEAAAAAMAAA'; end loop; commit; end; / 然后在V$SESSION_EVENT中查看两个Session的Buffer busy waits等待。会话1反复查询一行，会话2反复更新同一行300次，两个会话应该各有少许的Buffer busy waits，对吧。但实际情况不是这样的。会话2一般不会有，只有会话1会有Buffer busy wait等待。这就是写阻塞读、读在大部分情况下，不会阻塞写。当然，除了这种证明方法外，还有更加的方法，证明写阻塞读、读不阻塞写，我放在后面深入部分。二、减少Buffer busy waits的另类方法我在前一篇文章中，提到从宏观上减少Buffer busy waits等待的另一种方法，就是加快日志文件的写速度，使用更快的设备，放存Redo文件。原理是什么呢：进程在Buffer Cache中的某个Buffer加的锁，我称之为Buffer Pin。进程修改一个Buffer的过程，可以粗略的描述如下：（1）、加Cache buffers chains latch(下文中简称为CBC Latch) （2）、加Buffer Pin （3）、释放CBC Latch。（4）、将Redo信息拷贝到共享池的公有Redo区，或Log Buffer中。（5）、修改Buffer中的内容（6）、加CBC Latch （7）、释放Buffer Pin （8）、释放CBC Latch 1至3步，加CBC Latch，是为了加Buffer Pin。6至8步的CBC Latch，是释放Buffer pin。在加了Buffer Pin之后，主要要做的事情有两个，一个是修改Buffer中的内容。另一个，是拷贝Redo信息。减少Buffer busy waits，其实就是缩短Buffer Pin的持有时间。缩短Buffer Pin的持有时间，我们可以做的事情有两个，一个是加快第5步，“修改Buffer中的内容”。或者，是第4 步，拷贝Redo信息。在第5步，Oracle修改Buffer中内容，使用的是memcpy函数，这一步没什么好优化的了。但第4步拷贝Redo信息，还是可以调优的。在一定条件下，前台进程要将Redo信息直接拷贝到Log Buffer，而不是共享池中的私有Redo区。此时，如果Log Buffer中没有空间，遇到Log Buffer Space等待，前台进程要呼叫LGWR 刷新Log Buffer。一旦出现这种情况，Buffer Pin的持有时间不得不变的很长，直到Log buffer中有空间了，拷贝Redo信息结束，前台进程修改完Buffer中的内容。然后才会释放Buffer pin。因此，如果我们可以保证Log Buffer中总是有空间可用，就可以减少Log Buffer Space，从而减少前台进程呼叫LGWR的次数，从而在某些时候减少Buffer Pin的持有时间。这就是我在上一篇文章中，描述的加快Redo文件写速度，减少Buffer Busy Waits的原理。好，结论讨论完毕。下面是深层次原理部分，如果没啥兴趣，略过即可。

第二部分： Buffer Busy Waits探秘

工欲善其事，必先利其器。深入的探秘，没有好的工具可不行。我们平常探秘，只能使用Oracle提供的各种Event，比如10046等等，但在很多时候，它们也无法进入更加深入的底层。在此部分中，我们要使用的工具不再是任何Event，我的终极工具是GDB+DTrace。DTrace可以跟踪出Oracle每个函数调用，并且可以打印出各个参数的值。如果函数参数是指针，也可以将它所指向的内存块显示出来。当然也可以修改，但我们观察Oracle用，不需要修改。而GDB，做为大名鼎鼎的调试工具，其功能之强大，自不必多言。Oracle如一头奔腾的野马，我们要用 GDB让它慢下来、在需要的地方停下来，以便我们好好观察。 DTrace+GDB，可以让你发现很多Oracle的秘密。如果之前从没使用过此类工具，本文，让你对它们的功能有个大概了解。以后，我计划写个系列专题文章，详细介绍DTrace+GDB的使用。 Dtrace只能在Solaris平台使用，因此，如果你也想，深入到Oracle内部，装个Solaris吧。在开始之前，我们先来了解下Oracle逻辑读的大致过程，本文只围绕Buffer Pin相关的讨论，对逻辑读的其他环节，本文暂时不做深入探讨。首先，打开一个会话，查询得到它的SPID，然后，在会话中任意查询表的一行，我是这样查询的： select * from a1 where rowid='AAAChqAAEAAAAAMAAA'; 我们只观察逻辑读，所以要先执行一下这条语句。然后，编写如下DTRACE脚本： #!/usr/sbin/dtrace -s -n struct sembuf *sops; struct timespec *timeout; char *memnr; int mutexaddr,mut_pid; dtrace:::BEGIN { i=1; mut_pid=0; mutexaddr=0; } 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; } pid$1::sskgslcas:entry { mutexaddr=arg0; memnr=copyin(arg0,12); printf("[%2x%2x%2x%2x|%2x%2x%2x%2x|%2x%2x%2x%2x]",memnr[3],memnr[2],memnr[1],memnr[0],memnr[7],memnr[6],memnr[5],memnr[4],memnr[11],memnr[10],memnr [9],memnr[8]); 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; } pid$1::sskgslcas:return { memnr=copyin(mutexaddr,12); printf("[%2x%2x%2x%2x|%2x%2x%2x%2x|%2x%2x%2x%2x]",memnr[3],memnr[2],memnr[1],memnr[0],memnr[7],memnr[6],memnr[5],memnr[4],memnr[11],memnr[10],memnr [9],memnr[8]); printf("i=%d PID::entry:==%s:%s:%s:%s %x %x %x",i, probeprov, probemod, probefunc, probename,mutexaddr,arg0,arg1); i=i+1; } pid$1::kgxModifyRefCount:entry { mut_pid=arg0; mutexaddr=arg1; memnr=copyin(arg0,4); printf("[%2x%2x%2x%2x|",memnr[3],memnr[2],memnr[1],memnr[0]); memnr=copyin(arg1,16); printf("|%2x%2x%2x%2x|%2x%2x%2x%2x|%2x%2x%2x%2x|%2x%2x%2x%2x]", memnr[3],memnr[2],memnr[1],memnr[0],memnr[7],memnr[6],memnr[5],memnr[4],memnr[11],memnr[10],memnr[9],memnr[8],memnr[15],memnr[14],memnr[13],memnr[12]); 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; } pid$1::kgxModifyRefCount:return { memnr=copyin(mut_pid,4); printf("[%2x%2x%2x%2x|",memnr[3],memnr[2],memnr[1],memnr[0]); memnr=copyin(mutexaddr,16); printf("|%2x%2x%2x%2x|%2x%2x%2x%2x|%2x%2x%2x%2x|%2x%2x%2x%2x]", memnr[3],memnr[2],memnr[1],memnr[0],memnr[7],memnr[6],memnr[5],memnr[4],memnr[11],memnr[10],memnr[9],memnr[8],memnr[15],memnr[14],memnr[13],memnr[12]); 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; } pid$1::memcpy:entry { memnr=copyin(arg1,arg2); printf("%2x%2x%2x%2x%2x%2x%2x%2x%2x%2x%2x%2x%2x%2x%2x%2x%2x%2x%2x%2x", memnr[0],memnr[1],memnr[2],memnr[3],memnr[4],memnr[5],memnr[6],memnr[7],memnr[8],memnr[9], memnr[10],memnr[11],memnr[12],memnr[13],memnr[14],memnr[15],memnr[16],memnr[17],memnr[18],memnr[19]); printf("i=%d PID::entry:==%s:%s:%s:%s %x %x %d(END)",i, probeprov, probemod, probefunc, probename,arg0,arg1,arg2); i=i+1; } dtrace:::END { trace(i); } 我将脚本命名为all.d，你可以随意命名。然后，我们如下调用此脚本： ./all.d SPID >log.txt 假设我的SPID为1234，调用命令为：./all.d 1234 >log.txt （注意，DTrace脚本只能在Root下跑。）然后，在进程SPID为1234的会话中，再次执行： select * from a1 where rowid='AAAChqAAEAAAAAMAAA'; 查看log.txt，你可以看到Oracle调用的每个函数，格式如下： CPU ID FUNCTION:NAME 序号进程号参数1，参数2，………… ---- ----- --------------------- ----- ------------- ------ ------ ------------ ------------------------------------------- …………………… 3 87900 ktrget:entry i=509 PID::entry:==pid1034:oracle:ktrget:entry fdc0931c fdc092c4 243 0 100000c fdc09318 3 88312 ktsmg_max_query:entry i=510 PID::entry:==pid1034:oracle:ktsmg_max_query:entry 0 0 fdc0931c fdc09324 fdc09318 3f0 3 57758 kcbgtcr:entry i=511 PID::entry:==pid1034:oracle:kcbgtcr:entry fdc09324 0 243 0 fdc0931c fdc09324 …………………… 上例中，ktrget，是Oracle第509次调用的函数。它的个参数为fdc0931c，第二个参数为fdc092c4，第三个参数243，第四个参数0,……。 Ktrget是读取操作的开始。kcbgtcr，是完成逻辑读的函数。我已经探明的，kcbgtcr的个参数，此处值为fdc09324，这是前台进程中的一个内存地址。在此内存地址处，有一个结构（C语言中的Struct），其中包含有要读取的块的RDBA。好，闲言少叙，逻辑读是非常复杂的，我们今天还是专心点，只讨论和Buffer Pin相关的。其他的东西，我们慢慢再讨论。在不需要构造CR块时，逻辑读流程如下： 1、加Buffer Pin （1）、加CBC Latch （2）、加Buffer Pin （3）、释放CBC Latch。 2、读取Buffer中的行到PGA 3、释放Buffer Pin （1）、加CBC Latch （2）、释放Buffer Pin （3）、释放CBC Latch。所以，一次基本的逻辑读（通过ROWID访问一行，不需要构造CR块），需要审请、释放两次CBC Latch。一次为了在Buffer Header上加Buffer Pin，一次为了释放Buffer Pin。对应的函数调用如下： sskgslcas:entry i=519 PID::entry:==pid1034:oracle:sskgslcas:entry 5d973440 0 20000026 fdc0931c fdc092c4 fdc0931c sskgslcas:entry [ 0 0 0 0| 0 0 0 0| 0 0 07a]i=520 PID::entry:==pid1034:oracle:sskgslcas:entry 5d973440 0 20000026 fdc0931c fdc092c4 fdc0931c sskgslcas:return [20 0 026| 0 0 0 0| 0 0 07a]i=521 PID::entry:==pid1034:oracle:sskgslcas:return 5d973440 16 1 slmxnoop:entry i=522 PID::entry:==pid1034:oracle:slmxnoop:entry fdc0931c fdc092c4 fdc0931c 804541c 0 5e449c50 ktrexf:entry i=523 PID::entry:==pid1034:oracle:ktrexf:entry 8045448 557e68e4 0 0 1fe8 fdc0931c ktrexf:entry i=524 PID::entry:==pid1034:oracle:ktrexf:entry 8045448 5000b290 0 0 1fe8 fdc0931c slmxnoop:entry i=525 PID::entry:==pid1034:oracle:slmxnoop:entry fdc0931c fdc092c4 fdc0931c 804541c 0 5e449c50 slmxnoop:entry i=526 PID::entry:==pid1034:oracle:slmxnoop:entry fdc0931c fdc092c4 fdc0931c 804541c 0 5e449c50 slmxnoop:entry i=527 PID::entry:==pid1034:oracle:slmxnoop:entry fdc0931c fdc092c4 fdc0931c 804541c 0 5e449c50 slmxnoop:entry i=528 PID::entry:==pid1034:oracle:slmxnoop:entry fdc0931c fdc092c4 fdc0931c 804541c 0 5e449c50 slmxnoop:entry i=529 PID::entry:==pid1034:oracle:slmxnoop:entry fdc0931c fdc092c4 fdc0931c 804541c 0 5e449c50 slmxnoop:entry i=530 PID::entry:==pid1034:oracle:slmxnoop:entry fdc0931c fdc092c4 fdc0931c 804541c 0 5e449c50 sskgsldecr:entry i=531 PID::entry:==pid1034:oracle:sskgsldecr:entry 5d973440 20000026 fdc0931c fdc092c4 fdc0931c 804541c ktrvac:entry i=532 PID::entry:==pid1034:oracle:ktrvac:entry fdc092c4 5562c014 fdc0931c fdc09324 fdc09318 3f0 ktrgcm:entry i=533 PID::entry:==pid1034:oracle:ktrgcm:entry fdc0931c fdc0931c fdc09324 fdc09318 3f0 c030d18 kcbcge:entry i=534 PID::entry:==pid1034:oracle:kcbcge:entry fdc09324 0 fdc092c4 fdc0931c 8045428 54 kcbds2pbh:entry i=535 PID::entry:==pid1034:oracle:kcbds2pbh:entry fdc09324 0 fdc09158 5562c05c 0 55418014 ktcckv:entry i=536 PID::entry:==pid1034:oracle:ktcckv:entry fdc09324 fdc09158 0 fdc092c4 fdc0931c 8045428 kafger:entry i=537 PID::entry:==pid1034:oracle:kafger:entry 5562c064 8045594 59725244 2 1 1 kafcpy:entry i=538 PID::entry:==pid1034:oracle:kafcpy:entry 59725244 2 a9db4f2 1 59724d9c fdc09408 memcpy:entry i=539 PID::entry:==pid1034:libc.so.1:memcpy:entry fdc385c4 5562da81 28 1 fdc092b4 5562c064 memcpy:entry 6464646464642d2d2d2d2d2d2d2d2d2d2d2d2d2di=540 PID::entry:==pid1034:libc.so.1:memcpy:entry fdc385c4 5562da81 40(END) memcpy:entry i=541 PID::entry:==pid1034:libc.so.1:memcpy:entry fdc385ac 5562da7e 2 1 fdc092b4 5562c064 memcpy:entry c1 2 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0i=542 PID::entry:==pid1034:libc.so.1:memcpy:entry fdc385ac 5562da7e 2(END) kcbipnns:entry i=543 PID::entry:==pid1034:oracle:kcbipnns:entry fdc09324 a9db4f2 1 59724d9c fdc09408 8045270 kcbrls:entry i=544 PID::entry:==pid1034:oracle:kcbrls:entry fdc09324 a9db4f2 1 59724d9c fdc09408 8045270 slmxnoop:entry i=545 PID::entry:==pid1034:oracle:slmxnoop:entry 1 fdc092b4 5562c064 80454e4 fdbf824c fdc09158 sskgslcas:entry i=546 PID::entry:==pid1034:oracle:sskgslcas:entry 5d973440 0 20000026 1 fdc092b4 5562c064 sskgslcas:entry [ 0 0 0 0| 0 0 0 0| 0 0 07a]i=547 PID::entry:==pid1034:oracle:sskgslcas:entry 5d973440 0 20000026 1 fdc092b4 5562c064 sskgslcas:return [20 0 026| 0 0 0 0| 0 0 07a]i=548 PID::entry:==pid1034:oracle:sskgslcas:return 5d973440 16 1 slmxnoop:entry i=549 PID::entry:==pid1034:oracle:slmxnoop:entry 1 fdc092b4 5562c064 80454e4 fdbf824c fdc09158 slmxnoop:entry i=550 PID::entry:==pid1034:oracle:slmxnoop:entry 1 fdc092b4 5562c064 80454e4 fdbf824c fdc09158 slmxnoop:entry i=551 PID::entry:==pid1034:oracle:slmxnoop:entry 1 fdc092b4 5562c064 80454e4 fdbf824c fdc09158 slmxnoop:entry i=552 PID::entry:==pid1034:oracle:slmxnoop:entry 1 fdc092b4 5562c064 80454e4 fdbf824c fdc09158 kcbzar:entry i=553 PID::entry:==pid1034:oracle:kcbzar:entry 5da61640 5d973440 108000 8045338 1 fdc092b4 slmxnoop:entry i=554 PID::entry:==pid1034:oracle:slmxnoop:entry 557f2384 fdc09324 5d973440 8045308 fdbf824c 40c slmxnoop:entry i=555 PID::entry:==pid1034:oracle:slmxnoop:entry 557f2384 fdc09324 5d973440 8045308 fdbf824c 40c slmxnoop:entry i=556 PID::entry:==pid1034:oracle:slmxnoop:entry 557f2384 fdc09324 5d973440 8045308 fdbf824c 40c slmxnoop:entry i=557 PID::entry:==pid1034:oracle:slmxnoop:entry 557f2384 fdc09324 5d973440 8045308 fdbf824c 40c slmxnoop:entry i=558 PID::entry:==pid1034:oracle:slmxnoop:entry 557f2384 fdc09324 5d973440 8045308 fdbf824c 40c kcbzfw:entry i=559 PID::entry:==pid1034:oracle:kcbzfw:entry 557f2384 8045338 0 0 557f2384 fdc09324 slmxnoop:entry i=560 PID::entry:==pid1034:oracle:slmxnoop:entry 557f2384 fdc09324 5d973440 8045308 fdbf824c 40c slmxnoop:entry i=561 PID::entry:==pid1034:oracle:slmxnoop:entry 1 fdc092b4 5562c064 80454e4 fdbf824c fdc09158 sskgsldecr:entry i=562 PID::entry:==pid1034:oracle:sskgsldecr:entry 5d973440 20000026 1 fdc092b4 5562c064 80454e4 这里，我已经破解函数如下： sskgslcas ：加CBC Latch，或者Mutex。注意，Mutex也是用这个函数实现的，和CBC Latch一样，也就是说，从10G开始，CBC Latch，已经有点Mutex化了，已经在为过渡到Mutex作准备。关于Mutex，我也已经破解了一些单靠测试无法验证的东西，以后慢慢整理出来，继续关注我的BLOG吧：www.mythdata.com 。 sskgsldecr ：释放由sskgslcas加上的去的CBC Latch、或Mutex。其实，Mutex的释放很复杂，还要涉及减少“引用计数”的值，此处不再讨论。 kafger：读取数据。它的个参数，此处是5562c064，指向对应Buffer。我的Buffer地址为5562C000（可以从X$BH中的BA列得到），kafger的个参数比它稍大一点点。简单点说，它的个参数指向块的第100个字节。它把这里作为Oracle逻辑读的开始。如果你在开发绕过Oracle的直接块读取程序，详细了解Oracle在各种情况下逻辑读的完成方式，应该会对提高你的软件品质有所帮助。此函数将调用kafcpy。 kafcpy：完成数据拷贝的函数。它将数据从Buffer Cache拷贝到PGA。它会调用memcpy完成数据拷贝。 memcpy：这不是一个Oracle函数，这是系统调用。实际的完成数据拷贝任务。每个memcpy我用两行来显示，行显示Memcpy基本信息，第二行显示拷贝的内容。此处共调用两次Memcpy ，分别读取一行中的两列。读取第二列： memcpy:entry i=539 PID::entry:==pid1034:libc.so.1:memcpy:entry fdc385c4 5562da81 28 1 fdc092b4 5562c064 memcpy:entry 6464646464642d2d2d2d2d2d2d2d2d2d2d2d2d2di=540 PID::entry:==pid1034:libc.so.1:memcpy:entry fdc385c4 5562da81 40(END) 读取列： memcpy:entry i=541 PID::entry:==pid1034:libc.so.1:memcpy:entry fdc385ac 5562da7e 2 1 fdc092b4 5562c064 memcpy:entry c1 2 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0i=542 PID::entry:==pid1034:libc.so.1:memcpy:entry fdc385ac 5562da7e 2(END) kcbrls：释放逻辑读时的资源占用。它会再次调用sskgslcas，加CBC Latch，释放Buffer Pin。好了，大概来说明一下逻辑读的流程吧： 1：sskgslcas 加CBC Latch 2：从加CBC Latch到释放，中间有很多代码，Oracle作了很多事情，我确定其中之一是加Buffer Pin，因为可以用GDB作证明。 3：sskgsldecr 释放CBC Latch 4：调用kafger--》kafcpy--》memcpy，拷贝数据到PGA。 5：调用kcbrls 6：kcbrls调用sskgslcas，加CBC Latch。 7：kcbrls释放Buffer Pin 8: kcbrls调用sskgsldecr，释放CBC Latch 好，逻辑的大概流程是这样的。如果要构造CR块，会比这个更复杂些，这个以后再讲吧。下面，有了这些东西，要如何确定Select不会阻塞DML呢，单有DTrace还不够，要使用另一个终极武器：GDB。我们要做的事情，如下图：图1 图2 好，现在照着图上的操作开始。另开一个连接，以Oracle用户登录到OS，执行如下命令： gdb $ORACLE_HOME/bin/oracle 进程号假设此处，我们执行Select语句的会话，进程号是1234，我们执行如下命令：gdb $ORACLE_HOME/bin/oracle 1234。 $ gdb $ORACLE_HOME/bin/oracle 1234 GNU gdb 6.8 Copyright (C) 2008 Free Software Foundation, Inc. License GPLv3+: GNU GPL version 3 or later ………………执行结果附后……………… 0xfdddbca5 in _read () from /usr/lib/libc.so.1 (gdb)b kcbgtcr <---------------------------------------“b kcbgtcr”，是敲入的命令，b是设置断点命令，我们在kcbgtcr函数入口处设置断点。 Breakpoint 1 at 0x86f1d01 在1234进程对应的会话中，再次执行Select语句： select * from a1 where rowid='AAAChqAAEAAAAAMAAA'; 此语句的执行，将被GDB阻塞。回到GDB中 (gdb) c <----------------------------------“c”，是输入的命令，继续执行的意思 Continuing. Breakpoint 1, 0x086f1d01 in kcbgtcr () <--------此处代表已经执行到kcbgtcr 函数的入口处。 (gdb) b sskgsldecr <------------------------------------在释放CBC Latch的入口处设置断点。 Breakpoint 3 at 0xa949d00 (gdb) c <------------------继续执行到断点处。 Continuing. Breakpoint 2, 0x0a949d00 in sskgsldecr () 同时，另开一个会话，连接到Oracle中，使用DML修改同一行（同一块中的行都可），会发现修改操作被阻塞，等待事件还不是Buffer Busy Waits，是CBC Latch等待。因为我们的断点是在sskgsldecr处，释放CBC Latch的入口处，CBC Latch还没被释放。接下来，根据DTrace的跟踪结果，我们知道，在调用sskgsldecr释放CBC Latch后，接下来会调用ktrvac函数。我们在ktrvac处设置断点： (gdb) b ktrvac Breakpoint 4 at 0x9a63e27 (gdb) c Continuing. Breakpoint 3, 0x09a63e27 in ktrvac () 同时，我们可以发现，本来在等待CBC Latch的Update语句，已经不在等待了，Update一行已经成功。此时，其实Select已经在Buffer上加了Buffer Pin。但Select的Buffer Pin，并没有阻塞Update。接下来，我们可以依次在每个Select调用的函数处设置断点，ktrgcm、kcbcge、……，直到再次审请CBC Latch释放Buffer Pin。每执行到一个断点，都在另一个会话中执行一个Update，看下是否被阻塞。终可以发现，Select不会阻塞Update。但Update是否会阻塞Select？会的。测试方法和上面类似。我不再一一列出。简单描述下，Update会对要操作的Buffer上，审请、释放CBC Latch的操作，要进行多次。也就是在Update期间，要反复改变加在Buffer Header上的Buffer pin。次审请、释放CBC Latch之后，再用Update更新同一块中不同行，就开始等待Buffer Busy Waits了，不过，Select查询同一块中的行还不会阻塞。第二次审请、释放CBC Latch之后，Select也被阻塞，开始等待Buffer Busy Waits了。同时，Oracle会调用kcrfw_redo_gen函数，它会调用kslgetl，审请Redo Copy Latch和redo allocation，然后调用kcopre（也就是copy redo），kcopre则会调用OS系统函数Memcpy，向共享池或Log Buffer中拷贝日志信息。在完成这些调用时，Select和另一Update，一直在等待着Buffer Busy Waits。这就是为什么使用更快速的存储设备存放日志文件，可以减少Buffer Busy waits的原因。因为它减少了kcrfw_redo_gen、kcopre这些函数消耗的时间。第三次审请、释放CBC Latch之后，被阻塞的Select、DML可以成功执行。但马上再次执行DML修改同一块中不同行，又会被阻塞，还是在等待Buffer Busy Waits。这说明第三次审请、释放 CBC Latch时，有个短暂的释放Buffer Pin的操作。第四次审请、释放CBC Latch之后，Select又会被阻塞，不过，这次是在等待回滚块上的Buffer Busy Waits。当然，DML会一直在数据块上被阻塞的。再向下继续跟踪，阻塞就没有了。根据这些，已经足够我们得出结论。在第二次审请、释放CBC Latch之后，Select、DML都因Buffer Busy Waits被阻塞，要等到Oracle调用 kcrfw_redo_gen拷贝完Redo数据，阻塞才会消失。这就是为什么我们加快日志文件的写速度后，可以减少Buffer Busy Waits的原因。因为我们使用kcrfw_redo_gen函数完成的更快。另外，在进一步分析Buffer busy waits时，还有一个意外发现。在生成CR块时，cache buffers lru chain latch的获取，是包含在cache buffers chains latch之中的。这就意未着，在LRU上找寻可用Buffer的过程，是包含在cache buffers chains latch之中。如果可以加快搜寻LRU链的速度，这样会减少一致读时cache buffers chains latch的持有时间，从而降低 cache buffers chains latch争用。怎样才能加快搜寻LRU链的速度呢，简单的方法是加大Buffer cache。当然，还有一个方法，可以通过减少Buffer Cache中脏块的数量，来加快搜寻 LRU链的速度。这个道理很简单，脏块越少，寻找可用块的效率就越高。就像你去饭店吃饭，如果很多桌子都坐的有人，你找空位的速度就会慢点。如果桌子都空着，你会更快找到空位子。好，不再扯其他的了，关于这个问题，我以后另开帖子详细讲。继续关注我的BLOG吧：www.mythdata.com。好，本次深入Oracle之旅，就到这里吧。希望这次旅程，可以带给你不一样的体验。关于GDB、特别是DTrace的使用，还有Solaris测试环境的搭建，如果你不太熟，没关系，我已经计划写个系列专题，名称已经确定：Oracle揭秘之七种武器。名称响亮吧。 --------------------------------------------------------------------- 这是GDB的运行结果： $ gdb $ORACLE_HOME/bin/oracle 1234 GNU gdb 6.8 Copyright (C) 2008 Free Software Foundation, Inc. License GPLv3+: GNU GPL version 3 or later This is free software: you are free to change and redistribute it. There is NO WARRANTY, to the extent permitted by law. Type "show copying" and "show warranty" for details. This GDB was configured as "i386-pc-solaris2.10"... (no debugging symbols found) Attaching to program `/export/home/oracle/opt/product/10.2.0/bin/oracle', process 1034 Reading symbols from /export/home/oracle/opt/product/10.2.0/lib/libskgxp10.so...(no debugging symbols found)...done. Loaded symbols for /export/home/oracle/opt//product/10.2.0//lib/libskgxp10.so Reading symbols from /export/home/oracle/opt/product/10.2.0/lib/libhasgen10.so...(no debugging symbols found)...done. Loaded symbols for /export/home/oracle/opt//product/10.2.0//lib/libhasgen10.so Reading symbols from /export/home/oracle/opt/product/10.2.0/lib/libskgxn2.so...(no debugging symbols found)...done. Loaded symbols for /export/home/oracle/opt//product/10.2.0//lib/libskgxn2.so Reading symbols from /export/home/oracle/opt/product/10.2.0/lib/libocr10.so...(no debugging symbols found)...done. Loaded symbols for /export/home/oracle/opt//product/10.2.0//lib/libocr10.so Reading symbols from /export/home/oracle/opt/product/10.2.0/lib/libocrb10.so... (no debugging symbols found)...done. Loaded symbols for /export/home/oracle/opt//product/10.2.0//lib/libocrb10.so Reading symbols from /export/home/oracle/opt/product/10.2.0/lib/libocrutl10.so...(no debugging symbols found)...done. Loaded symbols for /export/home/oracle/opt//product/10.2.0//lib/libocrutl10.so Reading symbols from /export/home/oracle/opt/product/10.2.0/lib/libjox10.so...(no debugging symbols found)...done. Loaded symbols for /export/home/oracle/opt//product/10.2.0//lib/libjox10.so Reading symbols from /export/home/oracle/opt/product/10.2.0/lib/libclsra10.so...(no debugging symbols found)...done. Loaded symbols for /export/home/oracle/opt//product/10.2.0//lib/libclsra10.so Reading symbols from /export/home/oracle/opt/product/10.2.0/lib/libdbcfg10.so... (no debugging symbols found)...done. Loaded symbols for /export/home/oracle/opt//product/10.2.0//lib/libdbcfg10.so Reading symbols from /export/home/oracle/opt/product/10.2.0/lib/libnnz10.so...(no debugging symbols found)...done. Loaded symbols for /export/home/oracle/opt//product/10.2.0//lib/libnnz10.so Reading symbols from /usr/lib/libkstat.so.1...(no debugging symbols found)...done. Loaded symbols for /usr/lib/libkstat.so.1 Reading symbols from /usr/lib/libnsl.so.1...(no debugging symbols found)...done. Loaded symbols for /usr/lib/libnsl.so.1 Reading symbols from /usr/lib/libsocket.so.1... (no debugging symbols found)...done. Loaded symbols for /usr/lib/libsocket.so.1 Reading symbols from /usr/lib/libgen.so.1...(no debugging symbols found)...done. Loaded symbols for /usr/lib/libgen.so.1 Reading symbols from /usr/lib/libdl.so.1... warning: Lowest section in /usr/lib/libdl.so.1 is .hash at 00000094 (no debugging symbols found)...done. Loaded symbols for /usr/lib/libdl.so.1 Reading symbols from /usr/lib/libsched.so.1... warning: Lowest section in /usr/lib/libsched.so.1 is .dynamic at 00000074 (no debugging symbols found)...done. Loaded symbols for /usr/lib/libsched.so.1 Reading symbols from /usr/lib/libc.so.1... (no debugging symbols found)...done. Loaded symbols for /usr/lib/libc.so.1 Reading symbols from /usr/lib/librt.so.1...(no debugging symbols found)...done. Loaded symbols for /usr/lib/librt.so.1 Reading symbols from /usr/lib/libaio.so.1...(no debugging symbols found)...done. Loaded symbols for /usr/lib/libaio.so.1 Reading symbols from /usr/lib/libm.so.2...(no debugging symbols found)...done. Loaded symbols for /usr/lib/libm.so.2 Reading symbols from /usr/lib/libthread.so.1... warning: Lowest section in /usr/lib/libthread.so.1 is .dynamic at 00000074 (no debugging symbols found)...done. Loaded symbols for /usr/lib/libthread.so.1 Reading symbols from /usr/lib/libpthread.so.1... warning: Lowest section in /usr/lib/libpthread.so.1 is .dynamic at 00000074 (no debugging symbols found)...done. Loaded symbols for /usr/lib/libpthread.so.1 Reading symbols from /usr/lib/libmd.so.1...(no debugging symbols found)...done. Loaded symbols for /usr/lib/libmd.so.1 Reading symbols from /lib/ld.so.1...(no debugging symbols found)...done. Loaded symbols for /lib/ld.so.1 sol-thread active. Retry #1: Retry #2: Retry #3: Retry #4: [New LWP 1 ] [New Thread 1 (LWP 1)] Symbols already loaded for /export/home/oracle/opt//product/10.2.0//lib/libskgxp10.so Symbols already loaded for /export/home/oracle/opt//product/10.2.0//lib/libhasgen10.so Symbols already loaded for /export/home/oracle/opt//product/10.2.0//lib/libskgxn2.so Symbols already loaded for /export/home/oracle/opt//product/10.2.0//lib/libocr10.so Symbols already loaded for /export/home/oracle/opt//product/10.2.0//lib/libocrb10.so Symbols already loaded for /export/home/oracle/opt//product/10.2.0//lib/libocrutl10.so Symbols already loaded for /export/home/oracle/opt//product/10.2.0//lib/libjox10.so Symbols already loaded for /export/home/oracle/opt//product/10.2.0//lib/libclsra10.so Symbols already loaded for /export/home/oracle/opt//product/10.2.0//lib/libdbcfg10.so Symbols already loaded for /export/home/oracle/opt//product/10.2.0//lib/libnnz10.so Symbols already loaded for /usr/lib/libkstat.so.1 Symbols already loaded for /usr/lib/libnsl.so.1 Symbols already loaded for /usr/lib/libsocket.so.1 Symbols already loaded for /usr/lib/libgen.so.1 Symbols already loaded for /usr/lib/libdl.so.1 Symbols already loaded for /usr/lib/libsched.so.1 Symbols already loaded for /usr/lib/libc.so.1 Symbols already loaded for /usr/lib/librt.so.1 Symbols already loaded for /usr/lib/libaio.so.1 Symbols already loaded for /usr/lib/libm.so.2 Symbols already loaded for /usr/lib/libthread.so.1 Symbols already loaded for /usr/lib/libpthread.so.1 Symbols already loaded for /usr/lib/libmd.so.1 Symbols already loaded for /lib/ld.so.1 [Switching to Thread 1 (LWP 1)] 0xfdddbca5 in _read () from /usr/lib/libc.so.1 (gdb) <-------------------------------------------此处是gdb提示符，可以在此处输入命令。

相关文章