ITPub博客

首页 > Linux操作系统 > Linux操作系统 > 案例研究:使用实时诊断工具诊断间歇性数据库“挂起”

案例研究:使用实时诊断工具诊断间歇性数据库“挂起”

原创 Linux操作系统 作者:anchen211 时间:2006-12-13 11:33:46 0 删除 编辑
我翻译的一篇译文,请大家指正:
案例研究:使用实时诊断工具诊断间歇性数据库“挂起”

案例简述:
这个案例研究的目的是介绍如何运用LTOM和show_sessions等COE(center of expertise)工具来实时地诊断复杂的性能问题。这个案例将重点放在预分析阶段,这个阶段也是诊断工作的主要阶段。使用实时诊断工具来抽取必要的跟踪信息是这个案例的最困难的部分。一旦我们收集到了诊断的跟踪文件,对它们的分析只是一件简单的事情。

没有预警的间歇性的数据库性能问题,有着持续时间短的特点,因而非常难于确诊其原因。传统的诊断这类问题的方法是采用重复的尝试来捕捉一些必要的数据,这样往往会导致客户和支持者的长时间都从事于对事件原因的诊断。这样往往会让客户选择进行设备升级的方式以期能解决性能问题,事实上是问题没有得到真正的解决。这个案例将对一个间歇性的数据库“挂起”的性能问题进行诊断。

性能问题可以分成两类:“挂起”和变慢。真正的数据库“挂起”,有时候也叫数据库冻结,是一种最严重的数据库问题。在这种情形下,数据库将不响应已连接上的会话的请求,也不能建立新的连接会话。对代码的执行或者是中断了,或者是停滞在一个密集的循环之中,或者是非常缓慢的在程序流中前进,给用户造成的感觉是程序无休止地被“挂起”了。真正的数据库“挂起”因为不可能连接数据库,所以也将阻止客户或者技术分析者获取诊断的数据。
幸运的是,这类的“挂起”比较少见。

常见的是数据库的性能下降。性能下降与数据库“挂起”不同在于,性能下降时用户仍能连接到数据库,尤其是能以SYS用户进行连接。性能下降时数据库的活动虽然用户感觉到象被“挂起”,但数据库的确仍在进行处理。性能下降时因为连接仍然可能,所以并没有严重到客户或技术支持者不能获取来进行诊断的数据。

进一步区别真正的挂起和间歇性挂起。真正的挂起将使数据库无休止地停留在“冻结”状态,而间歇性的挂起最终将会从冻结中解脱出来。诊断任何一种的挂起都需要ORACLE之外的工具以收集诊断信息。操作系统的调试工具(如GDB)可以用于在分析某些挂起案例分析的跟踪文件中获得系统状态信息。如果数据库正经历一个真正的挂起,用户就可以在这时候使用GDB或相似的调试工具,因为数据库将停留在一个冻结状态,也就可以收集诊断信息。而间歇性的数据库挂起,可能持续的时间并不长,也就不适合于使用操作系统调试工具这一耗时的方法。

通过使用LTOM的手工数据记录器和自动挂起监控器有可能检测到挂起并发出外部命令来利用GDB或COE的show_sessions程序等操作系统工具收集诊断跟踪信息。我们目前的任务是展示如何使用这些实时工具来诊断复杂的性能问题。利用ORACLE的诊断理论,我们将一步步地展示数据收集、分析问题和解决问题的过程。

案例
六个月来,客户一起在忍受数据库间歇性“休克”的痛苦。ORACLE公司也已经介入调查,但事实证明在数据库挂起的3至5分钟内无法收集到必要的诊断跟踪信息。难于收集诊断信息的另一个更重要的原因是数据库的间歇性休克来的时候没有任何征兆。

客户收集了statspack的快照,但这再一次证明了这是个难题。因为尽管30分钟的快照包括了数据库挂起这段时间,但快照不能提供足够的细节来决定是什么导致了挂起。使用statspack快照来诊断间歇性的性能问题是一个挑战。使用静态的快照数据来解决间歇性的数据库挂起的难度在于,在快照收集期间出现的性能峰值将会平均分散到整个的快照收集间隔之中。在我们的例子中,3-5分钟的挂起将平均分散到30分钟的快照间隔中。

预分析工作
细节
步骤1 问题确认
对任何问题,首先要明确和清楚需要解决什么问题并且这个问题的确存在。我们用LTOM手工数据库记录器来从数据库和操作系统级别中收集信息。这可以提供我们一个完整的关于数据库发生挂起前、发生中、和发生后的描述。

我使用LTOM,设置手工记录器为3秒钟收集一次快照。当数据库挂起时,我们可以清楚地确定问题的本质原因并确认数据库的挂起是数据库本身的资源缺乏的结果而非一些ORACLE之外的因素造成的。下面的11:14:27时刻的LTOM快照显示:在数据库挂起之前,正常的ORACLE会话没有等待并有足够的资源。


---------------SNAPSHOT# 4751
Mon Feb 14 11:14:27 PST 2005
r b w swap free re mf pi po fr de sr s0 s1 s2 s3 in sy cs us sy id
0 0 28 94723088 26511624 1026 5418 412 4 4 0 0 20 0 0 20 7242 49559 9029 16 9 75
SID PID SPID %CPU TCPU PROGRAM USERNAME EVENT SEQ SECS P1 P2 P3

3秒后的11:14:30的下一个LTOM快照捕捉到了数据库快要挂起前系统的情况,可以看到基本上所有的数据库会话都在等待同一个库缓冲的latch(latch号106).

---------------SNAPSHOT# 4752
Mon Feb 14 11:14:30 PST 2005
r b w swap free re mf pi po fr de sr s0 s1 s2 s3 in sy cs us sy id
0 0 28 94723088 26511624 1026 5418 412 4 4 0 0 20 0 0 20 7242 49559 9029 16 9 75

SID PID SPID %CPU TCPU PROGRAM USERNAME EVENT SEQ SECS P1 P2 P3
8 9 21471 * * QMN0 null latch free 2952 0 43487260472 106 5
19 20 21804 * * TNS DEV latch free 62783 0 43487260472 106 2
63 601 19039 * * TNS KS4029 latch free 6313 0 43487260472 106 3
74 447 20696 * * TNS KG5770 latch free 1201 0 43487260472 106 3
79 660 21950 * * TNS AB0320 latch free 5442 0 43487260472 106 4
81 443 3430 * * TNS null latch free 54 2 43487260472 106 53
82 717 16672 * * TNS JL3855 latch free 6661 0 43487260472 106 5
95 664 6718 * * TNS RP5398 latch free 32354 0 43487260472 106 5
98 749 20654 * * TNS PF5036 latch free 609 0 43487260472 106 1
104 740 23674 * * TNS RF4846 latch free 1483 0 43487260472 106 3
108 166 24606 * * TNS NM227 latch free 11903 0 43487260472 106 5
109 518 12420 * * TNS AS5032 latch free 1839 0 43487260472 106 2
116 220 8864 * * TNS AL4171 latch free 34631 0 43487260472 106 3
120 547 24207 * * TNS FJ356 latch free 7192 0 43487260472 106 1
126 382 13454 * * TNS BM249 latch free 5902 0 43487260472 106 4
129 306 21359 * * TNS DI3891 latch free 2787 0 43487260472 106 3
130 665 24166 * * TNS EW3761 latch free 2078 0 43487260472 106 4
131 530 3773 * * TNS null latch free 51 2 43487260472 106 50…


817 813 5656 * * TNS null latch free 28 2 43487260472 106 27
818 814 5774 * * TNS null latch free 27 0 43487260472 106 26
819 815 5775 * * TNS null latch free 27 2 43487260472 106 26
820 816 5971 * * TNS null latch free 25 0 43487260472 106 24
821 817 6007 * * TNS null latch free 24 0 43487260472 106 23
822 818 6127 * * TNS null latch free 23 2 43487260472 106 22
823 819 6146 * * TNS null latch free 23 0 43487260472 106 22

Latch名可以从v$latch中查到,如下

The query to retrieve the latch name would be as follows:
Select name from v$latch where latch# = 106;

接下来的LTOM快照发生于2分25秒之后的11:16:52。如下:

---------------SNAPSHOT# 4753
Mon Feb 14 11:16:52 PST 2005
r b w swap free re mf pi po fr de sr s0 s1 s2 s3 in sy cs us sy id
0 0 25 94723012 26513624 1026 5418 412 4 4 0 0 20 0 0 20 7242 49559 9029 16 10 76 SID PID SPID %CPU TCPU PROGRAM USERNAME EVENT SEQ SECS P1 P2 P3

这里,我们看到数据库挂起结束后,系统又恢复到了正常的状态。我们的数据库连接在快照4752和4753之间也中止了,导致我们的快照在2分25秒之后产生而不是预期中的3秒后。

到这时,我们已经成功地确认了客户的问题是数据库挂起。我们也能从一个较高的层次上得到某种暗示----是什么原因导致了数据库挂起。很明显,数据库存在严重的库缓存latch竟争。特别是某些进程长时间(超过2分钟)地占有库缓存的父latch。通过检查LTOM的VMSTAT数据,我们还知道,数据库的挂起与操作系统的CPU或内存的资源无关。

步骤2 从数据库挂起中挖掘并抽取更多的诊断信息
一旦问题得到确认,我们需要继续收集进一步的诊断跟踪来决定问题的原因,也就是说,找到是什么导致了库缓冲latch冲突。从LTOM中收集到的数据表明数据库挂起是因为进程在等待父进程的latch。下面的挑战就是找到哪个进程占有这个latch和为什么它长时间地持有它并导致其它的进程等待。

使用GDB等操作系统调试工具来收集系统状态信息证明是不成功的。客户不用取到信息,因为当数据库挂起时,GDB同样也被挂起。尽管我们看到GDB已经在着手进行处理并且产生系统报告的命令也已经开始工作,但它没有产生跟踪文件。使用GDB的努力是有问题的,因于即使它可以产生系统状态信息的跟踪文件,但它也不可能在数据库挂起这前产生。数据库挂起将持续3-5分钟,而GDB通常要在生产系统数据库几乎没有什么活动时花5分多钟的时间来产生一个系统状态报告。因为在ORACLE8中无法通过GDB调用挂起分析,所以挂起分析是不可能的。

因为我们无法在数据库挂起时收集进一步的诊断数据,COE编写一个叫做show_session的程序用以替代GDB来直接从SGA中收集数据。Show_sessions关联到SGA并从ORACLE的数据的存储结构中读取信息,就象在做内存导出的工作一样。Show_sessions能够在数据库挂起时收集可以识别的进程信息和会话数据。这些信息通常可以通过系统状态日志和挂起分析日志来记录,或者通过查询v$session、v$processv、$session来获得,但在数据库挂起时便不能得到。

我们重新运用LTOM和它的自动挂起检测器来检测数据库挂起并在发现时调用show_sessions程序。LTOM的自动挂起检测器不但能检测到数据库挂起并且能够指定一个文件在挂起时运行它。我们配置在下一次数据库挂起时运行show_sessions程序。

查看show_sessions的输出,我们可以知道在发生数据库挂起时持有latch的进程是SMON。我们重新配置LTOM在数据库挂起时同时调用show_sessions和unix的pstack。我们再写一个shell脚本调用这两个程序,在发生数据库挂起后每隔30秒的间隔调用一次这个脚本,一共调用三次。这样我们可以在数据库挂起时用多个样本进行比较。Pstack程序可以产生一个16进制的堆栈跟踪文件列出在pstack命令发出后的进程的函数调用。我们等待下一次的数据库挂起并从LTOM、show_sessions和pstack对SMON这个进程的函数调用堆栈文件中收集信息。


使用如下命令调用pstack:
$ pstack ospid

最后,我们对所有的诊断信息进行分析并解决问题。

分析:
总结
现在我们获得了所有的诊断信息,我们可以定位数据库挂起的原因。我们做了以下的事情:
1 查看show_sessions的输出。找到持有父库缓存latch的进程和这个进程正在执行的sql语句;
2 查看堵塞进程的pstack。这样可以看出在挂起时ORACLE执行的潜在函数。
3 查看bug库查看是否是一个已知的bug。
4 确定有效的解决方法。
5 交付实施。

详细分析
1查看show_sessions的输出。找到持有父库缓存latch的进程和这个进程正在执行的sql语句;

*** Process (0xa01e272e0) Serial: 1 OSPid: 28710
HOLDING LATCH: 0x380014980
*** Latch: 106 (0x380014980) Level: 5 Gets: 1110 Misses: 0 ImmediateGets: 0
ImmediateMisses: 0
Sleeps: 0 SpinGets: 0 Sleeps1: 0 Sleeps2: 0 Sleeps3: 0
*** Session (5): a0269e608 User: SYS PID: 28710 blocker: 0
SQL Addr: 9e2a85958 SQL: delete from obj$ where owner#=:1 and name=:2 and namespace=:3 and(remoteowner=:4 or remoteowner is null and :4 is null)and(linkname=:5 or linkname is null and :5 is null)and(subname=:6 or subname is null and :6 is null)
pSQL Addr: 9e2a85958
pSQL: delete from obj$ where owner#=:1 and name=:2 and namespace=:3 and(remoteowner=:4 or remoteowner is null and :4 is null)and(linkname=:5 or linkname is null and :5 is null)and(subname=:6 or subname is null and :6 is null)
Session Waits: Seq: 632 Event#: 94 P1: 0x1 (1) P2: 0x51dd (20957) P3: 0x1 (1) Time: 3

我们可以看到进程地址为0xa01e272e0的进程持有106号latch。这是导致阻止其它进程获取latch并最终导致数据库挂起的原因。Show_sessions捕获的其它相关的信息是进程ID(28710),这个进程通过查询v$process和v$session可以确定是smon进程。我们也可以看到这个进程在执行的SQL语句是:

delete from obj$ where owner#=:1 and name=:2 and namespace=:3 and(remoteowner=:4 or remoteowner is null and :4 is null)and(linkname=:5 or linkname is null and :5 is null)and(subname=:6 or subname is null and :6 is null)

2 查看smon进程的进程堆栈

28710: ora_smon_live
0000000100fdb414 kglhdde (101e3c3e0, 9bf904bf8, a0001c1b8, 0, 9cce56774, 2000) + 114 0000000100fdb990 kglhdunp2 (1f, a200a2bc8, 3e8, 101ca1f30, 0, 1f0) + 2b0 0000000100fdb624 kglhdunp (101e3c3e0, 25, 0, 70000, 1, 7ffffffc) + 1a4 0000000100fcd9a4 kglobf0 (9cce56458, 0, 1, 1, 3c4, 0) + 1c4 0000000100fcbb08 kglhdiv (a2009f178, 9ef2dc040, 10000, ffffffffffffff98, 3c4, e) + 2c8 0000000100fd45b8 kglpndl (380003710, a2009f118, e, 101e3d748, ffffffff7fffc320, e) + a58000000010041e54c kssdct (a1f6cb5c8, 24, 1, 0, 101e3ede8, 0) + 18c 000000010034dfac ktcrcm (0, 0, 0, 0, 0, 0) + aec 00000001005dd1e0 kqlclo (a03b86d24, 0, 3, 20000000, 0, 0) + a80 000000010023b46c ktmmon (0, 380005880, 6, a01e272e0, 3800050b8, 0) + 188c 000000010042330c ksbrdp (0, 101e401e0, 0, 0, 100909238, 100909204) + 2ec 000000010090939c opirip (32, 0, 0, 0, 0, 0) + 31c 000000010015f720 opidrv (32, 0, 0, 6c6f6700, 0, 0) + 6a0 0000000100149e10 sou2o (ffffffff7fffe890, 32, 0, 0, 101e7c5c8, 100134e0c) + 10 0000000100134f28 main (1, ffffffff7fffeab8, ffffffff7fffeac8, 0, 0, 100000000) + 128 0000000100134ddc _start (0, 0, 0, 0, 0, 0) + 17c


比较SMON进程的三个堆栈样本,三个样本显示了同样的堆栈。这意味着在挂起时SMON进程在执行同样的代码。

3 既然知道了是哪个session持有latch和执行的sql,我们就可以查找BUG数据库来检查是否这是一个已知的BUG。SMON的堆栈跟踪清楚地匹配了bug2791662的签名。(注:这个BUG对客户不可见)。这个BUG会导致数据库挂起/冻结,是因为在执行DROP某个对象的操作时包含了相关的无效的只读对象。在这个案例中因为包含大量的只读的相关objects,导致latch被长时间占用。这就是导致用户数据库间断性挂起的原因。

4 与BUG2791662相关的补丁修正了这个问题。一个不太令人满意的方案是没人使用时删除那些有问题的对象。

5 最好的解决方法是打上BUG的补丁。补丁打好后,问题解决了。

总结
ODM的使用将减少解决问题的时间。问题的明确确认是一个非常重要的步骤并且经常容易被忽略。在这个案例中,可以选择不同的诊断工具,但首先要确定问题后才能够选择正确的诊断工具。数据库挂起和性能下降在技术上的区别对终端用户而言并不重要,但对于选择正确的诊断工具而言是非常重要的。使用statspack工具在确定数据库挂起的根本原因不如使用收集系统状态信息或挂起分析工具更可取。

参考:
ORACLE专家中心提供了一系列的工具来帮助用户解决性能问题,这些工具包括:
Note 352363.1: LTOM - The On-Board Monitor User Guide
Note 301137.1: OS Watcher User Guide
Note 362094.1: HANGFG User Guide
Note 362791.1: STACKX User Guide
Show_sessions: This is not currently available for download. However, if you are interested in getting information on this tool, please contact the author of this case study, Carl Davis.
Other relevant documents to this study include:
Note 312789.1: What is the Oracle Diagnostic Methodology (ODM)?
Note 215858.1: Interpreting HANGANALYZE trace files to diagnose hanging and performance problems
Note 273324.1: Using HP-UX Debugger GDB To Produce System State Dump

来自 “ ITPUB博客 ” ,链接:http://blog.itpub.net/9375/viewspace-555105/,如需转载,请注明出处,否则将追究法律责任。

请登录后发表评论 登录
全部评论

注册时间:2008-11-04

  • 博文量
    129
  • 访问量
    178193