故障排除:"WAITED TOO LONG FOR A ROW CACHE ENQUEUE LOCK! "

mosdoc發表於2016-12-04
故障排除:"WAITED TOO LONG FOR A ROW CACHE ENQUEUE LOCK! " (文件 ID 2016422.1)

轉到底部轉到底部

文件內容


用途

排錯步驟
  什麼是 row cache enqueue 鎖(Row Cache Enqueue Lock)?
  "WAITED TOO LONG FOR A ROW CACHE ENQUEUE LOCK!" 警告資訊是什麼意思?
  "WAITED TOO LONG FOR A ROW CACHE ENQUEUE LOCK!" 可能的原因
  SGA收縮(shrink)/調整大小的操作(resize)
  row cache enqueue 型別
  DC_TABLESPACES
  DC_SEQUENCES
  DC_USERS
  DC_OBJECT_IDS
  DC_SEGMENTS
  DC_ROLLBACK_SEGMENTS
  DC_TABLE_SCNS
  DC_AWR_CONTROL
  我可以收集哪些資訊,以確定原因?
  Systemstate dump
  AWR,ADDM 和 ASH 報告
  如何分析收集到的診斷資訊?
  Systemstate dump
  示例1:
  示例2:
  AWR 報告
  10g 以前的版本可能存在的問題
  其他問題疑難解答

參考


適用於:

Oracle Database - Personal Edition - 版本 8.0.6.0 和更高版本
Oracle Database - Enterprise Edition - 版本 8.0.6.0 和更高版本
Oracle Database - Standard Edition - 版本 8.0.6.0 和更高版本
本文件所含資訊適用於所有平臺

用途

本文件的目的是幫助排查原因"WAITED TOO LONG FOR A ROW CACHE ENQUEUE LOCK! "

排錯步驟

什麼是 row cache enqueue 鎖(Row Cache Enqueue Lock)?

行快取(Row Cache)或資料字典快取(Data Dictionary Cache)是儲存資料字典資訊的共享池的記憶體區域。row cache 儲存資料時並不是以資料塊的形式,而是以行的形式。row cache enqueue 鎖是在資料字典行的鎖。此 enqueue 是關於特定資料字典物件的。這就是所謂的 enqueue 型別,可以在檢視 V$rowcache 中找到。

對於每個版本 row cache 型別的列表,請參閱:

Document 468334.1  How to Match a Row Cache Object Child Latch to its Row Cache

"WAITED TOO LONG FOR A ROW CACHE ENQUEUE LOCK!" 警告資訊是什麼意思?

當我們試圖獲得 row cache 鎖,這種等待事件將被使用。
當 row cache 衝突發生時,如果不能在一個預定的時間週期內得到 enqueue,將在 USER_DUMP_DEST 或 background_dump_dest 目錄下生成一個跟蹤檔案,這取決於是使用者還是後臺程式建立的跟蹤檔案。alert.log 通常會相應的更新警告訊息和跟蹤檔案的位置。
資料庫檢測到核心資源被持有太久並通知管理員,從而讓這種情況可以得到解決。這也可能伴隨著資料庫掛起或變慢。
alert.log 的訊息和生成的跟蹤檔案趨向於包含訊息:

> WAITED TOO LONG FOR A ROW CACHE ENQUEUE LOCK! <<<

如果不能立即獲取 rowcache entry 鎖,那麼進入一個迴圈,先釋放 row cache 物件閂鎖,等待(等待上述等待事件),重新獲得閂鎖,然後再次嘗試獲取 rowcache 鎖。在單例項模式,會重複 1000次直到程式報錯“WAITED TOO LONG FOR A ROW CACHE ENQUEUE LOCK”。在 RAC 環境會一直重複,直到不能獲得例項鎖或者被中斷。

Systemstate dump 可以提供一些有用的資訊診斷爭用的原因。

請注意:The "WAITED TOO LONG FOR A ROW CACHE ENQUEUE LOCK!" 當達到閾值會引發這個訊息,因此,如果未達到閾值它不會被引發。這意味著,不太嚴重的問題,即使具有相同的原因,也可以不輸出該訊息。

 

"WAITED TOO LONG FOR A ROW CACHE ENQUEUE LOCK!" 可能的原因

SGA收縮(shrink)/調整大小的操作(resize)

如果 SGA 動態地改變大小,需要持有各種 latches 來避免其它程式同時操作,直到操作完成。如果調整大小需要一段時間,或者是經常發生,你會看到"WAITED TOO LONG FOR A ROW CACHE ENQUEUE LOCK!"的發生。定位這種情況的方法是,有很多'SGA: allocation forcing component growth'等待事件,或 AWR 的 TOP 列表有類似等待,以及阻塞等待"WAITED TOO LONG FOR A ROW CACHE ENQUEUE LOCK!" 的會話在等待'SGA: allocation forcing component growth'(或類似)。有一些可用的程式碼修復,請參閱:

Document 7189722.8 Bug 7189722 - Frequent grow/shrink SGA resize operations
Document 9267837.8 Bug 9267837 - Auto-SGA policy may see larger resizes than needed

row cache enqueue 型別

對於每一個 enqueue 型別,都有對應的一些操作會需要獲取這類 enqueue。佇列的型別,可能給出由於操作可能導致的問題的指示。一些常見的原因如下:

DC_TABLESPACES

最可能的原因是新 extent 的分配。如果 extent 大小設定過小,那麼應用程式可能會不斷地要求新的 extent,這可能導致爭用。你有很小的 extent 尺寸,正在迅速增長的物件嗎?(通過查詢具有大量 extents 的物件可以定位它們)。檢查 insert/update 活動的 trace,查詢那些就有很多 extents 的物件。

DC_SEQUENCES

檢查應用程式用到的 sequence 的 cache 的大小:

Document 853652.1 RAC and Sequences
Document 395314.1 RAC Hangs due to small cache size on SYS.AUDSES$ - fixed in 10.2.0.3
Document 6027068.8 Bug 6027068 - Contention on ORA_TQ_BASE sequence -fixed in 10.2.0.5 and 11.2.0.1
DC_USERS

一個會話正在對一個使用者執行 GRANT,與此同時此使用者正在登入到資料庫中,此時可能會發生死鎖或導致"WAITED TOO LONG FOR A ROW CACHE ENQUEUE LOCK!" 。

Document 4604972.8 Bug 4604972 - Deadlock on dc_users by Concurrent Grant/Revoke - fixed in 11.1.0.6
Document 6143420.8 Bug 6143420 - Deadlock involving "ROW CACHE LOCK" on dc_users AND "CURSOR: PIN S WAIT ON X"- fixed in 10.2.0.5 and 11.1.0.6  DC_OBJECTS
Document 12772404.8 Bug 12772404 - Significant "row cache objects" latch contention when using VPD
DC_OBJECT_IDS
Document 11693365.8 Bug 11693365 - Concurrent Drop table and Select on Reference constraint table hangs(deadlock) - fixed in 12.1
DC_SEGMENTS

這很可能是 segment 的分配導致的。確定持有鎖的使用者正在做什麼並使用 errorstacks 進行診斷。

DC_ROLLBACK_SEGMENTS

這可能是由於 rollback 段的分配導致的。正如 dc_segments,確定誰持有鎖並收集 errorstack 來進行診斷。請記住,在多節點系統(RAC)上,持有者可能在另一節點上,因此需要所有節點的 systemstate。

DC_TABLE_SCNS
Document 5756769.8 Bug 5756769 - Deadlock between Create MVIEW and DML - fixed in 10.2.0.5 ,11.1.07 and 11.2.0.1
DC_AWR_CONTROL

此 enqueue 關係到 AWR(Automatic Workload Repository)的控制權。任何操縱 AWR 資料庫的操作將持有它. 要分析這個問題,需要查詢是那些程式阻塞了它們。

  RAC 相關的 Bugs

Document 6004916.8 Bug 6004916 - Hang involving row cache enqueues in RAC (ORA-4021) - fixed in 102.0.5 and 11.1.0.6
Document 8666117.8 Bug 8666117 - High row cache latch contention in RAC - fixed in 11.2.0.2 and 12.1
Document 9866045.8 Bug 9866045 - Long wait on 'wait for master scn' in LCK causing long row cache lock waits - fixed in 12.1


我可以收集哪些資訊,以確定原因?

Systemstate dump

當問題發生時,錯誤會記入 alert.log,並自動產生一個 systemstate dump 檔案。

Wed Sep 21 13:39:19 2011
> WAITED TOO LONG FOR A ROW CACHE ENQUEUE LOCK! pid=37
System State dumped to trace file /oracle/diag/rdbms/..../.trc

 

AWR,ADDM 和 ASH 報告

收集兩份 AWR 報告,一份有問題時間段的,另一個是沒有問題時間段的,因為這些可以幫助我們理解問題發生時資料庫的狀況 AWR,ADDM,ASH 報告,可以相互取長補短,從而更完整地理解整個問題。

取決於 AWR 快照生成的時間間隔,收集最小時間間隔的報告。預設的快照是一個小時的時間間隔。

SQL>@$ORACLE_HOME/rdbms/admin/awrrpt.sql
SQL>@$ORACLE_HOME/rdbms/admin/addmrpt.sql
SQL>@$ORACLE_HOME/rdbms/admin/ashrpt.sql


鑑於分析 systemstate 是一件很複雜的事情,您可以建立一個服務請求,並上傳 alert.log,systemstate dump,以及問題發生前和問題發生時的 AWR 報告請 Oracle 技術支援來分析。

如何分析收集到的診斷資訊?

Systemstate dump

通常情況下, row cache enqueue 是一系列事件的一部分,阻塞了申請 row cache enqueue 的程式的程式很可能被另一個程式阻塞。Row cache enqueue 經常是問題的表象。

Systemstate dump 可以幫助查詢申請的是哪一個 row cache ,並可能有助於發現阻塞程式。

示例1:
Oracle process number: 77
Unix process pid: 10846, image: oracle@cpdb4532

*** 2011-05-13 08:08:58.775
*** SERVICE NAME:(ALFCMR_SERVICE) 2011-05-13 08:08:58.775
*** SESSION ID:(1076.796) 2011-05-13 08:08:58.775
> WAITED TOO LONG FOR A ROW CACHE ENQUEUE LOCK! <<<
row cache enqueue: session: 0x1df57ade8, mode: N, request: S


trace 的標題顯示下列內容:

  • 等待 row cache enqueue 鎖的 Oracle 程式號(PID)(在這個案例,程式 77)。
  • 正在申請的 row cache enqueue 的模式(請求:S)。

因此,在上述例子中,程式 77 是在請求以共享模式獲得 row cache(請求:S)。

Systemstate 包含資料庫中每一個程式的狀態資訊,因此可以在 systemstate 中查詢這個程式:

PROCESS 77
----------------------------------------
.
.
----------------------------------------
SO: 0x1cdf11958, type: 50, owner: 0x17d198288, flag: INIT/-/-/0x00
row cache enqueue: count=1 session=0x1df57ade8 object=0x1dc9a5d30, request=S
savepoint=0x87b70d
row cache parent object: address=0x1dc9a5d30 cid=7(dc_users)
.
.


從上面我們看到,程式 77 請求共享模式獲得 row cache dc_users。
程式 77 處於等待狀態,意味著被其它程式阻塞,我們現在需要檢查 systemstate 判斷誰持有資源並阻塞了這個程式。

搜尋引用的物件,在這個例子中,是 object=0x1dc9a5d30。
這樣做完以後,我們發現,程式 218 正以獨佔模式持有這個物件:

PROCESS 218:
----------------------------------------
.
.
SO: 0x1cdf118f8, type: 50, owner: 0x1ceb0f178, flag: INIT/-/-/0x00
row cache enqueue: count=1 session=0x1da54cf68 object=0x1dc9a5d30, request=X
savepoint=0x11e
row cache parent object: address=0x1dc9a5d30 cid=7(dc_users)


獨佔模式的請求,將會一直阻塞共享模式的請求,直到該程式獨佔模式的請求被滿足並稍後釋放了這個資源。因此,這將阻止其他共享模式請求。請注意,這是請求獨佔而不是獨佔持有,所以這個請求也一定被阻塞了。檢視其他程式中,我們看到程式 164 在以共享模式(mode=s)持有這個物件。

PROCESS 164:
----------------------------------------
.
.
O/S info: user: u1m, term: , ospid: 1234, machine: cpc44711
program:
last wait for 'SQL*Net message from client' blocking sess=0x(nil) seq=36289 wait_time=6943 seconds since wait started=2539
driver id=54435000, #bytes=1, =0
.
.
SO: 0x1cdf11418, type: 50, owner: 0x1ccc26120, flag: INIT/-/-/0x00
row cache enqueue: count=2 session=0x1df578318 object=0x1dc9a5d30, mode=S
savepoint=0xb1bd8e
row cache parent object: address=0x1dc9a5d30 cid=7(dc_users)
hash=fc968070 typ=11 transaction=(nil) flags=00000002
own=0x1dc9a5e00[0x1cdf11448,0x1cdf11448] wat=0x1dc9a5e10[0x1cdf11928,0x17d5192e0] mode=S


因此,程式 164 以共享模式持有 row cache enqueue(mode= S),從而防止了程式 218 以獨佔模式獲得該 row cache enqueue。此外,我們看到,程式 164 在 ON CPU(systemstate 顯示最後一個等待是'SQL*Net message from client',而不是等待'SQL*Net message from client')。為了進一步診斷,技術支援需要檢查堆疊呼叫,以確定為什麼這個程式在 ON CPU 並持有該佇列這麼久(從開始已經等待了2539秒)。

示例2:


在這個例子中,程式 18(MMON)等待以共享模式獲得型別為 dc_awr_control 的 row cache。

Oracle Database 10g Enterprise Edition Release 10.2.0.5.0 - 64bit Production
With the Partitioning, Oracle Label Security, OLAP, Data Mining
and Real Application Testing options
ORACLE_HOME = /opt/oracle10/product/10.2.0
System name: SunOS
Node name: saecopt51
Release: 5.10
Version: Generic_144488-04
Machine: sun4v
Instance name: PORT_V16
Redo thread mounted by this instance: 1
Oracle process number: 18
Unix process pid: 6196, image: oracle@sae (MMON)
.
.

PROCESS 18:
----------------------------------------
.
.
last wait for 'ksdxexeotherwait' wait_time=0.000013 sec, seconds since wait started=6
.
.
SO: 39bf1f0e8, type: 50, owner: 3980783a0, flag: INIT/-/-/0x00
row cache enqueue: count=1 session=3be37ea80 object=39a79f090, request=S
savepoint=0x41f0ae
row cache parent object: address=39a79f090 cid=22(dc_awr_control)
hash=6f60197e typ=9 transaction=3bc39f560 flags=0000002a
own=39a79f160[39bf1f178,39bf1f178] wat=39a79f170[39bf1f118,39bf1f118] mode=X
.
.


物件(object=39a79f090)的 row cache lock 被程式 269 以獨佔模式(mode=x)持有。程式在等待'SGA: allocation forcing component growth'。

PROCESS 269:
----------------------------------------
.
.

waiting for 'SGA: allocation forcing component growth' wait_time=0, seconds since wait started=3

.
.
SO: 39bf1f148, type: 50, owner: 3bc39f560, flag: INIT/-/-/0x00
row cache enqueue: count=1 session=3be1b7c98 object=39a79f090, mode=X
savepoint=0x41efe8
row cache parent object: address=39a79f090 cid=22(dc_awr_control)
hash=6f60197e typ=9 transaction=3bc39f560 flags=0000002a
own=39a79f160[39bf1f178,39bf1f178] wat=39a79f170[39bf1f118,39bf1f118] mode=X
.
.


因此根本原因就是 SGA 的大小調整,等待 row cache 是次要結果。
我們使用該期間的 AWR 報告看相關資訊:

AWR 報告

Top 5 Timed Events                                         Avg %Total               
~~~~~~~~~~~~~~~~~~                                        wait   Call               
Event                                 Waits    Time (s)   (ms)   Time Wait Class    
------------------------------ ------------ ----------- ------ ------ ----------    
SGA: allocation forcing compon   42,067,317      38,469      1    7.6      Other    
CPU time                                          2,796           0.6               
db file sequential read             132,906         929      7    0.2   User I/O    
latch free                        4,282,858         704      0    0.1      Other    
log file switch (checkpoint in          904         560    620    0.1 Configurat    
          -------------------------------------------------------------       


我們可以清楚地看到,在 Top 5 等待事件中,整個系統中有針對此事件的一個顯著等待;並且'SGA: allocation forcing component growth' 是這一時間點的一個主要問題。"WAITED TOO LONG FOR A ROW CACHE ENQUEUE LOCK!" 訊息的根本原因就是記憶體調整活動,TOP 5 的等待事件甚至不顯示等待“row cache"症狀。

注意:
如果調整記憶體大小沒有那麼嚴重,有些時候沒有"WAITED TOO LONG FOR A ROW CACHE ENQUEUE LOCK!"訊息。 - 主要是因為沒有達到在此之前提到的閾值。但是,您可能會看到其他等待事件。在以下文獻中概述了一個常見的例子:

Document 742599.1 High 'cursor: pin S wait on X' and/or 'library cache lock' Waits Generated by Frequent Shared Pool/Buffer Cache Resize Activity

對於頻繁的記憶體調整,有幾個潛在的可用修復,請參閱:

Document 7189722.8 Bug 7189722 - Frequent grow/shrink SGA resize operations
Document 9267837.8 Bug 9267837 - Auto-SGA policy may see larger resizes than needed

10g 以前的版本可能存在的問題

10g 之前的版本,檢測 row cache 級別死鎖的方法有限。為了儘量減少發生死鎖的可能性,可能的解決方法:

  • 設定 TIMED_STATISTICS=FALSE
  • 設定 _row_cache_cursors=20 以上(預設值 10)
  • 不要做任何 tracing
Document 30802.1 Init.ora Parameter "ROW_CACHE_CURSORS" Reference Note

其他問題疑難解答

對於其他效能問題的故障排除,請參閱:

Document 1377446.1 Troubleshooting Performance Issues

 

 

Bug 12772404 - Significant "row cache objects" latch contention when using VPD (Doc ID 12772404.8)

參考

BUG:11693365 - GETTING ERROR 'WAITED TOOL LONG FOR ROW CACHE ENQUEUE LOCK'


BUG:5756769 - ROW CACHE DEADLOCK "WAITED TOO LONG FOR A ROW CACHE ENQUEUE LOCK!"
NOTE:11693365.8 - Bug 11693365 - Concurrent Drop table and Select on Reference constraint table hangs (deadlock)
NOTE:1377446.1 - * Troubleshooting Performance Issues
NOTE:30802.1 - Init.ora Parameter "ROW_CACHE_CURSORS" Reference Note
NOTE:395314.1 - RAC Hangs due to small cache size on SYS.AUDSES$
NOTE:4604972.8 - Bug 4604972 - Deadlock on dc_users by Concurrent Grant/Revoke
NOTE:468334.1 - How to Match a Row Cache Object Child Latch to its Row Cache
NOTE:5756769.8 - Bug 5756769 - Deadlock between Create MVIEW and DML
NOTE:6004916.8 - Bug 6004916 - Hang involving row cache enqueues in RAC (ORA-4021)
NOTE:6027068.8 - Bug 6027068 - Contention on ORA_TQ_BASE$ sequence
NOTE:6143420.8 - Bug 6143420 - Deadlock involving "ROW CACHE LOCK" on dc_users AND "CURSOR: PIN S WAIT ON X"
NOTE:742599.1 - High 'Cursor: Pin S Wait On X', 'Library Cache Lock' And "Latch: Shared Pool" Waits due to Shared Pool/Buffer Cache Resize Activity
NOTE:853652.1 - RAC and Sequences
NOTE:8666117.8 - Bug 8666117 - High row cache latch contention in RAC
NOTE:9866045.8 - Bug 9866045 - Long wait on 'wait for master scn' in LCK causing long row cache lock waits



BUG:8666117 - LCK0 PROCESS STUCK AT WAITING FOR "LATCH: ROW CACHE OBJECTS"

來自 “ ITPUB部落格 ” ,連結:http://blog.itpub.net/31393455/viewspace-2129695/,如需轉載,請註明出處,否則將追究法律責任。

相關文章