Consider Reverse Key Index

Well this post was inspired by seeing some reverse index in our environment to avoid contention (May be tested with small set of data and might not have observed issues), which was pretty good but as we know this has very ugly side effects. Most of us know about it but this is just an reminder to myself and use reverse key indexes with extreme caution otherwise can lead to wild wild west.

So, as mention earlier there are few very nasty side effects of reverse key index and let’s start with some test. 1st performance test case with select queries based on reverse index, oh by the way i am not going to mention that reverse key index can’t be used with range predicates as we know.

Let’s start by creating a test table from dba_objects


create table REV_TEST parallel 4 tablespace soe as
select rownum id,x.owner,x.object_name,x.object_id,x.object_type,x.created
from dba_objects x ,(select rownum from dual connect by level <=100) y;

create unique index IX_REV_TEST on REV_TEST(ID) ;
exec dbms_Stats.gather_table_stats(null,'REV_TEST',cascade=>true,degree=>4);

declare
name rev_test.object_name%type;
begin
for i in 50000..60000 loop
select object_name into name from REV_TEST where id=i;
end loop;
end;
/

Now With first test case without reverse index, here are the details for that for loop with first showing size, leaf blocks and clustering factor


Non Reverse

SEGMENT_NAME                 MB     BLOCKS
-------------------- ---------- ----------
IX_REV_TEST                1472     188416
REV_TEST              5634.4375     721208

CLUSTERING_FACTOR
-----------------
           900381

   LF_BLKS   PCT_USED
---------- ----------
    182577         90

Before Any Query

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute  10001      0.51       0.56          0          0          0           0
Fetch    10001      0.14       0.12        113      40004          0       10001
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total    20003      0.66       0.69        113      40004          0       10001

Rows (1st) Rows (avg) Rows (max)  Row Source Operation
---------- ---------- ----------  ---------------------------------------------------
         1          1          1  TABLE ACCESS BY INDEX ROWID REV_TEST (cr=4 pr=4 pw=0 time=1808 us cost=3 size=31 card=1)
         1          1          1   INDEX UNIQUE SCAN IX_REV_TEST (cr=3 pr=3 pw=0 time=1323 us cost=2 size=0 card=1)(object id 109599)

Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  Disk file operations I/O                        2        0.00          0.00
  db file sequential read                       113        0.00          0.

As, you can see that we did approximately same amount of IO to get that equality key. Now, let’s drop this table and recreate same data but using reverse key index.


SEGMENT_NAME                 MB     BLOCKS
-------------------- ---------- ----------
IX_REV_TEST                1472     188416
REV_TEST              5634.4375     721208

CLUSTERING_FACTOR
-----------------
         83834113

   LF_BLKS   PCT_USED
---------- ----------
    182716         90

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute  10001      0.04       0.58          0          0          0           0
Fetch    10001      2.49       4.72      10342      40004          0       10001
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total    20003      2.54       5.31      10342      40004          0       10001

Rows (1st) Rows (avg) Rows (max)  Row Source Operation
---------- ---------- ----------  ---------------------------------------------------
         1          1          1  TABLE ACCESS BY INDEX ROWID REV_TEST (cr=4 pr=4 pw=0 time=3668 us cost=3 size=31 card=1)
         1          1          1   INDEX UNIQUE SCAN IX_REV_TEST (cr=3 pr=3 pw=0 time=3171 us cost=2 size=0 card=1)(object id 109598)

Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  db file sequential read                     10342        0.01          4.13

As, you can see from above output you’r clustering factor went to the roof, and now all your key are scattered all over the place and you have to do more IO’s to get that same work done and if this grows beyond your cache imagine what would happen, you’r cache will constantly flush in flush out blocks and even good blocks.

This is one case what about insert performance, because all we did this to avoid right hand tree contention reduction. While doing this let’s see what we have introduced here. First without reverse key


insert into rev_test select 82221812+rownum id,x.owner,x.object_name,x.object_id,x.object_type,x.created
    from dba_objects x

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.01       0.02          0          0          0           0
Execute      1      0.47       0.52       1622       5355      13497       91156
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        2      0.49       0.54       1622       5355      13497       91156

Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  db file sequential read                       100        0.00          0.04
  db file scattered read                          1        0.00          0.00
  direct path read                                6        0.00          0.01
  SQL*Net message to client                       1        0.00          0.00
  SQL*Net message from client                     1        7.43          7.43

SEGMENT I/O WAIT SUMMARY
~~~~~~~~~~~~~~~~~~~~~~~~
                                                                 Wait   Times    Average        Max          Average
 #      Obj  Type  Segment Name(1)         Event Name         Time(2)  Waited  Wait Time  Wait Time  Blocks   Blocks
--- ------- ------ ---------------- ------------------------ -------- ------- ---------- ---------- ------- --------
 1:  109593 TABLE  TARAL.REV_TEST   db file sequential read     0.032      72   0.000441   0.002966      72        1
 2:      18 TABLE  SYS.OBJ$         direct path read            0.011       6   0.001901   0.006582      87     14.5

As, you can see we have inserted about 91k rows and our top io wait just not that bad, let’s see if we have reverse key index


insert into rev_test select 82312968+rownum id,x.owner,x.object_name,x.object_id,x.object_type,x.created
	from dba_objects x 

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.01       0.02          0          0          0           0
Execute      1      4.76      12.94      27508       4778     282675       91156
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        2      4.78      12.97      27508       4778     282675       91156

Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  db file sequential read                     25986        0.05          9.99
  db file scattered read                          1        0.00          0.00
  direct path read                                6        0.00          0.00
  log file switch completion                      1        0.01          0.01
  SQL*Net message to client                       1        0.00          0.00
  SQL*Net message from client                     1        3.02          3.02

SEGMENT I/O WAIT SUMMARY
~~~~~~~~~~~~~~~~~~~~~~~~
                                                                   Wait   Times    Average        Max          Average
 #      Obj  Type   Segment Name(1)          Event Name         Time(2)  Waited  Wait Time  Wait Time  Blocks   Blocks
--- ------- ------ ------------------ ------------------------ -------- ------- ---------- ---------- ------- --------
 1:  109603 INDEX  TARAL.IX_REV_TEST  db file sequential read     9.966   25917   0.000385   0.053896   25917        1
 2:  109593 TABLE  TARAL.REV_TEST     db file sequential read     0.023      59   0.000385   0.001039      59        1

Now we have introduced much bigger problem with this. So, next time if you think of reverse key index consider all this issues. If anyone have anything more to say or can provide more information then i will be happy to include it

Oracle 12c TABLE ACCESS BY INDEX ROWID BATCHED


Few days back exploring 12c DB on my small VM found this little new feature. Here is the output from 11gR2

SQL_ID 3a936zyv7jupf, child number 0
-------------------------------------
SELECT w.WAREHOUSE_NAME, w.LOCATION_ID, i.PRODUCT_ID,i.QUANTITY_ON_HAND
 FROM WAREHOUSES w, INVENTORIES i WHERE i.PRODUCT_ID IN (10,5,1)
 AND w.WAREHOUSE_ID = i.WAREHOUSE_ID

Plan hash value: 2661993828

---------------------------------------------------------------------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows |E-Bytes| Cost (%CPU)| E-Time | A-Rows | A-Time | Buffers | Reads | OMem | 1Mem | Used-Mem |
---------------------------------------------------------------------------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | | | 61 (100)| | 2604 |00:00:00.09 | 40 | 30 | | | |
|* 1 | HASH JOIN | | 1 | 2700 | 105K| 61 (2)| 00:00:01 | 2604 |00:00:00.09 | 40 | 30 | 947K| 947K| 1298K (0)|
| 2 | TABLE ACCESS FULL | WAREHOUSES | 1 | 1000 | 26000 | 2 (0)| 00:00:01 | 1000 |00:00:00.01 | 6 | 6 | | | |
| 3 | INLIST ITERATOR | | 1 | | | | | 2604 |00:00:00.07 | 34 | 24 | | | |
| 4 | TABLE ACCESS BY INDEX ROWID| INVENTORIES | 3 | 2700 | 37800 | 58 (0)| 00:00:01 | 2604 |00:00:00.07 | 34 | 24 | | | |
|* 5 | INDEX RANGE SCAN | INV_PROD_IX | 3 | 2700 | | 8 (0)| 00:00:01 | 2604 |00:00:00.05 | 17 | 10 | | | |
---------------------------------------------------------------------------------------------------------------------------------------------------------------------------

Read more of this post

ON AIX Oracle Process ULSA Memory

It’s been long time i have blogged anything but few days back was researching some issue with my friend and came to know this issue not exactly an issue but a feature which can consume more oracle process memory on AIX due to Large USLA Heap Segment.

Here are the details for oracle process consuming memory while doing nothing


Unit: page
-------------------------------------------------------------------------------
Pid Command Inuse Pin Pgsp Virtual
19071118 oracle 2131887 8832 1264 2133518
...............................................................................
SYSTEM segments Inuse Pin Pgsp Virtual
12619 8784 528 13067
Vsid Esid Type Description PSize Inuse Pin Pgsp Virtual
20002 0 work kernel segment m 617 549 33 645
50005 9ffffffd work shared library sm 2699 0 0 2699
e000e 9ffffffe work shared library sm 37 0 0 37
31cab9b 8fffffff work private load data s 11 0 0 11
...............................................................................
EXCLUSIVE segments Inuse Pin Pgsp Virtual
4401 48 0 4401
Vsid Esid Type Description PSize Inuse Pin Pgsp Virtual
370aff7 11 work text data BSS heap m 125 0 0 125 <--Around 8MB Doing Nothing
380af07 80020014 work USLA heap sm 1873 0 0 1873 <--Around 7.3 MB In USLA
5aa8dd 9001000a work shared library data m 23 0 0 23
2afaa28 f00000002 work process private m 5 3 0 5
3945314 ffffffff work application stack m 4 0 0 4
22da2aa 8001000a work private load data m 1 0 0 1
3bfaf38 fffffffd work application stack m 0 0 0 0
204ae83 fffffff2 work application stack m 0 0 0 0
38caf0b fffffff9 work application stack m 0 0 0 0
21caa9b fffffff8 work application stack m 0 0 0 0
15a492 fffffff4 work application stack m 0 0 0 0
5e3cdd fffffff5 work application stack m 0 0 0 0
1788dfa fffffff3 work application stack m 0 0 0 0
17aadfd fffffffa work application stack m 0 0 0 0
222aea5 fffffff0 work application stack m 0 0 0 0
1c9ad4e fffffffc work application stack m 0 0 0 0

As, you can see oracle process is using around 8MB memory(64k Pages), But interesting thing is second line where it’s using 7 MB of memory and it’s persistence across all process. So, imagine if you have 1000 session’s than this will be  6.8 GB of whooping memory.

Here is the explanation from oracle note

11gR2/Aix – Dedicated Server Processes Have Large Usla Heap Segment Compared To Older Versions (Doc ID 1260095.1)

CAUSE

In 11gR2, the Oracle server process (oracle binary) is linked with an additional linker options:-bexpful and -brtllib.The -bexpfull and -brtllib linker options were added to implement the Oracle hot patching functionality.

In the previous releases of Oracle 11gR1, 10g and 9i, the -bexpful and -brtllib ld options are not used.

USLA heap usage from an “svmon -p of an Oracle server process” would be around 1800 4KB pages (~7MB) and this USLA heap is process private. This is needed for Oracle on-line patching: a new functionality implemented in 11gR2. With this feature, global symbols in the Oracle binary are saved in USLA heap for resolving the new object files in the shared libraries included in a patch.

Oracle has created fix in Bug 10190759
Abstract: PROCESSES CONSUMING ADDITIONAL MEMORY DUE TO ‘USLA HEAP’

Fix Notes:
With this interim patch it is possible to relink oracle by specifying :
make -f ins_rdbms.mk ‘EXP_OPTS=$(EXP_OPTS_OFF)’ ioracle
to remove -bexpfull and -brtllib link options and
make -f ins_rdbms.mk ‘EXP_OPTS=$(EXP_OPTS_ON)’ ioracle
to add them back.

ORA-21500 Bug for 11gR1 Client Using XMLTYPE

Recently one of the user got ORA-21500 and this was due to bug in 11gr1 client. User has 11gr1 client version which connects to 11gr2 DB and this bug is related to securefile handling in 11gr1 client. But, this post it not about going into much deeper details but  just wanted to document what i learned.

CREATE TABLE TARAL.BUG_TEST1(ID NUMBER(38,0) NOT NULL, XCOL1 SYS.XMLTYPE)
 XMLTYPE COLUMN XCOL1 STORE AS SECUREFILE BINARY XML(TABLESPACE USERS ENABLE STORAGE IN ROW CHUNK 8192);

CREATE TABLE TARAL.BUG_TEST2(ID NUMBER(38,0) NOT NULL, XCOL1 SYS.XMLTYPE)
 XMLTYPE COLUMN XCOL1 STORE AS BASICFILE CLOB(TABLESPACE USERS ENABLE STORAGE IN ROW CHUNK 8192);

SQL> select * from bug_test1;
ERROR:
ORA-21500: internal error code, arguments: [%s], [%s], [%s], [%s], [%s], [%s],[%s], [%s]

we are using windows client here,but if you use UNIX then it throws more specific error.

SQL> select * from bug_test1;
Errors in file :
OCI-21500: internal error code, arguments: [qmcxdEvtNextPPP], [], [], [], [], [], [], []
Ð@ø0Ð@ø0Ð@ø0ERROR:
ORA-21500: internal error code, arguments: [%s], [%s], [%s], [%s], [%s], [%s],[%s], [%s]

This indeed tells us it’s an OCI error. But, how to trace this in windows. Well, this is what i learned from this error.


No OCI Trace Generated With 10.2 Oracle Client Using Oracle Data Provider for .Net [ID 1371240.1]

set ORA_CLIENTTRACE_DIR=c:\temp
set EVENT_10842=server=all;user=all;stmt=all;level=15

The following levels are supported:
1 - Trace all server attach and server detach calls for servers listed in "server" attribute of the environment variable.
2 - Trace all session begin, logon, session end, logoff calls for the users listed in "user" attribute of the environment variable.
3 - Trace all prepare, execute, fetch calls for the specified statement types listed in "stmt" attribute of environment variable.
4 - Trace all Bind, Define, Describe calls.
5 - Trace all OCI LOB calls
7 - Get statistical info on all connection pooling /connection related calls
8 - Get statistical info on all session info
9 - Get statistical info on all handle info
10 - Get statistical info on time taken in execute and fetch calls
11 - Get statistical info on transaction related calls
15 - Trace all calls with statistical info.

trcsess

This is a short note about trcsess. Basically used to combine multiple trace files into one using different criteria.


trcsess [output=<output file name >] [session=<session ID>] [clientid=<clientid>] [service=<service name>] [action=<action name>] [module=<module name>] <trace file names>

output=<output file name> output destination default being standard output.
session=<session Id> session to be traced.
Session id is a combination of session Index & session serial number e.g. 8.13.
clientid=<clientid> clientid to be traced.
service=<service name> service to be traced.
action=<action name> action to be traced.
module=<module name> module to be traced.
<trace_file_names> Space separated list of trace files with wild card '*' supported.

So, it clearly says that it can support separated list of trace file, but what if you want to combine using multiple service or action etc. I got one situation yesterday that some calls from application are coming from one service and that call end using some other service. Without combining this two trace file it was not possible to get whole picture. For example


*** 2012-07-17 17:07:30.379
*** SESSION ID:(XXX.XXXXX) 2012-07-17 17:07:30.379
*** CLIENT ID:() 2012-07-17 17:07:30.379
*** SERVICE NAME:(DATA_SERVICE) 2012-07-17 17:07:30.379
*** MODULE NAME:(YYYYY.exe) 2012-07-17 17:07:30.379
*** ACTION NAME:() 2012-07-17 17:07:30.379

*** 2012-07-17 16:33:07.734
*** SESSION ID:(XXX.XXXXX) 2012-07-17 16:33:07.734
*** CLIENT ID:() 2012-07-17 16:33:07.734
*** SERVICE NAME:(WEB_SERVICE) 2012-07-17 16:33:07.734
*** MODULE NAME:(ZZZZZ.exe) 2012-07-17 16:33:07.734
*** ACTION NAME:() 2012-07-17 16:33:07.734

I don’t know if there is some other way but what i did was

sed -i ‘s/ACTION NAME:()/ACTION NAME:(TARAL)/g’ *.trc

Then combine using action


*** 2012-07-17 17:07:30.379
*** SESSION ID:(XXX.XXXXX) 2012-07-17 17:07:30.379
*** CLIENT ID:() 2012-07-17 17:07:30.379
*** SERVICE NAME:(DATA_SERVICE) 2012-07-17 17:07:30.379
*** MODULE NAME:(YYYYY.exe) 2012-07-17 17:07:30.379
*** ACTION NAME:(TARAL) 2012-07-17 17:07:30.379

*** 2012-07-17 16:33:07.734
*** SESSION ID:(XXX.XXXXX) 2012-07-17 16:33:07.734
*** CLIENT ID:() 2012-07-17 16:33:07.734
*** SERVICE NAME:(WEB_SERVICE) 2012-07-17 16:33:07.734
*** MODULE NAME:(ZZZZZ.exe) 2012-07-17 16:33:07.734
*** ACTION NAME:(TARAL) 2012-07-17 16:33:07.734

ORA-00600 [kksgaGetNoAlloc_Int0]

We received this error for Interval/List partition. Here is the sample test case


drop table part_test purge;
CREATE TABLE PART_TEST (
 ID NUMBER,ST_CODE VARCHAR2(1),ST_DESC VARCHAR2(4000),
 CR_DATE date, INFO VARCHAR2(200)
 ) partition by range(ID) interval(1)
 SUBPARTITION BY LIST(ST_CODE)
 SUBPARTITION TEMPLATE
 (SUBPARTITION ST_CODE_a VALUES ('A'),
 SUBPARTITION ST_CODE_s VALUES ('S'),
 SUBPARTITION ST_CODE_v VALUES ('V'),
 SUBPARTITION ST_CODE_e VALUES ('E'),
 SUBPARTITION ST_CODE_oth VALUES (DEFAULT))
 (partition ID_1 values less than (111000));

TARAL.ORALINUX>select * from part_test where id=321000 and st_code='A';
select * from part_test where id=321000 and st_code='A'
 *
ERROR at line 1:
ORA-00600: internal error code, arguments: [kksgaGetNoAlloc_Int0], [1050005], [1048575], [], [], [], [], [], [], [], [], []

Now getting into details found that 1048575 number in that error is nothing but MAX number of allowed partitions in oracle. By the way test was done in 11.2.0.3. So, when we start partition with 111000 and add any partition it should consider one 1 list and 5 sub-partition. But, it’s considering a lot’s more and actually it’s a BUG. It calculate holes in that partition and not the  actual partitions. Here is little more details about that first argument in that error.


TARAL.ORALINUX>select ((321000-111000)*5)+5 from dual;

((321000-111000)*5)+5
---------------------
 1050005

So, it’s calculated partition value and which exceeds partition limit. That means it won’t track lowest created partition.

</pre>
TARAL.ORALINUX>select (1048570/5) + 111000 from dual;

(1048570/5)+111000
------------------
 320714

1 row selected.

TARAL.ORALINUX>select * from part_test where id=320714 and st_code='A';
select * from part_test where id=320714 and st_code='A'
 *
ERROR at line 1:
ORA-00600: internal error code, arguments: [kksgaGetNoAlloc_Int0], [1048575], [1048575], [], [], [], [], [], [], [], [], []

TARAL.ORALINUX>select * from part_test where id=320713 and st_code='A';

no rows selected
<pre>

By the way this is coming from CURSOR compilation itself i believe but not sure.  And here is the BUG

Bug 13722697  ORA-600 [kksgaGetNoAlloc_Int0] on select against composite interval partitioned table

Futex Spinning on CPU

Lately we had issue with SQL running for long and after investigating found that it was just hanging/spinning on CPU. Even there was no system stats that were increasing


    SID USERNAME    STATE   EVENT                                          SEQ# SEC_IN_STATE SQL_ID         CHN P1                        P2                        P3
------- ----------  ------- ---------------------------------------- ---------- ------------ ------------- ---- ------------------------- ------------------------- -----------------------
   1281 XXXXXXXXXXX WORKING On CPU / runqueue                             50039        12284 xxxxxxxxxxxxx    0 file#= 283                block#= 1702095           id#= 33554433
   1281 XXXXXXXXXXX WORKING On CPU / runqueue                             50039        12287 xxxxxxxxxxxxx    0 file#= 283                block#= 1702095           id#= 33554433
   1281 XXXXXXXXXXX WORKING On CPU / runqueue                             50039        12288 xxxxxxxxxxxxx    0 file#= 283                block#= 1702095           id#= 33554433
   1281 XXXXXXXXXXX WORKING On CPU / runqueue                             50039        12289 xxxxxxxxxxxxx    0 file#= 283                block#= 1702095           id#= 33554433
   1281 XXXXXXXXXXX WORKING On CPU / runqueue                             50039        12290 xxxxxxxxxxxxx    0 file#= 283                block#= 1702095           id#= 33554433
   1281 XXXXXXXXXXX WORKING On CPU / runqueue                             50039        12291 xxxxxxxxxxxxx    0 file#= 283                block#= 1702095           id#= 33554433
   1281 XXXXXXXXXXX WORKING On CPU / runqueue                             50039        12291 xxxxxxxxxxxxx    0 file#= 283                block#= 1702095           id#= 33554433
   1281 XXXXXXXXXXX WORKING On CPU / runqueue                             50039        12292 xxxxxxxxxxxxx    0 file#= 283                block#= 1702095           id#= 33554433
   1281 XXXXXXXXXXX WORKING On CPU / runqueue                             50039        12293 xxxxxxxxxxxxx    0 file#= 283                block#= 1702095           id#= 33554433

----------------------------------------------------------------------------------------------------------------------
    SID, USERNAME  , TYPE, STATISTIC                               ,         DELTA, HDELTA/SEC,    %TIME, GRAPH
----------------------------------------------------------------------------------------------------------------------
     -1,           , ENQG, AE - Edition Lock                       ,             3,         .3,
     -1,           , ENQG, CF - Controlfile Transaction            ,            20,          2,
     -1,           , ENQG, CO - KTUCLO Master Slave enq            ,             3,         .3,
     -1,           , ENQG, DD - ASM Local Disk Group               ,             4,         .4,
     -1,           , ENQG, JD - Job Queue Date                     ,             2,         .2,
     -1,           , ENQG, JS - Job Scheduler                      ,           316,       31.6,
     -1,           , ENQG, MR - Media Recovery                     ,             4,         .4,
     -1,           , ENQG, PS - PX Process Reservation             ,             9,         .9,
     -1,           , ENQG, SE - Session Migration                  ,             3,         .3,
     -1,           , ENQG, TM - DML                                ,            51,        5.1,
     -1,           , ENQG, TX - Transaction                        ,            13,        1.3,
     -1,           , ENQG, XR - Quiesce / Force Logging            ,             3,         .3,
     -1,           , LATG, post/wait queue                         ,            27,        2.7,
     -1,           , LATG, test excl. parent l0                    ,             2,         .2,
     -1,           , LATG, test excl. parent2 l0                   ,             2,         .2,
     -1,           , LATG, process allocation                      ,            59,        5.9,
     -1,           , LATG, session allocation                      ,            78,        7.8,
     -1,           , LATG, session switching                       ,             3,         .3,
     -1,           , LATG, process group creation                  ,             9,         .9,
     -1,           , LATG, session idle bit                        ,           141,       14.1,
     -1,           , LATG, client/application info                 ,            44,        4.4,
     -1,           , LATG, longop free list parent                 ,             2,         .2,
     -1,           , LATG, ksuosstats global area                  ,             1,         .1,
     -1,           , LATG, ksim membership request latch           ,             6,         .6,
     -1,           , LATG, kss move lock                           ,             2,         .2,
     -1,           , LATG, parameter table management              ,            15,        1.5,
     -1,           , LATG, messages                                ,           481,       48.1,
     -1,           , LATG, enqueues                                ,           713,       71.3,
     -1,           , LATG, enqueue hash chains                     ,           986,       98.6,
     -1,           , LATG, FOB s.o list latch                      ,             8,         .8,
     -1,           , LATG, ksfv messages                           ,             2,         .2,
     -1,           , LATG, msg queue latch                         ,             2,         .2,
     -1,           , LATG, done queue latch                        ,             2,         .2,
     -1,           , LATG, session queue latch                     ,             2,         .2,
     -1,           , LATG, resmgr:free threads list                ,            15,        1.5,
     -1,           , LATG, resmgr group change latch               ,             8,         .8,
     -1,           , LATG, channel handle pool latch               ,            11,        1.1,
     -1,           , LATG, channel operations parent latch         ,          1493,      149.3,
     -1,           , LATG, message pool operations parent latch    ,            30,          3,
     -1,           , LATG, ksv class latch                         ,            14,        1.4,
     -1,           , LATG, ksv msg queue latch                     ,             2,         .2,
     -1,           , LATG, ksv allocation latch                    ,             1,         .1,
     -1,           , LATG, second spare latch                      ,             2,         .2,
     -1,           , LATG, third spare latch                       ,             2,         .2,
     -1,           , LATG, fifth spare latch                       ,             2,         .2,
     -1,           , LATG, ksxp shared latch                       ,             9,         .9,
     -1,           , LATG, IPC stats buffer allocation latch       ,            59,        5.9,
     -1,           , LATG, granule operation                       ,             2,         .2,
     -1,           , LATG, active service list                     ,           104,       10.4,
     -1,           , LATG, OS process allocation                   ,            13,        1.3,
     -1,           , LATG, OS process                              ,            20,          2,
     -1,           , LATG, OS process: request allocation          ,             9,         .9,
     -1,           , LATG, ksz_so allocation latch                 ,             9,         .9,
     -1,           , LATG, ges process table freelist              ,             9,         .9,
     -1,           , LATG, ges process parent latch                ,           787,       78.7,
     -1,           , LATG, ges process hash list                   ,          1847,      184.7,
     -1,           , LATG, ges resource table freelist             ,            43,        4.3,
     -1,           , LATG, ges caches resource lists               ,           260,         26,
     -1,           , LATG, ges resource hash list                  ,           644,       64.4,
     -1,           , LATG, ges resource scan list                  ,             2,         .2,
     -1,           , LATG, ges enqueue table freelist              ,           393,       39.3,
     -1,           , LATG, ges timeout list                        ,             4,         .4,
     -1,           , LATG, KJC message pool free list              ,            24,        2.4,
     -1,           , LATG, KJCT flow control latch                 ,           362,       36.2,
     -1,           , LATG, ges domain table                        ,           379,       37.9,
     -1,           , LATG, ges group table                         ,           571,       57.1,
     -1,           , LATG, gcs resource hash                       ,           246,       24.6,
     -1,           , LATG, gcs opaque info freelist                ,            44,        4.4,
     -1,           , LATG, gcs resource freelist                   ,            20,          2,
     -1,           , LATG, gcs resource scan list                  ,             2,         .2,
     -1,           , LATG, gcs shadows freelist                    ,             8,         .8,
     -1,           , LATG, gcs commit scn state                    ,             2,         .2,
     -1,           , LATG, name-service request queue              ,           104,       10.4,
     -1,           , LATG, name-service pending queue              ,             4,         .4,
     -1,           , LATG, name-service namespace bucket           ,            63,        6.3,
     -1,           , LATG, name-service memory objects             ,            20,          2,
     -1,           , LATG, gcs partitioned table hash              ,         24776,      2.48k,
     -1,           , LATG, gcs pcm hashed value bucket hash        ,             2,         .2,
     -1,           , LATG, recovery domain hash list               ,             2,         .2,
     -1,           , LATG, ges value block free list               ,             2,         .2,
     -1,           , LATG, Testing                                 ,             2,         .2,
     -1,           , LATG, heartbeat check                         ,             5,         .5,
     -1,           , LATG, KMG MMAN ready and startup request latch,             4,         .4,
     -1,           , LATG, Memory Management Latch                 ,             6,         .6,
     -1,           , LATG, mostly latch-free SCN                   ,            20,          2,
     -1,           , LATG, lgwr LWN SCN                            ,            20,          2,
     -1,           , LATG, Consistent RBA                          ,            19,        1.9,
     -1,           , LATG, cache buffers lru chain                 ,           688,       68.8,
     -1,           , LATG, buffer pool                             ,             2,         .2,
     -1,           , LATG, active checkpoint queue latch           ,            24,        2.4,
     -1,           , LATG, checkpoint queue latch                  ,          1202,      120.2,
     -1,           , LATG, cache buffers chains                    ,          2012,      201.2,
     -1,           , LATG, cache buffer handles                    ,             8,         .8,
     -1,           , LATG, multiblock read objects                 ,            54,        5.4,
     -1,           , LATG, tablespace key chain                    ,            11,        1.1,
     -1,           , LATG, simulator lru latch                     ,            29,        2.9,
     -1,           , LATG, simulator hash latch                    ,            29,        2.9,
     -1,           , LATG, sim partition latch                     ,             2,         .2,
     -1,           , LATG, object queue header operation           ,          1998,      199.8,
     -1,           , LATG, object queue header heap                ,           291,       29.1,
     -1,           , LATG, archive control                         ,             1,         .1,
     -1,           , LATG, archive process latch                   ,             3,         .3,
     -1,           , LATG, redo writing                            ,            87,        8.7,
     -1,           , LATG, redo copy                               ,           149,       14.9,
     -1,           , LATG, redo allocation                         ,           208,       20.8,
     -1,           , LATG, gc element                              ,           582,       58.2,
     -1,           , LATG, logminer work area                      ,             2,         .2,
     -1,           , LATG, logminer context allocation             ,             2,         .2,
     -1,           , LATG, logical standby cache                   ,             2,         .2,
     -1,           , LATG, mapped buffers lru chain                ,             2,         .2,
     -1,           , LATG, lock DBA buffer during media recovery   ,             2,         .2,
     -1,           , LATG, flashback copy                          ,             2,         .2,
     -1,           , LATG, cvmap freelist lock                     ,             2,         .2,
     -1,           , LATG, io pool granule metadata list           ,             2,         .2,
     -1,           , LATG, dml lock allocation                     ,             1,         .1,
     -1,           , LATG, DML lock allocation                     ,           104,       10.4,
     -1,           , LATG, list of block allocation                ,             9,         .9,
     -1,           , LATG, transaction allocation                  ,            11,        1.1,
     -1,           , LATG, dummy allocation                        ,            17,        1.7,
     -1,           , LATG, transaction branch allocation           ,             8,         .8,
     -1,           , LATG, commit callback allocation              ,             4,         .4,
     -1,           , LATG, undo global data                        ,            46,        4.6,
     -1,           , LATG, corrupted undo seg lock                 ,             3,         .3,
     -1,           , LATG, MinActiveScn Latch                      ,           127,       12.7,
     -1,           , LATG, intra txn parallel recovery             ,             2,         .2,
     -1,           , LATG, In memory undo latch                    ,             2,         .2,
     -1,           , LATG, KTF sga latch                           ,             2,         .2,
     -1,           , LATG, Change Notification Hash table latch    ,             3,         .3,
     -1,           , LATG, change notification client cache latch  ,             2,         .2,
     -1,           , LATG, sort extent pool                        ,             1,         .1,
     -1,           , LATG, lob segment hash table latch            ,             2,         .2,
     -1,           , LATG, lob segment query latch                 ,             2,         .2,
     -1,           , LATG, lob segment dispenser latch             ,             2,         .2,
     -1,           , LATG, space background task latch             ,            13,        1.3,
     -1,           , LATG, sequence cache                          ,             9,         .9,
     -1,           , LATG, File State Object Pool Parent Latch     ,             2,         .2,
     -1,           , LATG, Write State Object Pool Parent Latch    ,             2,         .2,
     -1,           , LATG, deferred cleanup latch                  ,             1,         .1,
     -1,           , LATG, kdlx hb parent latch                    ,             2,         .2,
     -1,           , LATG, Locator state objects pool parent latch ,             2,         .2,
     -1,           , LATG, row cache objects                       ,           435,       43.5,
     -1,           , LATG, kks stats                               ,             2,         .2,
     -1,           , LATG, global KZLD latch for mem in SGA        ,             3,         .3,
     -1,           , LATG, user lock                               ,            18,        1.8,
     -1,           , LATG, global ctx hash table latch             ,            13,        1.3,
     -1,           , LATG, global tx hash mapping                  ,             2,         .2,
     -1,           , LATG, k2q lock allocation                     ,             2,         .2,
     -1,           , LATG, k2q global data latch                   ,             6,         .6,
     -1,           , LATG, shared pool                             ,           455,       45.5,
     -1,           , LATG, Token Manager                           ,             2,         .2,
     -1,           , LATG, cas latch                               ,             2,         .2,
     -1,           , LATG, rm cas latch                            ,             2,         .2,
     -1,           , LATG, resmgr:actses change state              ,             2,         .2,
     -1,           , LATG, resmgr:actses change group              ,             8,         .8,
     -1,           , LATG, resmgr:session queuing                  ,             2,         .2,
     -1,           , LATG, resmgr:active threads                   ,            15,        1.5,
     -1,           , LATG, resmgr:plan CPU method                  ,             2,         .2,
     -1,           , LATG, resmgr:resource group CPU method        ,             2,         .2,
     -1,           , LATG, QMT                                     ,             2,         .2,
     -1,           , LATG, shared pool simulator                   ,             2,         .2,
     -1,           , LATG, shared pool sim alloc                   ,             2,         .2,
     -1,           , LATG, Streams Generic                         ,             2,         .2,
     -1,           , LATG, Shared B-Tree                           ,             5,         .5,
     -1,           , LATG, Memory Queue                            ,             2,         .2,
     -1,           , LATG, Memory Queue Subscriber                 ,             2,         .2,
     -1,           , LATG, Memory Queue Message Subscriber #1      ,             2,         .2,
     -1,           , LATG, Memory Queue Message Subscriber #2      ,             2,         .2,
     -1,           , LATG, Memory Queue Message Subscriber #3      ,             2,         .2,
     -1,           , LATG, Memory Queue Message Subscriber #4      ,             2,         .2,
     -1,           , LATG, pesom_hash_node                         ,             2,         .2,
     -1,           , LATG, pesom_free_list                         ,             2,         .2,
     -1,           , LATG, peshm                                   ,             2,         .2,
     -1,           , LATG, Mutex                                   ,             2,         .2,
     -1,           , LATG, Mutex Stats                             ,             2,         .2,
     -1,           , LATG, KGNFS-NFS:SHM structure                 ,             2,         .2,
     -1,           , LATG, KGNFS-NFS:SVR LIST                      ,             2,         .2,
     -1,           , LATG, SGA heap locks                          ,             2,         .2,
     -1,           , LATG, SGA pool locks                          ,             2,         .2,
     -1,           , LATG, SGA bucket locks                        ,             2,         .2,
     -1,           , LATG, SGA blob parent                         ,             2,         .2,
     -1,           , LATG, kgb parent                              ,             2,         .2,
     -1,           , LATG, Event Group Locks                       ,             5,         .5,
     -1,           , LATG, session timer                           ,             8,         .8,
     -1,           , LATG, parameter list                          ,            97,        9.7,
     -1,           , LATG, virtual circuit buffers                 ,             2,         .2,
     -1,           , LATG, virtual circuit queues                  ,             2,         .2,
     -1,           , LATG, virtual circuit holder                  ,             2,         .2,
     -1,           , LATG, cp server hash latch                    ,             2,         .2,
     -1,           , LATG, cp pool latch                           ,             2,         .2,
     -1,           , LATG, cp cmon/server latch                    ,             2,         .2,
     -1,           , LATG, cp sga latch                            ,             1,         .1,
     -1,           , LATG, job_queue_processes parameter latch     ,             2,         .2,
     -1,           , LATG, job workq parent latch                  ,             2,         .2,
     -1,           , LATG, query server freelists                  ,            15,        1.5,
     -1,           , LATG, error message lists                     ,             5,         .5,
     -1,           , LATG, process queue                           ,            19,        1.9,
     -1,           , LATG, process queue reference                 ,           568,       56.8,
     -1,           , LATG, parallel query stats                    ,             8,         .8,
     -1,           , LATG, business card                           ,             4,         .4,
     -1,           , LATG, parallel query alloc buffer             ,            38,        3.8,
     -1,           , LATG, SQL memory manager latch                ,             3,         .3,
     -1,           , LATG, SQL memory manager workarea list latch  ,           215,       21.5,
     -1,           , LATG, compile environment latch               ,             6,         .6,
     -1,           , LATG, kokc descriptor allocation latch        ,             8,         .8,
     -1,           , LATG, ncodef allocation latch                 ,             1,         .1,
     -1,           , LATG, session state list latch                ,             6,         .6,
     -1,           , LATG, KWQS pqueue ctx latch                   ,             1,         .1,
     -1,           , LATG, KWQS pqsubs latch                       ,             1,         .1,
     -1,           , LATG, kwqbsn:qsga                             ,             1,         .1,
     -1,           , LATG, qmn task queue latch                    ,             4,         .4,
     -1,           , LATG, KWQMN job cache list latch              ,             3,         .3,
     -1,           , LATG, XDB unused session pool                 ,             2,         .2,
     -1,           , LATG, XDB used session pool                   ,             2,         .2,
     -1,           , LATG, XDB NFS Security Latch                  ,             2,         .2,
     -1,           , LATG, KFC Hash Latch                          ,             2,         .2,
     -1,           , LATG, KFC FX Hash Latch                       ,             2,         .2,
     -1,           , LATG, ASM map operation hash table            ,           186,       18.6,
     -1,           , LATG, ASM network background latch            ,             4,         .4,
     -1,           , LATG, ASM db client latch                     ,             6,         .6,
     -1,           , LATG, KFR redo allocation latch               ,             2,         .2,
     -1,           , LATG, KFCL LE Freelist                        ,             2,         .2,
     -1,           , LATG, JS broadcast add buf latch              ,             2,         .2,
     -1,           , LATG, JS broadcast drop buf latch             ,             2,         .2,
     -1,           , LATG, JS broadcast load blnc latch            ,             2,         .2,
     -1,           , LATG, JS slv state obj latch                  ,             2,         .2,
     -1,           , LATG, JS queue state obj latch                ,           312,       31.2,
     -1,           , LATG, JS queue access latch                   ,             2,         .2,
     -1,           , LATG, JS Sh mem access                        ,             4,         .4,
     -1,           , LATG, PL/SQL warning settings                 ,             9,         .9,
--  End of snap 1, end=2012-04-02 21:37:13, seconds=10

 CH# PARENT_HANDLE    OBJECT_HANDLE     PLAN_HASH     PARSES   H_PARSES EXECUTIONS    FETCHES ROWS_PROCESSED     CPU_MS     ELA_MS       LIOS       PIOS      SORTS USERS_EXECUTING
---- ---------------- ---------------- ---------- ---------- ---------- ---------- ---------- -------------- ---------- ---------- ---------- ---------- ---------- ---------------
   0 000000041CE5D250 000000041CE5D100 1758161767          1          1          0          0              0 154999.436 297611.236    8382945     707682          1               1

<-ksedsts()+315<-ksdxfstk()+32<-ksdxcb()+1764<-sspuser()+112<-__restore_rt()<-__lll_lock_wait_private()+30<-_L_lock_1685()+19<-ksmskgmctx_()<-00007FFF36F46508
<-ksedsts()+315<-ksdxfstk()+32<-ksdxcb()+1764<-sspuser()+112<-__restore_rt()<-__lll_lock_wait_private()+30<-_L_lock_1685()+19<-ksmskgmctx_()<-00007FFF36F46508
<-ksedsts()+315<-ksdxfstk()+32<-ksdxcb()+1764<-sspuser()+112<-__restore_rt()<-__lll_lock_wait_private()+30<-_L_lock_1685()+19<-ksmskgmctx_()<-00007FFF36F46508
<-ksedsts()+315<-ksdxfstk()+32<-ksdxcb()+1764<-sspuser()+112<-__restore_rt()<-__lll_lock_wait_private()+30<-_L_lock_1685()+19<-ksmskgmctx_()<-00007FFF36F46508
<-ksedsts()+315<-ksdxfstk()+32<-ksdxcb()+1764<-sspuser()+112<-__restore_rt()<-__lll_lock_wait_private()+30<-_L_lock_1685()+19<-ksmskgmctx_()<-00007FFF36F46508
<-ksedsts()+315<-ksdxfstk()+32<-ksdxcb()+1764<-sspuser()+112<-__restore_rt()<-__lll_lock_wait_private()+30<-_L_lock_1685()+19<-ksmskgmctx_()<-00007FFF36F46508
<-ksedsts()+315<-ksdxfstk()+32<-ksdxcb()+1764<-sspuser()+112<-__restore_rt()<-__lll_lock_wait_private()+30<-_L_lock_1685()+19<-ksmskgmctx_()<-00007FFF36F46508
<-ksedsts()+315<-ksdxfstk()+32<-ksdxcb()+1764<-sspuser()+112<-__restore_rt()<-__lll_lock_wait_private()+30<-_L_lock_1685()+19<-ksmskgmctx_()<-00007FFF36F46508
<-ksedsts()+315<-ksdxfstk()+32<-ksdxcb()+1764<-sspuser()+112<-__restore_rt()<-__lll_lock_wait_private()+30<-_L_lock_1685()+19<-ksmskgmctx_()<-00007FFF36F46508
<-ksedsts()+315<-ksdxfstk()+32<-ksdxcb()+1764<-sspuser()+112<-__restore_rt()<-__lll_lock_wait_private()+30<-_L_lock_1685()+19<-ksmskgmctx_()<-00007FFF36F46508

futex(0x3596554594, FUTEX_WAIT_PRIVATE, 2, NULL

#0  0x00000035962e027e in __lll_lock_wait_private () from /lib64/libc.so.6
#1  0x000000359628d56d in _L_lock_1685 () from /lib64/libc.so.6
#2  0x000000359628d2b7 in __tz_convert () from /lib64/libc.so.6
#3  0x0000000001db392a in sldxgd ()
#4  0x000000000339ddfd in nldatxtmil ()
#5  0x000000000339dd20 in nldatxt ()
#6  0x00000000076c6135 in nstimexp ()
#7  0x00000000064c1bca in ltmdvp ()
#8  0x00000000064c1ae3 in ltmdrv ()
#9  0x00000000064a6fc0 in sltmdf ()
#10 0x0000000006496325 in sslsstehdlr ()
#11 0x00000000064957e9 in sslsshandler ()
#12 <signal handler called>
#13 0x000000359628d88f in __tzfile_compute () from /lib64/libc.so.6
#14 0x000000359628d2ef in __tz_convert () from /lib64/libc.so.6
#15 0x0000000007ccdbb2 in sLdiGetDate ()
#16 0x00000000019104b7 in psdsts ()
#17 0x0000000002b0ffe4 in pessts ()
#18 0x0000000007dd6fae in pevm_icd_call_common ()
#19 0x0000000007dce9c3 in pfrinstr_BCAL ()
#20 0x0000000007dcdc3f in pfrrun_no_tool ()
#21 0x0000000002a276e7 in pfrrun ()
#22 0x0000000002a38c7d in plsql_run ()
#23 0x0000000002a1ebc4 in peicnt ()
#24 0x0000000002a1ea0d in peiet_execute_trigger ()
#25 0x00000000023f8080 in kkxtexe ()
#26 0x00000000019437dc in kxtExecuteTriggerRecursive ()
#27 0x0000000007c1267a in rpiswu2 ()
#28 0x0000000001942f66 in kxtExecuteTriggerReal ()
#29 0x0000000001942d3f in kxtexe ()
#30 0x0000000001cc468e in qesltcExecuteBeforeRowTriggers ()
#31 0x0000000007cacc8b in qesltcBeforeRowProcessing ()
#32 0x0000000007c8c9a3 in __PGOSF606_qerltcKdtBufferedInsRowCBK ()
#33 0x0000000007c8c47e in qerltcLoadStateMachine ()
#34 0x0000000007c8bf9d in __PGOSF596_qerltcInsertSelectRop ()
#35 0x0000000001c8d868 in qerghFetch ()
#36 0x0000000007afa0a9 in rwsfcd ()
#37 0x0000000007c8a447 in qerltcFetch ()
#38 0x0000000007bd5a1d in insexe ()
#39 0x0000000007c9bfe7 in opiexe ()
#40 0x0000000001cd1dc5 in kpoal8 ()
#41 0x0000000007b4e0d4 in opiodr ()
#42 0x0000000007d0ea8b in ttcpip ()
#43 0x000000000106800d in opitsk ()
#44 0x000000000106aa2a in opiino ()
#45 0x0000000007b4e0d4 in opiodr ()
#46 0x0000000001063d6c in opidrv ()
#47 0x000000000177d4c2 in sou2o ()
#48 0x0000000000975603 in opimai_real ()
#49 0x0000000001782a79 in ssthrdmain ()
#50 0x000000000097552f in main ()

This is from metalink.

Bug 6918493 – Net DCD (sqlnet.expire_time>0) can cause OS level mutex hang, possible to get PMON failed to acquired latch

Using Net dead connection detection (DCD) by setting SQLNET.EXPIRE_TIME > 0 in the SQLNET.ORA file can cause an OS level mutex hang under nsexptim -> … -> localtime_r .. and possibly under other substacks under nsexptim . The hang is very intermittent in nature as it depends on a specific timing scenario.

If the hung process is holding a critical resource, such as a latch, then this can lead to a wider hang scenario.

Rediscovery Notes:
Dead Connection Detection is enabled (SQLNET.EXPIRE_TIME > 0 )
The stack includes nsexptim and is likely to include
localtime_tz_r or localtime_r
The top of the stack shows the session blocked on an
OS mutex. (eg: In __lll_mutex_lock_wait on Linux, or in a
futex call)
If the hung process holds a latch, or other critical
resource, then PMON may give a clue in its tracefile.

Workaround:
Disable DCD and configure OS level keepalive instead.
eg: Set SQLNET.EXPIRE_TIME=0 in the SQLNET.ORA file
and configure TCP keepalive to the required timeouts
at OS level (exact parameters and steps vary between
platforms as TCP keepalive is an OS level configuration)