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