DRM 分析及案例讲解

本文是转载文章，原文出自：
http://blog.csdn.net/wuweilong/article/details/17254373

DRM 分析及案例讲解

1. 什么是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

 

1. remastering的发生:

    Remastering问题发生时会影响性能。以下AWR报告显示了DRM重配置问题导致的实例冻结。同样类型的冻结在其它的所有节点上也都可以看见。gc buffer busy等待只是DRM冻结的副作用（不是总有，但是在这个case是这样）。

[sql] view plaincopy

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

   在同一时刻，DRM大量发生，导致了重复的DRM冻结、实例重配置，从而引发严重的性能问题。

[sql] view plaincopy

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

可以看到，TOP 5中，有3个是latch相关的等待，而另外2个则是跟RAC相关的等待。
如果再查看更细的等待数据，可以发现其他问题：

[sql] view plaincopy

1.                                                   Avg  
2.                                             %Time  Total Wait    wait     Waits  
3. Event                                 Waits -outs    Time (s)    (ms)      /txn  
4. ---------------------------- -------------- ----- ----------- ------- ---------  
5. latch: cache buffers lru cha        774,812   N/A     140,185     181       1.9  
6. gc buffer busy                    1,356,786     6      61,708      45       3.3  
7. latch: object queue header o        903,456   N/A      55,089      61       2.2  
8. latch: cache buffers chains         360,522   N/A      49,016     136       0.9  
9. gc current grant busy               112,970    25      19,893     176       0.3  
10. gcs drm freeze in enter serv         38,442    97      18,537     482       0.1  
11. gc cr block 2-way                 1,626,280     0      15,742      10       3.9  
12. gc remaster                           6,741    89      12,397    1839       0.0  
13. 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完成之后，这些等待消失，系统性能恢复到正常。

[sql] view plaincopy

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

 

A small test case 
   我们来看一个测试，观察一下DRM的产生。使用了索引读路径的查询从一个大索引中读取了几乎所有数据块。

[sql] view plaincopy

1. Session #1:  
2. select data_object_id from dba_objects where object_name='WMS_N1';  
3. DATA_OBJECT_ID  
4. -------------  
5. 6099472  
6.   
7.   
8. REM 还没有affinity统计信息  
9.   
10.   
11.   
12.   
13. select * from x$object_affinity_statistics where object=6099472;  
14.   
15. no rows selected.  
16.   
17.    
18. REM 执行高代价的查询语句  
19.   
20. select /*+ index(a WMS_N1) */ count(*) from big_table1 a;  
21.   
22.    
23. Session #2: 观察DRM表:  
24.   
25. REM DRM字段现在是409,。我们将持续观察这个数值。在这个视图中还有其它比较有趣的字段。  
26.   
27. select drms from X$KJDRMAFNSTATS;  
28.   
29. DRM  
30. ----  
31. 409  
32.   
33.    
34.   
35. REM 观察到自从会话#1开始运行在该索引上已经有23442个OPENs  
36.   
37. select * from x$object_affinity_statistics where object=6099472;  
38.   
39. ADDR                   INDX    INST_ID     OBJECT       NODE      OPENS  
40. ---------------- ---------- ---------- ---------- ---------- ----------  
41. FFFFFFFF7C05BFA8         14          1    6099472          1      23442  
42.    
43.   
44. REM 该对象上还没有发生mastering  
45.   
46. select * from v$gcspfmaster_info where object_id=6099472;  
47.   
48. no rows selected  
49.   
50. REM 几秒后，OPENs计数从23442上升到33344  
51.   
52. select * from x$object_affinity_statistics where object=6099472;  
53. ADDR                   INDX    INST_ID     OBJECT       NODE      OPENS  
54. ---------------- ---------- ---------- ---------- ---------- ----------  
55. FFFFFFFF7C05BFA8         16          1    6099472          1      33344  
56.   
57.    
58.   
59. REM该对象上还没有发生mastering  
60.   
61. select * from v$gcspfmaster_info where object_id=6099472;  
62. no rows selected  
63.   
64.    
65.   
66. REM 让人诧异，会话#1还在运行，OPENs计数忽然清零即使DRM还未发生过  
67.   
68. REM OPENs从0又升到1229因为会话#1还在运行  
69.   
70. ADDR                   INDX    INST_ID     OBJECT       NODE      OPENS  
71. ---------------- ---------- ---------- ---------- ---------- ----------  
72.   
73. FFFFFFFF7C05BFA8          0          1    6099472          1       1229  
74.   
75.    
76.   
77. REM 大约10分钟以后，remastering发生了。DRMS从409上升到411。  
78.   
79. select drms from X$KJDRMAFNSTATS;  
80.   
81. DRM  
82. ----  
83. 411  
84.   
85.    
86.   
87. REM 该索引的remastering发生了。现在该对象的属主是0，也就是实例1  
88.   
89. select * from v$gcspfmaster_info where object_id=6099472;  
90.   
91.    FILE_ID  OBJECT_ID CURRENT_MASTER PREVIOUS_MASTER REMASTER_CNT  
92. ---------- ---------- -------------- --------------- ------------  
93.          0    6099472              0           32767            1  
94.   
95.    
96. REM OPENs还在上升，但是remastering已经发生了。  
97.   
98. select * from x$object_affinity_statistics where object=6099472;  
99.   
100. ADDR                   INDX    INST_ID     OBJECT       NODE      OPENS  
101. ---------------- ---------- ---------- ---------- ---------- ----------  
102. FFFFFFFF7C05AF78          2          1    6099472          1      42335  
103. FFFFFFFF7C05AF78          3          1    6099472          2          1  
104.   
105.    
106. REM LMON trace文件也指出pkey的传递。注意pkey和object_id是相同的。  
107.   
108. *** 2010-03-23 10:41:57.355  
109. Begin DRM(411) - transfer pkey 6099472 to 0 oscan 0.0  
110.  ftd received from node 1 (4/0.30.0)  
111.  all ftds received  
112.   
113.    
114.   
115. REM 几秒后，OPENs被再次重置。  
116.   
117. select * from x$object_affinity_statistics where object=6099472;  
118.   
119. ADDR                   INDX    INST_ID     OBJECT       NODE      OPENS  
120. ---------------- ---------- ---------- ---------- ---------- ----------  
121. FFFFFFFF7C05BFA8          0          1    6099472          1       7437  
122.    
123.   
124. REM 属主仍然是实例1。  
125.   
126. select * from v$gcspfmaster_info where object_id=6099472;  
127.   
128.    FILE_ID  OBJECT_ID CURRENT_MASTER PREVIOUS_MASTER REMASTER_CNT  
129. ---------- ---------- -------------- --------------- ------------  
130.          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）。

[sql] view plaincopy

1. select objecT_id, object_id-4294950912 usn, current_master, previous_master,  
2.   
3. remaster_cnt  from v$gcspfmaster_info where object_id>4294950912;  
4.   
5.   
6.  OBJECT_ID        USN CURRENT_MASTER PREVIOUS_MASTER REMASTER_CNT  
7. ---------- ---------- -------------- --------------- ------------  
8. 4294950913          1              0           32767            1  
9. 4294950914          2              0           32767            1  
10. 4294950915          3              0           32767            1  
11. 4294950916          4              0           32767            1  
12. 4294950917          5              0           32767            1  
13. 4294950918          6              0           32767            1  
14. 4294950919          7              0           32767            1  
15. 4294950920          8              0           32767            1  
16. 4294950921          9              0           32767            1  
17. 4294950922         10              0           32767            1  
18. 4294950923         11              1           32767            1  
19. 4294950924         12              1           32767            1  
20. 4294950925         13              1           32767            1  
21. ...  
22.   
23.    
24.   
25. REM 注意usn 0在两个实例中都存在，这是系统回滚段。  
26.   
27. REM 下面结果显示，头10个回滚段被node1掌控，而接下来的3个被实例2掌控。  
28.   
29. select inst_id, usn, gets from gv$rollstat where usn <=13 order by inst_id, usn;  
30.   
31.    INST_ID        USN       GETS  
32. ---------- ---------- ----------  
33.          1          0       3130  
34.          1          1     108407  
35.          1          2      42640  
36.          1          3      43985  
37.          1          4      41743  
38.          1          5     165166  
39.          1          6      43485  
40.          1          7     109044  
41.          1          8      23982  
42.          1          9      39279  
43.          1         10      48552  
44.          2          0       4433  
45.          2         11     231147  
46.          2         12      99785  
47.          2         13      1883  

  我没有成功试验出触发下一次回滚段remastering。我创建了一个活动事务在一个节点上产生了200K回滚数据块，然后另外一个节点在读这个表，我观察到在回滚数据块上有大量等待。但是我没有发现这个回滚段上有任何remastering事件。无法确认为什么没有产生，也许是回滚段remastering的条件有所不同吧。

译者注：回滚段的remastering是不会因为另外一个节点对于回滚段有大量读取而发生的，只有在某个实例失效，然后负责进行实例恢复的另外那个实例会暂时的成为这些回滚段的master，这是为了进行实例恢复的需要，在恢复完毕以后所有的undo buffers都会被flush到磁盘上。

PS：我能够使用后面将描述的lkdebug命令手动remaster回滚段，所以oracle也应该可以自动remaster回滚段，只是可能还有一个其它条件也必须满足。

[sql] view plaincopy

1. select * from v$gcspfmaster_info where object_id=431+4294950912;  
2.   
3.    FILE_ID  OBJECT_ID CURRENT_MASTER PREVIOUS_MASTER REMASTER_CNT  
4. ---------- ---------- -------------- --------------- ------------  
5.          0 4294951343              0           32767            1  
6.   
7.    
8. Oradebug lkdebug –m pkey 4294951343  
9.    
10.     
11. * kjdrchkdrm: found an RM request in the request queue  
12.   
13.   Transfer pkey 4294951343 to node 1  
14.   
15. *** 2010-03-24 12:47:29.011  
16.   
17. Begin DRM(520) - transfer pkey 4294951343 to 1 oscan 0.1  
18.   
19.  ftd received from node 0 (4/0.31.0)  
20.   
21.  all ftds received  
22.    
23.   
24. select * from v$gcspfmaster_info where object_id=431+4294950912;  
25.   
26. SQL> /  
27.   
28.    FILE_ID  OBJECT_ID CURRENT_MASTER PREVIOUS_MASTER REMASTER_CNT  
29. ---------- ---------- -------------- --------------- ------------  
30.   
31.          0 4294951343              1               0            2  

  我不是在劝你们应该去修改这些隐含参数。只是要去理解这些参数，如果你们碰到诸如’gc remaster’, ‘gcs freeze for instancereconfiguration’这样的等待事件，那么应该知道是不是因为默认值太低了。跟技术支持沟通尝试是否能够调整。

Manual remastering
你可以使用oradebug命令来手动remaster一个对象：

[sql] view plaincopy

1. oradebug lkdebug -m pkey  

 

这会将一个对象remaster请求放入队列。LMD0和LMON进程会完成这个请求。

当前属主是从0开始计数的。

[sql] view plaincopy

1. *** 2010-01-08 23:25:54.948  
2. * received DRM start msg from 1 (cnt 1, last 1, rmno 191)  
3. Rcvd DRM(191) Transfer pkey 6984154 from 0 to 1 oscan 0.0  
4. ftd received from node 1 (8/0.30.0)  
5. ftd received from node 0 (8/0.30.0)  
6. ftd received from node 3 (8/0.30.0)  
7.   
8.   
9.   
10. select * from v$gcspfmaster_info whereobject_id=6984154;  
11.   
12. SQL> /   
13.   
14. FILE_ID OBJECT_ID CURRENT_MASTERPREVIOUS_MASTER REMASTER_CNT   
15. ---------- ---------- ----------------------------- ------------   
16. 0 6984154 1 0 2   
17.   
18.   
19. SQL> oradebug lkdebug -m pkey 6984154   
20.   
21. Statement processed.   
22.   
23.   
24. SQL> select * from v$gcspfmaster_info where object_id=6984154;   
25.   
26. FILE_ID OBJECT_ID CURRENT_MASTERPREVIOUS_MASTER REMASTER_CNT   
27. ---------- ---------- ----------------------------- ------------   
28. 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事件。

[sql] view plaincopy

1. select * from  v$policy_history  
2.   
3.    INST_ID POLICY_EVENT         DATA_OBJECT_ID TARGET_INSTANCE_NUMBER  EVENT_DATE  
4.   
5. ---------- -------------------- -------------- ----------------------  --------------------  
6.           2 glru_on                           0                      1  10/15/2010 10:58:28  
7.          2 glru_on                           0                      1  10/15/2010 11:21:32  
8.          2 initiate_affinity             74809                      1  10/15/2010 13:27:44  

 

1. 与DRM有关的一些参数

10g：

看起来，只需要关闭DRM就能避免这个问题。怎么样来关闭/禁止DRM呢？很多MOS文档提到的方法是设置2个隐含参数：

[sql] view plaincopy

1. _gc_affinity_time=0  
2.   
3. _gc_undo_affinity=FALSE  

 

不幸的是，这2个参数是静态参数，也就是说必须要重启实例才能生效。
实际上可以设置另外2个动态的隐含参数，来达到这个目的。按下面的值设置这2个参数之后，不能完全算是禁止/关闭了DRM，而是从”事实上“关闭了DRM。

甚至可以将以上2个参数值设置得更大。这2个参数是立即生效的，在所有的节点上设置这2个参数之后，系统不再进行DRM，经常一段时间的观察，本文描述的性能问题也不再出现。

 

11g

[sql] view plaincopy

1. _gc_policy_limit=1500  
2.   
3. _gc_policy_time=0  

 

 

参考：

http://www.dbaleet.org/the_evolution_of_oracle_rac_drm_season_1/

http://www.dbform.com/html/tag/drm

http://wenku.baidu.com/link?url=DykRyVGrvpLkfHUMrgoUOKghYXLAzh3YRSu1AHksMwdSmL5b8XtEcEocQcC7ziRrzd6OF54w9w4TBHuHo486MsXwJFhBrtKe5r3jdtA8joS

http://www.laoxiong.net/problem-caused-by-drm.html