一个Bug引起ora_o000_sid进程占用大量CPU的问题

环境信息

 

数据库版本：11.2.0.2 RAC

操作系统：AIX 6.1

 

 

现象描述

 

通过监控发现服务器负载相对以前上升20-30%

 

 

诊断过程

查看AWR没有发现有特殊的等待事件或SQL

Top 5 Timed Foreground Events

Event	Waits	Time(s)	Avg wait (ms)	% DB time	Wait Class
DB CPU		5,297		37.04
db file sequential read	546,298	2,658	5	18.59	User I/O
gc current block 2-way	2,593,242	2,656	1	18.57	Cluster
log file sync	1,512,801	1,480	1	10.35	Commit
gc cr block 2-way	479,451	470	1	3.29	Cluster

 

 

 

再查看服务器，其中一个节点有个进程一直占用大量CPU，而且没有释放的迹象,进程的名称名为ora_o000_xxxxprod1

 

Topas Monitor for host:    p520db1              EVENTS/QUEUES    FILE/TTY

Fri Jun 14 10:33:29 2013   Interval:  2         Cswitch    7961  Readch   354.8K

                                                Syscall   22757  Writech   16898

CPU  User%  Kern%  Wait%  Idle%                 Reads       143  Rawin         0

ALL   29.0    3.3    1.7   66.1                 Writes       83  Ttyout      438

                                                Forks         2  Igets         0

Network  KBPS   I-Pack  O-Pack   KB-In  KB-Out  Execs         3  Namei       223

Total    49.3     92.8    68.3    29.3    20.0  Runqueue    3.0  Dirblk        0

                                                Waitqueue   0.0

Disk    Busy%     KBPS     TPS KB-Read KB-Writ                   MEMORY

Total     7.0    302.7    29.0   231.4    71.3  PAGING           Real,MB   31615

                                                Faults     2355  % Comp     75

FileSystem        KBPS     TPS KB-Read KB-Writ  Steals        0  % Noncomp  24

Total            123.0   134.2  117.7    5.3    PgspIn        0  % Client   24

                                                PgspOut       0

Name            PID  CPU%  PgSp Owner           PageIn        0  PAGING SPACE

oracle      8061062  24.6  14.9 oracle          PageOut       4  Size,MB   17920

octssd.b    4390912   0.5  20.3 root            Sios          4  % Used      0

oracle      4587816   0.5 1825.2 grid                            % Free    100

gipcd.bi    3670122   0.5  31.1 grid            NFS (calls/sec)

oraroota   10158456   0.5  48.0 root            SerV2         0  WPAR Activ    0

evmd.bin    4194570   0.5  46.3 grid            CliV2         0  WPAR Total    0

crsd.bin    2884034   0.5  83.9 root            SerV3         0  Press: "h"-help

ohasd.bi    9241020   0.4  99.1 root            CliV3         0         "q"-quit

gil          459056   0.3   0.9 root 

oraagent   10224030   0.3 105.1 grid 

oracle      7536726   0.3  46.0 oracle

oraagent    8323190   0.3  54.2 oracle

oracle      9699748   0.2  20.0 grid 

oraagent    4063586   0.1  83.4 grid 

oracle      4980778   0.1  27.2 grid 

oraroota    8388684   0.1  54.8 root 

oracle      9896076   0.1  30.1 oracle

oracle      4849714   0.1  19.8 grid

dtgreet      852334   0.1   1.3 root 

oracle      5308858   0.0  16.4 oracle

 

bash-3.00$ ps -ef|grep 8061062                         

  oracle  8061062        1 120   Sep 29      - 13907:17 ora_o000_xxxxprod1

  oracle  1966452  6357172   0 10:36:18  pts/0  0:00 grep 8061062

 

 

 

 

通过下面进程号我们看到一直在执行下面SQL，可以看到这个SQL是数据库自己的SQL

 

SQL> SELECT /* +RULE */

  2          Q.SQL_TEXT,  Q.PIECE,

  3          DECODE(S.SQL_HASH_VALUE, 0, 'Last', 'Current') STAUTS

  4     FROM GV$SQLTEXT Q, GV$SESSION S, GV$PROCESS P

  5    WHERE Q.HASH_VALUE(+) = DECODE(S.SQL_HASH_VALUE,

  6                                   0,

  7                                   S.PREV_HASH_VALUE,

  8                                   S.SQL_HASH_VALUE)

  9      AND Q.ADDRESS(+) =

 10          DECODE(S.SQL_HASH_VALUE, 0, S.PREV_SQL_ADDR, S.SQL_ADDRESS)

 11      AND S.PADDR = P.ADDR

 12      AND P.SPID = 8061062

 13      order by piece

 14  ;

 

SQL_TEXT                                                              PIECE STAUTS

---------------------------------------------------------------- ---------- -------

select job, nvl2(last_date, 1, 0) from sys.job$ where (((:1 <= n          0 Last

ext_date) and (next_date <= :2))    or  ((last_date is null) and          1 Last

 (next_date < :3))) and (field1 = :4 or (field1 = 0 and 'Y' = :5          2 Last

)) and (this_date is null) and ((dbms_logstdby.db_is_logstdby =           3 Last

0 and job < 1000000000) or  (dbms_logstdby.db_is_logstdby = 1 an          4 Last

d job >= 1000000000)) order by next_date, job                             5 Last

                                                                            Last

 

7 rows selected

 

SQL>

 

 

查看这个session的等待事件

 

SQL>  select event from v$session_wait where sid=1707;

 

EVENT

----------------------------------------------------------------

class slave wait

 

SQL>

 

 

 

根据这个等待事件，我们发现为Bug 10285394

 

 

 

解决方案

 

打上补丁10285394

 

 

 

这个Bug相关的说明

 

ora_o00n Process High CPU Usage in 11.2.0.2 [ID 1459376.1]

To Bottom

Modified:Jan 11, 2013 Type:PROBLEM Status:PUBLISHED Priority:2

Comments (0)

In this Document

Symptoms

 

Cause

 

Solution

 

References

1              Applies to:

Oracle Server - Enterprise Edition - Version 11.2.0.2 to 11.2.0.2.0 [Release 11.2]
Information in this document applies to any platform.

2              Symptoms

11.2.0.2 database on ASM, the ora_o00n process consumes high CPU: 

• top command output

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND          
  
 2921 oracle    25   0 1715m  17m  15m R 99.5  0.1 658:32.91 ora_o001_trng

 

• Oracle process dump:

Call stack:  .. dbgtTrc_int ksvreceive kfncPoolCb ksvrdp opirip ..
 
Current Wait Stack:

     0: waiting for 'class slave wait'
        slave id=0x0, =0x0, =0x0
        wait_id=139 seq_num=140 snap_id=1
        wait times: snap=358705 min 17 sec, exc=358705 min 17 sec, total=358705 min 17 sec

 

• OS truss/strace command shows the process is spinning on OS call gettimeofday

3              Cause

Due to bug 10285394

Multiple duplicates open: bug 13767869 bug 13789248 bug 13767461 bug 13918332 bug 13952464 bug 12929268  bug 12671004 bug 13363390 bug 14044697

4              Solution

Refer to note 10285394.8 for more info about the bug. 

5              References

BUG:12929268 - HIGH CPU ON ORA_O00N PROCESS

 

 

来自 “ ITPUB博客 ” ，链接：http://blog.itpub.net/21605631/viewspace-765425/，如需转载，请注明出处，否则将追究法律责任。

转载于:http://blog.itpub.net/21605631/viewspace-765425/