Know more about Oracle Latches

Two purposes of latches were:Serialize Execution,Serialize Access Match the characteristics with latches and enqueues.

Several modes of access                   Enqueue
FIFO queue acquisition                    Enqueue
Mostly exclusive access                   Latch
Non-deterministic acquisition             Latch
No atomicity                              Enqueue
Atomicity                                 Latch

Most latches have a level between 0 and 8. Usually a process can request a latch X only:After obtaining latch Y and if level X > level Y. Remember that the level of X, which is child latch, must be greater than level Y, which is most likely a parent latch. The structure for parent and child latches can be seen by querying X$KSLLT . There is one KSLLT structure for each parent and child latch in an instance. The characteristic of latch acquisition in NO-WAIT mode is: One attempt to get a latch, no spin or sleep . This is typically for latches where there are many of the same type. The process will attempt to acquire another latch. The sleep time on latches approximately doubles with each wait until upper limit is reached. This is an exponential backoff. The statistic waiters_woken counts the number of times a posting for a latch has occurred. It can be found in V$LATCH.This view contains aggregate statistics for latches PMON invokes a clean up function for releasing latches if the holding process dies.PMON will initiate the clean up function. _MAX_SLEEP_HOLDING_LATCH The maximum exponential backoff when waiting for a latch and already holding anothers _MAX_EXPONENTIAL_SLEEP Controls the maximum time a process has to sleep before requesting the latch again _SPIN_COUNT Designates the number of times a process will spin while trying to acquire a latchs V$SESSION_WAIT dynamic performance view gives real time information regarding what sessions are currently waiting or have just waited for an event. When diagnosing latch contention, we should typically look for Latches with the most impact. We should use below formula  to calculate the total cost of latch spinning: _spin_count * sleeps/misses Statistics from V$LATCH with their associated description: IMMEDIATE_MISSES Number of times the fast get failed when requested in "no-wait" mode MISSES Number of times the fast get call failed when requested in "willing-to-wait" modes SPIN_GETS Number of times where the fast get failed but the latch was acquired during the first spin before having to yield to the CPU GETS Number of times the latch was obtained when requested in "willing-to-wait" mode SLEEPi Number of times a "willing-to-wait" request had to sleep I times IMMEDIATE_GETS Number of times the latch was obtained when requested in "no-wait" mode We can set event 10005 to perform latch tracing, or oradebug dump latches 3 ;

SQL> select * from v$version;

BANNER
----------------------------------------------------------------
Oracle Database 10g Enterprise Edition Release 10.2.0.4.0 - 64bi
PL/SQL Release 10.2.0.4.0 - Production
CORE    10.2.0.4.0      Production
TNS for Linux: Version 10.2.0.4.0 - Production
NLSRTL Version 10.2.0.4.0 - Production

SQL> select * from global_name;

GLOBAL_NAME
--------------------------------------------------------------------------------
www.oracledatabase12g.com

[oracle@rh2 ~]$ oerr ora 10005
10005, 00000, "trace latch operations for debugging"
// *Document: NO
// *Cause:
// *Action: Enable tracing for various latch operations
// *Comment:
//    level 1 - trace latch gets and frees
//    level 4 - trace multiple posts by processes when latch is freed
//

Wait and latch (KSL) layer (10005)

We can set events 10005 (trace latch gets and frees) and 10073 (have PMON
dump info before latch cleanup).  Level does not matter for these events.
We can also set event="600 trace name LATCHES level 1" to dump latch info
when PMON hits the error (I'm not so sure this one is going to work).

 event = "600 trace name latches level 10"
 event = "10005 trace name context forever, level 1"

10005 event has been removed above 9i , try dump KSTDUMPCURPROC 1

SQL> oradebug setmypid;
SQL> oradebug unlimit;
SQL> oradebug dump KSTDUMPCURPROC 1
SQL> oradebug tracefile_name;

KSTDUMP: In-memory trace dump
TIME(usecs):SEQ# ORAPID   SID EVENT  OP DATA
========================================================================
D9396B13:000044F8    14     0 10005   1 KSL WAIT BEG [PX Idle Wait] 200/0xc8 146/0x92 0/0x0
D9573C3D:00004568    14     0 10005   2 KSL WAIT END [PX Idle Wait] 200/0xc8 146/0x92 0/0x0 time=1954087
D9573C4F:00004569    14     0 10005   1 KSL WAIT BEG [PX Idle Wait] 200/0xc8 147/0x93 0/0x0
D9750D82:000045FC    14     0 10005   2 KSL WAIT END [PX Idle Wait] 200/0xc8 147/0x93 0/0x0 time=1954097
D9750D8F:000045FD    14     0 10005   1 KSL WAIT BEG [PX Idle Wait] 200/0xc8 148/0x94 0/0x0
D992DEA2:00004639    14     0 10005   2 KSL WAIT END [PX Idle Wait] 200/0xc8 148/0x94 0/0x0 time=1954065
D992DEB2:0000463A    14     0 10005   1 KSL WAIT BEG [PX Idle Wait] 200/0xc8 149/0x95 0/0x0
D9B0AFD8:000046A9    14     0 10005   2 KSL WAIT END [PX Idle Wait] 200/0xc8 149/0x95 0/0x0 time=1954084
D9B0AFEB:000046AA    14     0 10005   1 KSL WAIT BEG [PX Idle Wait] 200/0xc8 150/0x96 0/0x0
D9CE8110:00004742    14     0 10005   2 KSL WAIT END [PX Idle Wait] 200/0xc8 150/0x96 0/0x0 time=1954083
D9CE811E:00004743    14     0 10005   1 KSL WAIT BEG [PX Idle Wait] 200/0xc8 151/0x97 0/0x0
D9EC5246:00004790    14     0 10005   2 KSL WAIT END [PX Idle Wait] 200/0xc8 151/0x97 0/0x0 time=1954086
D9ECA80D:00004792    14     0 10280   8 kst: process state object about to be deleted
E308018E:00006780    14     0 10280   1 kst: process state object created on 06-30 22:11:24.211
E308018F:00006781    14     0 10280   3 kst: process info: ospid=10380 pso_num=14 pso_serial#=2
E30801D0:00006782    14     0 10420   1 kso: new process: pid=10380 (legacy spawn)
E4ACF279:00006D4A    14     0 10280   8 kst: process state object about to be deleted
E4B2CD42:00006D4B    14     0 10280   1 kst: process state object created on 06-30 22:11:52.853
E4B2CD43:00006D4C    14     0 10280   3 kst: process info: ospid=10382 pso_num=14 pso_serial#=3
E4B2CDA3:00006D4D    14     0 10420   1 kso: new process: pid=10382 (legacy spawn)
KSTDUMP: End of in-memory trace dump


**** LGWR trace
05A46022:0000DEB0     6   221 10254  73 KSBCTI: (LGWR) : (timeout action)   : acnum=[58] comment=[Redo writer log switch operations]
05A46025:0000DEB1     6   221 10254  73 KSBCTI: (LGWR) : (timeout action)   : acnum=[59] comment=[Redo writer generate offline immed marker]
05A46026:0000DEB2     6   221 10254  73 KSBCTI: (LGWR) : (timeout action)   : acnum=[170] comment=[kfr Poke LGWR]
05A46027:0000DEB3     6   221 10254  73 KSBCTI: (LGWR) : (timeout action)   : acnum=[171] comment=[kfr Incr Ckpt]
05A46029:0000DEB4     6   221 10254  73 KSBCTI: (LGWR) : (timeout action)   : acnum=[172] comment=[kfr ACD relocation]
05A4602A:0000DEB5     6   221 10254  71 KSBCTI: (LGWR) : (interrupt action) : acnum=[1] comment=[KSB action for X-instance calls]
05A4602A:0000DEB6     6   221 10254  71 KSBCTI: (LGWR) : (interrupt action) : acnum=[63] comment=[Scumnt mount lock]
05A4602B:0000DEB7     6   221 10254  71 KSBCTI: (LGWR) : (interrupt action) : acnum=[64] comment=[Poll system events broadcast channel]
05A4602E:0000DEB8     6   221 10005   1 KSL WAIT BEG [rdbms ipc message] 300/0x12c 0/0x0 0/0x0
05D117DB:0000DF45     6   221 10005   2 KSL WAIT END [rdbms ipc message] 300/0x12c 0/0x0 0/0x0 time=2930603
05D117E6:0000DF46     6   221 10254  71 KSBCTI: (LGWR) : (interrupt action) : acnum=[1] comment=[KSB action for X-instance calls]
05D117E7:0000DF47     6   221 10254  71 KSBCTI: (LGWR) : (interrupt action) : acnum=[63] comment=[Scumnt mount lock]
05D117E8:0000DF48     6   221 10254  71 KSBCTI: (LGWR) : (interrupt action) : acnum=[64] comment=[Poll system events broadcast channel]
05D117ED:0000DF49     6   221 10254  73 KSBCTI: (LGWR) : (timeout action)   : acnum=[0] comment=[Monitor Cleanup]
05D117EE:0000DF4A     6   221 10254  73 KSBCTI: (LGWR) : (timeout action)   : acnum=[56] comment=[Redo writer IO's]
05D117FE:0000DF4B     6   221 10254  73 KSBCTI: (LGWR) : (timeout action)   : acnum=[57] comment=[Redo writer post action]
05D117FF:0000DF4C     6   221 10254  73 KSBCTI: (LGWR) : (timeout action)   : acnum=[58] comment=[Redo writer log switch operations]
05D11803:0000DF4D     6   221 10254  73 KSBCTI: (LGWR) : (timeout action)   : acnum=[59] comment=[Redo writer generate offline immed marker]
05D11804:0000DF4E     6   221 10254  73 KSBCTI: (LGWR) : (timeout action)   : acnum=[170] comment=[kfr Poke LGWR]
05D11805:0000DF4F     6   221 10254  73 KSBCTI: (LGWR) : (timeout action)   : acnum=[171] comment=[kfr Incr Ckpt]
05D11807:0000DF50     6   221 10254  73 KSBCTI: (LGWR) : (timeout action)   : acnum=[172] comment=[kfr ACD relocation]
05D11808:0000DF51     6   221 10254  71 KSBCTI: (LGWR) : (interrupt action) : acnum=[1] comment=[KSB action for X-instance calls]
05D11808:0000DF52     6   221 10254  71 KSBCTI: (LGWR) : (interrupt action) : acnum=[63] comment=[Scumnt mount lock]
05D11809:0000DF53     6   221 10254  71 KSBCTI: (LGWR) : (interrupt action) : acnum=[64] comment=[Poll system events broadcast channel]
05D1180C:0000DF54     6   221 10005   1 KSL WAIT BEG [rdbms ipc message] 300/0x12c 0/0x0 0/0x0
05FDCFC0:0000DFE1     6   221 10005   2 KSL WAIT END [rdbms ipc message] 300/0x12c 0/0x0 0/0x0 time=2930610
05FDCFCB:0000DFE2     6   221 10254  71 KSBCTI: (LGWR) : (interrupt action) : acnum=[1] comment=[KSB action for X-instance calls]
05FDCFCC:0000DFE3     6   221 10254  71 KSBCTI: (LGWR) : (interrupt action) : acnum=[63] comment=[Scumnt mount lock]
05FDCFCD:0000DFE4     6   221 10254  71 KSBCTI: (LGWR) : (interrupt action) : acnum=[64] comment=[Poll system events broadcast channel]
05FDCFD1:0000DFE5     6   221 10254  73 KSBCTI: (LGWR) : (timeout action)   : acnum=[0] comment=[Monitor Cleanup]
05FDCFD2:0000DFE6     6   221 10254  73 KSBCTI: (LGWR) : (timeout action)   : acnum=[56] comment=[Redo writer IO's]
05FDCFEF:0000DFE7     6   221 10254  73 KSBCTI: (LGWR) : (timeout action)   : acnum=[57] comment=[Redo writer post action]
05FDCFF0:0000DFE8     6   221 10254  73 KSBCTI: (LGWR) : (timeout action)   : acnum=[58] comment=[Redo writer log switch operations]
05FDCFF3:0000DFE9     6   221 10254  73 KSBCTI: (LGWR) : (timeout action)   : acnum=[59] comment=[Redo writer generate offline immed marker]
05FDCFF4:0000DFEA     6   221 10254  73 KSBCTI: (LGWR) : (timeout action)   : acnum=[170] comment=[kfr Poke LGWR]
05FDCFF5:0000DFEB     6   221 10254  73 KSBCTI: (LGWR) : (timeout action)   : acnum=[171] comment=[kfr Incr Ckpt]
05FDCFF7:0000DFEC     6   221 10254  73 KSBCTI: (LGWR) : (timeout action)   : acnum=[172] comment=[kfr ACD relocation]