Re: Locking issue

I collected two different section of the 10222 trace , a few occurrences of the CID = 62 and few for the CID=63.

Now it does point to the fact that it was calling those row cache objects(dc_realtime_tabst and dc_realtime_colst), but then how can i check if this should be called or not. But one thing I suspect, as the name suggests, this must be related to real time statistics and thus seeing no entry in gv$rowcache in the 11.2 database for these parameters.

This select query was running from multiple sessions at the same time, so is it correct to assume that in this version it can cause such contention in the dictionary cache, as it has to keep fetching the real time stats collection details from there for the object , even during run time of the query? But still why will it block others on the same 'row cache lock' or 'cursor:pin S wait on X' ?

• Calls related to cid=63 i.e. dc_realtime_tabst******************

kqrpad: new po 0x6e2e6ae18 hash 69d02eda key_index 0 from kqrpre1

kqrAllocateEnqueue: bis: po=0x6e2e6ae18 flag=00010000 before=00000000 after=00010000

kqrGetClusterLock bic: po=0x6e2e6ae18 flag=00010000 before=00010000 after=00000000

kqrInstanceLock: op = KQRILGET po = 0x6e2e6ae18 lk = 0x6d0cca918 mode = 3 ilh = 0x6d0cca970

kqrInstanceLock: po = 0x6e2e6ae18 status = 0 error = 0 ilh = 0x6d0cca970

kqrClusterLock po=0x6e2e6ae18 mode=3 timeout=ffff opt=NWT flg=82 err=0

kqrGetClusterLock bis: po=0x6e2e6ae18 flag=00008000 before=00000000 after=00008000

kqrReadFromDB : kqrpre1.1 po=0x6e2e6ae18 flg=8000 cid=63 eq=0x6d0cca8a0 idx=0 dsflg=0

kqrpre: start hash=2cad6213 mode=S keyIndex=0 dur=CALL opt=TRUE

kqrpre: optimistic lookup: hash=2cad6213

kqrpre: optimistic lookup: searching cache 0 po 0x73b9cab68 hash 75ce5c5a ver 1

kqrpre: optimistic lookup: searching cache 1 po 0x6d74a1a90 hash c83b322f ver 1

kqrpre: optimistic lookup: searching cache 2 po 0x6f1e84c58 hash ba7ce53e ver 1

kqrpre: optimistic lookup: searching cache 3 po 0x6e0da0a50 hash a2379e64 ver 1

kqrpre: optimistic lookup: searching cache 4 po 0x6df176b78 hash 46229d00 ver 1

kqrpre: optimistic lookup: searching cache 5 po 0x73f06c678 hash f0b75847 ver 2

kqrpre: optimistic lookup: searching cache 6 po 0x70080f6b8 hash 3a94fe37 ver 1

kqrpre: optimistic lookup: searching cache 7 po 0x70ec02a38 hash aa2feb13 ver 3

kqrpre: optimistic lookup: searching cache 8 po 0x6ccb89820 hash 35e74caf ver 1

kqrpre: optimistic lookup: searching cache 9 po 0x69b1554c8 hash 9482d0a1 ver 1

kqrpre: optimistic lookup: reading hash mtx addr=0x7675d92c6 version=50

kqrpre: optimistic lookup: processing po 0x70d33b6a8 mtx addr=0x70d33ba68 version=560

kqrpre: optimistic lookup: lock mode 0 flag 00000002

kqrpre: optimistic lookup: copied po 0x70d33b6a8 to cache 5

kqrpre: optimistic lookup: success

kqrpre: done po=0x7faef0cc5758 cid=8 flg=2 eq=0x70c6c79c8 pso=0x73e7049c8 dur=CALL

kqrpre: keyIndex=0 hash=2cad6213 edbf39fd 0

kqrpre: obobn=678 obname=WRI$_OPTSTAT_TAB_HISTORY obtyp=2 obsta=1 obflg=4194304

kqrpre: returnVal: TRUE

kqrTestAndClearLoad bic: po=0x6e2e6ae18 flag=00008000 before=00008000 after=00000000

kqrpre set: po=0x6e2e6ae18 flag=00000002 before=00000000 after=00000002

kqrpre: done po=0x6e2e6ae18 cid=63 flg=2 eq=0x6d0cca8a0 pso=0x738640a80 dur=CALL

kqrpre: keyIndex=0 hash=69d02eda 0 0

kqrpre: returnVal: TRUE

.

kqrpre: start hash=69d02eda mode=S keyIndex=0 dur=CALL opt=FALSE

kqrpre: found cached object po=0x6e2e6ae18 flg=2

kqrpre: pinned po=0x6e2e6ae18 flg=2 pso=0x738640a80

kqrAllocateEnqueue: bis: po=0x6e2e6ae18 flag=00010000 before=00000002 after=00010002

kqrGetClusterLock bic: po=0x6e2e6ae18 flag=00010000 before=00010002 after=00000002

kqrInstanceLock: op = KQRILGET po = 0x6e2e6ae18 lk = 0x67bc13370 mode = 3 ilh = 0x67bc133c8

kqrInstanceLock: po = 0x6e2e6ae18 status = 0 error = 0 ilh = 0x67bc133c8

kqrClusterLock po=0x6e2e6ae18 mode=3 timeout=ffff opt=NWT flg=82 err=0

kqrpre: done po=0x6e2e6ae18 cid=63 flg=2 eq=0x67bc132f8 pso=0x738640a80 dur=CALL

kqrpre: keyIndex=0 hash=69d02eda 0 0

kqrpre: returnVal: TRUE

kqrpre: start hash=69d02eda mode=S keyIndex=0 dur=CALL opt=FALSE

kqrpre: found cached object po=0x6e2e6ae18 flg=2

kqrpre: pinned po=0x6e2e6ae18 flg=2 pso=0x738640a80

kqrAllocateEnqueue: bis: po=0x6e2e6ae18 flag=00010000 before=00000002 after=00010002

kqrGetClusterLock bic: po=0x6e2e6ae18 flag=00010000 before=00010002 after=00000002

kqrInstanceLock: op = KQRILGET po = 0x6e2e6ae18 lk = 0x67bc13370 mode = 3 ilh = 0x67bc133c8

kqrInstanceLock: po = 0x6e2e6ae18 status = 0 error = 0 ilh = 0x67bc133c8

kqrClusterLock po=0x6e2e6ae18 mode=3 timeout=ffff opt=NWT flg=82 err=0

kqrpre: done po=0x6e2e6ae18 cid=63 flg=2 eq=0x67bc132f8 pso=0x738640a80 dur=CALL

kqrpre: keyIndex=0 hash=69d02eda 0 0

kqrpre: returnVal: TRUE

• Calls related to cid=62 i.e. dc_realtime_colst******************

kqrpad: new po 0x703db4568 hash dc7ac22a key_index 0 from kqrpre1

kqrAllocateEnqueue: bis: po=0x703db4568 flag=00010000 before=00000000 after=00010000

kqrGetClusterLock bic: po=0x703db4568 flag=00010000 before=00010000 after=00000000

kqrInstanceLock: op = KQRILGET po = 0x703db4568 lk = 0x67bc135f0 mode = 3 ilh = 0x67bc13648

kqrInstanceLock: po = 0x703db4568 status = 0 error = 0 ilh = 0x67bc13648

kqrClusterLock po=0x703db4568 mode=3 timeout=ffff opt=NWT flg=82 err=0

kqrGetClusterLock bis: po=0x703db4568 flag=00008000 before=00000000 after=00008000

kqrReadFromDB : kqrpre1.1 po=0x703db4568 flg=8000 cid=62 eq=0x67bc13578 idx=0 dsflg=0

kqrpre: start hash=19430df7 mode=S keyIndex=0 dur=CALL opt=TRUE

kqrpre: optimistic lookup: hash=19430df7

kqrpre: optimistic lookup: searching cache 0 po 0x6ccb89820 hash 35e74caf ver 1

kqrpre: optimistic lookup: searching cache 1 po 0x701b1f8c8 hash f07219c5 ver 1

kqrpre: optimistic lookup: searching cache 2 po 0x6f1e84c58 hash ba7ce53e ver 1

kqrpre: optimistic lookup: searching cache 3 po 0x6e0da0a50 hash a2379e64 ver 1

kqrpre: optimistic lookup: searching cache 4 po 0x6df176b78 hash 46229d00 ver 1

kqrpre: optimistic lookup: searching cache 5 po 0x70d33b6a8 hash 2cad6213 ver 1

kqrpre: optimistic lookup: searching cache 6 po 0x730813b00 hash 760e449 ver 1

kqrpre: optimistic lookup: searching cache 7 po 0x717c94360 hash 5b2ad36f ver 1

kqrpre: optimistic lookup: searching cache 8 po 0x6c5a448b8 hash 1eb76ed1 ver 1

kqrpre: optimistic lookup: searching cache 9 po 0x71c9a6fd0 hash b6d844b9 ver 1

kqrpre: optimistic lookup: reading hash mtx addr=0x7675cea8e version=80

kqrpre: optimistic lookup: processing po 0x733271218 mtx addr=0x7332715d8 version=130

kqrpre: optimistic lookup: lock mode 0 flag 00000002

kqrpre: optimistic lookup: copied po 0x733271218 to cache 2

kqrpre: optimistic lookup: success

kqrpre: done po=0x7faef0cbf320 cid=8 flg=2 eq=0x685d09510 pso=0x73e7049c8 dur=CALL

kqrpre: keyIndex=0 hash=19430df7 b24a568a 0

kqrpre: obobn=14862 obname=WRI$_OPTSTAT_HISTHEAD_HISTORY obtyp=2 obsta=1 obflg=4194304

kqrpre: returnVal: TRUE

kqrTestAndClearLoad bic: po=0x703db4568 flag=00008000 before=00008000 after=00000000

kqrpre set: po=0x703db4568 flag=00000002 before=00000000 after=00000002

kqrpre: done po=0x703db4568 cid=62 flg=2 eq=0x67bc13578 pso=0x738640a80 dur=CALL

kqrpre: keyIndex=0 hash=dc7ac22a 0 0

kqrpre: returnVal: TRUE

kqrpad: new po 0x6d0870df8 hash 7f0f612a key_index 0 from kqrpre1

kqrAllocateEnqueue: bis: po=0x6d0870df8 flag=00010000 before=00000000 after=00010000

kqrGetClusterLock bic: po=0x6d0870df8 flag=00010000 before=00010000 after=00000000

kqrInstanceLock: op = KQRILGET po = 0x6d0870df8 lk = 0x67bc135f0 mode = 3 ilh = 0x67bc13648

kqrInstanceLock: po = 0x6d0870df8 status = 0 error = 0 ilh = 0x67bc13648

kqrClusterLock po=0x6d0870df8 mode=3 timeout=ffff opt=NWT flg=82 err=0

kqrGetClusterLock bis: po=0x6d0870df8 flag=00008000 before=00000000 after=00008000

kqrReadFromDB : kqrpre1.1 po=0x6d0870df8 flg=8000 cid=62 eq=0x67bc13578 idx=0 dsflg=0

kqrTestAndClearLoad bic: po=0x6d0870df8 flag=00008000 before=00008000 after=00000000

kqrpre set: po=0x6d0870df8 flag=00000002 before=00000000 after=00000002

kqrpre: done po=0x6d0870df8 cid=62 flg=2 eq=0x67bc13578 pso=0x738640a80 dur=CALL

kqrpre: keyIndex=0 hash=7f0f612a 0 0

kqrpre: returnVal: TRUE

On Thu, May 20, 2021 at 12:37 PM Noveljic Nenad <nenad.noveljic_at_vontobel.com> wrote:

> I traced the row cache locks (event 10222, level 4) for both a select with
> dynamic sampling and the statistic job:
>
>
>
> --select with dynamic sampling
>
> SQL> !grep cid
> /u00/oracle/orabase/diag/rdbms/db_site1/DB/trace/DB_ora_15329_0001.trc |
> grep 'kqrpre:' | awk '{print $4}' | sort -u
>
> cid=0
>
> cid=10
>
> cid=16
>
> cid=2
>
> cid=8
>
>
>
> --gather_table_stats
>
> SQL> !grep cid
> /u00/oracle/orabase/diag/rdbms/db_site1/DB/trace/DB_ora_15329_0002.trc |
> grep 'kqrpre:' | awk '{print $4}' | sort -u
>
> cid=0
>
> cid=10
>
> cid=11
>
> cid=13
>
> cid=16
>
> cid=17
>
> cid=2
>
> cid=3
>
> cid=61
>
> cid=63
>
> cid=8
>
>
>
> (cid is the rowcache id.)
>
>
>
> Only the statistic job acquired the rowcache lock id 63.It’s therefore
> still unclear what boundary condition caused acquiring the rowcache lock
> for select.
>
>
>
> Lok, you could try to capture the stack trace for the event 10222. Sayan
> has just published the article on how to do that:
> http://orasql.org/2021/05/20/oracle-diagnostic-events-cheat-sheet/
>
>
>
> Best regards,
>
>
>
> Nenad
>
>
>
> ____________________________________________________
>
> Please consider the environment before printing this e-mail.
>
> Bitte denken Sie an die Umwelt, bevor Sie dieses E-Mail drucken.
>
>
> Important Notice
>
> This message is intended only for the individual named. It may contain
> confidential or privileged information. If you are not the named addressee
> you should in particular not disseminate, distribute, modify or copy this
> e-mail. Please notify the sender immediately by e-mail, if you have
> received this message by mistake and delete it from your system.
> Without prejudice to any contractual agreements between you and us which
> shall prevail in any case, we take it as your authorization to correspond
> with you by e-mail if you send us messages by e-mail. However, we reserve
> the right not to execute orders and instructions transmitted by e-mail at
> any time and without further explanation.
> E-mail transmission may not be secure or error-free as information could
> be intercepted, corrupted, lost, destroyed, arrive late or incomplete. Also
> processing of incoming e-mails cannot be guaranteed. All liability of
> Vontobel Holding Ltd. and any of its affiliates (hereinafter collectively
> referred to as "Vontobel Group") for any damages resulting from e-mail use
> is excluded. You are advised that urgent and time sensitive messages should
> not be sent by e-mail and if verification is required please request a
> printed version.
> Please note that all e-mail communications to and from the Vontobel Group
> are subject to electronic storage and review by Vontobel Group. Unless
> stated to the contrary and without prejudice to any contractual agreements
> between you and Vontobel Group which shall prevail in any case,
> e-mail-communication is for informational purposes only and is not intended
> as an offer or solicitation for the purchase or sale of any financial
> instrument or as an official confirmation of any transaction.
> The legal basis for the processing of your personal data is the legitimate
> interest to develop a commercial relationship with you, as well as your
> consent to forward you commercial communications. You can exercise, at any
> time and under the terms established under current regulation, your rights.
> If you prefer not to receive any further communications, please contact
> your client relationship manager if you are a client of Vontobel Group or
> notify the sender. Please note for an exact reference to the affected group
> entity the corporate e-mail signature. For further information about data
> privacy at Vontobel Group please consult www.vontobel.com.
>

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