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.askmac.cn [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]
Comment