Parsing 10046 traces
UPDATE July 9, 2011: README.TXT 10046.pl
NEW INFO: more trace file analyzer tools at http://ba6.us/node/177
Often when I have a 10046 trace file, especially when looking at I/O issues, I want a histogram of I/O response time. To get I/O response time I’ve hacked out incomple awk scripts from time to time, always meaning to write a more complete one, well now I don’t have to. It’s already been done!
Here is a cool perl script from Clive Bostock: 10046.pl
(also checkout orasrp which produces a more indepth report in HTML. I like both. I like 10046.pl as a short easy portable script that I can modify, whereas orasrp is a binary and only works on some ports)
For example, if I trace a session with 10046, and retrieve the tracefile, then I can run:
$ 10046.pl -t mytrace.trc
and it will output a header and three sections
Header
- Summary of all events for tracefile
- Events by object summary
- Events by object histogram
This looks like
Header
Trace file mytrace.trc Oracle Database 11g Enterprise Edition Release 11.1.0.7.0 - 64bit Production With the Partitioning, OLAP, Data Mining and Real Application Testing options ORACLE_HOME = /u02/oracle System name: SunOS Node name: toto Release: 5.10 Version: Generic_142900-12 Machine: sun4u Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 177 Unix process pid: 16553, image: oracle@toto Trace input file : mytrace.trc
Wait summary
EVENT AGGREGATES ================ Wait Event Count Elapsed(ms) Avg Ela (ms) %Total ~~~~~~~~~~~~~~~~~~~~~~~ ~~~~~ ~~~~~~~~~~~~ ~~~~~~~~~~~~ ~~~~~~~~~~ db file sequential read 2715 11593 4 3.74 direct path read 4484 4506 1 1.45 db file scattered read 141 898 6 0.29 log file sync 3 8 2 0.00 ~~~~~~~~~~~~ Total Elapsed: 309821
Wait Summary by object
Object Id : Wait Event Count Tot Ela (ms) %Total Avg Ela (ms) ~~~~~~~~~~ : ~~~~~~~~~~~~~~~~~~~~~~~~~~~ ~~~~~ ~~~~~~~~~~~~ ~~~~~ ~~~~~~~~~~~~~ 28581 : direct path read 4484 4506 1.45 1 1756433 : db file sequential read 725 1891 0.61 2 764699 : db file sequential read 332 1762 0.57 5 37840 : db file sequential read 200 1044 0.34 5 38018 : db file sequential read 108 1009 0.33 9 81596 : db file scattered read 140 887 0.29 6
wait histogram by object
EVENT HISTOGRAM BREAKDOWN =========================== This section splits the event counts into elapsed time buckets so that we can see if there are any suspiciousn or anomalous response time / frequency patterns. Object Id : Wait Event <1ms <2ms <4ms <8ms <16ms <32ms <64ms <128ms <256ms <512ms >=1024ms ~~~~~~~~~ : ~~~~~~~~~~~~~~~~~~~~~~~ ~~~~ ~~~~ ~~~~ ~~~~ ~~~~~ ~~~~~ ~~~~~ ~~~~~~ ~~~~~~ ~~~~~~ ~~~~~~~~ 28581 : direct path read 7680 87 148 221 144 40 4 0 0 0 0 1756433 : db file sequential read 606 268 45 35 66 6 2 0 0 0 0 764699 : db file sequential read 74 119 11 78 78 9 0 0 0 0 0 37840 : db file sequential read 50 72 6 45 47 5 0 0 0 0 0 38018 : db file sequential read 12 38 7 10 30 12 5 0 0 0 0 81596 : db file scattered read 64 4 13 62 18 8 3 0 0 0 0 41995 : db file sequential read 20 39 0 7 16 8 4 0 0 0 0 108718 : db file sequential read 74 54 5 12 24 4 0 0 0 0 0 33490 : db file sequential read 0 5 11 25 19 4 0 0 0 0 0
Trackbacks
Comments