DRM 分析及案例講解

什麼是DRM

DRM（Dynamic Resource management）是oracle10.10.2裡面推出來的一個新特性，一直到現在最新的12cR1，都存在，且bug非常多而著稱。在10gR1 RAC是每個例項都有其自己的SGA和buffer cache。RAC為了確保這些塊發生時的最大化效能,確保資料完整。每個緩衝區副本也稱為快取資源有一個主要的將做為一個主要的叢集節點。在資料庫版本10g(10.1.0.2)一個主要的快取資源負責掌管一個例項,re-mastering或改變主節點只會發生在重新配置,會自動在兩個正常操作例項啟動或例項關閉，異常節點叢集管理器將對其進行逐出。因此,如果節點B這個時候作為一個主快取的資源,這個資源仍將掌握在節點B直到重新配置。10g中引入了一個新概念,透過DRM資源進行remaster。與DRM資源可以在另一個節點上重新最佳化,從節點B節點如果發現更頻繁地訪問快取資源從節點a重新配置不再是資源重新最佳化的唯一原因。

到10gR2是基於相關物件的，下面是DRM的跟蹤trace檔案，在Oracle日誌中的LMD程式資訊裡面。

Sample LMD trace file during a DRM operation

Begin DRM(202) - transfer pkey 4294951314 to0 oscan 1.1
*** 2006-08-01 17:34:54.645
Begin DRM(202) - transfer pkey 4294951315 to 0 oscan 1.1
*** 2006-08-01 17:34:54.646
Begin DRM(202) - transfer pkey 4294951316 to 0 oscan 1.1
*** 2006-08-01 17:34:54.646
Begin DRM(202) - transfer pkey 4294951317 to 0 oscan 1.1

remastering的發生:

Remastering問題發生時會影響效能。以下AWR報告顯示了DRM重配置問題導致的例項凍結。同樣型別的凍結在其它的所有節點上也都可以看見。gc buffer busy等待只是DRM凍結的副作用（不是總有，但是在這個case是這樣）。

Top 5 Timed Events                                         Avg %Total
~~~~~~~~~~~~~~~~~~                                        wait   Call
Event                                 Waits    Time (s)   (ms)   Time Wait Class
------------------------------ ------------ ----------- ------ ------ ----------
gc buffer busy                    1,826,073     152,415     83   62.0    Cluster
CPU time                                         30,192          12.3
enq: TX - index contention           34,332      15,535    453    6.3 Concurrenc
gcs drm freeze in enter server       22,789      11,279    495    4.6      Other
enq: TX - row lock contention        46,926       4,493     96    1.8 Applicatio

在同一時刻，DRM大量發生，導致了重複的DRM凍結、例項重配置，從而引發嚴重的效能問題。

Top 5 Timed Events                                         Avg %Total
~~~~~~~~~~~~~~~~~~                                        wait   Call
Event                                 Waits    Time (s)   (ms)   Time Wait Class
------------------------------ ------------ ----------- ------ ------ ----------
latch: cache buffers lru chain      774,812     140,185    181   29.7      Other
gc buffer busy                    1,356,786      61,708     45   13.1    Cluster
latch: object queue header ope      903,456      55,089     61   11.7      Other
latch: cache buffers chains         360,522      49,016    136   10.4 Concurrenc
gc current grant busy               112,970      19,893    176    4.2    Cluster

可以看到，TOP 5中，有3個是latch相關的等待，而另外2個則是跟RAC相關的等待。
如果再檢視更細的等待資料，可以發現其他問題：

                                                  Avg
                                            %Time  Total Wait    wait     Waits
Event                                 Waits -outs    Time (s)    (ms)      /txn
---------------------------- -------------- ----- ----------- ------- ---------
latch: cache buffers lru cha        774,812   N/A     140,185     181       1.9
gc buffer busy                    1,356,786     6      61,708      45       3.3
latch: object queue header o        903,456   N/A      55,089      61       2.2
latch: cache buffers chains         360,522   N/A      49,016     136       0.9
gc current grant busy               112,970    25      19,893     176       0.3
gcs drm freeze in enter serv         38,442    97      18,537     482       0.1
gc cr block 2-way                 1,626,280     0      15,742      10       3.9
gc remaster                           6,741    89      12,397    1839       0.0
row cache lock                       52,143     6       9,834     189       0.1

從上面的資料還可以看到，除了TOP 5等待，還有”gcs drm freeze in enter servermode“以及”gc remaster”這2種比較少見的等待事件，從其名稱來看，明顯與DRM有關。那麼這2種等待事件與TOP5的事件有沒有什麼關聯？。MOS文件”Bug 6960699- “latch: cache buffers chains” contention/ORA-481/kjfcdrmrfg: SYNC TIMEOUT/OERI[kjbldrmrpst:!master] [ID 6960699.8]”提及，DRM的確可能會引起大量的”latch: cache buffers chains”、”latch: objectqueue header operation”等待，雖然文件沒有提及，但不排除會引起”latch: cachebuffers lru chain“這樣的等待。

為了進一步證實效能問題與DRM相關，使用tail -f命令監控LMD後臺程式的trace檔案。在trace檔案中顯示開始進行DRM時，查詢v$session檢視，發現大量的 “latch: cache buffers chains” 、”latch:object queue header operation”等待事件，同時有”gcs drm freezein enter server mode“和”gc remaster”等待事件，同時系統負載升高，前臺反映效能下降。而在DRM完成之後，這些等待消失，系統效能恢復到正常。

* received DRM start msg from 2 (cnt 5, last 1, rmno 404)
Rcvd DRM(404) Transfer pkey 1598477 from 3 to 2 oscan 1.1
Rcvd DRM(404) Dissolve pkey 6100030 from 2 oscan 0.1
Rcvd DRM(404) Dissolve pkey 5679943 from 2 oscan 0.1
Rcvd DRM(404) Transfer pkey 6561036 from 0 to 2 oscan 1.1
Rcvd DRM(404) Transfer pkey 5095243 to 2 oscan 0.1
...

A small test case
我們來看一個測試，觀察一下DRM的產生。使用了索引讀路徑的查詢從一個大索引中讀取了幾乎所有資料塊。

Session #1:
select data_object_id from dba_objects where object_name='WMS_N1';
DATA_OBJECT_ID
-------------
6099472


REM 還沒有affinity統計資訊




select * from x$object_affinity_statistics where object=6099472;

no rows selected.

 
REM 執行高代價的查詢語句

select /*+ index(a WMS_N1) */ count(*) from big_table1 a;

 
Session #2: 觀察DRM表:

REM DRM欄位現在是409,。我們將持續觀察這個數值。在這個檢視中還有其它比較有趣的欄位。

select drms from X$KJDRMAFNSTATS;

DRM
----
409

 

REM 觀察到自從會話#1開始執行在該索引上已經有23442個OPENs

select * from x$object_affinity_statistics where object=6099472;

ADDR                   INDX    INST_ID     OBJECT       NODE      OPENS
---------------- ---------- ---------- ---------- ---------- ----------
FFFFFFFF7C05BFA8         14          1    6099472          1      23442
 

REM 該物件上還沒有發生mastering

select * from v$gcspfmaster_info where object_id=6099472;

no rows selected

REM 幾秒後，OPENs計數從23442上升到33344

select * from x$object_affinity_statistics where object=6099472;
ADDR                   INDX    INST_ID     OBJECT       NODE      OPENS
---------------- ---------- ---------- ---------- ---------- ----------
FFFFFFFF7C05BFA8         16          1    6099472          1      33344

 

REM該物件上還沒有發生mastering

select * from v$gcspfmaster_info where object_id=6099472;
no rows selected

 

REM 讓人詫異，會話#1還在執行，OPENs計數忽然清零即使DRM還未發生過

REM OPENs從0又升到1229因為會話#1還在執行

ADDR                   INDX    INST_ID     OBJECT       NODE      OPENS
---------------- ---------- ---------- ---------- ---------- ----------

FFFFFFFF7C05BFA8          0          1    6099472          1       1229

 

REM 大約10分鐘以後，remastering發生了。DRMS從409上升到411。

select drms from X$KJDRMAFNSTATS;

DRM
----
411

 

REM 該索引的remastering發生了。現在該物件的屬主是0，也就是例項1

select * from v$gcspfmaster_info where object_id=6099472;

   FILE_ID  OBJECT_ID CURRENT_MASTER PREVIOUS_MASTER REMASTER_CNT
---------- ---------- -------------- --------------- ------------
         0    6099472              0           32767            1

 
REM OPENs還在上升，但是remastering已經發生了。

select * from x$object_affinity_statistics where object=6099472;

ADDR                   INDX    INST_ID     OBJECT       NODE      OPENS
---------------- ---------- ---------- ---------- ---------- ----------
FFFFFFFF7C05AF78          2          1    6099472          1      42335
FFFFFFFF7C05AF78          3          1    6099472          2          1

 
REM LMON trace檔案也指出pkey的傳遞。注意pkey和object_id是相同的。

*** 2010-03-23 10:41:57.355
Begin DRM(411) - transfer pkey 6099472 to 0 oscan 0.0
 ftd received from node 1 (4/0.30.0)
 all ftds received

 

REM 幾秒後，OPENs被再次重置。

select * from x$object_affinity_statistics where object=6099472;

ADDR                   INDX    INST_ID     OBJECT       NODE      OPENS
---------------- ---------- ---------- ---------- ---------- ----------
FFFFFFFF7C05BFA8          0          1    6099472          1       7437
 

REM 屬主仍然是例項1。

select * from v$gcspfmaster_info where object_id=6099472;

   FILE_ID  OBJECT_ID CURRENT_MASTER PREVIOUS_MASTER REMASTER_CNT
---------- ---------- -------------- --------------- ------------
         0    6099472              0           32767            1

我們的測試表明，該索引上發生了大量的BL鎖請求，之後物件被remastering。

Undo and affinity
回滾段的Mastering和其它段不同。對於非回滾段而言，一個段上的所有資料塊透過雜湊演算法被分散在各個例項間。只有在經過大量的BL鎖請求以後，段才會被mastering。但是對於回滾段而言，啟用了一個回滾段的例項立刻成為該段的屬主。這是合乎情理的，因為在大多數情況下回滾段將會被開啟這個segment的例項使用。初始化引數_gc_undo_affinity控制這種動態undo remastering動作是否發生。

因為回滾段沒有真正的object_id，所以使用4294950912作為虛擬object_ids的基準值。比如說，回滾段1（usn=1）的object_id是4294950913，回滾段2（usn=2）的object_id就是4294950914，依次類推（4294950912 = power(2,32) – power (2,14)= xFFFFC000）。

select objecT_id, object_id-4294950912 usn, current_master, previous_master,

remaster_cnt  from v$gcspfmaster_info where object_id>4294950912;


 OBJECT_ID        USN CURRENT_MASTER PREVIOUS_MASTER REMASTER_CNT
---------- ---------- -------------- --------------- ------------
4294950913          1              0           32767            1
4294950914          2              0           32767            1
4294950915          3              0           32767            1
4294950916          4              0           32767            1
4294950917          5              0           32767            1
4294950918          6              0           32767            1
4294950919          7              0           32767            1
4294950920          8              0           32767            1
4294950921          9              0           32767            1
4294950922         10              0           32767            1
4294950923         11              1           32767            1
4294950924         12              1           32767            1
4294950925         13              1           32767            1
...

 

REM 注意usn 0在兩個例項中都存在，這是系統回滾段。

REM 下面結果顯示，頭10個回滾段被node1掌控，而接下來的3個被例項2掌控。

select inst_id, usn, gets from gv$rollstat where usn <=13 order by inst_id, usn;

   INST_ID        USN       GETS
---------- ---------- ----------
         1          0       3130
         1          1     108407
         1          2      42640
         1          3      43985
         1          4      41743
         1          5     165166
         1          6      43485
         1          7     109044
         1          8      23982
         1          9      39279
         1         10      48552
         2          0       4433
         2         11     231147
         2         12      99785
         2         13      1883

我沒有成功試驗出觸發下一次回滾段remastering。我建立了一個活動事務在一個節點上產生了200K回滾資料塊，然後另外一個節點在讀這個表，我觀察到在回滾資料塊上有大量等待。但是我沒有發現這個回滾段上有任何remastering事件。無法確認為什麼沒有產生，也許是回滾段remastering的條件有所不同吧。

譯者注：回滾段的remastering是不會因為另外一個節點對於回滾段有大量讀取而發生的，只有在某個例項失效，然後負責進行例項恢復的另外那個例項會暫時的成為這些回滾段的master，這是為了進行例項恢復的需要，在恢復完畢以後所有的undo buffers都會被flush到磁碟上。

PS：我能夠使用後面將描述的lkdebug命令手動remaster回滾段，所以oracle也應該可以自動remaster回滾段，只是可能還有一個其它條件也必須滿足。

select * from v$gcspfmaster_info where object_id=431+4294950912;

   FILE_ID  OBJECT_ID CURRENT_MASTER PREVIOUS_MASTER REMASTER_CNT
---------- ---------- -------------- --------------- ------------
         0 4294951343              0           32767            1

 
Oradebug lkdebug –m pkey 4294951343
 
  
* kjdrchkdrm: found an RM request in the request queue

  Transfer pkey 4294951343 to node 1

*** 2010-03-24 12:47:29.011

Begin DRM(520) - transfer pkey 4294951343 to 1 oscan 0.1

 ftd received from node 0 (4/0.31.0)

 all ftds received
 

select * from v$gcspfmaster_info where object_id=431+4294950912;

SQL> /

   FILE_ID  OBJECT_ID CURRENT_MASTER PREVIOUS_MASTER REMASTER_CNT
---------- ---------- -------------- --------------- ------------

         0 4294951343              1               0            2

我不是在勸你們應該去修改這些隱含引數。只是要去理解這些引數，如果你們碰到諸如’gc remaster’, ‘gcs freeze for instancereconfiguration’這樣的等待事件，那麼應該知道是不是因為預設值太低了。跟技術支援溝通嘗試是否能夠調整。

Manual remastering
你可以使用oradebug命令來手動remaster一個物件：

oradebug lkdebug -m pkey

這會將一個物件remaster請求放入佇列。LMD0和LMON程式會完成這個請求。

當前屬主是從0開始計數的。

*** 2010-01-08 23:25:54.948
* received DRM start msg from 1 (cnt 1, last 1, rmno 191)
Rcvd DRM(191) Transfer pkey 6984154 from 0 to 1 oscan 0.0
ftd received from node 1 (8/0.30.0)
ftd received from node 0 (8/0.30.0)
ftd received from node 3 (8/0.30.0)





SQL> select * from v$gcspfmaster_info whereobject_id=6984154; 

FILE_ID OBJECT_ID CURRENT_MASTERPREVIOUS_MASTER REMASTER_CNT 
---------- ---------- ----------------------------- ------------ 
0 6984154 1 0 2 


SQL> oradebug lkdebug -m pkey 6984154 

Statement processed. 


SQ> select * from v$gcspfmaster_info where object_id=6984154; 

FILE_ID OBJECT_ID CURRENT_MASTERPREVIOUS_MASTER REMASTER_CNT 
---------- ---------- ----------------------------- ------------ 
0 6984154 2 1 3

Summary
總結一下，remarstering是個很棒的功能。不過遺憾的是，我們有時候會成為它負面效果的受害者。所以，如果你碰到remastering引起的問題，不要直接就禁用它，而是應該去看看能否調優那些引數從而控制remastering事件。如果你仍然想完全禁用DRM，那麼我建議設定_gc_affinity_limit和_gc_affinity_minimum引數到一個較高值，比如說1千萬。將引數_gc_affinity_time設定為0也可以完全禁用DRM，但是這也意味著再也無法手工remaster物件了。另外，Arup也提到如果DRM被禁用那麼x$object_affinity_statistics表也不會再被維護。

Update 1:
從11g開始，affinity管理更名為policy管理（策略管理）。比如說，x$object_affinity_statistics表改名為x$object_policy_statistics，與之相似的，初始化引數也發生了改變：引數_gc_affinity_limit改名為_gc_policy_limit；引數_gc_affinity_time改名為_gc_policy_time；出現了一個新的檢視v$policy_history，其中所有policy_event = ‘initiate_affinity’的記錄都是與DRM事件相關的。
本blog的其它部分仍然沒問題，除了預設的_gc_policy_limit引數值降低為1500，這意味著，在理論上，11g可能會產生更多的DRM事件。

select * from  v$policy_history

   INST_ID POLICY_EVENT         DATA_OBJECT_ID TARGET_INSTANCE_NUMBER  EVENT_DATE

---------- -------------------- -------------- ----------------------  --------------------
          2 glru_on                           0                      1  10/15/2010 10:58:28
         2 glru_on                           0                      1  10/15/2010 11:21:32
         2 initiate_affinity             74809                      1  10/15/2010 13:27:44

與DRM有關的一些引數

10g：

看起來，只需要關閉DRM就能避免這個問題。怎麼樣來關閉/禁止DRM呢？很多MOS文件提到的方法是設定2個隱含引數：

_gc_affinity_time=0

_gc_undo_affinity=FALSE

不幸的是，這2個引數是靜態引數，也就是說必須要重啟例項才能生效。
實際上可以設定另外2個動態的隱含引數，來達到這個目的。按下面的值設定這2個引數之後，不能完全算是禁止/關閉了DRM，而是從”事實上“關閉了DRM。

甚至可以將以上2個引數值設定得更大。這2個引數是立即生效的，在所有的節點上設定這2個引數之後，系統不再進行DRM，經常一段時間的觀察，本文描述的效能問題也不再出現。

11g

_gc_policy_limit=1500

_gc_policy_time=0

參考：

DRM 分析及案例講解

相關文章