11.2.0.1的ASM出现ORA-600[kfgFinalize_2]错误。
错误信息为:
Fri Jun 17 09:59:51 2011
NOTE: No asm libraries found in the system
* instance_number obtained from CSS = 2, checking for the existence of node
0...
* node 0 does not exist. instance_number = 2
Starting ORACLE instance (normal)
sskgpgetexecname failed to get name
LICENSE_MAX_SESSION = 0
LICENSE_SESSIONS_WARNING = 0
Interface type 1 en1 192.168.138.0 configured from GPnP Profile for use as a
cluster interconnect
Interface type 1 en0 10.121.128.0 configured from GPnP Profile for use as a
public interface
Picked latch-free SCN scheme 3
Using LOG_ARCHIVE_DEST_1 parameter default value as /u01/app/grid/dbs/arch
Autotune of undo retention is turned on.
LICENSE_MAX_USERS = 0
SYS auditing is disabled
Starting up:
Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - 64bit Production
With the Real Application Clusters and Automatic Storage Management options.
Using parameter settings in server-side spfile
+CRS/jhzw-cluster/asmparameterfile/registry.253.732844175
System parameters with non-default values:
large_pool_size = 12M
instance_type = "asm"
remote_login_passwordfile=
"EXCLUSIVE"
asm_diskgroups = "DATA"
asm_diskgroups = "FRA"
asm_power_limit = 1
diagnostic_dest = "/u01/grid"
Cluster communication is configured to use the following interface(s) for this
instance
192.168.138.187
cluster interconnect IPC version:Oracle UDP/IP (generic)
IPC Vendor 1 proto 2
Fri Jun 17 09:59:59 2011
PMON started with pid=2, OS id=258330
Fri Jun 17 09:59:59 2011
VKTM started with pid=3, OS id=311588 at elevated priority
VKTM running at (10)millisec precision with DBRM quantum (100)ms
Fri Jun 17 09:59:59 2011
GEN0 started with pid=4, OS id=319784
Fri Jun 17 10:00:00 2011
DIAG started with pid=5, OS id=282666
Fri Jun 17 10:00:00 2011
PING started with pid=6, OS id=323882
Fri Jun 17 10:00:00 2011
PSP0 started with pid=7, OS id=327980
Fri Jun 17 10:00:00 2011
DIA0 started with pid=8, OS id=286766
Fri Jun 17 10:00:00 2011
LMON started with pid=9, OS id=332080
Fri Jun 17 10:00:02 2011
LMD0 started with pid=10, OS id=278586
Fri Jun 17 10:00:03 2011
LMS0 started with pid=11, OS id=290872 at elevated priority
Fri Jun 17 10:00:03 2011
LMHB started with pid=12, OS id=299072
Fri Jun 17 10:00:03 2011
MMAN started with pid=13, OS id=336182
Fri Jun 17 10:00:03 2011
DBW0 started with pid=14, OS id=303170
Fri Jun 17 10:00:03 2011
LGWR started with pid=15, OS id=348478
Fri Jun 17 10:00:03 2011
CKPT started with pid=16, OS id=352578
Fri Jun 17 10:00:03 2011
SMON started with pid=17, OS id=311366
Fri Jun 17 10:00:03 2011
RBAL started with pid=18, OS id=307272
Fri Jun 17 10:00:03 2011
GMON started with pid=19, OS id=315464
Fri Jun 17 10:00:04 2011
MMON started with pid=20, OS id=340278
Fri Jun 17 10:00:04 2011
MMNL started with pid=21, OS id=319562
lmon registered with NM - instance number 2 (internal mem no 1)
Reconfiguration started (old inc 0, new inc 12)
ASM instance
List of instances:
1 2 (myinst: 2)
Global Resource Directory frozen
* allocate domain 0, invalid = TRUE
Communication channels reestablished
* domain 0 valid = 1 according to
instance 1
* allocate domain 1, invalid = TRUE
* domain 1 valid = 1 according to
instance 1
* allocate domain 2, invalid = TRUE
* domain 2 valid = 1 according to
instance 1
* allocate domain 3, invalid = TRUE
* domain 3 valid = 1 according to
instance 1
Master broadcasted resource hash value
bitmaps
Non-local Process blocks cleaned out
LMS 0: 0 GCS shadows cancelled, 0
closed, 0 Xw survived
Set master node info
Submitted all remote-enqueue requests
Dwn-cvts replayed, VALBLKs dubious
All grantable enqueues granted
Submitted all GCS remote-cache requests
Fix write in gcs resources
Reconfiguration complete
Fri Jun 17 10:00:06 2011
LCK0 started with pid=22, OS id=327758
Fri Jun 17 10:00:09 2011
ORACLE_BASE not set in environment. It is recommended
that ORACLE_BASE be set in the environment
Fri Jun 17 10:00:12 2011
SQL> ALTER DISKGROUP ALL MOUNT /* asm agent */
NOTE: Diskgroups listed in ASM_DISKGROUPS are
DATA
FRA
NOTE: Diskgroup used for Voting files is:
CRS
Diskgroup with spfile:CRS
Diskgroup used for OCR is:CRS
NOTE: cache registered group CRS number=1 incarn=0xfdaebf4e
NOTE: cache began mount (not first) of group CRS number=1 incarn=0xfdaebf4e
NOTE: cache registered group DATA number=2 incarn=0xfe4ebf4f
NOTE: cache began mount (not first) of group DATA number=2 incarn=0xfe4ebf4f
NOTE: cache registered group FRA number=3 incarn=0xfe5ebf50
NOTE: cache began mount (not first) of group FRA number=3 incarn=0xfe5ebf50
NOTE: Assigning number (1,2) to disk (/dev/rhdisk10)
NOTE: Assigning number (1,0) to disk (/dev/rhdisk8)
NOTE: Assigning number (1,1) to disk (/dev/rhdisk9)
NOTE: Assigning number (2,1) to disk (/dev/rhdisk12)
NOTE: Assigning number (2,0) to disk (/dev/rhdisk6)
NOTE: Assigning number (3,0) to disk (/dev/rhdisk7)
kfdp_query(CRS): 4
Fri Jun 17 10:00:14 2011
kfdp_queryBg(): 4
NOTE: cache opening disk 0 of grp 1: CRS_0000 path:/dev/rhdisk8
NOTE: F1X0 found on disk 0 au 2 fcn 0.0
NOTE: cache opening disk 1 of grp 1: CRS_0001 path:/dev/rhdisk9
NOTE: F1X0 found on disk 1 au 2 fcn 0.0
NOTE: cache opening disk 2 of grp 1: CRS_0002 path:/dev/rhdisk10
NOTE: F1X0 found on disk 2 au 2 fcn 0.0
NOTE: cache mounting (not first) normal redundancy group 1/0xFDAEBF4E (CRS)
Fri Jun 17 10:00:14 2011
kjbdomatt send to inst 1
Fri Jun 17 10:00:14 2011
NOTE: attached to recovery domain 1
Fri Jun 17 10:00:14 2011
NOTE: LGWR attempting to mount thread 2 for diskgroup 1 (CRS)
NOTE: LGWR found thread 2 open - signalling ORA-15133
WARNING: instance recovery required during mount
kfdp_query(DATA): 5
kfdp_queryBg(): 5
NOTE: cache opening disk 0 of grp 2: DATA_0000 path:/dev/rhdisk6
NOTE: F1X0 found on disk 0 au 2 fcn 0.61290
NOTE: cache opening disk 1 of grp 2: DATA_0001 path:/dev/rhdisk12
NOTE: cache mounting (not first) external redundancy group 2/0xFE4EBF4F (DATA)
kjbdomatt send to inst 1
NOTE: attached to recovery domain 2
NOTE: LGWR attempting to mount thread 2 for diskgroup 2 (DATA)
NOTE: LGWR found thread 2 closed at ABA 12.1279
NOTE: LGWR mounted thread 2 for diskgroup 2 (DATA)
NOTE: LGWR opening thread 2 at fcn 0.1600788 ABA 13.1280
NOTE: cache mounting group 2/0xFE4EBF4F (DATA) succeeded
NOTE: cache ending mount (success) of group DATA number=2 incarn=0xfe4ebf4f
kfdp_query(FRA): 6
kfdp_queryBg(): 6
NOTE: cache opening disk 0 of grp 3: FRA_0000 path:/dev/rhdisk7
NOTE: F1X0 found on disk 0 au 2 fcn 0.0
NOTE: cache mounting (not first) external redundancy group 3/0xFE5EBF50 (FRA)
kjbdomatt send to inst 1
NOTE: attached to recovery domain 3
NOTE: LGWR attempting to mount thread 2 for diskgroup 3 (FRA)
NOTE: LGWR found thread 2 closed at ABA 12.91
NOTE: LGWR mounted thread 2 for diskgroup 3 (FRA)
NOTE: LGWR opening thread 2 at fcn 0.2439 ABA 13.92
NOTE: cache mounting group 3/0xFE5EBF50 (FRA) succeeded
NOTE: cache ending mount (success) of group FRA number=3 incarn=0xfe5ebf50
Fri Jun 17 10:00:17 2011
kfdp_query(DATA): 7
kfdp_queryBg(): 7
NOTE: Instance updated compatible.asm to 11.2.0.0.0 for grp 2
SUCCESS: diskgroup DATA was mounted
kfdp_query(FRA): 8
kfdp_queryBg(): 8
NOTE: Instance updated compatible.asm to 11.2.0.0.0 for grp 3
SUCCESS: diskgroup FRA was mounted
kfdp_query(CRS): 10
kfdp_queryBg(): 10
NOTE: cache opening disk 0 of grp 1: CRS_0000 path:/dev/rhdisk8
NOTE: F1X0 found on disk 0 au 2 fcn 0.0
NOTE: cache opening disk 1 of grp 1: CRS_0001 path:/dev/rhdisk9
NOTE: F1X0 found on disk 1 au 2 fcn 0.0
NOTE: cache opening disk 2 of grp 1: CRS_0002 path:/dev/rhdisk10
NOTE: F1X0 found on disk 2 au 2 fcn 0.0
NOTE: cache mounting (not first) (retry) normal redundancy group 1/0xFDAEBF4E
(CRS)
NOTE: LGWR attempting to mount thread 2 for diskgroup 1 (CRS)
NOTE: LGWR found thread 2 open - signalling ORA-15133
WARNING: instance recovery required during mount
.
.
.
Fri Jun 17 10:06:55 2011
kfdp_query(CRS): 406
kfdp_queryBg(): 406
NOTE: cache opening disk 0 of grp 1: CRS_0000 path:/dev/rhdisk8
NOTE: F1X0 found on disk 0 au 2 fcn 0.0
NOTE: cache opening disk 1 of grp 1: CRS_0001 path:/dev/rhdisk9
NOTE: F1X0 found on disk 1 au 2 fcn 0.0
NOTE: cache opening disk 2 of grp 1: CRS_0002 path:/dev/rhdisk10
NOTE: F1X0 found on disk 2 au 2 fcn 0.0
NOTE: cache mounting (not first) (retry) normal redundancy group 1/0xFDAEBF4E
(CRS)
NOTE: LGWR attempting to mount thread 2 for diskgroup 1 (CRS)
NOTE: LGWR found thread 2 open - signalling ORA-15133
WARNING: instance recovery required during mount
Errors in file /u01/grid/diag/asm/+asm/+ASM2/trace/+ASM2_ora_340052.trc (incident=11385):
ORA-00600: internal error code, arguments: [kfgFinalize_2], [], [], [], [], [],
[], [], [], [], [], []
Incident details in: /u01/grid/diag/asm/+asm/+ASM2/incident/incdir_11385/+ASM2_ora_340052_i11385.trc
Fri Jun 17 10:07:01 2011
Trace dumping is performing id=[cdmp_20110617100701]
ORA-00600: internal error code, arguments: [kfgFinalize_2], [], [], [], [], [],
[], [], [], [], [], []
ERROR: ALTER DISKGROUP ALL MOUNT /* asm agent */
NOTE: cache dismounting (clean) group 1/0xFDAEBF4E (CRS)
NOTE: lgwr not being msg'd to dismount
Fri Jun 17 10:07:02 2011
kjbdomdet send to inst 1
detach from dom 1, sending detach message to inst 1
Fri Jun 17 10:07:02 2011
NOTE: detached from domain 1
NOTE: cache dismounted group 1/0xFDAEBF4E (CRS)
NOTE: cache ending mount (fail) of group CRS number=1 incarn=0xfdaebf4e
kfdp_dismount(): 407
Fri Jun 17 10:07:02 2011
kfdp_dismountBg(): 407
NOTE: De-assigning number (1,0) from disk (/dev/rhdisk8)
NOTE: De-assigning number (1,1) from disk (/dev/rhdisk9)
NOTE: De-assigning number (1,2) from disk (/dev/rhdisk10)
ERROR: diskgroup CRS was not mounted
NOTE: cache deleting context for group CRS 1/-38879410
Fri Jun 17 10:07:02 2011
Shutting down instance (abort)
License high water mark = 2
USER (ospid: 307518): terminating the instance
Instance terminated by USER, pid = 307518
Fri Jun 17 10:07:03 2011
Instance shutdown complete
在实例异常崩溃后,尝试启动ASM实例时,ASM尝试进行实例回复,并导致了错误,Oracle在不断的进行多次尝试后,出现了这个ORA-600的错误,并最终导致了实例的异常关闭。
查询MOS,发现存在几个和当前类似的错误信息,错误函数都是kfgFinalize_2,不过绝大部分错误都明确在11.2.0.1中被FIXED。经排除和文档Bug 6771400 - ASM fails to mount a disk group with OERI[kfgfinalize_2] [ID 6771400.8]描述的最为解决,该错误确认影响的版本是10.2.0.3和10.2.0.4,在10.2.0.5和11.1.0.6中被FIXED,该bug并没有提及11.2版本,因此不确认当前问题是否在11.2.0.1版本出现,不过从其他表相上看,当前问题属于这个bug的可能性很大。
这个问题发生在ASM异常崩溃后,可能会导致ASM实例第一次重启出现异常,随后的手工启动并未发生异常,且该问题出现概率很低,可以忽略掉该错误。
来自 “ ITPUB博客 ” ,链接:https://blog.itpub.net/4227/viewspace-749439/ ,如需转载,请注明出处,否则将追究法律责任。