Pending Problem

这个问题发生在今年的1月，用户以操作系统认证形式登陆RAC中的主用实例时发现登陆挂起，但不出现错误。之后应用人员陆续手动杀死服务进程，杀死进程后发现实例可以登录了，应用人员在没有做任何信息转储的情况下重启了数据库，这就造成了我们后期诊断时缺乏必要的信息，也是这个case变成悬案的主要原因。在实例hang住的一个半小时中告警日志没有任何信息；仅有的有用信息是该实例中diag，pmon，lmd后台进程的trace文件。以下为trace文件:

<code>lmd0 trace:</code>

<code>DUMP </code><code>LOCAL</code> <code>BLOCKER/HOLDER: block </code><code>level</code> <code>5 res [0x10b0005][0xeb5],[TX]</code>

<code>----------resource 0x70000044a76e1a0----------------------</code>

<code>resname : [0x10b0005][0xeb5],[TX]</code>

<code>Local</code> <code>node : 1</code>

<code>master_node : 1</code>

<code>current</code> <code>inc : 20</code>

<code>hv status : 0</code>

<code>hv master : 0</code>

<code>open</code> <code>options : dd</code>

<code>grant_bits : KJUSERNL KJUSEREX</code>

<code>grant</code> <code>mode : KJUSERNL KJUSERCR KJUSERCW KJUSERPR KJUSERPW KJUSEREX</code>

<code>count</code> <code>: 1 0 0 0 0 1</code>

<code>val_state : KJUSERVS_NOVALUE</code>

<code>valblk : 0x00000000000000000000000000000000 .</code>

<code>access_node : 1</code>

<code>vbreq_state : 0</code>

<code>state : x0</code>

<code>Total accesses: 15061</code>

<code>Imm. accesses: 12545</code>

<code>Granted_locks : 1</code>

<code>Cvting_locks : 1</code>

<code>value_block: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00</code>

<code>GRANTED_Q :</code>

<code>lp 700000488546990 gl KJUSEREX rp 70000044a76e1a0 [0x10b0005][0xeb5],[TX]</code>

<code> </code><code>master 1 gl owner 70000048dd08220 possible pid 2928930 xid 2033-0333-0026D22C bast 0 rseq 215 mseq 0 history 0x14951495</code>

<code> </code><code>open</code> <code>opt KJUSERDEADLOCK</code>

<code>CONVERT_Q:</code>

<code>lp 700000488546ae0 gl KJUSERNL rl KJUSEREX rp 70000044a76e1a0 [0x10b0005][0xeb5],[TX]</code>

<code> </code><code>master 1 gl owner 70000048ee0ed48 possible pid 2040272 xid 2006-0066-0006F888 bast 0 rseq 215 mseq 0 history 0x1495149a</code>

<code> </code><code>convert</code> <code>opt KJUSERGETVALUE KJUSERTRCCANCEL</code>

<code>----------enqueue 0x700000488546990------------------------</code>

<code>lock version : 2242641</code>

<code>Owner node : 1</code>

<code>grant_level : KJUSEREX</code>

<code>req_level : KJUSEREX</code>

<code>bast_level : KJUSERNL</code>

<code>notify_func : 0</code>

<code>procp : 70000048928b8f0</code>

<code>proc version : 40135</code>

<code>oprocp : 0</code>

<code>group</code> <code>lock owner : 70000048dd08220</code>

<code>possible pid : 2928930</code>

<code>dd_count : 0</code>

<code>timeout : 0.0 secs</code>

<code>On_timer_q? : N</code>

<code>lock_state : GRANTED</code>

<code>Open</code> <code>Options : KJUSERDEADLOCK</code>

<code>Convert</code> <code>options : KJUSERNOQUEUE</code>

<code>History : 0x14951495</code>

<code>valblk : 0x00000000000000000000000000000000 .</code>

<code>DUMP </code><code>LOCAL</code> <code>BLOCKER: initiate state dump </code><code>for</code> <code>TIMEOUT</code>

<code> </code><code>possible owner[819.2928930] </code><code>on</code> <code>resource TX-010B0005-00000EB5</code>

<code>Submitting asynchronized dump request [28]</code>

<code>pmon trace:</code>

<code>*** SESSION ID:(3384.1) 2010-01-16 11:00:11.349</code>

<code>[claim lock </code><code>for</code> <code>dead process][lp 0x7000004870f7078][p 0x7000004891a79e0.2928930][hist x49514951]</code>

<code>[claim lock </code><code>for</code> <code>dead process][lp 0x700000488546990][p 0x70000048928b8f0.0][hist x49514951] <<<< note:this message@2010-01-16 12:35</code>

<code>Dump requested </code><code>by</code> <code>process [orapid=6]</code>

<code>REQUEST:custom dump [2] </code><code>with</code> <code>parameters [6][819][2][2]</code>

<code>. process info </code><code>of</code> <code>pid[819.2928930] requested </code><code>by</code> <code>pid[6.3621092]</code>

<code>Dumping process 819.2928930 info:</code>

<code>Dumping diagnostic information </code><code>for</code> <code>ospid 2928930:</code>

<code>loadavg : 10.83 10.96 10.91</code>

<code> </code><code>alloc = 235.52M avail = 32768.00M swap_free = 32532.48M</code>

<code> </code><code>F S UID PID PPID C PRI NI ADDR SZ WCHAN STIME TTY </code><code>TIME</code> <code>CMD</code>

<code> </code><code>240001 A orauser 2928930 1 120 120 20 6da7bd510 174068 10:35:28 - 1:50 oracleCRMDB22 (</code><code>LOCAL</code><code>=</code><code>NO</code><code>)</code>

<code>open</code><code>: The file access permissions do </code><code>not</code> <code>allow the specified </code><code>action</code><code>.</code>

<code>procstack: write(/proc/2928930/ctl): The requested resource </code><code>is</code> <code>busy.</code>

<code>2928930: oracleCRMDB22 (</code><code>LOCAL</code><code>=</code><code>NO</code><code>)</code>

lmd0进程的trace文件显示该进程发现了本地存在阻塞超时的问题，[0x10b0005][0xeb5],[TX]资源的拥有者是2928930进程，而pmon进程认为2928930进程可能出于僵死状态，故希望RAC中的diag进程能对该进程做进一步的诊断，diag进程受到pmon的邀请"Dump requested by process [orapid=6]",尝试"Dumping process 819.2928930 info:"，并利用AIX上的procstack调试工具分析此进程当时的调用栈，但出现了"procstack: write(/proc/2928930/ctl): The requested resource is busy"的错误，在网上搜索该记录的相关信息发现可能是AIX上procstack工具的一个Bug，而跟实例挂起问题关系不大:

Problem summary **************************************************************** * USERS AFFECTED: * Users of the procstac command on the 5300-09 Technology Level * with the bos.perf.proctools fileset at the 5.3.9.0 and 5.3.9.1 * levels. **************************************************************** * PROBLEM DESCRIPTION: * The procstac command fails with an error similar to: * * open: Permission denied * procstack: write(/proc/2068724/ctl): Device busy **************************************************************** * RECOMMENDATION: * Install APAR IZ47903. **************************************************************** Problem conclusion *Modified the code to fix this problelm.

diag进程的跟踪文件还显示2928930进程持有redo copy latch；这个case发生后的一个礼拜恰好有Oracle原厂工程师到该客户单位做巡检，原厂工程师查看了实例挂起期间的ASH报告，发现该时段内实例中redo相关的等待频繁发生，基本可以认定是僵死进程持有"redo copy latch"造成了RAC中单实例hang住。原厂工程师的结论令客户比较满意，这个case基本可以结束了。但我对这个结论并不完全认同，2928930进程持有的redo copy latch是一个子栓，该类子栓在实例上的总数取决于CPU总数，一般来说等于CPU * 2；该实例所在服务器为IBM的p595配有32个cpu，redo copy latch共有64个，单单一个子栓被hold住会造成整个实例都hang住，且登录挂起吗？

<code>SQL> show parameter cpu_count</code>

<code>NAME</code> <code>TYPE VALUE</code>

<code>cpu_count </code><code>integer</code> <code>32</code>

<code>SQL> </code><code>select</code> <code>count</code><code>(*) </code><code>from</code> <code>v$latch_children </code><code>where</code> <code>name</code><code>=</code><code>'redo copy'</code><code>;</code>

<code> </code><code>COUNT</code><code>(*)</code>

<code>/*我们在非生产环境测试一下*/</code>

<code>select</code> <code>addr </code><code>"十六进制地址"</code><code>,</code>

<code> </code><code>to_number(addr, </code><code>'xxxxxxxxxxxx'</code><code>) </code><code>"十进制地址"</code><code>,</code>

<code> </code><code>misses,</code>

<code> </code><code>immediate_gets,</code>

<code> </code><code>immediate_misses</code>

<code> </code><code>from</code> <code>v$latch_children</code>

<code> </code><code>where</code> <code>name</code> <code>= </code><code>'redo copy'</code><code>;</code>

<code>十六进制十进制地址 GETS MISSES IMMEDIATE_GETS IMMEDIATE_MISSES</code>

<code>8 </code><code>rows</code> <code>selected.</code>

<code>/*正式测试前的redo copy child latch统计信息，我们还要用到这里的十进制latch地址*/</code>

<code>/*我们尝试手动hold住一个redo copy child latch，并在其他会话中执行一些产生redo的操作*/</code>

<code>session A:</code>

<code>SQL> oradebug setmypid;</code>

<code>Statement processed.</code>

<code>SQL> oradebug call kslgetl 766203160 1;</code>

<code>Function</code> <code>returned 1</code>

<code>/* kslgetl是Oracle内部用get latch的函数，oradebug 可以调用该函数*/</code>

<code>session B:</code>

<code>SQL> </code><code>select</code> <code>* </code><code>From</code> <code>v$latchholder;</code>

<code> </code><code>PID SID LADDR </code><code>NAME</code> <code>GETS</code>

<code>另外开三个session,执行一下批量插入数据的匿名块，测试redo是否能够正常产生：</code>

<code>begin</code>

<code> </code><code>insert</code> <code>into</code> <code>tv </code><code>values</code> <code>(i, i, i);</code>

<code> </code><code>commit</code><code>;</code>

<code>PL/SQL </code><code>procedure</code> <code>successfully completed.</code>

<code>SQL> oradebug call kslfre 766203160 1;</code>

<code>Function</code> <code>returned 2FD548E0</code>

<code>/*手动释放766203160对应的redo copy 子闩*/</code>

<code>/*可以看到虽然8个子闩中一个被手动hold住，但对实例的影响远不足以到达hang所需要的条件*/</code>

虽然能证明单个redo copy latch被僵死进程长期持有和实例hang住没有必然的因果联系，但因为缺少相关的systemstate和hanganalyze转储信息，我们也无法进一步做出推断。这个case发生后的几个月，我无意中在MOS上发现了以下Bug note:

Diagnostic collection may hang or crash the instance Description Sometimes while the DIAG process is collecting diagnostics the database may hang or crash. This is more likely to occur in a RAC or ASM environment . You may be seeing this problem if the database crashes or hangs just after you see the following text in a trace file: "Dumping diagnostic information for X" where X is the process that hung or terminated. This fix replaces invokations of a port specific OS debugger (like gdb) with Oracle ORADEBUG calls to gather the required diagnostics. Note: For HP Itanium fixes for this issue in 10.2.0.3/10.2.0.4 use bug 8767023 instead of this bug#. For AIX fixes for this issue in 10.2.0.3/10.2.0.4 use bug 8929701 instead of this bug#. Workaround >=10.2.0.3 only: Set init.ora parameter "_ksb_disable_diagpid" = TRUE but this will disable automatic diagnostics collection.

当diag诊断进程调用系统debugger工具调试问题进程时可能出现实例hang或crash的，且该问题多发于RAC或ASM环境中，workaroud的方法是动态设置_ksb_disable_diagpid为TRUE，可以避免diag诊断进程对问题进程的调试，但这些调试信息往往对我们又是有用的，这倒有些《种树郭橐驼说》中"既然已，勿动勿虑，去不复顾"的味道。好了这个问题，仍旧pending着，是个悬案。

本文转自maclean_007 51CTO博客，原文链接:http://blog.51cto.com/maclean/1277132

Pending Problem

继续阅读

ASP编程中20个非常有用的例子

龙珠训练营task04

阿里云天池龙珠计划SQL训练营打卡

阿里云天池龙珠计划SQL训练营day1

赋予用户dba权限--解释以上：

实验楼sql进阶之成绩管理系统的数据操作(window)

Oracle的基本操作

为什么要选择UniDAC

SQL优化SQL语句优化的目的

JAVA高效编程指南

windows不能在本地计算机上运行oracleDbConsoleorcl

关于SQL语言

SQL语言基础：常用的数据查询语句

neo4j之cypher使用文档

sqlServer根据经纬查距离

Oracle 批量查询传入List 返回List