Large Incident files with error: kksfbc-new-child-thresh-exceeded

===========================
General
===========================
Large incident files with error kksfbc-new-child-thresh-exceeded are generated under incident/ folder

=========================
Oracle Documentation

=========================

This is a is known bug:
ORA-600 [kksfbc-new-child-thresh-exceeded] Error In 11.1 (Doc ID 1200693.1)

CAUSE
This is most likely caused by unpublished Bug 7626014 fixed in 11.2 and PSU 11.1.0.7.5. 
The error occurs against a heavily used cursor which has multiple children with high concurrency.  
This problem can also cause unnecessary additional child cursors to be created.

SOLUTION
To fix this issue apply one of the following solutions:

Either Upgrade to 11.2.0.1, or

Install Patch 7626014 on top of 11.1.0.7.

Install the 11.1.0.7 PSU #5 or higher like 11.1.0.7 PSU #6 which contain the fix for this defect.

On Windows, install our 11.1.0.7.BP 22 or above - preferably the most recent one.

If this fix does not exist on top of the latest available patchset for your platform, please log a new Service Request and provide evidences that you are encountering this issue and request for an interim patch for your platform.

Note:

This fix alters the method used if a session cannot find an existing child cursor that can be shared. 

With this fix, builds of a new child cursor are serialized.

===========================
Example
===========================

*** 2018-12-23 17:44:55.692

*** SESSION ID:(440.41588) 2018-12-23 17:44:55.692

*** CLIENT ID:() 2018-12-23 17:44:55.692

*** SERVICE NAME:(SYS$USERS) 2018-12-23 17:44:55.692

*** MODULE NAME:(JDBC Thin Client) 2018-12-23 17:44:55.692

*** ACTION NAME:() 2018-12-23 17:44:55.692

Dump continued from file: /software/oracle/diag/rdbms/igt/igt/trace/igt_ora_17188.trc

ORA-00600: internal error code, arguments: [kksfbc-new-child-thresh-exceeded], [], [], [], [], [], [], [], [], [], [], []

========= Dump for incident 212913 (ORA 600 [kksfbc-new-child-thresh-exceeded]) ========

*** 2018-12-23 17:44:55.692

----- Current SQL Statement for this session (sql_id=6ug9rkhbfzgsa) -----

MERGE into SGA_W_PSMS_SUBSCRIBER o using (select :1  MSISDN from dual) o1 on (o.MSISDN = o1.MSISDN) when matched then update set o.IMSI= :2 ,o.CURRENT_COUNTRY= :3 ,o.CURRENT_NETWORK_ID = :4  , o.CURRENT_VLR = :5  ,o.CURRENT_MSC = :6  ,o.TS_FIRST_REGISTRATION = :7  ,o.TS_E_LAST_LU = :8  ,o.IS_ROAMING = :9 , o.CURRENT_SGSN = :10   , o.PREVIOUS_VLR=:11 , o.PREVIOUS_SGSN=:12 , o.TS_E_LAST_CANCEL=:13 ,o.TS_VISIT_START=:14 , o.TS_VISIT_END=:15 , o.TS_LAST_MODIFIED=:16 ,o.MAP_CAMEL_SERVICE_KEY=:17 , o.SCENARIO_HISTORY =:18 , o.RE_ACTIVATION_HISTORY =:19 , o.CAMPAIGN_HISTORY =:20  , o.PREVIOUS_VISIT_END_TIME=:21 ,o.CURRENT_SCENARIO_START_TIME=:22 ,o.SCENARIO_ID=:23 ,o.SPARX_BW_LIST_CHECK_RESULT=:24 ,o.VISIT_ID=:25 , o.LOCATION_GROUP_HISTORY=:26 , o.MVNO_HISTORY=:27 , o.IS_SUBSCRIBER=:28 , o.IS_LTE_USER =:29 ,  o.CURRENT_LTE_MCC_MNC=:30 , o.LTE_CANCELLATION_TYPE=:31 , o.LTE_SUBSCRIBER_STATUS=:32 , o.TS_E_LAST_LU_LTE=:33 , o.TS_E_LAST_CANCEL_LTE=:34 , o.CURRENT_MME=:35 , o.CURRENT_TECHNOLOigt_ora_17188_i212913.trc 

incdir_212889

Dump continued from file: /software/oracle/diag/rdbms/igt/igt/trace/igt_ora_17164.trc

ORA-00600: internal error code, arguments: [kksfbc-new-child-thresh-exceeded], [], [], [], [], [], [], [], [], [], [], []

========= Dump for incident 212889 (ORA 600 [kksfbc-new-child-thresh-exceeded]) ========

*** 2018-12-23 15:54:12.188

----- Current SQL Statement for this session (sql_id=6ug9rkhbfzgsa) -----

MERGE into SGA_W_PSMS_SUBSCRIBER o using (select :1  MSISDN from dual) o1 on (o.MSISDN = o1.MSISDN) when matched then update set o.IMSI= :2 ,o.CURRENT_COUNTRY= :3 ,o.CURRENT_NETWORK_ID = :4  , o.CURRENT_VLR = :5  ,o.CURRENT_MSC = :6  ,o.TS_FIRST_REGISTRATION = :7  ,o.TS_E_LAST_LU = :8  ,o.IS_ROAMING = :9 , o.CURRENT_SGSN = :10   , o.PREVIOUS_VLR=:11 , o.PREVIOUS_SGSN=:12 , o.TS_E_LAST_CANCEL=:13 ,o.TS_VISIT_START=:14 , o.TS_VISIT_END=:15 , o.TS_LAST_MODIFIED=:16 ,o.MAP_CAMEL_SERVICE_KEY=:17 , o.SCENARIO_HISTORY =:18 , o.RE_ACTIVATION_HISTORY =:19 , o.CAMPAIGN_HISTORY =:20  , o.PREVIOUS_VISIT_END_TIME=:21 ,o.CURRENT_SCENARIO_START_TIME=:22 ,o.SCENARIO_ID=:23 ,o.SPARX_BW_LIST_CHECK_RESULT=:24 ,o.VISIT_ID=:25 , o.LOCATION_GROUP_HISTORY=:26 , o.MVNO_HISTORY=:27 , o.IS_SUBSCRIBER=:28 , o.IS_LTE_USER =:29 ,  o.CURRENT_LTE_MCC_MNC=:30 , o.LTE_CANCELLATION_TYPE=:31 , o.LTE_SUBSCRIBER_STATUS=:32 , o.TS_E_LAST_LU_LTE=:33 , o.TS_E_LAST_CANCEL_LTE=:34 , o.CURRENT_MME=:35 , o.CURRENT_TECHNOLOigt_ora_17164_i212889.trc 

===========================

Solution
===========================
As a workaround, I have tried to Flush the Shared pool for the sql_id entries in question

Per some tech-notes, it is possible to flush specific sql_id.

But when running this code, I could not see that the child cursors was flushed.

As they still are present in table V$SQL_BIND_CAPTURE.

As a workaround, I have Flushed Shared Pool, and this has resolved the issue.

SELECT sql_id, count(*) AS child_records
  FROM V$SQL_BIND_CAPTURE
 GROUP BY sql_id
HAVING  count(*) > 400
ORDER BY count(*) DESC;

SQL_ID        CHILD_RECORDS
------------- -------------
6ug9rkhbfzgsa         52584
akh1m5g2waych         13254
7dh0ddg65qpbv          3528
b8ya3z8kq3c6r          2086
adbf1h2dx6m81          1800
7ng34ruy5awxq           880
7y6yta0cajvr5           735
5yv0nj5hwfz5d           725
fwb25vcr3c2wk           688
dwypdxsjg4juq           624
2q93zsrvbdw48           478
6aq34nj2zb2n7           477

SELECT ADDRESS, HASH_VALUE from V$SQLAREA 
WHERE SQL_Id IN ('6ug9rkhbfzgsa','akh1m5g2waych','7dh0ddg65qpbv','b8ya3z8kq3c6r','adbf1h2dx6m81');

ADDRESS          HASH_VALUE
---------------- ----------
0000000257DEEAE0 2614316289
0000000253EC17B0 3428537723
0000000253AE12A8 3318053264
0000000253D3EB30  627159255
0000000257DAF2C0  384810762

BEGIN
  DBMS_SHARED_POOL.PURGE ('0000000257DEEAE0,2614316289','C');
  DBMS_SHARED_POOL.PURGE ('0000000253EC17B0,3428537723','C');
  DBMS_SHARED_POOL.PURGE ('0000000253AE12A8,3318053264','C');
  DBMS_SHARED_POOL.PURGE ('0000000253D3EB30,627159255','C');
  DBMS_SHARED_POOL.PURGE ('0000000257DAF2C0,384810762','C');
END;
/  

SELECT sql_id, count(*) AS child_records
  FROM V$SQL_BIND_CAPTURE
 GROUP BY sql_id
HAVING  count(*) > 400
ORDER BY count(*) DESC;

SQL_ID        CHILD_RECORDS
------------- -------------
6ug9rkhbfzgsa         52584
akh1m5g2waych         13254
7dh0ddg65qpbv          3528
b8ya3z8kq3c6r          2086
adbf1h2dx6m81          1800
7ng34ruy5awxq           880
7y6yta0cajvr5           735
5yv0nj5hwfz5d           725
fwb25vcr3c2wk           688
dwypdxsjg4juq           624
2q93zsrvbdw48           478
6aq34nj2zb2n7           477

Since this did not wirk, I have Flushed the Shared Pool.
Flush Shared Pool has resolved the issue.

ALTER SYSTEM FLUSH SHARED_POOL;

Oracle SCN - System Change Number

==============================
Oracle SCN - System Change Number
==============================
SCN is an internal time stamp used by Oracle Database. 

Oracle Database uses SCNs to mark the SCN before which all changes are known to be on disk so that recovery avoids applying unnecessary redo. 

The database also uses SCNs to mark the point at which no redo exists for a set of data so that recovery can stop.

SCNs occur in a monotonically increasing sequence. 

Oracle Database can use an SCN like a clock because an observed SCN indicates a logical point in time and repeated observations return equal or greater values. 
If one event has a lower SCN than another event, then it occurred at an earlier time with respect to the database.
Several events may share the same SCN, which means that they occurred at the same time with respect to the database.

Every transaction has an SCN. 

For example, if a transaction updates a row, then the database records the SCN at which this update occurred. 

Other modifications in this transaction have the same SCN. 

When a transaction commits, the database records an SCN for this commit.

Oracle Database increments SCNs in the system global area (SGA). 

When a transaction modifies data, the database writes a new SCN to the undo data segment assigned to the transaction. 

The log writer process then writes the commit record of the transaction immediately to the online redo log. 

The commit record has the unique SCN of the transaction. 

Oracle Database also uses SCNs as part of its instance recovery and media recovery mechanisms.

==============================
At commit time
==============================
A system change number (SCN) is generated for the COMMIT.

The internal transaction table for the associated undo tablespace records that the transaction has committed. 
The corresponding unique SCN of the transaction is assigned and recorded in the transaction table. 

The log writer (LGWR) process writes remaining redo log entries in the redo log buffers to the online redo log and writes the transaction SCN to the online redo log. 

This atomic event constitutes the commit of the transaction.

==============================
How to find current SCN
==============================
Option 1.
SELECT CURRENT_SCN FROM V$DATABASE;
294565574

Option 2.

SELECT TIMESTAMP_TO_SCN(SYSDATE) FROM DUAL;
294565581

Option 3.
SELECT DBMS_FLASHBACK.GET_SYSTEM_CHANGE_NUMBER AS SCN FROM DUAL;
ORA-00904: : invalid identifier


oracle@my_server:~>% sqlplus / as sysdba

SQL> GRANT EXECUTE ON DBMS_FLASHBACK to RI_CENTRAL;

Grant succeeded.

sqlplus RI_CENTRAL/RI_CENTRAL@ora_inst
SELECT DBMS_FLASHBACK.get_system_change_number AS SCN FROM DUAL;

       SCN
----------
 294565682

==============================
SCN to Time
==============================
SQL> SELECT SCN_TO_TIMESTAMP(294565682) AS SCN_TIME FROM DUAL;

SCN_TIME
---------------------------------
09-DEC-18 04.34.28.000000000 PM

SQL> SELECT TO_CHAR(SCN_TO_TIMESTAMP(294565682),'YYYYMMDD hh24:mi:ss') AS SCN_TIME FROM DUAL;

SCN_TIME
------------------------------

20181209 16:34:28

==============================
Script to get current SCN

==============================


CURRENT_SCN=`echo -e "set head off term off echo off feed off ver off space 1 linesize 1000\ncol  DBMS_FLASHBACK.GET_SYSTEM_CHANGE_NUMBER() format 999999999999999999999999999999999999999\nselect DBMS_FLASHBACK.GET_SYSTEM_CHANGE_NUMBER() from dual;" | sqlplus -S $MY_USER/$MY_PASS@$MY_CONNECTSTR`


echo CURRENT_SCN is: $CURRENT_SCN