有个客户的系统中某个模块突然变得十分慢，以前每小时处理1万必业务，今天每小时只能处理1000笔业务。大量的业务堆积，使客户感到十分头痛。从V$SESSION_WAIT看，存在大量的LATCH FREE等待，从STATSPACK报告上看：

Load Profile
~~~~~~~~~~~~ Per Second Per Transaction
--------------- ---------------
Redo size: 606,513.75 10,096.93
Logical reads: 263,689.83 4,389.77
Block changes: 3,438.74 57.25
Physical reads: 817.62 13.61
Physical writes: 319.30 5.32
User calls: 9,289.06 154.64
Parses: 2,764.50 46.02
Hard parses: 334.28 5.56
Sorts: 1,460.77 24.32
Logons: 3.53 0.06
Executes: 2,808.80 46.76
Transactions: 60.07

Instance Efficiency Percentages (Target 100%)
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
Buffer Nowait %: 97.29 Redo NoWait %: 100.00
Buffer Hit %: 99.75 In-memory Sort %: 100.00
Library Hit %: 93.44 Soft Parse %: 87.91
Execute to Parse %: 1.58 Latch Hit %: 88.50
Parse CPU to Parse Elapsd %: 74.96 % Non-Parse CPU: 88.71

Top 5 Timed Events
~~~~~~~~~~~~~~~~~~ % Total
Event Waits Time (s) Ela Time
-------------------------------------------- ------------ ----------- --------
latch free 44,261,551 122,352 46.29
CPU time 44,436 16.81
buffer busy global CR 24,549,325 29,212 11.05
db file sequential read 2,298,542 23,234 8.79
wait list latch free 810,305 17,562 6.64
-------------------------------------------------------------
LATCH FREE等待占了46.29%。经过检查，发现是ROW CACHE OBJECTS等待十分严重。初步怀疑在某张表上，客户在前一天晚上对这张表做了一些修改。询问应用开发部门，他们都不承认做了操作。从数据库上看，并没有多大的问题。通过HANGANALYZE看：

存在大量的HANG住现象：

Found 26 objects waiting for <cnode/sid/sess_srno/proc_ptr/ospid/wait_event>
<1/270/2196/0x47a8100/1259/No Wait>
Found 10 objects waiting for <cnode/sid/sess_srno/proc_ptr/ospid/wait_event>
<1/1238/35370/0x4784820/966/latch free>
Found 14 objects waiting for <cnode/sid/sess_srno/proc_ptr/ospid/wait_event>
<1/373/3688/0x47b9ae0/2253/No Wait>
Found 11 objects waiting for <cnode/sid/sess_srno/proc_ptr/ospid/wait_event>
<1/855/23311/0x47a76c0/1253/latch free>

Cycle 1 : <cnode/sid/sess_srno/proc_ptr/ospid/wait_event> :
<1/754/1937/0x47add40/1310/latch free>
-- <1/905/1505/0x47ac3a0/1302/latch free>
-- <1/71/1827/0x479e220/1161/latch free>
Cycle 2 : <cnode/sid/sess_srno/proc_ptr/ospid/wait_event> :
<1/1238/35370/0x4784820/966/latch free>
-- <1/125/2442/0x47b8660/1720/latch free>
-- <1/905/1505/0x47ac3a0/1302/latch free>
-- <1/71/1827/0x479e220/1161/latch free>
-- <1/508/4711/0x47ae780/1329/latch free>
-- <1/855/23311/0x47a76c0/1253/latch free>
-- <1/531/2223/0x47ab440/1286/latch free>
Cycle 3 : <cnode/sid/sess_srno/proc_ptr/ospid/wait_event> :
<1/508/4711/0x47ae780/1329/latch free>
-- <1/855/23311/0x47a76c0/1253/latch free>
Open chains found:
Chain 1 : <cnode/sid/sess_srno/proc_ptr/ospid/wait_event> :
<1/238/45371/0x47b90a0/2307/global cache cr request>
-- <1/508/4711/0x47ae780/1329/latch free>
-- <1/855/23311/0x47a76c0/1253/latch free>
-- <1/531/2223/0x47ab440/1286/latch free>
-- <1/1239/12911/0x47a71a0/1249/latch free>
-- <1/562/765/0x47ae260/1335/latch free>
-- <1/33/24430/0x47ac8c0/1298/latch free>
Chain 2 : <cnode/sid/sess_srno/proc_ptr/ospid/wait_event> :
<1/270/2196/0x47a8100/1259/No Wait>
-- <1/562/765/0x47ae260/1335/latch free>
-- <1/33/24430/0x47ac8c0/1298/latch free>
Chain 3 : <cnode/sid/sess_srno/proc_ptr/ospid/wait_event> :
<1/373/3688/0x47b9ae0/2253/No Wait>
-- <1/1239/12911/0x47a71a0/1249/latch free>
-- <1/562/765/0x47ae260/1335/latch free>
-- <1/33/24430/0x47ac8c0/1298/latch free>
Chain 4 : <cnode/sid/sess_srno/proc_ptr/ospid/wait_event> :
<1/927/2464/0x47b67a0/2112/No Wait>
-- <1/744/287/0x46f12a0/2057/latch free>
-- <1/460/1881/0x47afc00/1344/latch free>
-- <1/71/1827/0x479e220/1161/latch free>
-- <1/508/4711/0x47ae780/1329/latch free>
-- <1/855/23311/0x47a76c0/1253/latch free>
-- <1/531/2223/0x47ab440/1286/latch free>
-- <1/1239/12911/0x47a71a0/1249/latch free>
-- <1/562/765/0x47ae260/1335/latch free>
-- <1/33/24430/0x47ac8c0/1298/latch free>
Other chains found:
Chain 5 : <cnode/sid/sess_srno/proc_ptr/ospid/wait_event> :
<1/2/7/0x468a060/7842/No Wait>
Chain 6 : <cnode/sid/sess_srno/proc_ptr/ospid/wait_event> :
<1/40/55347/0x46958e0/2392/latch free>
Chain 7 : <cnode/sid/sess_srno/proc_ptr/ospid/wait_event> :
<1/113/8784/0x47a9aa0/1276/enqueue>
Chain 8 : <cnode/sid/sess_srno/proc_ptr/ospid/wait_event> :
<1/134/24816/0x47b7c20/1711/latch free>
-- <1/614/18700/0x47ba000/2353/latch free>
Chain 9 : <cnode/sid/sess_srno/proc_ptr/ospid/wait_event> :
<1/135/577/0x47a9060/1280/latch free>
-- <1/1191/36393/0x4762e00/706/latch free>
Chain 10 : <cnode/sid/sess_srno/proc_ptr/ospid/wait_event> :

经过多次HANGANALYZE看到，目前的状态主要是比较慢，并不是真正的HANG住。过一段时间做的HANGANALYZE，BLOCKER和BLOCKED是不停变化的。

由于在另外一个地方做另外一个项目的支持，所以我也没有太多的时间协助客户做详细的分析。也就没有仔细阅读STATSPACK报告。不过以我的经验，这种情况往往和应用系统的某些变化有关。询问了开发部门，他们都说没有修改过数据字典，也没有异常的操作。这种回答也给了我很大的误导，当时把重点放到了ROW CACHE OBJECTS的分析上，重点放在了共享池方面。最后证明，这是极其错误的。

基于上述分析，首先决定针对共享池进行操作。刷新共享池，系统没有任何改善。无奈之下，客户只好重启服务器，服务器重启后，状态依然。看样子肯定是应用出了问题。回过头再分析STATSPACK报告，刚才一直萦绕在心头的一个问题终于又引起了我的注意：

Instance Efficiency Percentages (Target 100%)
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
Buffer Nowait %: 97.29 Redo NoWait %: 100.00
Buffer Hit %: 99.75 In-memory Sort %: 100.00
Library Hit %: 93.44 Soft Parse %: 87.91
Execute to Parse %: 1.58 Latch Hit %: 88.50
Parse CPU to Parse Elapsd %: 74.96 % Non-Parse CPU: 88.71

BUFFER BUSY WAIT等待十分严重。并且buffer busy global CR等待也十分严重。客户的系统虽然是RAC,但是两个节点之间共享的数据十分少，而且共享数据基本上遵循在某个节点上写操作的，在另外一个节点上尽可能不做写操作。这种情况下，buffer busy global CR不可能存在这么大的问题。一份HANGANALYZE的信息引起了我的注意：

Chain 1 : <cnode/sid/sess_srno/proc_ptr/ospid/wait_event> :
<1/523/25/0x772efc0/10816/buffer busy global CR>
-- <1/601/97/0x7747f80/11045/latch free>
-- <1/832/136/0x7788080/12069/latch free>
-- <1/820/374/0x778b8e0/12055/latch free>
-- <1/837/177/0x778ec20/12144/latch free>
-- <1/705/38/0x7768f60/11419/latch free>
-- <1/611/21/0x774ada0/11075/latch free>
-- <1/760/86/0x777b8a0/11724/latch free>
-- <1/600/7/0x7747540/11041/latch free>
-- <1/520/59/0x772db40/10818/latch free>
Chain 3 : <cnode/sid/sess_srno/proc_ptr/ospid/wait_event> :
<1/769/286/0x7782e80/11835/buffer busy global CR>
-- <1/738/33/0x7773880/11611/latch free>
-- <1/524/5/0x772eaa0/10812/latch free>
-- <1/845/46/0x7790ae0/12204/latch free>
-- <1/820/374/0x778b8e0/12055/latch free>
-- <1/837/177/0x778ec20/12144/latch free>
-- <1/705/38/0x7768f60/11419/latch free>
-- <1/611/21/0x774ada0/11075/latch free>
-- <1/760/86/0x777b8a0/11724/latch free>
-- <1/600/7/0x7747540/11041/latch free>
-- <1/520/59/0x772db40/10818/latch free>
Chain 7 : <cnode/sid/sess_srno/proc_ptr/ospid/wait_event> :
<1/825/255/0x778d280/12061/buffer busy global CR>
-- <1/777/9/0x777a940/11716/latch free>
-- <1/520/59/0x772db40/10818/latch free>
Chain 8 : <cnode/sid/sess_srno/proc_ptr/ospid/wait_event> :
<1/831/119/0x778cd60/12122/buffer busy global CR>
-- <1/845/46/0x7790ae0/12204/latch free>
-- <1/820/374/0x778b8e0/12055/latch free>
-- <1/837/177/0x778ec20/12144/latch free>
-- <1/705/38/0x7768f60/11419/latch free>
-- <1/611/21/0x774ada0/11075/latch free>
-- <1/760/86/0x777b8a0/11724/latch free>
-- <1/600/7/0x7747540/11041/latch free>
-- <1/520/59/0x772db40/10818/latch free>
Chain 10 : <cnode/sid/sess_srno/proc_ptr/ospid/wait_event> :
<1/842/108/0x77900a0/12176/buffer busy global CR>
-- <1/520/59/0x772db40/10818/latch free>
Chain 11 : <cnode/sid/sess_srno/proc_ptr/ospid/wait_event> :
<1/846/15/0x7791520/12190/global cache cr request>
-- <1/600/7/0x7747540/11041/latch free>
-- <1/520/59/0x772db40/10818/latch free>
Chain 12 : <cnode/sid/sess_srno/proc_ptr/ospid/wait_event> :
<1/867/46/0x7794860/12346/buffer busy global CR>
-- <1/823/175/0x77861c0/12028/latch free>
-- <1/741/3/0x77742c0/11601/latch free>
-- <1/783/32/0x7781f20/11807/latch free>
-- <1/520/59/0x772db40/10818/latch free>

通过检查v$segment_statistics和V$CR_BLOCK_TRANSFER，发现有一张表的CR BLOCK TRANSFER是最活跃的，而这张表就是这个业务出问题的那张表。我再次咨询了开发部门，提出了我的疑问，并把我找到的证据发给了他们。两个小时后，系统突然恢复正常。

由于关键业务系统白天营业时间停机，主管领导一定要搞清楚具体原因。在强大的政治攻势下，开发部门终于承认，早上在另外一个节点上对这张表的200万条记录进行UPDATE。UPDATE操作特别慢，几个小时后，他们杀掉了UPDATE的进程。