本案例客户来自某省电信,alert日志大量的ORA-00600[4187]报错,已经影响到业务正常运行。
Fri Nov 19 16:07:09 2021
Errors in file /u01/ora

cle/app/oracle/diag/rdbms/lcfa/LCFA1/trace/LCFA1_smon_5811.trc  (incident=184182):
ORA-00600: internal error code, arguments: [4187], [], [], [], [], [], [], [], [], [], [], []
Use ADRCI or Support Workbench to package the incident.
See Note 411.1 at My Oracle Support for error and packaging details.
Block recovery from logseq 54671, block 287204 to scn 17162371413499
Recovery of Online Redo Log: Thread 1 Group 5 Seq 54671 Reading mem 0
  Mem# 0: +DATA/lcfa/onlinelog/group_5.287.904064243
Block recovery stopped at EOT rba 54671.287388.16
Block recovery completed at rba 54671.287388.16, scn 3995.3977065979
Non-fatal internal error happenned while SMON was doing flushing of monitored table stats.
SMON encountered 1 out of maximum 100 non-fatal internal errors.
Fri Nov 19 16:07:10 2021
Sweep [inc][184182]: completed
Fri Nov 19 16:07:10 2021
Errors in file /u01/oracle/app/oracle/diag/rdbms/lcfa/LCFA1/trace/LCFA1_ora_1734.trc  (incident=190317):
ORA-00600: Ě²¿´펳´ú«, ²Ίý: [4187], [], [], [], [], [], [], [], [], [], [], []
Use ADRCI or Support Workbench to package the incident.
See Note 411.1 at My Oracle Support for error and packaging details.
Fri Nov 19 16:09:04 2021
Block recovery from logseq 54671, block 287204 to scn 17162371413499
Recovery of Online Redo Log: Thread 1 Group 5 Seq 54671 Reading mem 0
  Mem# 0: +DATA/lcfa/onlinelog/group_5.287.904064243
Block recovery completed at rba 54671.287388.16, scn 3995.3977065982
Fri Nov 19 16:10:30 2021
Errors in file /u01/oracle/app/oracle/diag/rdbms/lcfa/LCFA1/trace/LCFA1_ora_6392.trc  (incident=184485):
ORA-00600: Ě²¿´펳´ú«, ²Ίý: [4187], [], [], [], [], [], [], [], [], [], [], []
Use ADRCI or Support Workbench to package the incident.
See Note 411.1 at My Oracle Support for error and packaging details.

可以看到ORA-00600[4187]并伴随着blockrecover,通常ORA-00600[4XXX]错误都来自于undo相关,并且都会触发BRR。SMON已经遇到1次内部错误,如果smon遇到100次内部错误则会重启实例,由参数_smon_internal_errlimit控制。

SQL> @sp smon_inter

-- show parameter by sp

-- show hidden parameter by sp
old   3: where x.indx=y.indx and ksppinm like '_%&p%'
new   3: where x.indx=y.indx and ksppinm like '_%smon_inter%'

NAME                                     VALUE      DESC
---------------------------------------- ---------- ------------------------------------------------------------------------------------------
_smon_internal_errlimit                  100        limit of SMON internal errors

ORA-00600 4187在Doc ID 19700135.8上有比较清楚的说明:

Description
ORA-600 [4187] can occur for undo segments where wrap# is close to the max value of 0xffffffff (KSQNMAXVAL).

This normally affects databases with high transaction rate that have existed for a relatively long time.

大致意思是长期的高TPS的环境,当在新的事务绑定到某个undo段某个slot上,将递增wrap#,但是递增后的wrap#超过最大值 KSQNMAXVAL(0xffffffff),就会抛出ORA-00600[4187]错误。

继续查看trace文件查找报异常的undo段头:

 TRN CTL:: seq: 0xd14f chd: 0x0009 ctl: 0x0004 inc: 0x00000000 nfb: 0x0000
            mgc: 0xb000 xts: 0x0068 flg: 0x0001 opt: 2147483646 (0x7ffffffe)
            uba: 0x00c06434.d14f.2c scn: 0x0f9b.ed0bc826
Version: 0x01
  FREE BLOCK POOL::
    uba: 0x00000000.d14f.2b ext: 0x2  spc: 0x1dc
    uba: 0x00000000.d14f.2a ext: 0x2  spc: 0x70e
    uba: 0x00000000.d14b.02 ext: 0x1e spc: 0x1f02
    uba: 0x00000000.ce3f.02 ext: 0x12 spc: 0x14da
    uba: 0x00000000.3226.02 ext: 0x32 spc: 0x14ae
  TRN TBL::

  index  state cflags  wrap#    uel         scn            dba            parent-xid    nub     stmt_num    cmt
  ------------------------------------------------------------------------------------------------
   0x00    9    0x00  0xfffffa0c  0x000c  0x0f9b.ed0bc8f1  0x00c06434  0x0000.000.00000000  0x00000001   0x00000000  1637305928
   0x01    9    0x00  0xfffff4ab  0x0016  0x0f9b.ed0bc84e  0x00c06434  0x0000.000.00000000  0x00000001   0x00000000  1637305927
   0x02    9    0x00  0xfffff3aa  0x0008  0x0f9b.ed0bc934  0x00c06434  0x0000.000.00000000  0x00000001   0x00000000  1637305928
   0x03    9    0x00  0xfffff8d9  0x000e  0x0f9b.ed0bc985  0x00c06434  0x0000.000.00000000  0x00000001   0x00000000  1637305928
   0x04    9    0x00  0xfffffce8  0xffff  0x0f9b.ed0bc9e7  0x00c06434  0x0000.000.00000000  0x00000001   0x00000000  1637305928
   0x05    9    0x00  0xfffff627  0x001a  0x0f9b.ed0bc833  0x00c06434  0x0000.000.00000000  0x00000001   0x00000000  1637305927
   0x06    9    0x00  0xfffff4e6  0x0004  0x0f9b.ed0bc9cb  0x00c06434  0x0000.000.00000000  0x00000001   0x00000000  1637305928
   0x07    9    0x00  0xffffece5  0x000b  0x0f9b.ed0bc85c  0x00c06434  0x0000.000.00000000  0x00000001   0x00000000  1637305927
   0x08    9    0x00  0xfffff724  0x0021  0x0f9b.ed0bc93a  0x00c06434  0x0000.000.00000000  0x00000001   0x00000000  1637305928
   0x09    9    0x00  0xfffffff3  0x0015  0x0f9b.ed0bc828  0x00c06434  0x0000.000.00000000  0x00000001   0x00000000  1637305927
   0x0a    9    0x00  0xfffffaf2  0x0018  0x0f9b.ed0bc90c  0x00c06434  0x0000.000.00000000  0x00000001   0x00000000  1637305928
   0x0b    9    0x00  0xfffff671  0x0010  0x0f9b.ed0bc867  0x00c06434  0x0000.000.00000000  0x00000001   0x00000000  1637305927
   0x0c    9    0x00  0xfffffec0  0x001e  0x0f9b.ed0bc900  0x00c06434  0x0000.000.00000000  0x00000001   0x00000000  1637305928
   0x0d    9    0x00  0xfffff8bf  0x0020  0x0f9b.ed0bc889  0x00c06434  0x0000.000.00000000  0x00000001   0x00000000  1637305928
   0x0e    9    0x00  0xfffff4ce  0x0013  0x0f9b.ed0bc9ab  0x00c06434  0x0000.000.00000000  0x00000001   0x00000000  1637305928
   0x0f    9    0x00  0xfffff64d  0x000d  0x0f9b.ed0bc875  0x00c06434  0x0000.000.00000000  0x00000001   0x00000000  1637305927
   0x10    9    0x00  0xfffff5ec  0x000f  0x0f9b.ed0bc86b  0x00c06434  0x0000.000.00000000  0x00000001   0x00000000  1637305927
   0x11    9    0x00  0xfffffccb  0x001c  0x0f9b.ed0bc950  0x00c06434  0x0000.000.00000000  0x00000001   0x00000000  1637305928
   0x12    9    0x00  0xfffff55a  0x001f  0x0f9b.ed0bc976  0x00c06434  0x0000.000.00000000  0x00000001   0x00000000  1637305928
   0x13    9    0x00  0xfffff659  0x0014  0x0f9b.ed0bc9b1  0x00c06434  0x0000.000.00000000  0x00000001   0x00000000  1637305928
   0x14    9    0x00  0xffffefb8  0x0006  0x0f9b.ed0bc9c2  0x00c06434  0x0000.000.00000000  0x00000001   0x00000000  1637305928
   0x15    9    0x00  0xffffed27  0x0005  0x0f9b.ed0bc82e  0x00c06434  0x0000.000.00000000  0x00000001   0x00000000  1637305927
   0x16    9    0x00  0xfffffd66  0x0007  0x0f9b.ed0bc854  0x00c06434  0x0000.000.00000000  0x00000001   0x00000000  1637305927
   0x17    9    0x00  0xfffffdd5  0x0000  0x0f9b.ed0bc8e6  0x00c06434  0x0000.000.00000000  0x00000001   0x00000000  1637305928
   0x18    9    0x00  0xfffff1f4  0x001d  0x0f9b.ed0bc917  0x00c06434  0x0000.000.00000000  0x00000001   0x00000000  1637305928
   0x19    9    0x00  0xfffff303  0x0002  0x0f9b.ed0bc927  0x00c06434  0x0000.000.00000000  0x00000001   0x00000000  1637305928
   0x1a    9    0x00  0xfffff592  0x0001  0x0f9b.ed0bc83b  0x00c06434  0x0000.000.00000000  0x00000001   0x00000000  1637305927
   0x1b    9    0x00  0xfffff9f1  0x0017  0x0f9b.ed0bc8df  0x00c06434  0x0000.000.00000000  0x00000001   0x00000000  1637305928
   0x1c    9    0x00  0xffffeee0  0x0012  0x0f9b.ed0bc95b  0x00c06434  0x0000.000.00000000  0x00000001   0x00000000  1637305928
   0x1d    9    0x00  0xfffff23f  0x0019  0x0f9b.ed0bc91e  0x00c06434  0x0000.000.00000000  0x00000001   0x00000000  1637305928
   0x1e    9    0x00  0xfffff67e  0x000a  0x0f9b.ed0bc908  0x00c06434  0x0000.000.00000000  0x00000001   0x00000000  1637305928
   0x1f    9    0x00  0xfffff1ad  0x0003  0x0f9b.ed0bc982  0x00c06434  0x0000.000.00000000  0x00000001   0x00000000  1637305928
   0x20    9    0x00  0xfffffb0c  0x001b  0x0f9b.ed0bc8ba  0x00c06434  0x0000.000.00000000  0x00000001   0x00000000  1637305928
   0x21    9    0x00  0xfffff1eb  0x0011  0x0f9b.ed0bc943  0x00c06434  0x0000.000.00000000  0x00000001   0x00000000  1637305928

异常的undo段头的dump可以看到所有slot的wrap#都非常高,ktuxc中的chd为0009,说明下一次事务将使用slot 9的事务槽,而slot 9的wrap#为 0xfffffff3已经非常接近 KSQNMAXVAL ,但是我们知道每次wrap#重用只会加1,并不会超过 KSQNMAXVAL ,那么为什么会报出ORA-00600[4187]呢?

原因在于重用slot时wrap#+1的算法已经过时了,当前采用的是在执行ktubnd函数为事务绑定undo段时,会调用kjqghd去计算出一个重用slot递增值delta,这个delta也是有限制的,必须小于16(由KTU_MAX_KSQN_DELTA定义),所以就可能会出现 0xfffffff3 +delta的值超过KSQNMAXVAL 。

知道了错误原因,解决方法其实很简单,就是删除异常的undo段或者重建undo表空间,如果删除不掉undo段,比如还有其他活动事务,那么可以用_corrupted_rollback_segments屏蔽掉该undo段。mos也提供了脚本去检查哪些undo段面临这样的问题。

 select b.segment_name, b.tablespace_name
         ,a.ktuxeusn "Undo Segment Number"
         ,a.ktuxeslt "Slot"
         ,a.ktuxesqn "Wrap#"
   from  x$ktuxe a, dba_rollback_segs b
   where a.ktuxesqn > -429496730 and a.ktuxesqn < 0
       and a.ktuxeusn = b.segment_id;

这里还有一点需要思考的是,为什么会出现wrap#如此大?仅仅是高TPS吗?我们知道事务绑定undo段的原则是尽可能的将活动事务平均的各个undo段上,具体算法为:

在当前undo tablespace中的online undo segment中寻找事务表中没有活动事务的undo segment;

如果没有找到则尝试在当前undo tablespace online那些处于offline状态的undo segment;

如果没有找到则尝试在当前undo tablespace创建undo segment并online;

如果无法创建则会寻找最近最少使用的undo segment。

有一种非常大的可能性就是可以online的undo段太少,经过查看该实例undo表空间大小为1.5g,且不可自动扩展,这才导致了undo事务表的各个slot的wrap#如此之高。

所以针对该case的补充建议是根据高峰期TPS,合理设置undo表空间大小以及_rollback_segment_count。

墨天轮原文链接:https://www.modb.pro/db/17494...(复制链接至浏览器或点击文末阅读原文查看)

关于作者
李翔宇,云和恩墨西区交付技术顾问,长期服务移动运营商行业客户,熟悉Oracle性能优化,故障诊断,特殊恢复。

03-05 21:37