ORA-00600: internal error code, arguments: [kcbr_apply_change_11] 12 July 2010
Posted by David Alejo Marcos in Dataguard Broker, Oracle 11.2.Tags: Dataguar broker, Oracle 11.2
trackback
This morning we found out that one of our standby databases was lagging behind. The problem was a gap in the archivelogs:
Media Recovery Waiting for thread 1 sequence 10110
Fetching gap sequence in thread 1, gap sequence 10110-10143
Completed: ALTER DATABASE RECOVER MANAGED STANDBY DATABASE THROUGH ALL SWITCHOVER DISCONNECT USING CURRENT LOGFILE
Mon Jul 12 07:39:35 2010
FAL[client]: Failed to request gap sequence
GAP - thread 1 sequence 10110-10143
DBID 666702615 branch 708427666
FAL[client]: All defined FAL servers have been attempted.
The archivelogs were not longer on the primary server so I had to restore them from our backup; not a big problem…
The problem:
Once the missing archivelogs were restored to the current location, I enabled the recovery manager, just to find out that it was reporting errors. Below is an extract of the Alert.log file:
ALTER DATABASE RECOVER MANAGED STANDBY DATABASE THROUGH ALL SWITCHOVER DISCONNECT USING CURRENT LOGFILE
Attempt to start background Managed Standby Recovery process (xxxxx)
Mon Jul 12 08:22:30 2010
MRP0 started with pid=31, OS id=6766
MRP0: Background Managed Standby Recovery process started (xxxxx)
started logmerger process
Mon Jul 12 08:22:35 2010
Managed Standby Recovery starting Real Time Apply
Parallel Media Recovery started with 4 slaves
Waiting for all non-current ORLs to be archived...
All non-current ORLs have been archived.
Media Recovery Log /u01/oradata/xxxxx/arch/log1_10110_708427666.arc
Mon Jul 12 08:22:35 2010
Errors in file /opt/oracle/diag/rdbms/ssssssssss/xxxxx/trace/xxxxx_pr04_6788.trc (incident=20316):
ORA-00600: internal error code, arguments: [kcbr_apply_change_11], [], [], [], [], [], [], [], [], [], [], []
Incident details in: /opt/oracle/diag/rdbms/ssssssssss/xxxxx/incident/incdir_20316/xxxxx_pr04_6788_i20316.trc
Completed: ALTER DATABASE RECOVER MANAGED STANDBY DATABASE THROUGH ALL SWITCHOVER DISCONNECT USING CURRENT LOGFILE
Slave exiting with ORA-600 exception
Errors in file /opt/oracle/diag/rdbms/ssssssssss/xxxxx/trace/xxxxx_pr04_6788.trc:
ORA-00600: internal error code, arguments: [kcbr_apply_change_11], [], [], [], [], [], [], [], [], [], [], []
Errors in file /opt/oracle/diag/rdbms/ssssssssss/xxxxx/trace/xxxxx_mrp0_6766.trc (incident=20260):
ORA-00600: internal error code, arguments: [kcbr_apply_change_11], [], [], [], [], [], [], [], [], [], [], []
Incident details in: /opt/oracle/diag/rdbms/ssssssssss/xxxxx/incident/incdir_20260/xxxxx_mrp0_6766_i20260.trc
Mon Jul 12 08:22:36 2010
Trace dumping is performing id=[cdmp_20100712082236]
Recovery Slave PR04 previously exited with exception 600
MRP0: Background Media Recovery terminated with error 448
Errors in file /opt/oracle/diag/rdbms/ssssssssss/xxxxx/trace/xxxxx_pr00_6772.trc:
ORA-00448: normal completion of background process
Managed Standby Recovery not using Real Time Apply
Recovery interrupted!
Recovered data files to a consistent state at change 1289063311
Errors in file /opt/oracle/diag/rdbms/ssssssssss/xxxxx/trace/xxxxx_pr00_6772.trc:
ORA-00448: normal completion of background process
Errors in file /opt/oracle/diag/rdbms/ssssssssss/xxxxx/trace/xxxxx_mrp0_6766.trc:
ORA-00600: internal error code, arguments: [kcbr_apply_change_11], [], [], [], [], [], [], [], [], [], [], []
MRP0: Background Media Recovery process shutdown (xxxxx)
And the contents of /opt/oracle/diag/rdbms/ssssssssss/xxxxx/trace/xxxxx_mrp0_6766.trc did not look good:
Dump file /opt/oracle/diag/rdbms/ssssssssss/xxxxxx/incident/incdir_20260/xxxxxx_mrp0_6766_i20260.trc
Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - 64bit Production
With the Partitioning option
ORACLE_HOME = /opt/oracle/product/11.2.0/dbhome_1
System name: Linux
Node name: ssssssssss.marketxs.com
Release: 2.6.18-128.1.1.el5
Version: #1 SMP Mon Jan 26 13:58:24 EST 2009
Machine: x86_64
Instance name: xxxxxx
Redo thread mounted by this instance: 1
Oracle process number: 31
Unix process pid: 6766, image: oracle@ssssssssss.marketxs.com (MRP0)
*** 2010-07-12 08:22:36.474
*** SESSION ID:(313.13054) 2010-07-12 08:22:36.474
*** CLIENT ID:() 2010-07-12 08:22:36.474
*** SERVICE NAME:(SYS$BACKGROUND) 2010-07-12 08:22:36.474
*** MODULE NAME:() 2010-07-12 08:22:36.474
*** ACTION NAME:() 2010-07-12 08:22:36.474
Dump continued from file: /opt/oracle/diag/rdbms/ssssssssss/xxxxxx/trace/xxxxxx_mrp0_6766.trc
ORA-00600: internal error code, arguments: [kcbr_apply_change_11], [], [], [], [], [], [], [], [], [], [], []
========= Dump for incident 20260 (ORA 600 [ORA-00600: internal error code, arguments: [kcbr_apply_change_11], [], [], [], [], [], [], [], [], [], [], []
]) ========
*** 2010-07-12 08:22:36.474
dbkedDefDump(): Starting incident default dumps (flags=0x2, level=3, mask=0x0)
----- SQL Statement (None) -----
Current SQL information unavailable - no cursor.
----- Call Stack Trace -----
calling call entry argument values in hex
location type point (? means dubious value)
-------------------- -------- -------------------- ----------------------------
skdstdst()+36 call kgdsdst() 000000000 ? 000000000 ?
7FFFFFE5EEF8 ? 000000001 ?
7FFFFFE633F8 ? 000000000 ?
ksedst1()+98 call skdstdst() 000000000 ? 000000000 ?
7FFFFFE5EEF8 ? 000000001 ?
000000000 ? 000000000 ?
ksedst()+34 call ksedst1() 000000000 ? 000000001 ?
7FFFFFE5EEF8 ? 000000001 ?
000000000 ? 000000000 ?
dbkedDefDump()+2736 call ksedst() 000000000 ? 000000001 ?
7FFFFFE5EEF8 ? 000000001 ?
000000000 ? 000000000 ?
ksedmp()+36 call dbkedDefDump() 000000003 ? 000000002 ?
7FFFFFE5EEF8 ? 000000001 ?
000000000 ? 000000000 ?
ksfdmp()+64 call ksedmp() 000000003 ? 000000002 ?
7FFFFFE5EEF8 ? 000000001 ?
000000000 ? 000000000 ?
dbgexPhaseII()+1764 call ksfdmp() 000000003 ? 000000002 ?
7FFFFFE5EEF8 ? 000000001 ?
000000000 ? 000000000 ?
dbgexProcessError() call dbgexPhaseII() 2B3BAC46A6F0 ? 2B3BAC7FA598 ?
+2279 7FFFFFE6B1E8 ? 000000001 ?
000000000 ? 000000000 ?
The solution:
As we had the necessary archivelogs on the server, I disabled the recovery manager:
alter database recover managed standby database cancel
and cleared the logfiles (as the information was not longer necessary):
SQL> select 'alter database clear logfile group '|| group# ||';' from v$standby_log;
'ALTERDATABASECLEARLOGFILEGROUP'||GROUP#||';'
----------------------------------------------------------------------------
alter database clear logfile group 6;
alter database clear logfile group 7;
alter database clear logfile group 8;
alter database clear logfile group 9;
and executed the commands printed above.
I did shutdown and mounted the database to have a clean startup, but I think we can avoid this step.
After the database reported to be in mounted state, I enabled the recovery and it worked perfectly:
alter database recover managed standby database disconnect
Attempt to start background Managed Standby Recovery process (xxx)
Mon Jul 12 08:30:45 2010
MRP0 started with pid=42, OS id=8143
MRP0: Background Managed Standby Recovery process started (xxx)
started logmerger process
Mon Jul 12 08:30:50 2010
Managed Standby Recovery not using Real Time Apply
Parallel Media Recovery started with 4 slaves
Waiting for all non-current ORLs to be archived...
All non-current ORLs have been archived.
Media Recovery Log /u01/oradata/xxxx/arch/log1_10110_708427666.arc
Completed: alter database recover managed standby database disconnect
Mon Jul 12 08:31:06 2010
Media Recovery Log /u01/oradata/xxxx/arch/log1_10111_708427666.arc
........
As always, comments are welcome.
Comments
Sorry comments are closed for this entry
David Marcos' Blog 
David,
Not the exact same bug but looks like clean startup is necessary
Bug 8677584
Thanks for sharing
Hi David,
But then, you’re not using Real Time Apply any more.
Morning Tram,
as the standby redo logs are still there and the database was bounced, yes, you are still maintaining real-time apply.
I should have probably mentioned that we use DG Broker, so as soon as we enable DB Broker, the following entry appear on the alert.log file:
Mon Jul 12 08:39:40 2010
ALTER DATABASE RECOVER MANAGED STANDBY DATABASE CANCEL
Mon Jul 12 08:39:48 2010
Errors with log /u01/oradata/xxxx/arch/log1_10138_708427666.arc
MRP0: Background Media Recovery cancelled with status 16037
Errors in file /opt/oracle/diag/rdbms/sssssss/xxxxxx/trace/xxxxx_pr00_8151.trc:
ORA-16037: user requested cancel of managed recovery operation
Mon Jul 12 08:40:09 2010
Recovery interrupted!
Recovered data files to a consistent state at change 1291051140
Errors in file /opt/oracle/diag/rdbms/ssssss/xxxxxx/trace/xxxx_pr00_8151.trc:
ORA-16037: user requested cancel of managed recovery operation
Mon Jul 12 08:40:09 2010
Waiting for MRP0 pid 8143 to terminate
Mon Jul 12 08:40:09 2010
MRP0: Background Media Recovery process shutdown (xxx)
Managed Standby Recovery Canceled (xxx)
Completed: ALTER DATABASE RECOVER MANAGED STANDBY DATABASE CANCEL
ALTER DATABASE RECOVER MANAGED STANDBY DATABASE THROUGH ALL SWITCHOVER DISCONNECT USING CURRENT LOGFILE
Attempt to start background Managed Standby Recovery process (xxx)
Mon Jul 12 08:40:09 2010
MRP0 started with pid=18, OS id=8713
MRP0: Background Managed Standby Recovery process started (xxx)
started logmerger process
Mon Jul 12 08:40:14 2010
Managed Standby Recovery starting Real Time Apply
Parallel Media Recovery started with 4 slaves
Waiting for all non-current ORLs to be archived…
All non-current ORLs have been archived.
Media Recovery Log /u01/oradata/xxxxx/arch/log1_10138_708427666.arc
Completed: ALTER DATABASE RECOVER MANAGED STANDBY DATABASE THROUGH ALL SWITCHOVER DISCONNECT USING CURRENT LOGFILE
Mon Jul 12 08:41:04 2010
Media Recovery Log /u01/oradata/xxxx/arch/log1_10139_708427666.arc
Unsure if related, but I ran across your post searching for “kcbr_apply_change_11”. Appears Oracle may have released an Alert on LOB corruption.
If you have Metalink access:
Logical corruption of LOB data during recovery. [ID 1206814.1]
Thank you Robert,
I see the note has been created quite recently and, interestinly we have LOBs on those databases.
We are in the process of upgrading our Dev databases to 11.2.0.2, so it should be fixed.
Regards,
David.