Re: Is it possible to trace what locks my session obtains?

From: Jared Still <jkstill_at_gmail.com>
Date: Sat, 16 Jul 2016 12:48:58 -0700
Message-ID: <CAORjz=PxcgEQAy7Vkg9+pSogRqucQXD+U6aiAnC4SjMpYC19yA_at_mail.gmail.com>

On Fri, Jul 15, 2016 at 8:04 AM, Michael Cunningham < napacunningham_at_gmail.com> wrote:

> Thank you everyone. Damn, this list is awesome. I can't believe I have so
> much trouble getting people to use it.
>

Hi Michael,

Here's how you may find some of these yourself.

In this case you were looking for information on tracing locks, so this grep shows matching info from the messages file (linux assumed here, with Gnu grep)

grep -E "^1[0-9]{4}.*\block" $ORACLE_HOME/rdbms/mesg/oraus.msg

10028, 00000, "Dump trace information during lock / resource latch cleanup"
10219, 00000, "monitor multi-pass row locking"
10621, 00000, "specify retry count for online index build cleanup DML lock

get"
10623, 00000, "test synchronized flow of SORT rows into FOR UPDATE lock phase"
10629, 00000, "force online index build to backoff and retry DML lock upgrade"
10988, 00000, "event to get exclusive lock during materialized view refresh in IAS"

12766,00000, "ACMS failed to acquire share-mode mount lock"
12843, 00000, "pdml lock not held properly on the table"
13771, 00000, "cannot obtain exclusive lock %s on \"SQL Tuning Set\" \"%s\"

owned by user \"%s\""
14403, 00000, "cursor invalidation detected after getting DML partition lock"

14700, 00000, "Object(s) owned by SYS cannot be locked by non-SYS user"
15003, 00000, "diskgroup \"%s\" already mounted in another lock name space"
15069, 00000, "ASM file '%s' not accessible; timed out waiting for lock"
15150, 00000, "instance lock mode '%s' conflicts with other ASM instance(s)"
16040, 00000, "Destination archive log file is locked."
16415, 0000, "Event to enable lock dumping"
16641, 0000, "failure to acquire broker configuration metadata lock"

The output may be restricted to show only 'lock', and not include 'locked' or 'locking'

 grep -wE "^1[0-9]{4}.*\block" $ORACLE_HOME/rdbms/mesg/oraus.msg 10028, 00000, "Dump trace information during lock / resource latch cleanup" 10621, 00000, "specify retry count for online index build cleanup DML lock get"
10623, 00000, "test synchronized flow of SORT rows into FOR UPDATE lock phase"
10629, 00000, "force online index build to backoff and retry DML lock upgrade"
10988, 00000, "event to get exclusive lock during materialized view refresh in IAS"

12766,00000, "ACMS failed to acquire share-mode mount lock"
12843, 00000, "pdml lock not held properly on the table"
13771, 00000, "cannot obtain exclusive lock %s on \"SQL Tuning Set\" \"%s\"

owned by user \"%s\""
14403, 00000, "cursor invalidation detected after getting DML partition lock"

15003, 00000, "diskgroup \"%s\" already mounted in another lock name space"
15069, 00000, "ASM file '%s' not accessible; timed out waiting for lock"
15150, 00000, "instance lock mode '%s' conflicts with other ASM instance(s)"
16415, 0000, "Event to enable lock dumping"
16641, 0000, "failure to acquire broker configuration metadata lock"

Keeping in mind that in Oracle lock has synonyms, such as enqueue

grep -wE "^1[0-9]{4}.*\benqueue" $ORACLE_HOME/rdbms/mesg/oraus.msg

10425, 00000, "enable global enqueue operations event trace"
10427, 00000, "enable global enqueue service traffic controller event trace"
10428, 00000, "enable tracing of global enqueue service cached resource"
10429, 00000, "enable tracing of global enqueue service IPC calls"
10433, 00000, "global enqueue service testing event"
10434, 00000, "enable tracing of global enqueue service multiple LMS"
10435, 00000, "enable tracing of global enqueue service deadlock detetction"
10437, 00000, "enable trace of global enqueue service S optimized resources"
10440, 00000, "enable global enqueue service inquire resource modes trace"
10666, 00000, "Do not get database enqueue name"
10706, 00000, "Print out information about global enqueue manipulation"
10862, 00000, "resolve default queue owner to current user in

enqueue/dequeue"

10868, 00000, "event to enable interop patch for AQ enqueue options"
10999, 00000, "do not get database enqueue name"
12806, 00000, "could not get background process to hold enqueue"
16146, 00000, "%scontrol file enqueue unavailable"
19573, 00000, "cannot obtain %s enqueue for datafile %s"
19725, 00000, "can not acquire plug-in enqueue"

Still not finding anything useful, the -w parameter can be removed from grep to allow variations, such as 'enqueued' and 'enqueues'

 grep -E "^1[0-9]{4}.*\benqueue" $ORACLE_HOME/rdbms/mesg/oraus.msg

10425, 00000, "enable global enqueue operations event trace"
10427, 00000, "enable global enqueue service traffic controller event trace"
10428, 00000, "enable tracing of global enqueue service cached resource"
10429, 00000, "enable tracing of global enqueue service IPC calls"
10433, 00000, "global enqueue service testing event"
10434, 00000, "enable tracing of global enqueue service multiple LMS"
10435, 00000, "enable tracing of global enqueue service deadlock detetction"
10437, 00000, "enable trace of global enqueue service S optimized resources"
10440, 00000, "enable global enqueue service inquire resource modes trace"
10666, 00000, "Do not get database enqueue name"
10704, 00000, "Print out information about what enqueues are being obtained"
10706, 00000, "Print out information about global enqueue manipulation"
10862, 00000, "resolve default queue owner to current user in

enqueue/dequeue"

10868, 00000, "event to enable interop patch for AQ enqueue options"
10999, 00000, "do not get database enqueue name"
12806, 00000, "could not get background process to hold enqueue"
16146, 00000, "%scontrol file enqueue unavailable"
19573, 00000, "cannot obtain %s enqueue for datafile %s"
19725, 00000, "can not acquire plug-in enqueue"

Since you are looking for trace (debug) specific information, a perusal of the oraus.msg file reveals:

/ Pseudo-error debugging events:
/    Error codes 10000 .. 10999 are reserved for debug event codes that are
/    not really errors.

So searches can be further restricted by changing the range of numbers to search for, showing only debug events:

grep -E "^10[0-9]{3}.*\benqueue" $ORACLE_HOME/rdbms/mesg/oraus.msg

10425, 00000, "enable global enqueue operations event trace"
10427, 00000, "enable global enqueue service traffic controller event trace"
10428, 00000, "enable tracing of global enqueue service cached resource"
10429, 00000, "enable tracing of global enqueue service IPC calls"
10433, 00000, "global enqueue service testing event"
10434, 00000, "enable tracing of global enqueue service multiple LMS"
10435, 00000, "enable tracing of global enqueue service deadlock detetction"
10437, 00000, "enable trace of global enqueue service S optimized resources"
10440, 00000, "enable global enqueue service inquire resource modes trace"
10666, 00000, "Do not get database enqueue name"
10704, 00000, "Print out information about what enqueues are being obtained"
10706, 00000, "Print out information about global enqueue manipulation"
10862, 00000, "resolve default queue owner to current user in

enqueue/dequeue"
10868, 00000, "event to enable interop patch for AQ enqueue options" 10999, 00000, "do not get database enqueue name"

Notice the use of -i now to ignore case

> grep -iE "^10[0-9]{3}.*sql\*net" $ORACLE_HOME/rdbms/mesg/oraus.msg
10079, 00000, "trace data sent/received via SQL*Net"

That particular event was one I found in the messages file a couple years ago, and it was instrumental in discovering and issue with SqlNet, thin clients and lobs.
The issue was far too much network traffic, proved out by this trace event. The solution was to use a 12.1.0.2 thick client.

Jared Still
Certifiable Oracle DBA and Part Time Perl Evangelist Principal Consultant at Pythian
Pythian Blog http://www.pythian.com/blog/author/still/ Oracle Blog: http://jkstill.blogspot.com Home Page: http://jaredstill.com

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

Received on Sat Jul 16 2016 - 21:48:58 CEST