ENQ: JI – CONTENTION ORACLE

ENQ: JI – CONTENTION ORACLE

Definition:

Lock held during materialized view operations (like refresh, alter) to prevent concurrent
operations on the same materialized view

This form of enqueue is used to serialise the refresh in a materialised view lock.
During a refresh, locks are only applied on the MVIEW base table, ensuring that all other sessions are queued.

ENQ : JI – contention

This enqueue is intended to ensure that two or more snapshot processes do not attempt to refresh the same item when a snapshot process intends to perform an aggregate join view (AJV) refresh.

AWR and ASH analysis:

kish@x3z6zx9<^>!oerr ora 10704
10704, 00000, "Print out information about what enqueues are being obtained"
// *Cause:  When enabled, prints out arguments to calls to ksqcmi and
//          ksqlrl and the return values.
// *Action: Level indicates details:
//   Level: 1-4: print out basic info for ksqlrl, ksqcmi
//          5-9: also print out stuff in callbacks:  ksqlac, ksqlop
//          10+: also print out time for each line

Enable enqueue trace to identify the JI activity

After tracing the refresh, JI enqueue is observed in lock mode 6 with the object id

*** 2022-06-05 11:58:44.942
ksqgtl *** JI-00015a30-00000000 mode=6 flags=0x10001 timeout=5 *** <<== Hold lock
ksqgtl: no transaction
ksqgtl: use existing ksusetxn DID
ksqgtl:
        ksqlkdid: 0001-001C-00000015 

*** 2022-06-05 11:58:44.985
ksqrcl: JI,15a30,0           <<== Release the lock
ksqrcl: returns 0

By converting hexadecimal to decimal value, the object id of the enq is identified

ENQ type: JI

OBJECT ID IN HEXADECIMAL : 00015a30-00000000

Lock mode=6 (exclusive)

kish@x3z6zx9<^>select object_name from dba_objects where object_id=88624;

OBJECT_NAME
--------------------------------------------------------------------------------------------------------------------------------
MVSAL

These waits can be observed in v$session_wait

old   1: select &vswc
new   1: select case when state = 'ON CPU' THEN 'BURN_CPU' when state = 'WAITING' THEN 'LONG_WAIT' when state = 'WAITED SHORT TIME' THEN 'SHORT_WAIT' else 'KNOWN_WAIT' end as state,event,count(*) as counter
old   2:   from &vswv
new   2:   from v$session_wait
old   3:   &vswh
new   3:   where wait_class <> 'Idle'
old   4:   &vswg
new   4:   group by state,event
old   5:   &vswo
new   5:   order by counter desc

STATE      EVENT                                                                                                       COUNTER
---------- ---------------------------------------------------------------- --------------------------------------------------
SHORT_WAIT SQL*Net message to client                                                                                         1
LONG_WAIT  enq: JI - contention                       <<==                                                       1
SHORT_WAIT cell single block physical read                                                                                   1

Session 151 is blocked by 14 in enq: JI – contention. Here either session 14 has to complete the job or it needs to be killed to release the JI lock from MVIEW base table

set lines 200 pages 1000
col TIME for a18
col SID for 9999
col "WHO_BLOCK_WHO" for a20
col W_CHAINS for a60
col EVENT for a25
col WHO for a7
col PROGRAM for a7
col username for a7
def acol="ash.session_id as sid,to_char(ash.sample_time,'dd-mm-yy hh24:mi:ss') as TIME,regexp_substr(PROGRAM,'[^@]+') as WHO,regexp_substr(ash.PROGRAM,'\((.*?)\)',1,1,null,1) as PROGRAM"
def ucol="du.username"
def aview="v$active_session_history ash"
def uview="dba_users du"
def aujoin="( ash.user_id = du.user_id )"
def awhere="ash.session_state like '%WAIT%'"
--def astime="to_char(ash.sample_time,'dd-mm-yy hh24:mi:ss') between 14-05-22 20:30:50 and 14-05-22 20:30:59"
def aord="order by to_char(ash.sample_time,'dd-mm-yy hh24:mi:ss')"
select &acol,
       &ucol,
       case when session_state = 'ON CPU' 
	   then 'BURN_CPU' 
	        when session_state = 'WAITING' 
			then 'LONG_WAIT' 
			     when session_state = 'WAITED SHORT TIME' 
				 then 'SHORT_WAIT' 
				 else 'KNOWN_WAIT' 
				 end as state,
       case when ash.BLOCKING_SESSION is NULL 
       then 'NULL'
	        when ash.BLOCKING_SESSION is NOT NULL 
		    then '|'||lag(ash.EVENT) over (order by sample_id)||' [|]<~~~ '||ash.EVENT||'|' 	
       end W_CHAINS,				
       '|'||nvl(to_char(ash.BLOCKING_SESSION),'NULL')||' blocks===> '||ash.SESSION_ID||'|' as "WHO_BLOCK_WHO"
from &aview
full outer join &uview on &aujoin
where &awhere;
   14 05-06-22 14:06:39  sqlplus TNS V1- KISH    LONG_WAIT  NULL                                                         |NULL blocks===> 14|
                                 V3

  151 05-06-22 14:06:40  sqlplus TNS V1- SYS     LONG_WAIT  |cell single block physical read [|]<~~~ enq: JI - contentio |14 blocks===> 151|
                                 V3                         n|

  151 05-06-22 14:06:41  sqlplus TNS V1- SYS     LONG_WAIT  |enq: JI - contention [|]<~~~ enq: JI - contention|          |14 blocks===> 151|
                                 V3

Next identify the objects using ASH

1246298118:n 88990:view <<== p2 column denotes the object id and

set lines 200 pages 1000
col TIME for a18
col SID for 9999
col "WHO_BLOCK_WHO" for a20
col W_CHAINS for a60
col EVENT for a25
col WHO for a7
col PROGRAM for a7
col username for a7
col p1obj for a12
col p2obj for a12
col p3obj for a10
def acol="ash.session_id as sid,to_char(ash.sample_time,'dd-mm-yy hh24:mi:ss') as TIME,''||p1||':'||p1text||'' as p1obj,''||p2||':'||p2text||'' as p2obj,''||p3||':'||p3text||'' as p3obj"
def aview="v$active_session_history ash"
def uview="dba_users du"
def aujoin="( ash.user_id = du.user_id )"
def awhere="ash.session_state like '%WAIT%'"
--def astime="to_char(ash.sample_time,'dd-mm-yy hh24:mi:ss') between 14-05-22 20:30:50 and 14-05-22 20:30:59"
def aord="order by to_char(ash.sample_time,'dd-mm-yy hh24:mi:ss')"
select &acol,
       case when ash.BLOCKING_SESSION is NULL 
       then 'NULL'
	        when ash.BLOCKING_SESSION is NOT NULL 
		    then '|'||lag(ash.EVENT) over (order by sample_id)||' [|]<~~~ '||ash.EVENT||'|' 	
       end W_CHAINS,				
       '|'||nvl(to_char(ash.BLOCKING_SESSION),'NULL')||' blocks===> '||ash.SESSION_ID||'|' as "WHO_BLOCK_WHO"
from &aview
full outer join &uview on &aujoin
where &awhere;
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
   14 05-06-22 14:06:39  1858131412:c 3234425683:d 8192:bytes NULL                                                         |NULL blocks===> 14|
                         ellhash#     iskhash#

  151 05-06-22 14:06:40  1246298118:n 88990:view o 0:0        |cell single block physical read [|]<~~~ enq: JI - contentio |14 blocks===> 151|
                         ame|mode     bject #                 n|

  151 05-06-22 14:06:41  1246298118:n 88990:view o 0:0        |enq: JI - contention [|]<~~~ enq: JI - contention|          |14 blocks===> 151|
                         ame|mode     bject #

The type of lock can be identified by below query

kish@x3z6zx9<^>col type for a5
col lmode for 99999
col description for a30
select l.sid,
       lt.type,
       l.lmode,
           lt.description
       from v$lock_type lt
       inner join v$lock l on lt.type = l.type
where l.lmode=(select bitand(1246298118,65535) "Mode" from dual);kish@x3z6zx9<^>kish@x3z6zx9<^>kish@x3z6zx9<^>  2    3    4    5    6    7

  SID TYPE   LMODE DESCRIPTION
----- ----- ------ ------------------------------
   14 JI         6 Lock held during materialized
                   view operations (like refresh,
                    alter) to prevent concurrent
                   operations on the same materia
                   lized view

    6 RT         6 Thread locks held by LGWR, DBW
                   0, and RVWR to indicate mounte
                   d or open status

kish@x3z6zx9<^>col WAITING_SESSION for 99999999
kish@x3z6zx9<^>col HOLDING_SESSION for 99999999
kish@x3z6zx9<^>col LOCK_TYPE for a10
kish@x3z6zx9<^>col MODE_HELD for a10
kish@x3z6zx9<^>col MODE_REQUESTED for a10
kish@x3z6zx9<^>col LOCK_ID1 for 9999999
kish@x3z6zx9<^>select * from dba_waiters;

WAITING_SESSION HOLDING_SESSION LOCK_TYPE  MODE_HELD  MODE_REQUE LOCK_ID1                                           LOCK_ID2
--------------- --------------- ---------- ---------- ---------- -------- --------------------------------------------------
            151              14 JI         Exclusive  Exclusive     88990                                                  0

To identify the exact stage of where the session is blocked, use oradebug tool

Important points are highlighted with an arrow. Closely eyeball the hang analyzer chain

Even though the first session which is doing its job to complete the work, sometimes this can be misdiagnosed as performance issue with the second job which waits on JI contention.

-------------------------------------------------------------------------------
Chain 1:
-------------------------------------------------------------------------------
    Oracle session identified by:
    {
                instance: 1 (x3z6zx9.x3z6zx9)
                   os id: 16305
              process id: 43, oracle@x3dbzx36 (TNS V1-V3)
              session id: 151
        session serial #: 25
    }
    is waiting for 'enq: JI - contention' with wait info:  <========= 2nd session is blocked
    {
                      p1: 'name|mode'=0x4a490006
                      p2: 'view object #'=0x15b9e
                      p3: '0'=0x0
            time in wait: 2.386072 sec
      heur. time in wait: 1 min 32 sec
           timeout after: 2.613928 sec
                 wait id: 249
                blocking: 0 sessions
             current sql: BEGIN DBMS_MVIEW.REFRESH('KISH.MVSAL','F',PARALLELISM=>6,atomic_refresh=>true); END;
             short stack: ksedsts()+465<-ksdxfstk()+32<-ksdxcb()+1927<-sspuser()+112<-__sighandler()<-semtimedop()+10<-skgpwwait()+160<-ksliwat()+2022<-kslwaitctx()+163<-ksqcmi()+2848<-ksqgtlctx()+3501<-ksqgelctx()+557<-kkzfgenq()+162<-kkzfgenq_ord()+157<-kkzigenq()+449<-spefcmpa()+196<-spefmccallstd()+235<-pextproc()+41<-peftrusted()+150<-psdexsp()+255<-rpiswu2()+1776<-psdextp()+700<-pefccal()+726<-pefcal()+224<-pevm_FCAL()+169<-pfrinstr_FCAL()+75<-pfrrun_no_tool()+63<-pfrrun()+627<-plsql_run()+649<-peicnt()+302<-kkxexe()+525<-opiexe()+18
            wait history:
              * time between current wait and wait #1: 0.000100 sec
              1.       event: 'enq: JI - contention' <===========
                 time waited: 5.011015 sec
                     wait id: 248             p1: 'name|mode'=0x4a490006
                                              p2: 'view object #'=0x15b9e
                                              p3: '0'=0x0
              * time between wait #1 and #2: 0.000049 sec
              2.       event: 'enq: JI - contention'
                 time waited: 5.005329 sec
                     wait id: 247             p1: 'name|mode'=0x4a490006
                                              p2: 'view object #'=0x15b9e
                                              p3: '0'=0x0
              * time between wait #2 and #3: 0.000247 sec
              3.       event: 'enq: JI - contention'
                 time waited: 5.006765 sec
                     wait id: 246             p1: 'name|mode'=0x4a490006
                                              p2: 'view object #'=0x15b9e
                                              p3: '0'=0x0
    }
    and is blocked by
 => Oracle session identified by:
    {
                instance: 1 (x3z6zx9.x3z6zx9)
                   os id: 16269
              process id: 28, oracle@x3dbzx36 (TNS V1-V3)
              session id: 14
        session serial #: 287
    }
    which is not in a wait:
    {
               last wait: 0.000341 sec ago
                blocking: 1 session
             current sql:  delete from "KISH"."MVSAL"  <==============
             short stack: ksedsts()+465<-ksdxfstk()+32<-ksdxcb()+1927<-sspuser()+112<-__sighandler()<-times()+7<-kcbchg1_main()+4187<-kcbchg1()+205<-ktuchg2()+1417<-ktbchg2()+281<-kdimod0()+4144<-kaudelLoadIndexList()+1529<-kaudel()+153<-delrow()+1512<-qerdlFetch()+1774<-qerstFetch()+520<-delexe()+964<-opiexe()+10315<-opiall0()+1276<-opikpr()+524<-opiodr()+917<-rpidrus()+211<-skgmstack()+148<-rpiswu2()+690<-kprball()+1232<-kkzfrc()+1669<-kkzfrsh_execute()+7719<-kkzfrsh()+9022<-kkzifr3g()+1247<-spefcmpa()+874<-spefmccallstd()+235<-pextproc(

Solution:

Kill the first session to release the lock or wait for the session to complete

Check if MVIEW logs are purged and check the size of log with respect to base table

Summary:

  • Multiple jobs cannot access same MVIEW base table during refresh
  • Mainly during fast refresh, there can be hangs if other jobs are accessing the MVIEW base table

Leave a Reply

%d bloggers like this: