Bug 2974637: MANY ORA-600[KKSSCL-INF-INL-LOOP] OCCUR AND CAN NOT CREATE NEW CONNECTION

Hdr: 2974637 9.2.0.3 RDBMS 9.2.0.3 PRODID-5 PORTID-59 ORA-600
Abstract: MANY ORA-600[KKSSCL-INF-INL-LOOP] OCCUR AND CAN NOT CREATE NEW CONNECTION

*** 05/22/03 11:03 pm ***
TAR:
----

PROBLEM:
--------
1. Clear description of the problem encountered:

A lot of ORA-600[kksscl-inf-inl-loop] error occurred.
And no new connections can not be established.

2. Pertinent configuration information (MTS/OPS/distributed/etc)
n/a

3. Indication of the frequency and predictability of the problem

After my customer kills the process(OraclePID:88/OSPID=25256),
ORA-600 error didn't occur. And it became to be able to create
a new connection.
This problem does not occur after it.

4. Sequence of events leading to the problem
n/a

DIAGNOSTIC ANALYSIS:
--------------------
1. About the process which occurred ORA-600[kksscl-inf-inl-loop].

I paid my attention to one process.(OraclePID:197/OSPID=5616)
In systemstate at 2003-05-20 17:36:19 <fmc93_01_ora_7202.trc>
this process has a wait event as below:

waiting for 'library cache load lock' blocking sess=0x0
seq=4061 wait_time=0 object address=c00000002cbd1298,
lock address=c000000026275728, 100*mask+namespace=65

In systemstate at 2003-05-20 17:41:25 <fmc93_01_ora_7202.trc>
this process has a wait event as below:

waiting for 'kksfbc child completion' blocking sess=0x0
seq=6300 wait_time=0  =0, =0, =0

In systemstate at 2003-05-20 17:46:37 <fmc93_01_ora_7202.trc>
this process has a wait event as below:

last wait for 'null event' blocking sess=0x0 seq=6646
wait_time=19469 =0, =0, =0

In alert.log<alert.trail> this process occurred ORA-600.
So I think wait event of 'kksfbc child completion' is just
before ORA-600 error.

Tue May 20 17:41:33 2003
Errors in file /Oracle_fmc93/admin/udump/fmc93_01_ora_5616.trc:
ORA-600[kksscl-inf-inl-loop],[2500],[0],[1],[3],[3],[],[]

2. About the process (OraclePID:88/OSPID=25256)

By looking at all systemstate dump during error occurrence,
the process (OraclePID:88/OSPID=25256) keeps waiting for same
library cache pin.

waiting for 'library cache pin' blocking sess=0x0 seq=153 wait_time=0
handle address=c00000002bb671e8, pin address=c00000002b882268,
100*mode+namespace=c8 <- mode=S

This process has LIBRARY OBJECT PIN in mode=S.
Thus it seems self-deadlock.

SO: c00000002b882268, type: 52, owner: c000000024816bd0, flag:
INIT/-/-/0x00
LIBRARY OBJECT PIN: pin=c00000002b882268 handle=c00000002bb671e8
mode=S lock=c00000002c037d98
user=c00000002478ac90 session=c000000024816bd0 count=0 mask=0000
savepoint=10944 flags=[00]

This process is not active from result of tusc.<25256.log>

( Attached to process 25256 ("oracleFMC93_01 (LOCAL=NO)") [64-bit] )
[25256] semop(184349, 0x800003ffc0003a28, 1) ............. [sleeping]
sem[0].sem_num: 92
sem[0].sem_op: -1
sem[0].sem_flg: 0

This process of errorstack<fmc93_01_ora_25256.trc> is as below:

ksedmp ksdxfdmp ksdxcb sspuser sigreturn semop_sys
kslwait ksfwat kglpnal kglpin kkslce kkschkcsr ...

The handle address of c00000002bb671e8 appears several times
in systemstates.

process197( which occurres ORA-600 error )

LIBRARY OBJECT: object=c00000002c86c4b8
type=CRSR flags=EXS[0001] pflags= [00] status=VALD load=0
CHILDREN: size=16
child#    table reference   handle
------ -------- --------- --------
0 c00000002c86c6f0 c00000002b3329d0 c00000002bb671e8 <--
DATA BLOCKS:
data#     heap  pointer status pins change
----- -------- -------- ------ ---- ------
0 c00000002be205e8 c00000002c86c5b0 I/P/A     0 NONE

After my customer executes 'kill -9' for this process,
ORA-600 does not occur any more. And it becomes to be able
to create new connection.

During this operation, took some systemstate.
before kill 2003-05-20 22:47:31<fmc93_01_ora_10318.trc>
after  kill 2003-05-20 22:48:45<fmc93_01_ora_10318.trc>
after  kill 2003-05-20 22:55:19<fmc93_01_ora_10408.trc>

WORKAROUND:
-----------
n/a

RELATED BUGS:
-------------
n/a

REPRODUCIBILITY:
----------------
n/a

TEST CASE:
----------
n/a

STACK TRACE:
------------
(OraclePID:88/OSPID=25256)
ksedmp ksdxfdmp ksdxcb sspuser sigreturn semop_sys
kslwait ksfwat kglpnal kglpin kkslce kkschkcsr
kksscl kksfbc kkspsc0 opiosq0 opiosq opiodr
rpidrus skgmstack rpidru rpiswu2 rpidrv rpisplu
rpispl kqllod kglobld kglobpn kglpim kglpin
kglgob kkdlgob qcsfgob qcsprfro qcspafq qcspqb
kkmdrv opiSem opiprs kksald rpiswu2 kkslod
kglobld kglobpn kglpim kglpin kksfbc kkspsc0
opiosq0 kpooprx kpoal8 opiodr ttcpip opitsk
opiino opiodr opidrv sou2o main $START$

SUPPORTING INFORMATION:
-----------------------

24 HOUR CONTACT INFORMATION FOR P1 BUGS:
----------------------------------------
n/a

DIAL-IN INFORMATION:
--------------------
n/a

IMPACT DATE:
------------
n/a

*** 05/22/03 11:11 pm ***
*** 05/22/03 11:14 pm *** 
*** 05/23/03 12:41 am *** (CHG: Sta->10)
*** 05/23/03 12:41 am ***
*** 05/27/03 08:41 am *** (CHG: Sta->16)
*** 05/27/03 08:41 am ***
*** 05/27/03 08:54 pm *** (CHG: Sta->11 Asg->NEW OWNER)
*** 05/27/03 08:54 pm ***
*** 05/27/03 09:46 pm *** 
*** 05/27/03 09:46 pm ***
*** 05/28/03 01:34 am *** 
*** 05/28/03 01:34 am *** 
*** 05/28/03 01:34 am ***
*** 05/28/03 08:51 am ***
*** 05/28/03 09:52 am ***
*** 05/28/03 10:15 am *** (CHG: Sta->30)
*** 05/28/03 10:19 pm *** (CHG: Sta->11)
*** 05/28/03 10:19 pm ***
*** 05/28/03 11:18 pm *** (CHG: Sta->30)
*** 05/28/03 11:18 pm ***
*** 05/29/03 01:18 am ***
*** 06/02/03 12:31 am *** (CHG: Sta->11)
*** 06/02/03 12:31 am ***
*** 06/02/03 01:28 am ***
*** 06/02/03 02:06 am ***
*** 06/03/03 06:50 am *** 
*** 06/03/03 06:50 am ***
*** 06/03/03 07:45 pm *** 
*** 06/03/03 07:45 pm ***
*** 06/04/03 02:39 am *** 
*** 06/05/03 06:09 am ***
*** 06/05/03 06:17 am *** (CHG: Sta->30)
*** 06/05/03 06:17 am ***
*** 07/02/03 06:27 am *** (CHG: Sta->33)
*** 07/02/03 06:27 am ***