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@xxxxxxxxxxxx>
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.
