最老的新技术：调试Oracle技术实战-在堆栈中寻找异常宕库原因-吕海波.pdf

《最老的新技术：调试Oracle技术实战-在堆栈中寻找异常宕库原因-吕海波.pdf》由会员分享，可在线阅读，更多相关《最老的新技术：调试Oracle技术实战-在堆栈中寻找异常宕库原因-吕海波.pdf（67页珍藏版）》请在三一文库上搜索。

1、最老的新技术：调试Oracle技术实战 -在堆栈中寻找异常宕库原因 ebay 首要数据库工程师 吕海波（VAGE） 内容简介 内容简介： 什么是调试Oracle技术 程序的机器级表示 断点 发现断点 神奇的等待事件：等待事件原理分析 案例 什么是调试Oracle技术 调试Oracle就是对Oracle进行逆向工程，再通俗点说，就是反汇编Oracle。 相信听到这个结果的朋友，一定会认为： 调试Oracle就是对Oracle进行逆向工程，再通俗点说，就是反汇编Oracle。 相信听到这个结果的朋友，一定会认为： 什么是调试Oracle技术 什么是调试Oracle技术 但其实不是这样的， Orac

2、le的逆向工程没有你想像中的哪么难。它是真正的纸老虎。 什么是调试Oracle技术：逆向工程 我们的目的，并不是要读懂Oracle每一条反汇编代码，我相信这不可能，代码量太 大了。我们只需要从反编代码找出我们感兴趣的片断即可。这样一来，难度就大大 下降，再借助现在优秀的调试工具，gdb/mdb和DTrace，对于有开发功底的DBA来 说，可以说易如反掌。 调试Oracle技术有什么用 在开始之前，还要回答一个问题： 为什么要这么做？或者，调试Oracle有什么用。 搞这么难的东西有什么用？ 调试Oracle技术有什么用 答案很简单，一是这东西其实没相像中哪么难。二是在我做DBA的职业生涯中，总

3、 有些疑难问题，让我有求神拜佛的冲动。 什么是调试Oracle技术 就像这样： 调试Oracle技术有什么用 或这样： 什么是调试Oracle技术 告诉浙江地区DBA一个经验， 我2010年初，去灵隐上完香之后，大半年内，事故率没有下降 2010年底去普陀山上完香之后，大半年内事故率下降了50% 什么是调试Oracle技术 除了去普陀山上香外，我想，我也要做点什么。不能老是麻烦神仙帮忙。 于是，我就开始了我的“调试Oracle”之旅。 程序的机器级表示 让我们从一个简单的小例子开始吧。 有个笑话，程序员准备练书法，提起狼毫笔，占足墨汁，在徽州宣纸上写下饱满的 程序的机器级表示 让我们从一个简单

4、的小例子开始吧。 有个笑话，程序员准备练书法，提起狼毫笔，占足墨汁，在徽州宣纸上写下饱满的 Holle word 程序的机器级表示 很可惜，我们不能Hello Word开始，它包含的元素太少了，我们从下面这个例子开 始。 它包含几个对我们来说最基本的元素：变量（局部变量、全局变量）、函数调用、 参数传递。 这个程序很简单，先了解一下它是干吗的。然后，我们就先从它开始。 int result; void add(int p1, int p2) result=p1+p2; return ; int main() int a,b; a=1; b=2; add(a,b); printf(“%d+%d=

5、%dn“,a,b,result); return 0; 程序的机器级表示 它包含几个对我们来说最基本的元素：变量（局部变量、全局变量）、函数调用、 参数传递。 右边是main函数的反汇编代码，我们逐条对照的了解一下它的意义，你就会发现， 其实这很简单。 main: pushq %rbp main+1: movq %rsp,%rbp main+4: subq $0x10,%rsp main+8: movl $0x1,-0x4(%rbp) main+0xf: movl $0x2,-0x8(%rbp) main+0x16: movl -0x8(%rbp),%esi main+0x19: movl -

6、0x4(%rbp),%edi main+0x1c: call -0x34 main+0x21: movl -0x8(%rbp),%edx main+0x24: movl -0x4(%rbp),%esi main+0x27: movl 0x103e3(%rip),%ecx main+0x2d: movl $0x400df0,%edi main+0x32: movl $0x0,%eax main+0x37: call -0x19f main+0x3c: movl $0x0,%eax main+0x41: leave main+0x42: ret int result; void add(int p

7、1, int p2) result=p1+p2; return ; int main() int a,b; a=1; b=2; add(a,b); printf(“%d+%d=%dn“,a,b,result); return 0; 程序的机器级表示 main: pushq %rbp main+1: movq %rsp,%rbp main+4: subq $0x10,%rsp main+8: movl $0x1,-0x4(%rbp) / a=1 main+0xf: movl $0x2,-0x8(%rbp) / b=2 main+0x16: movl -0x8(%rbp),%esi main+0x

8、19: movl -0x4(%rbp),%edi main+0x1c: call -0x34 main+0x21: movl -0x8(%rbp),%edx main+0x24: movl -0x4(%rbp),%esi main+0x27: movl 0x103e3(%rip),%ecx main+0x2d: movl $0x400df0,%edi main+0x32: movl $0x0,%eax main+0x37: call -0x19f main+0x3c: movl $0x0,%eax main+0x41: leave main+0x42: ret int result; void

9、 add(int p1, int p2) result=p1+p2; return ; int main() int a,b; a=1; b=2; add(a,b); printf(“%d+%d=%dn“,a,b,result); return 0; “xx(%rbp)” 这样形式的， 括号中是rbp的，都是局部 变量。 另外，补充一点基础知识，xx(%rbp)，这种方式叫“基址加偏移量 寻址”。rbp中保存一个内存地址，也就是“基址”，此基址加上偏移量xx， 就是我们这里要操作的目标内存。打个比方，“天安门广场向东100米”， 等于：100米（天安门广场）。基址是“天安门广场”，偏移量是10

10、0米。 程序的机器级表示 main: pushq %rbp main+1: movq %rsp,%rbp main+4: subq $0x10,%rsp main+8: movl $0x1,-0x4(%rbp) / a=1 main+0xf: movl $0x2,-0x8(%rbp) / b=2 main+0x16: movl -0x8(%rbp),%esi main+0x19: movl -0x4(%rbp),%edi main+0x1c: call main+0x1c: call - -0x34 0x34 main+0x21: movl -0x8(%rbp),%edx main+0x24:

11、 movl -0x4(%rbp),%esi main+0x27: movl 0x103e3(%rip),%ecx main+0x2d: movl $0x400df0,%edi main+0x32: movl $0x0,%eax main+0x37: call -0x19f main+0x3c: movl $0x0,%eax main+0x41: leave main+0x42: ret int result; void add(int p1, int p2) result=p1+p2; return ; int main() int a,b; a=1; b=2; add(a,b); print

12、f(“%d+%d=%dn“,a,b,result); return 0; 将变量a,b传到esi和edi 中作为参数，为调用 add函数作准备 调用add函数 注意这里，64位系统中，调用函数传递参数时，第一个参 数只能放在rdi中，第二个参数只能在 rsi中，第三、第四等 等参数，只能依次放入： rdx, rcx, rbx, r8, r9, r10, 等寄存 器中。 程序的机器级表示 add: pushq %rbp add+1: movq %rsp,%rbp add+4: movl %edi,-0x4(%rbp) / p1=1 add+7: movl %esi,-0x8(%rbp) / p2

13、=2 add+0xa: movl -0x8(%rbp),%eax / eax=p1 add+0xd: addl -0x4(%rbp),%eax / eax=eax+p2 add+0x10: movl %eax,0x10412(%rip) / result=eax add+0x16: leave add+0x17: ret int result; void add(int p1, int p2) result=p1+p2; return ; int main() int a,b; a=1; b=2; add(a,b); printf(“%d+%d=%dn“,a,b,result); return

14、 0; “xxx(%rip)”这样形式的东 西，代表是全局变量 “-0x4(%rbp)”和“- 0x8(%rbp)”是局部变量。 Edi和esi中是调用者要传 递的第一、二个参数。 这两步的意义，是将参 数值传递到变量p1和p2 中。 用以下两步完成一个加法： Eax=p1; Eax=eax+p2; 程序的机器级表示 main: pushq %rbp main+1: movq %rsp,%rbp main+4: subq $0x10,%rsp main+8: movl $0x1,-0x4(%rbp) / a=1 main+0xf: movl $0x2,-0x8(%rbp) / b=2 main

15、+0x16: movl -0x8(%rbp),%esi main+0x19: movl -0x4(%rbp),%edi main+0x1c: call -0x34 main+0x21: movl -0x8(%rbp),%edx /第三个参数,变量b main+0x24: movl -0x4(%rbp),%esi /第二个参数,变量a main+0x27: movl 0x103e3(%rip),%ecx /第四个参数,result main+0x2d: movl $0x400df0,%edi /第一个参数,格式字符 串 main+0x32: movl $0x0,%eax main+0x37: c

16、all -0x19f /调用printf main+0x3c: movl $0x0,%eax main+0x41: leave main+0x42: ret int result; void add(int p1, int p2) result=p1+p2; return ; int main() int a,b; a=1; b=2; add(a,b); printf(“%d+%d=%dn“,a,b,result); return 0; 函数的参数，会依次 放入rdi, rsi, rdx, rcx, rbx, r8, r9, r10, 等寄存器 程序的机器级表示 main: pushq %rb

17、p main+1: movq %rsp,%rbp main+4: subq $0x10,%rsp main+8: movl $0x1,-0x4(%rbp) / a=1 main+0xf: movl $0x2,-0x8(%rbp) / b=2 main+0x16: movl -0x8(%rbp),%esi main+0x19: movl -0x4(%rbp),%edi main+0x1c: call -0x34 main+0x21: movl -0x8(%rbp),%edx /第三个参数,变量b main+0x24: movl -0x4(%rbp),%esi /第二个参数,变量a main+0x

18、27: movl 0x103e3(%rip),%ecx /第四个参数,result main+0x2d: movl $0x400df0,%edi /第一个参数,格式字符串 main+0x32: movl $0x0,%eax main+0x37: call -0x19f /调用printf main+0x3c: movl $0x0,%eax main+0x41: leave main+0x42: ret int result; void add(int p1, int p2) result=p1+p2; return ; int main() int a,b; a=1; b=2; add(a,b

19、); printf(“%d+%d=%dn“,a,b,result); return 0; 函数的返回值放入eax 寄存器。 程序的机器级表示 阅读反汇编代码，难吗？只是传说中很难。所以说，一切帝国主义，都是： 程序的机器级表示 更多信息，请参考深入理解计算机系统第三章，此章的名字就是“程序 的机器级表示”。 在此章中，有详细的C语言的条件、分支和各种循环和汇编的对应关系。读 完这章，你会发现，阅读Oracle反汇编的片段，是很简单的事。 有人经常和我聊：“你花了这么多时间去研究这个，值得吗”。 先不说值不值的问题，其实，这么简单的东西，真的花不了太多时间。 程序的机器级表示 有了基本的汇编基础

20、，哪么，理解后面的问题也就简单了。下面我们讨论下 一个问题：断点断点。 断点，是程序调试的重要工具。断点就是让程序在某个地方停下来，然后我 们可以慢慢观察程序的状态。 设置断点，需要使用调试工具：gdb/mdb。断点命令是： mdb: 函数名:b gdb : b 函数名 断点 程序，对CPU来说，不过一串长长的指令流: 断点 main: pushq %rbp main+1: movq %rsp,%rbp main+4: subq $0x10,%rsp main+8: movl $0x1,-0x4(%rbp) / a=1 main+0x37: call -0x19f main+0xf: movl

21、 $0x2,-0x8(%rbp) / b=2 main+0x16: movl -0x8(%rbp),%esi main+0x19: movl -0x4(%rbp),%edi main+0x1c: call -0x34 main+0x21: movl -0x8(%rbp),%edx main+0x24: movl -0x4(%rbp),%esi main+0x27: movl 0x103e3(%rip),%ecx main+0x2d: movl $0x400df0,%edi main+0x32: movl $0x0,%eax main+0x3c: movl $0x0,%eax add+0x16:

22、 leave main+0x41: leave main+0x42: ret add: pushq %rbp add+1: movq %rsp,%rbp add+4: movl %edi,-0x4(%rbp) add+7: movl %esi,-0x8(%rbp) add+0xa: movl -0x8(%rbp),%eax add+0xd: addl -0x4(%rbp),%eax add+0x10: movl %eax,0x10412(%rip) add+0x17: ret CPU逐条的执行命 令。 。 断点 main: pushq %rbp main+1: movq %rsp,%rbp m

23、ain+4: subq $0x10,%rsp main+8: movl $0x1,-0x4(%rbp) / a=1 main+0x37: call -0x19f main+0xf: movl $0x2,-0x8(%rbp) / b=2 main+0x16: movl -0x8(%rbp),%esi main+0x19: movl -0x4(%rbp),%edi main+0x1c: call -0x34 main+0x21: movl -0x8(%rbp),%edx main+0x24: movl -0x4(%rbp),%esi main+0x27: movl 0x103e3(%rip),%e

24、cx main+0x2d: movl $0x400df0,%edi main+0x32: movl $0x0,%eax main+0x3c: movl $0x0,%eax add+0x16: leave main+0x41: leave main+0x42: ret add: pushq %rbp add+1: movq %rsp,%rbp add+4: movl %edi,-0x4(%rbp) add+7: movl %esi,-0x8(%rbp) add+0xa: movl -0x8(%rbp),%eax add+0xd: addl -0x4(%rbp),%eax add+0x10: mo

25、vl %eax,0x10412(%rip) add+0x17: ret 如果你想让CPU执 行到某个命令处暂 停，那么，就把哪 条命令设置为断点 比如，我想让CPU 停在黑底白字处的 位置。 这里是add函数的入 口点，我们可以使 用mdb命令”add:b”， 在此处设置断点。 断点 main: pushq %rbp main+1: movq %rsp,%rbp main+4: subq $0x10,%rsp main+8: movl $0x1,-0x4(%rbp) / a=1 main+0x37: call -0x19f main+0xf: movl $0x2,-0x8(%rbp) / b=

26、2 main+0x16: movl -0x8(%rbp),%esi main+0x19: movl -0x4(%rbp),%edi main+0x1c: call -0x34 main+0x21: movl -0x8(%rbp),%edx main+0x24: movl -0x4(%rbp),%esi main+0x27: movl 0x103e3(%rip),%ecx main+0x2d: movl $0x400df0,%edi main+0x32: movl $0x0,%eax main+0x3c: movl $0x0,%eax add+0x16: leave main+0x41: lea

27、ve main+0x42: ret add: pushq %rbp add+1: movq %rsp,%rbp add+4: movl %edi,-0x4(%rbp) add+7: movl %esi,-0x8(%rbp) add+0xa: movl -0x8(%rbp),%eax add+0xd: addl -0x4(%rbp),%eax add+0x10: movl %eax,0x10412(%rip) add+0x17: ret CPU在执行到黑底 白字的指令处，将 会停止，这里就是 add函数的入口处。 这里是断点 断点 对调试Oracle来说，断点作用巨大。在后面马上就有一个例子，演

28、示断点的作用。 我们自己写的程序，我可以知道程序中有个子函数：add，我们可以在add处设置断点。 对于Oracle，它完全是一个黑盒子，我们又要在哪里设置断点呢？ 发现断点 是DTrace登场的时候了。 DTrace发源于Solaris系统，虽然现在也移植到Linux下，但Linux下的DTrace确少一个重 要功能，目前我们还不能使用它来“发现断点”。 注意： 虽然DTrace只能在Solaris下，但Oracle在所有OS系统中的原理基本都是一致的， 因此我们发现的Oracle规则、原理，可以用于所有Oracle系统。 发现断点 DTrace内置了很多探针，用DBA的语言来说，相当于So

29、laris系统中内置了很多触发器， 这些触发器平常是Disable的，你可以使用DTrace enable指定的触发器。同时，你还可 以为这个触发器定义动作，也就是当此触发器被触发时要作什么。通常“动作”就是 使用printf函数显示一些参数或内存的值。 当然，除了显示内存值，也可以修改。比如，想研究一下Oracle DBWR进程写脏块有 没有什么调优空间，哪么第一步就是要先了解 DBWR进程的工作原理，DBWR有个3秒 超时机制，但除DBWR外，Oracle很多进程都有3秒超时机制，哪么多进程大家混在一 起超时，也不知道是谁的超时影响了系统，我在我的书Oracle内核技术揭密中， 有一段脚本

30、，可以修改进程的超时时间。在这儿，把这段脚本分享一下： 发现断点 修改进程超时时间： bash-3.2# cat time_out.d #!/usr/sbin/dtrace -s -n struct timespec *timeout; pid$1:semtimedop:entry timeout=(struct timespec *)copyin(arg3,8); timeout-tv_sec=$2; copyout(timeout,arg3,8); Bash-3.2# time_out.d 1234 300 进程号 超时时间 发现断点 更多DTrace相关的基础知识，可以参考我在ITPUB

31、上的帖子。 使用DTrace可以做什么呢？ 它可以把Oracle的函数名都显示出来。这是我们“调试Oracle”的第一步，也是我们打 开Oracle这个黑盒子的第一步。 只需要用下面短短几行代码，就可以得到Oracle在进行某个操作时的所调用的函数名， 以及函数相关参数： #!/usr/sbin/dtrace -s -n dtrace:BEGIN i=1; pid$1:entry printf(“i=%d %s(%x,%x,%x,%x,%x,%x);“,i, probefunc,arg0,arg1,arg2,arg3,arg4,arg5); i=i+1; 发现断点 这是跟踪下列测试SQL执行的

32、结果： SQL select * from vage where rowid=AAADLMAAEAAAACDAAA; ID NAME - - 1 aaaaaa 看到满屏奇奇怪怪的函数名，很多人在这一步放弃了。其实，这才刚刚开始。理解它们很简单。 下面我们就以等待事件为例，说一下如何从这里面发现价值。 有没有觉得Oracle的等待事件非常神奇？它是我们DBA的重要工具。它的原理是什么 呢？下面，我们就以它为例，使用“调试Oracle”技术，详细分析等待事件的原理。 神奇的等待事件 神奇的等待事件 万事开头难。为了研究等待事件，我还是花了点时间开头的。DTrace中有一个简单的 方法，可以统计调用

33、每个函数的次数。我就是从这个次数开始的。 执行测试SQL：“select * from vage where rowid=AAADLMAAEAAAACDAAA”，当是软软 解析、逻辑读时，在没有竞争的情况下，会有四次等待事件： 两次SQL*Net message to client 两次SQL*Net message from client 关于这点，可以很容易的从v$session_event中得到。 神奇的等待事件 然后，我用如下脚步跟踪测试SQL的执行： #!/usr/sbin/dtrace -s -n dtrace:BEGIN printf(“Start.n“); pid$1:entr

34、y countsprobefunc=count(); dtrace:END trace(“-“); printa(counts); 关键在于这里，它统计 所有函数的调用次数 神奇的等待事件 因为测试SQL一共会有4次等待事件，所以我只观注调用次数为4的函数，这些函数共 有15个： KGHISPIR 4 _save_nv_regs 4 kews_sqlcol_begin 4 kews_update_wait_time 4 kghxhal 4 kghxhfr 4 kglGetMutex 4 kksGetStats 4 kskthbwt 4 kskthewt 4 kslwt_end_snapshot

35、 4 kslwt_start_snapshot 4 kslwtbctx 4 kslwtectx 4 opikndf2 4 在这些函数里面，一定有一些是关于等待事件的函数？ 神奇的等待事件 经过观察，如下几个函数引起我的注意，原因很简单，它们的名字中带有”wt” : KGHISPIR 4 _save_nv_regs 4 kews_sqlcol_begin 4 kews_update_wait_time 4 kghxhal 4 kghxhfr 4 kglGetMutex 4 kksGetStats 4 kskthbwt 4 kskthewt 4 kslwt_end_snapshot 4 kslwt

36、_start_snapshot 4 kslwtbctx 4 kslwtectx 4 opikndf2 4 神奇的等待事件 这其中kslwtbctx是最早被调用的函数: KGHISPIR 4 _save_nv_regs 4 kews_sqlcol_begin 4 kews_update_wait_time 4 kghxhal 4 kghxhfr 4 kglGetMutex 4 kksGetStats 4 kskthbwt 4 kskthewt 4 kslwt_end_snapshot 4 kslwt_start_snapshot 4 kslwtbctx 4 kslwtectx 4 opikndf

37、2 4 下面，我们就从kslwtbctx开始。 我查看了从kslwtbctx开始Oracle会调用的一些函数，它们依次是： i=520 kslwtbctx(fffffd7fffdfb180,1,fffffd7fffdfb3d7,1,c725158,4034); i=521 gethrtime(21,1,fffffd7fffdfb3d7,1,ceed648,0); i=522 kskthbwt(0,42beed13,742beed13,4c5e2df93bee,3ff0,395c42ba8); i=523 memcpy(395be69b0,fffffd7fffdfb1e8,30,7b,c7251

38、58,395c42ba8); 0 1 2 3 4 5 6 7 8 9 a b c d e f 0123456789abcdef 0: 55 01 00 00 00 00 00 00 ff ff ff 7f 7f fd ff ff U. i=524 kslwt_start_snapshot(395be6948,395be6948,1,7b,ced881c,ceed648); i=525 nioqsn(cedda60,0,fffffd7fffdfb3d7,1,380009ce8,ceed648); Oracle在第520次函数调用时，调用了kslwtbctx，在第521次调用了gethrtime，

39、这是一 个获取时间的函数。等待事件的一个重要操作，不就是记录时间吗！ 补充一点，观察内存的流动很重要吗。Memcpy就是完成内存的流动函数。因此观察 memcpy拷贝了什么样的值很重要。 神奇的等待事件 i=520 kslwtbctx(fffffd7fffdfb180,1,fffffd7fffdfb3d7,1,c725158,4034); i=521 gethrtime(21,1,fffffd7fffdfb3d7,1,ceed648,0); i=522 kskthbwt(0,42beed13,742beed13,4c5e2df93bee,3ff0,395c42ba8); i=523 memcp

40、y(395be69b0,fffffd7fffdfb1e8,30,7b,c725158,395c42ba8); 0 1 2 3 4 5 6 7 8 9 a b c d e f 0123456789abcdef 0: 55 01 00 00 00 00 00 00 ff ff ff 7f 7f fd ff ff U. i=524 kslwt_start_snapshot(395be6948,395be6948,1,7b,ced881c,ceed648); i=525 nioqsn(cedda60,0,fffffd7fffdfb3d7,1,380009ce8,ceed648); 它从fffffd7f

41、ffdfb1e8处，向395be69b0拷贝0x30（十进制48）个字节。拷贝的内容我也 用DTrace把它显示出来了， “55 01 00 00 00 00 00 00 ff ff ff 7f 7f fd ff ff ”。 这其中前两个字节“5501”引起了我的注意，我的测试机是小端，5501真正表示的数 据是0155，十进制是341. 神奇的等待事件 神奇的等待事件 i=520 kslwtbctx(fffffd7fffdfb180,1,fffffd7fffdfb3d7,1,c725158,4034); i=521 gethrtime(21,1,fffffd7fffdfb3d7,1,ceed

42、648,0); i=522 kskthbwt(0,42beed13,742beed13,4c5e2df93bee,3ff0,395c42ba8); i=523 memcpy(395be69b0,fffffd7fffdfb1e8,30,7b,c725158,395c42ba8); 0 1 2 3 4 5 6 7 8 9 a b c d e f 0123456789abcdef 0: 55 01 00 00 00 00 00 00 ff ff ff 7f 7f fd ff ff U. i=524 kslwt_start_snapshot(395be6948,395be6948,1,7b,ced88

43、1c,ceed648); i=525 nioqsn(cedda60,0,fffffd7fffdfb3d7,1,380009ce8,ceed648); Oracle中的每个等待事件，都有一个编号，这个341会不会就是等待事件编号呢？这很 容易验证，查询等待事件编号等于341的，看看到底有没有这个编号，如果有的话， 等待事件是什么！ 神奇的等待事件 查询结果： SQL select event#, event_id from v$event_name where event#=341; EVENT# NAME - - 341 SQL*Net message to client 编号341的等待事件是SQL*Ne