Re: Excessive "latch: row cache objects" waits with simple INSERT statement

Jonathan Lewis schrieb am 02.10.2020 um 14:47:
> Have I said anything yet about creating a logon trigger (on one of
> your schemas) to enable SQL tracing with waits events enabled for
> just the SQL_ID of the critical statement - perhaps with a limited
> lifetime so you only capture a few occurrences of the statement.

I enabled SQL trace for that statement through ALTER SYSTEM and here is a part of the trace file of one of the sessions:

• snip ---------------- *** 2020-10-05 08:00:44.936

  ---

  PARSING IN CURSOR #140112424508552 len=66 dep=0 uid=115 oct=2 lid=115 tim=103070917361722 hv=2215798297 ad='4fff64290' sqlid='dkv2b06214tht' insert into APP_USER.LOOKUP_TABLE (lookup_value) values (:1 ) END OF STMT BINDS #140112424508552: Bind#0 oacdty=01 mxl=128(112) mxlc=00 mal=00 scl=00 pre=00 oacflg=03 fl2=1000010 frm=01 csi=873 siz=128 off=0 kxsbbbfp=7f6e774b7010 bln=128 avl=28 flg=05 value="****************************" EXEC #140112424508552:c=820,e=473,p=0,cr=1,cu=22,mis=0,r=1,dep=0,og=1,plh=0,tim=103070917362179 STAT #140112424508552 id=1 cnt=0 pid=0 pos=1 obj=0 op='LOAD TABLE CONVENTIONAL LOOKUP_TABLE (cr=1 pr=0 pw=0 time=367 us)' WAIT #140112424508552: nam='SQL*Net message to client' ela= 2 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=103070917362338 WAIT #140112424508552: nam='SQL*Net message from client' ela= 1284 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=103070917363640 CLOSE #140112424508552:c=0,e=4,dep=0,type=1,tim=103070917363708

  ---

  PARSING IN CURSOR #140112424494776 len=66 dep=0 uid=115 oct=2 lid=115 tim=103070917822795 hv=2215798297 ad='4fff64290' sqlid='dkv2b06214tht' insert into APP_USER.LOOKUP_TABLE (lookup_value) values (:1 ) END OF STMT BINDS #140112424494776: Bind#0 oacdty=01 mxl=128(112) mxlc=00 mal=00 scl=00 pre=00 oacflg=03 fl2=1000010 frm=01 csi=873 siz=128 off=0 kxsbbbfp=7f6e774b7010 bln=128 avl=28 flg=05 value="****************************" WAIT #140112424494776: nam='latch: row cache objects' ela= 36924 address=21728500976 number=411 tries=0 obj#=-1 tim=103070917859840 WAIT #140112424494776: nam='latch: row cache objects' ela= 8 address=21728500976 number=411 tries=0 obj#=-1 tim=103070917859907 WAIT #140112424494776: nam='latch: row cache objects' ela= 4 address=21728500976 number=411 tries=0 obj#=-1 tim=103070917859930 WAIT #140112424494776: nam='latch: row cache objects' ela= 16 address=21728500976 number=411 tries=0 obj#=-1 tim=103070917859960 EXEC #140112424494776:c=0,e=37922,p=0,cr=1,cu=22,mis=0,r=1,dep=0,og=1,plh=0,tim=103070917860701 STAT #140112424494776 id=1 cnt=0 pid=0 pos=1 obj=0 op='LOAD TABLE CONVENTIONAL LOOKUP_TABLE (cr=1 pr=0 pw=0 time=37814 us)' WAIT #140112424494776: nam='SQL*Net message to client' ela= 2 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=103070917860786 WAIT #140112424494776: nam='SQL*Net message from client' ela= 849 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=103070917861650 CLOSE #140112424494776:c=0,e=7,dep=0,type=1,tim=103070917861696

  ---

  PARSING IN CURSOR #140112424493680 len=66 dep=0 uid=115 oct=2 lid=115 tim=103070918048079 hv=2215798297 ad='4fff64290' sqlid='dkv2b06214tht' insert into APP_USER.LOOKUP_TABLE (lookup_value) values (:1 ) END OF STMT BINDS #140112424493680: Bind#0 oacdty=01 mxl=128(112) mxlc=00 mal=00 scl=00 pre=00 oacflg=03 fl2=1000010 frm=01 csi=873 siz=128 off=0 kxsbbbfp=7f6e774bfed8 bln=128 avl=28 flg=05 value="****************************" EXEC #140112424493680:c=0,e=831,p=0,cr=1,cu=23,mis=0,r=1,dep=0,og=1,plh=0,tim=103070918048885 STAT #140112424493680 id=1 cnt=0 pid=0 pos=1 obj=0 op='LOAD TABLE CONVENTIONAL LOOKUP_TABLE (cr=1 pr=0 pw=0 time=463 us)' WAIT #140112424493680: nam='SQL*Net message to client' ela= 3 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=103070918049187 WAIT #140112424493680: nam='SQL*Net message from client' ela= 2741 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=103070918052062 CLOSE #140112424493680:c=0,e=7,dep=0,type=1,tim=103070918052126
  • snip ----------

Does this mean the inserts aren't actually batched, but multiple single row inserts?

The trace was enabled using:

   alter system set events 'sql_trace[sql: dkv2b06214tht] level=12';

Thomas

--
http://www.freelists.org/webpage/oracle-l