Troubleshooting ORA-00600 [ORA_NPI_ERROR] ORA-00600: internal error code [kffilCreate01]
Oracle 11.2.0.3 2nodes RAC on AIX, node1 DB instance crash and db alert log show “ORA-00600 [ORA_NPI_ERROR] ORA-00600: internal error code [kffilCreate01]” and “ORA-15064: communication failure with ASM instance” then Instance terminated by ASMB.
# db alert log
Fri May 22 04:16:23 2020 Use ADRCI or Support Workbench to package the incident. See Note 411.1 at My Oracle Support for error and packaging details. NOTE: ASMB terminating Errors in file /oracle/app/oracle/diag/rdbms/anbob/anbob1/trace/anbob1_asmb_40373526.trc: ORA-15064: communication failure with ASM instance ORA-00600: internal error code, arguments: [ORA_NPI_ERROR], [600], [ORA-00600: internal error code, arguments: [kffilCreate01], [anbob1:anbob], [], [], [], [], [], [], [], [], [], [] ], [], [], [], [], [], [], [], [], [] ASMB (ospid: 40373526): terminating the instance due to error 15064 Fri May 22 04:16:33 2020 Instance terminated by ASMB, pid = 40373526
# asm instance alert
2020-05-22 04:16:18.672000 +08:00 Errors in file /oracle/app/11.2.0.3/grid/log/diag/asm/+asm/+ASM1/trace/+ASM1_ora_27264968.trc (incident=312217): ORA-00600: internal error code, arguments: [kffilCreate01], [anbob1:anbob], [], [], [], [], [], [], [], [], [], [] Incident details in: /oracle/app/11.2.0.3/grid/log/diag/asm/+asm/+ASM1/incident/incdir_312217/+ASM1_ora_27264968_i312217.trc
# tracefile
dump file: /oracle/app/11.2.0.3/grid/log/diag/asm/+asm/+ASM1/incident/incdir_312217/+ASM1_ora_27264968_i312217.trc
ORA-00600: internal error code, arguments: [kffilCreate01], [anbob1:anbob], [], [], [], [], [], [], [], [], [], []
*** 2020-05-22 04:16:33.782
-------------------------------------------------------------------------------
Trace Bucket Dump Begin: default bucket for process 27 (osid: 27264968)
TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA
-------------------------------------------------------------------------------
2020-05-22 04:16:18.656615 :C88A0662:KFNS:kfn.c@741:kfnDispatch(): completed KFNOP=5 callcnt=-1077812999
2020-05-22 04:16:18.656714 :C88A0667:KFNS:kfn.c@710:kfnDispatch(): calling server stub for KFNOP=5
2020-05-22 04:16:18.656715 :C88A0668:KFNU:kfns.c@1727:kfnsBackground(): kfnsBackground consuming in-progress message typ=14 unread=1 status=0xfffffff1
2020-05-22 04:16:18.656716 :C88A0669:KFNU:kfns.c@1965:kfnsConsume(): kfnsConsume message 0x70000013d66d2f8 status=0xfffffff1 flags=0x1
2020-05-22 04:16:18.656722 :C88A066A:KFNU:kfn.c@5315:kfnmsg_Dump(): kfnsBg (kfnmsg) opcode=15 (KFNMS_MAPLOAD) fd 0x7000001177b7e08 mid 4294967291, gn [2.1165624170], fn [1147.963253597] exts 4480, sta
rt 0, cnt 60
2020-05-22 04:16:18.656723 :C88A066B:KFNU:kfns.c@1786:kfnsBackground(): kfnsBackground got targeted message
2020-05-22 04:16:18.656726 :C88A066C:db_trace:kfns.c@5385:kfnsFillMapMsg(): [10491:27:838] MAP_LOAD: gn=2 fn=1147, mapid=-5 start=0 cnt=60
2020-05-22 04:16:18.656727 :C88A066D:KFNU:kfns.c@1942:kfnsBackground(): kfnsBackground completed in 0 seconds (KFNPM=2)
2020-05-22 04:16:18.656728 :C88A066E:KFNS:kfn.c@741:kfnDispatch(): completed KFNOP=5 callcnt=-1077812998
2020-05-22 04:16:18.656813 :C88A0673:KFNS:kfn.c@710:kfnDispatch(): calling server stub for KFNOP=5
2020-05-22 04:16:18.656814 :C88A0674:KFNU:kfns.c@1727:kfnsBackground(): kfnsBackground consuming in-progress message typ=15 unread=1 status=0xfffffff1
2020-05-22 04:16:18.656814 :C88A0675:KFNU:kfns.c@1965:kfnsConsume(): kfnsConsume message 0x70000011769cfa8 status=0xfffffff1 flags=0x1
2020-05-22 04:16:18.657300 :C88A06AA:KFNU:kfn.c@5366:kfnmsg_Dump(): kfnsBg (kfnmsg) op=25 (KFNMS_FILEUSE) (filuse) gn 2 un 0 mid 4294967292 cod 65535
----- Call Stack Trace -----
calling call entry
location type point
-------------------- -------- --------------------
dbkePostKGE_kgsf()+ call dbgePostErrorKGE()
68
kgeadse()+380 call dbkePostKGE_kgsf()
kgerinv_internal()+ call kgeadse()
48
kgerinv()+48 call kgerinv_internal()
kgeasnmierr()+72 call kgerinv()
kffilCreate()+540 call kgeasnmierr()
kfnsUFG()+4036 call kffilCreate()
kfnsBackground()+39 call kfnsUFG()
88
kfnDispatch()+1128 call kfnsBackground()
opiodr()+720 call kfnDispatch()
ttcpip()+1028 call opiodr()
opitsk()+1508 call ttcpip()
opiino()+940 call opitsk()
opiodr()+720 call opiino()
opidrv()+1132 call opiodr()
sou2o()+136 call opidrv()
opimai_real()+608 call sou2o()
ssthrdmain()+268 call opimai_real()
main()+204 call ssthrdmain()
__start()+112 call main()
kffilCreate()+540 kernel automatic storage management file Create
kfnsUFG()+4036 kernel automatic storage management networking subsystem server networking [partial hit for: kfns ]
# grep -i mapid /oracle/app/11.2.0.3/grid/log/diag/asm/+asm/+ASM1/incident/incdir_312217/+ASM1_ora_27264968_i312217.trc (kffil) netnm: , mapid: (kffil) netnm: anbob1:anbob, mapid: 4294967295 (kffil) netnm: anbob1:anbob, mapid: 4294967294 (kffil) netnm: anbob1:anbob, mapid: 4294946774 (kffil) netnm: anbob1:anbob, mapid: 3849552408 (kffil) netnm: anbob1:anbob, mapid: 3562194217 (kffil) netnm: anbob1:anbob, mapid: 3487906158 (kffil) netnm: anbob1:anbob, mapid: 3230128050 (kffil) netnm: anbob1:anbob, mapid: 3185598356 (kffil) netnm: anbob1:anbob, mapid: 3128598163 (kffil) netnm: anbob1:anbob, mapid: 3080044389 (kffil) netnm: anbob1:anbob, mapid: 3078043616 (kffil) netnm: anbob1:anbob, mapid: 3044289890 (kffil) netnm: anbob1:anbob, mapid: 2866698183 (kffil) netnm: anbob1:anbob, mapid: 2764660939 (kffil) netnm: anbob1:anbob, mapid: 2603804616 (kffil) netnm: anbob1:anbob, mapid: 2412295670 (kffil) netnm: anbob1:anbob, mapid: 2367686953 (kffil) netnm: anbob1:anbob, mapid: 2358398223 (kffil) netnm: anbob1:anbob, mapid: 2358377032 (kffil) netnm: anbob1:anbob, mapid: 1469824483 (kffil) netnm: anbob1:anbob, mapid: 1029941947 (kffil) netnm: anbob1:anbob, mapid: 501493211 (kffil) netnm: anbob1:anbob, mapid: 501288479 (kffil) netnm: anbob1:anbob, mapid: 104836 (kffil) netnm: anbob1:anbob, mapid: 89301 (kffil) netnm: anbob1:anbob, mapid: 49316 (kffil) netnm: anbob1:anbob, mapid: 47922 (kffil) netnm: anbob1:anbob, mapid: 1067 (kffil) netnm: anbob1:anbob, mapid: 1066 (kffil) netnm: anbob1:anbob, mapid: 1065 (kffil) netnm: anbob1:anbob, mapid: 1064 (kffil) netnm: anbob1:anbob, mapid: 1062 (kffil) netnm: anbob1:anbob, mapid: 1061 ... ... (kffil) netnm: anbob1:anbob, mapid: 8 (kffil) netnm: anbob1:anbob, mapid: 7 (kffil) netnm: anbob1:anbob, mapid: 6 (kffil) netnm: anbob1:anbob, mapid: 5 (kffil) netnm: anbob1:anbob, mapid: 4 (kffil) netnm: anbob1:anbob, mapid: 3 (kffil) netnm: anbob1:anbob, mapid: 2 2020-05-22 04:16:18.656726 :C88A066C:db_trace:kfns.c@5385:kfnsFillMapMsg(): [10491:27:838] MAP_LOAD: gn=2 fn=1147, mapid=-5 start=0 cnt=60 2020-05-22 04:16:18.657439 :C88A06CD:db_trace:kfns.c@5310:kfnsFillMapMsg(): [10491:27:838] MAP_ALLOCATE: gn=2 fn=1135, mapid=-4 size=4480 2020-05-22 04:16:18.658157 :C88A079C:db_trace:kfns.c@5385:kfnsFillMapMsg(): [10491:27:838] MAP_LOAD: gn=2 fn=1135, mapid=-4 start=0 cnt=60 2020-05-22 04:16:18.658236 :C88A07BF:db_trace:kfns.c@5385:kfnsFillMapMsg(): [10491:27:838] MAP_LOAD: gn=2 fn=1147, mapid=-5 start=60 cnt=4420 [oracle@Xanbob1:/home/oracle> ---------------------------------------- SO: 0x7000001417a46a0, type: 4, owner: 0x7000001421bb628, flag: INIT/-/-/0x00 if: 0x3 c: 0x3 proc=0x7000001421bb628, name=session, file=ksu.h LINE:12624 ID:, pg=0 (session) sid: 838 ser: 19 trans: 0x0, creator: 0x7000001421bb628 flags: (0x41) USR/- flags_idl: (0x1) BSY/-/-/-/-/- flags2: (0x9) -/-/INC DID: , short-term DID: txn branch: 0x0 oct: 0, prv: 0, sql: 0x0, psql: 0x0, user: 0/SYS ksuxds FALSE at location: 0 service name: SYS$USERS client details: O/S info: user: oracle, term: , ospid: 40373526 machine: Xanbob1 program: oracle@Xanbob1 (TNS V1-V3) application name: oracle@Xanbob1 (TNS V1-V3), hash value=2834275364 Current Wait Stack: 1: waiting for 'ASM file metadata operation' msgop=0x19, locn=0x2, =0x0 wait_id=3031433093 seq_num=59721 snap_id=1 wait times: snap=3.413248 sec, exc=3.413248 sec, total=3.413248 sec wait times: max=infinite, heur=3.413248 sec wait counts: calls=0 os=0 in_wait=1 iflags=0x520 ---------------------------------------- SO: 0x70000012919e930, type: 130, owner: 0x7000001417a46a0, flag: INIT/-/-/0x00 if: 0x3 c: 0x3 proc=0x7000001421bb628, name=ASM db client, file=kfn2.h LINE:1353 ID:, pg=0 (kfncl) netnm: anbob1:anbob, proc: 0x7000001421bb628, serial: 10 state: 0x1 type: 257 compat: 11020003 version: 11020003 hbeat: 1590092178 (3) asmb: ---------------------------------------- SO: 0x70000012a41f510, type: 125, owner: 0x70000012919e930, flag: INIT/-/-/0x00 if: 0x3 c: 0x3 proc=0x7000001421bb628, name=KFG state obj, file=kfg2.h LINE:1178 ID:, pg=0 (kfgso) flags: 00000000 clt: 4 err: 0 hint: 29193b70 (kfgpn) rpi: 23 itrn:0 gst:0 usrp:0 busy: 0 rep: 0 grp: 0 check: 0/0 glink: 70000012a41f5d0 70000012a41f5d0 ---------------------------------------- SO: 0x700000129193b70, type: 126, owner: 0x70000012a41f510, flag: INIT/-/-/0x00 if: 0x3 c: 0x3 proc=0x7000001421bb628, name=KFG SO child, file=kfg2.h LINE:1181 ID:, pg=0 (kfgsc) pwr: 0 flag: 0 op: 0 recur: 0 (kfgpn) rpi: 3891 itrn:0 gst:0 usrp:0 ---------------------------------------- SO: 0x7000001177b8c30, type: 132, owner: 0x700000129193b70, flag: INIT/-/-/0x00 if: 0x3 c: 0x3 proc=0x7000001421bb628, name=ASM file, file=kff2.h LINE:855 ID:, pg=0 (kffil) netnm: anbob1:anbob, mapid: 4294967295 gnum: 2.1165624170, fnum: 1135.963253681, flgs: 0x182 family: 0.0, parent: 0.0 opennm: +DATADG/rzwb_redo12 openflags: 0x80000000 fullnm: +datadg/rzwb_redo12 redun: 0x11, fdflg: 0x0, blksiz: 512, fsiz: 9172993 ftype: 3, extsz: [4294967295,0,0] extents: 4480, start: 60, count: 4420, xp: 0x0 base: 2754, lxcnt: 1 enq: 0x70000013b03deb0, cod: 0x0 unlock[0].au: 0, unlock[0].disk: 0, unlock[0].flags 0x0 SQL> @dec 4294967295 DEC HEX ----------------------------------- -------------------- 4294967295.000000 FFFFFFFF
Note:
We can find the “MAPID” has reached the maximum value.
The mapid I think is a sequence number mapped to ASM FILE id in each process, and the same as the file handle number called in the program.Due to a bug, a larger span of the serial number jumps. Search in MOS, hit Bug 16357438.
对不起,这篇文章暂时关闭评论。