Archive
Consistent get trace file parser
Similar to my last post, this relates to another posting http://hoopercharles.wordpress.com/2011/01/24/watching-consistent-gets-10200-trace-file-parser. Tracing the event 10200 allows to see consistent reads. For details read linked blog entry. So now I also learned how to quote source code and < and >.
My contribution to the topic, added as comment in above mentioned post, a small awk script, that allows direct parsing of the trace file output on unix (although, I actually used it on cygwin …., so may be not 100% compatible).
In order to change to another trace file format, you just have to change $nr references in the script.
$ more cons_get_trc.awk
BEGIN {
FS ="[ \t<>:]+"
print "Details for file: " trcfile
print "---------------------------------"
while( getline < trcfile != EOF ){
if ( $0 ~ /started for block/ ) {
rdba[$6]+=1
obj[$8]+=1
both[$6","$8]+=1
print $6 " " rdba[$6] ", " $8 " " obj[$8]
}
}
close (trcfile)
print ""
print ""
print "Summary rdba and obj for file: " trcfile
print "---------------------------------"
for ( var in both) {
print var " " both[var]
}
print ""
print "Summary obj for file: " trcfile
print "---------------------------------"
for ( var in obj ) {
print var " " obj[var]
}
}
One third code, two thirds output. Usage demonstration, with just head -50 of a trace file into small.trc. (header info removed below)
Oracle Database 11g Enterprise Edition Release 11.1.0.7.0 - 64bit Production ....... ktrget2(): started for block <0x0104 : 0x09e3d4cc> objd: 0x00189fa5 env: (scn: 0x05b5.3bb87c76 xid: 0x0000.000.00000000 uba: 0x00000000.0000.00 statement num=0 parent xid: xid: 0x0000.000.00000000 scn: 0x0000.00000000 97sch: scn: 0x0000.00000000 mascn: (scn: 0x0000.00000000) ktrexf(): returning 9 on: 10a102abc scn: 0xffff.ffffffff xid: 0x0000.000.00000000 uba: 0x00000000.0000.00 scn: 0xffff.ffffffff sfl: 0 ktrgcm(): completed for block <0x0104 : 0x09e3d4cc> objd: 0x00189fa5 ktrget2(): completed for block <0x0104 : 0x09e3d4cc> objd: 0x00189fa5 ktrget2(): started for block <0x0104 : 0x09fa4692> objd: 0x00189fa5 env: (scn: 0x05b5.3bb87c76 xid: 0x0000.000.00000000 uba: 0x00000000.0000.00 statement num=0 parent xid: xid: 0x0000.000.00000000 scn: 0x0000.00000000 96sch: scn: 0x0000.00000000 mascn: (scn: 0x0000.00000000) ktrexf(): returning 9 on: 10a102abc scn: 0xffff.ffffffff xid: 0x0000.000.00000000 uba: 0x00000000.0000.00 scn: 0xffff.ffffffff sfl: 0 ktrgcm(): completed for block <0x0104 : 0x09fa4692> objd: 0x00189fa5 ktrget2(): completed for block <0x0104 : 0x09fa4692> objd: 0x00189fa5 ktrget2(): started for block <0x0104 : 0x0a0ac450> objd: 0x00189fa5 env: (scn: 0x05b5.3bb87c76 xid: 0x0000.000.00000000 uba: 0x00000000.0000.00 statement num=0 parent xid: xid: 0x0000.000.00000000 scn: 0x0000.00000000 96sch: scn: 0x0000.00000000 mascn: (scn: 0x0000.00000000) ktrexf(): returning 9 on: 10a102abc scn: 0xffff.ffffffff xid: 0x0000.000.00000000 uba: 0x00000000.0000.00 scn: 0xffff.ffffffff sfl: 0 ktrgcm(): completed for block <0x0104 : 0x0a0ac450> objd: 0x00189fa5 ktrget2(): completed for block <0x0104 : 0x0a0ac450> objd: 0x00189fa5 ktrget2(): started for block <0x0104 : 0x009d94fc> objd: 0x00189fa5 env: (scn: 0x05b5.3bb87c76 xid: 0x0000.000.00000000 uba: 0x00000000.0000.00 statement num=0 parent xid: xid: 0x0000.000.00000000 scn: 0x0000.00000000 96sch: scn: 0x0000.00000000 mascn: (scn: 0x0000.00000000) ktrexf(): returning 9 on: 10a102abc scn: 0xffff.ffffffff xid: 0x0000.000.00000000 uba: 0x00000000.0000.00 scn: 0xffff.ffffffff sfl: 0 ktrgcm(): completed for block <0x0104 : 0x009d94fc> objd: 0x00189fa5 ktrget2(): completed for block <0x0104 : 0x009d94fc> objd: 0x00189fa5 ktrget2(): started for block <0x0104 : 0x09fa4698> objd: 0x00189fa5 env: (scn: 0x05b5.3bb87c76 xid: 0x0000.000.00000000 uba: 0x00000000.0000.00 statement num=0 parent xid: xid: 0x0000.000.00000000 scn: 0x0000.00000000 96sch: scn: 0x0000.00000000 mascn: (scn: 0x0000.00000000) ktrexf(): returning 9 on: 10a102abc scn: 0xffff.ffffffff xid: 0x0000.000.00000000 uba: 0x00000000.0000.00 scn: 0xffff.ffffffff sfl: 0 ktrgcm(): completed for block <0x0104 : 0x09fa4698> objd: 0x00189fa5 ktrget2(): completed for block <0x0104 : 0x09fa4698> objd: 0x00189fa5 ktrget2(): started for block <0x0104 : 0x009d94ff> objd: 0x00189fa5 env: (scn: 0x05b5.3bb87c76 xid: 0x0000.000.00000000 uba: 0x00000000.0000.00 statement num=0 parent xid: xid: 0x0000.000.00000000 scn: 0x0000.00000000 96sch: scn: 0x0000.00000000 mascn: (scn: 0x0000.00000000)
$ awk -v trcfile=small.trc -f cons_get_trc.awk
Details for file: small.trc --------------------------------- 0x09e3d4cc 1, 0x00189fa5 1 0x09fa4692 1, 0x00189fa5 2 0x0a0ac450 1, 0x00189fa5 3 0x009d94fc 1, 0x00189fa5 4 0x09fa4698 1, 0x00189fa5 5 0x009d94ff 1, 0x00189fa5 6 Summary rdba and obj for file: small.trc --------------------------------- 0x0a0ac450,0x00189fa5 1 0x09fa4698,0x00189fa5 1 0x09fa4692,0x00189fa5 1 0x009d94ff,0x00189fa5 1 0x009d94fc,0x00189fa5 1 0x09e3d4cc,0x00189fa5 1 Summary obj for file: small.trc --------------------------------- 0x00189fa5 6
TM enqueues and deadlock with one user session
For quite some time now, I have been thinking about writing some blog items, but never did. A recent blog entry on http://jonathanlewis.wordpress.com/2011/04/08/deadlock prompted me to give it a try.
So the first post is just a repetition of the comment I made:
TM-enqueues for foreign key locking seems to be a well known fact. What I personally would like to know, what other reasons can cause TM-Locks.
A few times already I had issues with them, not involving foreign keys.
Another reason are exclusive lock and the following. Did anyone know, that a single user connected session can cause a deadlock?
on 10.2.0.3 and 11.1.0.7 verified:
DROP TABLE TESTSZ; CREATE TABLE TESTSZ ( I NUMBER, K VARCHAR2(50)); INSERT INTO TESTSZ SELECT MOD(ROWNUM,1000), LPAD(‘X’,40,’Y') FROM DUAL CONNECT BY ROWNUM < 1000000; COMMIT; LOCK TABLE TESTSZ IN EXCLUSIVE MODE; INSERT INTO TESTSZ X WITH X1 AS (SELECT /*+ no_PARALLEL(T) MATERIALIZE*/ 2000, K FROM TESTSZ T WHERE I=1) SELECT * FROM X1; rollback; LOCK TABLE TESTSZ IN EXCLUSIVE MODE; set timing on INSERT INTO TESTSZ X WITH X1 AS (SELECT /*+ PARALLEL(T,4) MATERIALIZE*/ 2000, K FROM TESTSZ T WHERE I=1) SELECT * FROM X1; rollback;
Result of the last insert statement:
INSERT INTO TESTSZ X
*
FEHLER in Zeile 1:
ORA-12801: error signaled in parallel query server P000
ORA-00060: deadlock detected while waiting for resource
Before anyone complains there are more than one session involved,
yes, but the importance is only one “user” connected session.
Moving back to TM locks, in the case above with the factored subquery
in combination with parallel query, the deadlock occurs while the sessions
are trying to get TM-locks.
SID PROGRAM LAST_CALL_ET BLOCKING_SESSION EVENT SECONDS_IN_WAIT 116 sqlplus.exe 48 PX Deq: Parse Reply 3 WAITING 117 oracle@cyber-ora10 (P005) 48 PX Deq: Execution Msg 3 WAITING 128 oracle@cyber-ora10 (P004) 48 PX Deq: Execution Msg 3 WAITING 115 oracle@cyber-ora10 (P003) 48 PX Deq: Execution Msg 3 WAITING 129 oracle@cyber-ora10 (P002) 48 116 enq: TM – contention 48 WAITING 120 oracle@cyber-ora10 (P001) 48 116 enq: TM – contention 48 WAITING 136 oracle@cyber-ora10 (P000) 48 116 enq: TM – contention 48 WAITING
To finish, Oracle support agreed, that this is not supposed to happen. The workaround is to use the inline hint.
And to credit, this originally happened to a co-worker sitting two desks next to me.
Oracle Episodes 