ORA-00470: LGWR process terminated with error

武汉-SSH

请帮忙定位下核心问题，谢谢！

Thu Aug  2 08:25:57 2012
GES: Potential blocker (pid=30867594) on resource CF-0x0-0x0;
enqueue info in file /oracle/admin/zdcomora/bdump/zdcomora2_lmd0_43647204.trc and DIAG trace file
Thu Aug  2 08:25:57 2012
Errors in file /oracle/admin/zdcomora/bdump/zdcomora2_lgwr_18546918.trc:
ORA-00600: internal error code, arguments: [2103], [0], [0], [1], [900], [], [], []
Thu Aug  2 08:25:57 2012
Errors in file /oracle/admin/zdcomora/bdump/zdcomora2_lgwr_18546918.trc:
ORA-00600: internal error code, arguments: [2103], [0], [0], [1], [900], [], [], []
Thu Aug  2 08:25:57 2012
LGWR: terminating instance due to error 470
Thu Aug  2 08:25:57 2012
Errors in file /oracle/admin/zdcomora/bdump/zdcomora2_lms2_21823688.trc:
ORA-00470: LGWR process terminated with error


GES: Potential blocker (pid=43450460) on resource CF-0x0-0x0;
enqueue info in file /oracle/admin/zdcomora/bdump/zdcomora2_lmd0_37748874.trc and DIAG trace file
Thu Aug  2 17:15:35 2012
Errors in file /oracle/admin/zdcomora/bdump/zdcomora2_lgwr_12976142.trc:
ORA-00600: internal error code, arguments: [2103], [0], [0], [1], [900], [], [], []
Thu Aug  2 17:15:35 2012
Errors in file /oracle/admin/zdcomora/bdump/zdcomora2_lgwr_12976142.trc:
ORA-00600: internal error code, arguments: [2103], [0], [0], [1], [900], [], [], []
Thu Aug  2 17:15:35 2012
LGWR: terminating instance due to error 470
Thu Aug  2 17:15:36 2012
Trace dumping is performing id=[cdmp_20120802171536]
Thu Aug  2 17:15:40 2012
Instance terminated by LGWR, pid = 12976142

upload.rar (743.72 KB, 下载次数: 1062)

2012-8-6 18:26 上传

点击文件名下载附件

枕霜卧雪

精彩，学习了！分析丝丝入扣，步步深入啊。
我们也遇到过10.2.0.4的RAC上的类似问题，最终确定是bug引起的。
因此在采用10g的时候，大师们都建议升级到最新的版本并打上相应的补丁。不是没有道理的。

武汉-SSH

谢谢！很精辟！

参考了以下信息，自己觉得理解了！

http://blog.csdn.net/tianlesoftware/article/details/7239890

https://support.oracle.com/CSP/m ... OT&id=4390868.8

https://support.oracle.com/CSP/m ... =BUG&id=4390868

https://support.oracle.com/CSP/m ... NOT&id=395314.1

https://support.oracle.com/CSP/m ... =BUG&id=2855838

http://www.technicalconferenceso ... NTERNAL&z=16260

Maclean Liu(刘相兵

Event        Waits        Time(s)        Avg Wait(ms)        % Total Call Time        Wait Class
row cache lock         4,300         11,481         2,670         47.5        Concurrency
buffer busy waits         5,303         4,956         935         20.5        Concurrency
gc buffer busy         4,710         4,598         976         19.0        Cluster
CPU time                  1,265                  5.2         
library cache pin         407         958         2,354         4.0        Concurrency


TOp 5是主要是解析等待 和 buffer busy

硬解析耗费了绝大多数的DB TIME

Soft Parse %:         72.49   软解析率很低
parse time elapsed        12,484.70        51.71
hard parse elapsed time        11,497.50        47.62
sql execute elapsed time        11,308.88        46.84
DB CPU        1,264.62        5.24
sequence load elapsed time        0.04        0.00

sequence load elapsed time         很低

2,375        0        1,718        1.38        9.84        84jtsaytwuj7s         zdcomddbagent@localhost.localdomain (TNS V1-V3)        INSERT /*+APPEND*/ INTO T_CA_S...
2,322        11        49,382        0.05        9.62        1dk3s4t7krtba         zdcomddbagent@localhost.localdomain (TNS V1-V3)        INSERT /*+APPEND*/ INTO T_JK_L...
2,147        10        49,650        0.04        8.89        b8ba5qu9kamvv         zdcomddbagent@localhost.localdomain (TNS V1-V3)        INSERT /*+APPEND*/ INTO T_JK_A...


INSERT /*+APPEND*/ INTO T_CA_STARTENDINF201208(O_TERMINALNO, O_BUSNAME, O_LINENO, O_LINENAME, O_UP , O_SSTATIONNO, O_SSTATIONNOC, O_SSTATIONNAME, O_STARTTIME, O_SDATE, O_STIME, O_SCMDKIND, O_RUNNUMBER, O_BANNUMBER, O_DOWNLINE) VALUES (:V1, :V2, :V3, :V4, :V5, :V6, :V7, :V8, :V9, :V10, :V11, :V12, :V13, :V14, :V15)


这种单条插入用了append ? 有什么意义？ 而且绑定变量这么多 可能导致 游标无法共享的

建议你先解决上面的问题

武汉-SSH

间歇就会有row cache lock wait， awr_report_2624_2625.html (348.1 KB, 下载次数: 694)

2012-8-7 17:16 上传

点击文件名下载附件

我查到的enq: SQ - contention，P2 值是 144，SYS.AUDSES$ SEQUENCE，能否介绍一下？

Maclean Liu(刘相兵

enq: SQ - contention         24,680         71,997         2,917         63.1        Configuration
gc domain validation         8,007         15,443         1,929         13.5        Cluster
row cache lock         4,932         12,071         2,448         10.6        Concurrency
gc buffer busy         9,922         9,491         957         8.3        Cluster
gc cr failure         2,581         3,147         1,219         2.8        Cluster


发生问题重启的 是2节点， 这是1节点经历的 hang， 请你在语境里说明清楚，   2节点重启会导致 gcs/ges frozen ，1节点hang住属于意料中的现象， 但就这个AWR看 1节点hang 了很久

还是建议至少升级到 10.2.0.5.8

武汉-SSH

这个是当时段的AWR，可以解释下enq: SQ - contention，row cache lock 分别在干嘛吗？
awr_report_2499_2500.html (349.5 KB, 下载次数: 754)

2012-8-7 17:11 上传

点击文件名下载附件

当时，节点2重启了，跟上面的BUG有关系吗？

武汉-SSH

LGWR在等待 enq: CF - contention 时，数据库是什么状态？会挂起吗？

Maclean Liu(刘相兵

kccocx + 2103 搜索metalink 可以找到bug note:

ODM FINDING:

        10.2.0.3 Instance Crash With ORA-600 [2103] Error


Applies to:

Oracle Server - Enterprise Edition - Version: 10.2.0.3 to 10.2.0.3 - Release: 10.2 to 10.2
Information in this document applies to any platform.
Symptoms

-- Problem Statement:
Getting ORA-00600: internal error code, arguments: [2103], [1], [0], [1], [900], [], [], []. After this instance fails due to timeout on control file.

Call stack:

ksedmp kgeriv kgesiv ksesic4 kccocx kcrribcx kcrrcrl_dbc kcrrcrlc kcrrwk ksbcti ksbabs ksbrdp opirip opidrv sou2o opimai_real main start


Cause

Call stack in the trace file matched that of the Bug 7375873 which was closed as a duplicate of Bug 7309327 which was closed as a duplicate of a merged patch on top of 10.2.0.3

Solution


Download and apply patch 8608814



Cause

This has been addressed in the following Bugs:
Bug 4582225 ORA-00600: INTERNAL ERROR CODE, ARGUMENTS: [2103], [0], [0], [1], [900], [], []
Solution



Set the following  hidden parameter _CONTROLFILE_ENQUEUE_TIMEOUT > 900 .


一种可选的 解决方式是  设置控制文件队列 超时为900s以上 即_CONTROLFILE_ENQUEUE_TIMEOUT > 900 .


实际建议 升级 数据库到 版本10.2.0.5.8

Maclean Liu(刘相兵

Thu Aug  2 17:15:35 2012
GES: Potential blocker (pid=43450460) on resource CF-0x0-0x0;
enqueue info in file /oracle/admin/zdcomora/bdump/zdcomora2_lmd0_37748874.trc and DIAG trace file
Thu Aug  2 17:15:35 2012
Errors in file /oracle/admin/zdcomora/bdump/zdcomora2_lgwr_12976142.trc:
ORA-00600: internal error code, arguments: [2103], [0], [0], [1], [900], [], [], []
Thu Aug  2 17:15:35 2012
Errors in file /oracle/admin/zdcomora/bdump/zdcomora2_lgwr_12976142.trc:
ORA-00600: internal error code, arguments: [2103], [0], [0], [1], [900], [], [], []
Thu Aug  2 17:15:35 2012
LGWR: terminating instance due to error 470


AIX 10.2.0.1 + RAC

LGWR进程终止了实例


LGWR之前一直在等 enq: CF - contention
484432E9:06AAA558    14   158 10005   1 KSL WAIT BEG [enq: CF - contention] 1128660997/0x43460005 0/0x0 0/0x0
484BA64E:06AAA633    14   158 10005   2 KSL WAIT END [enq: CF - contention] 1128660997/0x43460005 0/0x0 0/0x0 time=488292
484BA652:06AAA634    14   158 10005   1 KSL WAIT BEG [enq: CF - contention] 1128660997/0x43460005 0/0x0 0/0x0
485319B7:06AAA750    14   158 10005   2 KSL WAIT END [enq: CF - contention] 1128660997/0x43460005 0/0x0 0/0x0 time=488291
485319BA:06AAA751    14   158 10005   1 KSL WAIT BEG [enq: CF - contention] 1128660997/0x43460005 0/0x0 0/0x0
485A8D1F:06AAA870    14   158 10005   2 KSL WAIT END [enq: CF - contention] 1128660997/0x43460005 0/0x0 0/0x0 time=488291
485A8D23:06AAA871    14   158 10005   1 KSL WAIT BEG [enq: CF - contention] 1128660997/0x43460005 0/0x0 0/0x0
48620087:06AAA961    14   158 10005   2 KSL WAIT END [enq: CF - contention] 1128660997/0x43460005 0/0x0 0/0x0 time=488291
48620089:06AAA962    14   158 10005   1 KSL WAIT BEG [enq: CF - contention] 1128660997/0x43460005 0/0x0 0/0x0
4867DFD8:06AAAA06    14   158 10005   2 KSL WAIT END [enq: CF - contention] 1128660997/0x43460005 0/0x0 0/0x0 time=384846


call stack;

Media recovery not enabled or manual archival only 0x10000
*** 2012-08-02 16:51:40.395
Media recovery not enabled or manual archival only 0x10000
*** 2012-08-02 17:15:35.132
TIMEOUT ON CONTROL FILE ENQUEUE
mode=X, type=0, wait=1, eqt=900
*** 2012-08-02 17:15:35.132
ksedmp: internal or fatal error
ORA-00600: internal error code, arguments: [2103], [0], [0], [1], [900], [], [], []
----- Call Stack Trace -----
calling              call     entry                argument values in hex      
location             type     point                (? means dubious value)     
-------------------- -------- -------------------- ----------------------------
ksedst+001c          bl       ksedst1              900000000311754 ? 000000000 ?
ksedmp+0290          bl       ksedst               1047CA430 ?
ksfdmp+0018          bl       03F53DA4            
kgeriv+0108          bl       _ptrgl               
kgesiv+0080          bl       kgeriv               000000020 ? 700000010008000 ?
                                                   FFFFFFFFFFFFED0 ? 000000004 ?
                                                   10484B7A0 ?
ksesic4+0060         bl       kgesiv               FFFFFFFFFFFCBE0 ? 000000000 ?
                                                   FFFFFFFFFFFCC48 ? 000000001 ?
                                                   FFFFFFFFFFFD148 ?
kccocx+06c0          bl       ksesic4              83700000837 ? 000000000 ?
                                                   000000000 ? 000000000 ?
                                                   000000000 ? 000000000 ?
                                                   000000001 ? 000000000 ?
kccbcx+0018          bl       kccocx               FFFFFFFFFFFD148 ? 00481211C ?
                                                   04A41A910 ? 11003BEA8 ?
kcrfwl+021c          bl       kccbcx               000000000 ? 700000010018148 ?
ksbabs+03a8          bl       _ptrgl               
ksbrdp+03e0          bl       _ptrgl               
opirip+03fc          bl       01FC6EC0            
opidrv+0448          bl       opirip               1103BE410 ? 4103BFD50 ?
                                                   FFFFFFFFFFFF330 ?
sou2o+0090           bl       opidrv               3202337C1C ? 4A006EC80 ?
                                                   FFFFFFFFFFFF330 ?
opimai_real+0150     bl       01FC1614            
main+0098            bl       opimai_real          000000000 ? 000000000 ?
__start+0070         bl       main                 000000000 ? 000000000 ?





2100        server/rcv        Control File mgmt


*** 2012-08-02 17:15:35.131
DUMP LOCAL BLOCKER/HOLDER: block level 4 res [0x0][0x0],[CF]
----------resource 0x7000002407d0ba8----------------------
resname       : [0x0][0x0],[CF]
Local node    : 1
dir_node      : 0
master_node   : 0
hv idx        : 95
hv last r.inc : 0
current inc   : 8
hv status     : 0
hv master     : 0
open options  : dd
Held mode     : KJUSERPR
Cvt mode      : KJUSERNL
Next Cvt mode : KJUSERNL
msg_seq       : a8e0a8e
res_seq       : 10
grant_bits    : KJUSERNL KJUSERCR KJUSERPR
grant mode    : KJUSERNL  KJUSERCR  KJUSERCW  KJUSERPR  KJUSERPW  KJUSEREX
count         : 1         1         0         1         0         0
val_state     : KJUSERVS_VALUE
valblk        : 0x0009b3abffffdd780700000010018148 .xH
access_node   : 1
vbreq_state   : 0
state         : x8
resp          : 7000002407d0ba8
On Scan_q?    : N
Total accesses: 24215
Imm.  accesses: 10126
Granted_locks : 2
Cvting_locks  : 1
value_block:  00 09 b3 ab ff ff dd 78 07 00 00 00 10 01 81 48
GRANTED_Q :
lp 700000259297980 gl KJUSERPR rp 7000002407d0ba8 [0x0][0x0],[CF]
  master 0 gl owner 700000257171a20 possible pid 43450460 xid 2002-002E-0000000C bast 0 rseq 10 mseq 0 history 0x495149a5
  open opt KJUSERDEADLOCK  KJUSERIDLK
lp 70000025e3aec90 gl KJUSERCR rp 7000002407d0ba8 [0x0][0x0],[CF]
  master 0 gl owner 70000025817f5a8 possible pid 32899162 xid 0000-000F-0000000A bast 0 rseq 10 mseq 0 history 0x9a5
  open opt KJUSERDEADLOCK  KJUSERIDLK
CONVERT_Q:
lp 7000002592791f8 gl KJUSERNL rl KJUSERPW rp 7000002407d0ba8 [0x0][0x0],[CF]
  master 0 gl owner 700000257183530 possible pid 12976142 xid 2000-000E-00000006 bast 0 rseq 10 mseq 0 history 0x1495149a
  convert opt KJUSERGETVALUE KJUSERNODEADLOCKWAIT KJUSERTRCCANCEL  
----------enqueue 0x700000259297980------------------------
lock version     : 471
Owner node       : 1
grant_level      : KJUSERPR
req_level        : KJUSERPR
bast_level       : KJUSERNL
notify_func      : 0
resp             : 7000002407d0ba8
procp            : 700000257237528
pid              : 43450460
proc version     : 4
oprocp           : 0
opid             : 0
group lock owner : 700000257171a20
possible pid     : 43450460
xid              : 2002-002E-0000000C
dd_time          : 0.0 secs
dd_count         : 0
timeout          : 0.0 secs
On_timer_q?      : N
On_dd_q?         : N
lock_state       : GRANTED
Open Options     : KJUSERDEADLOCK  KJUSERIDLK
Convert options  : KJUSERGETVALUE KJUSERNODEADLOCKWAIT KJUSERTRCCANCEL
History          : 0x495149a5
Msg_Seq          : 0x0
res_seq          : 10
valblk           : 0x0009b3abffffdd780700000010018148 .xH
DUMP LOCAL BLOCKER: initiate state dump for
  possible owner[46.43450460]
Submitting asynchronized dump request [28]
KCC: controlfile sequence number from SGA =  635819


PID 43450460  持有此 CF enqueue lock ， 导致 lgwr 12976142 长期无法完成工作