客户一套运行在Oracle 10.2.0.5 RAC上的系统,间歇性地出现性能问题。其性能现象为前台反映性能缓慢,从系统上看CPU利用率大幅增加,load增加。这种性能问题通常在出现几分钟后自动恢复正常。

从AWR中的TOP 5等待来看:

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 server mode“以及"gc remaster"这2种比较少见的等待事件,从其名称来看,明显与DRM有关。那么这2种等待事件与TOP 5的事件有没有什么关联?。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: object queue header operation"等待,虽然文档没有提及,但不排除会引起”latch: cache buffers lru chain“这样的等待。

为了进一步证实性能问题与DRM相关,使用tail -f命令监控LMD后台进程的trace文件。在trace文件中显示开始进行DRM时,查询v$session视图,发现大量的 "latch: cache buffers chains" 、"latch: object queue header operation"等待事件,同时有"gcs drm freeze in enter server mode“和"gc remaster"等待事件,同时系统负载升高,前台反映性能下降。而在DRM完成之后,这些等待消失,系统性能恢复到正常。

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

_gc_affinity_time=0
_gc_undo_affinity=FALSE

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

_gc_affinity_limit=250
_gc_affinity_minimum=10485760

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

下面是关闭DRM之后的等待事件数据:

Top 5 Timed Events                                         Avg %Total
~~~~~~~~~~~~~~~~~~                                        wait   Call
Event                                 Waits    Time (s)   (ms)   Time Wait Class
------------------------------ ------------ ----------- ------ ------ ----------
CPU time                                         15,684          67.5
db file sequential read           1,138,905       5,212      5   22.4   User I/O
gc cr block 2-way                   780,224         285      0    1.2    Cluster
log file sync                       246,580         246      1    1.1     Commit
SQL*Net more data from client       296,657         236      1    1.0    Network
          -------------------------------------------------------------
          
                                                                  Avg
                                            %Time  Total Wait    wait     Waits
Event                                 Waits -outs    Time (s)    (ms)      /txn
---------------------------- -------------- ----- ----------- ------- ---------
db file sequential read           1,138,905   N/A       5,212       5       3.8
gc cr block 2-way                   780,224   N/A         285       0       2.6
log file sync                       246,580     0         246       1       0.8
SQL*Net more data from clien        296,657   N/A         236       1       1.0
SQL*Net message from dblink          98,833   N/A         218       2       0.3
gc current block 2-way              593,133   N/A         218       0       2.0
gc cr grant 2-way                   530,507   N/A         154       0       1.8
db file scattered read               54,446   N/A         151       3       0.2
kst: async disk IO                    6,502   N/A         107      16       0.0
gc cr multi block request           601,927   N/A         105       0       2.0
SQL*Net more data to client       1,336,225   N/A          91       0       4.5
log file parallel write             306,331   N/A          83       0       1.0
gc current block busy                 6,298   N/A          72      11       0.0
Backup: sbtwrite2                     4,076   N/A          63      16       0.0
gc buffer busy                       17,677     1          54       3       0.1
gc current grant busy                75,075   N/A          54       1       0.3
direct path read                     49,246   N/A          38       1       0.2

那么,这里不得不提的是,什么是DRM?DRM对系统来说有什么好处?本文不再详述,因为下面的2篇文档已经描述得比较清楚,有兴趣的朋友可以参考:

关于本文所使用的2个隐含参数,在上述第二篇文档中也有详细描述。
--END---

Trackback

2 comments untill now

  1. 牛啊,学习了

Add your comment now