訪問ASM的ONNN程式佔用大量CPU

客戶的11.2 RAC環境中突然一個O002程式佔用了100%的CPU，且一直不釋放。

導致這個問題的原因應該是透過ASMCMD工具從ASM中複製了一個歸檔日誌到本地磁碟，隨後就發現一個ora_

[root@node-2 ~]# top

top - 21:14:25 up 257 days,  4:33,  2 users,  load average: 1.69, 1.70, 1.56
Tasks: 994 total,   2 running, 991 sleeping,   0 stopped,   1 zombie
Cpu(s):  2.2%us,  0.1%sy,  0.0%ni, 97.5%id,  0.2%wa,  0.0%hi,  0.0%si,  0.0%st
Mem:  132060636k total, 131006336k used,  1054300k free,   535524k buffers
Swap: 67108856k total,  1649936k used, 65458920k free, 39758892k cached

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
 7622 oracle    25   0 50.6g  18m  16m R 100.0  0.0   9498:03 oracle
29924 root      RT   0  304m  86m  54m S  2.0  0.1   5333:37 osysmond.bin
13804 root      15   0 13424 1844  828 R  1.6  0.0   0:00.16 top
29158 oracle    15   0 50.6g  10g  10g S  1.0  8.2 317:51.59 oracle
30337 root      15   0  971m  25m  13m S  1.0  0.0   1938:12 orarootagent.bi
.
.
.
   25 root      RT  -5     0    0    0 S  0.0  0.0   0:00.00 watchdog/7
[root@node-2 ~]# ps -ef|grep 7622
oracle    7622     1  2  2011 ?        6-14:18:09 ora_o002_orcl2
root     13810 13645  0 21:14 pts/1    00:00:00 grep 7622

從資料庫中查詢，發現這個會話處於空閒等待狀態：

[oracle@settle-2 ~]$ sqlplus / as sysdba

SQL*Plus: Release 11.2.0.2.0 Production on Mon Apr 23 21:14:45 2012

Copyright (c) 1982, 2010, Oracle.  All rights reserved.

Connected to:
Oracle Database 11g Enterprise Edition Release 11.2.0.2.0 - 64bit Production
With the Partitioning, Real Application Clusters, Automatic Storage Management, OLAP,
Data Mining and Real Application Testing options

SQL> set pages 100 lines 140
SQL> select sid, username, program, status, event from v$session where paddr in (select addr from v$process where spid = 7622);

       SID USERNAME   PROGRAM                        STATUS   EVENT
---------- ---------- ------------------------------ -------- ------------------------------
       529            oracle@node-2 (O002)           ACTIVE   class slave wait

SQL> select sql_id, prev_sql_id from v$session where sid = 529;

SQL_ID        PREV_SQL_ID
------------- -------------

可以看到，這個會話一直處以空閒等待，而且沒有執行任何SQL語句。

SQL> select sid, serial# from v$session where sid = 529;

       SID    SERIAL#
---------- ----------
       529         43

SQL> exec dbms_monitor.session_trace_enable(529, 43, true, true)

PL/SQL procedure successfully completed.

SQL> exec dbms_monitor.session_trace_disable(529, 43)

PL/SQL procedure successfully completed.

透過設定TRACE，發現這個異常的會話並沒有產生任何的TRACE檔案。

由於ONNN程式是ASM連線池程式，當資料庫在ASM上建立檔案時，就會透過ONNN程式來完成，這個程式在日常很少會處於工作狀態。

[oracle@node-2 ~]$ ps -ef|grep ora_o
oracle    3831     1  0 Feb15 ?        00:00:03 ora_o004_orcl2
oracle    6350     1  0  2011 ?        00:00:08 ora_o000_orcl2
oracle    6358     1  0  2011 ?        00:00:08 ora_o003_orcl2
oracle    7475     1  0  2011 ?        00:00:00 ora_o001_orcl2
oracle    7622     1  2  2011 ?        6-15:38:56 ora_o002_orcl2
oracle   28211 28168  0 22:35 pts/1    00:00:00 grep ora_o

[oracle@node-2 ~]$ kill -9 7622

由於ONNN程式並非系統核心程式，且Oracle會在需要的時候自動分配ONNN程式，因此可以透過kill -9的方法來清除會話。結束程式後，top命令顯示佔用100%CPU資源的程式已經消失。

根據MOS的最新更新，這個問題屬於BUG:12929268對應的文件為ora_o00n Process High CPU Usage in 11.2.0.2 [ID 1459376.1]。

根據文件的描述，如果ONNN程式空閒時間超過248.5天左右，也就是按照百分之一秒計算超過2G，就會導致ONNN程式陷入死迴圈中。Oracle對於程式的最大等待時間的定義並不是無符號的LONG，導致程式等待時間只有2G釐秒，而不是4G。

Oracle目前沒有明確的fixed計劃，而給出的解決方案和我上面的方法一致，就是KILL掉對應的程式。另外重啟系統可以保證250天內不會再次出現同樣的錯誤。