I have been tasked to create an Intro to Oracle Tracing using the Trace File Browser within Toad. I’ve search all over the internet trying to find a guide or some sort of tutorial that can explain the tabs on the Trace File Browser for 12.10. Is there any one who can explain/describe what each of those tabs suppose to display or list?? For example, how can one explain what kind of information/data is on the Raw Data tab or the Waits by Object tab.
Hi,
“Raw Data” displays the information straight from the trace file for the selected statement.
“Waits by Object” summarizes wait information for each object used while the session was being traced.
I’ll be happy to answer whatever other questions you have, but maybe we should take the conversation offline. You can email me directly at john.dorlon@quest.com.
-John
By the way, Oracle Trace Files are not very well documented by Oracle (at least not the last time I looked!) I’m not making any assumptions about your understanding of trace file data, but I had to learn quite a bit about it when creating the Trace File Browser in Toad.
This book helped tremendously, especially chapter 5.
https://www.amazon.com/Optimizing-Oracle-Performance-Practitioners-Response/dp/059600527X
A lot of the terminology used in the Trace File Browser came from the abbreviations used by Oracle in their trace files and from this book. So a good understanding of trace file data will go a long way to understanding the Trace File Browser.
But again, don’t hesitate to email me with questions. I’m here to help.
Hi John,
I’m also writing up a document (well, improving my own notes!) for colleagues here at work. I’m looking (puzzled!) at the “Deadlock” tab on the lower part of the screen. I’ve got many many trace files and so far, nothing has ever appeared in this tab.
I assume (probably wrongly!) that it depends on some trace file holding details of a deadlock situation? I’m too lazy busy at the moment to go off and create a trace of this nature! [;)]
I shall, of course, make my document available to one and all if anyone is interested.
Hi Norm,
That’s great, thank you!
If a deadlock occurred during the trace, then it will be detailed there on the deadlock tab. I may have such a trace file laying around. If I can find it, I’ll email it to you.
[mention:94f721e2061d4b00adcd796985a397bc:e9ed411860ed4f2ba0265705b8793d05] - Norm was also very helpful when I was creating the Trace File Browser!
-John
Here is some documentation that may help you both
In searching my email for a deadlock, I found the following in an email that I sent to someone a few years ago. Thought it would be helpful.
What I am showing in the Trace File Browser is actually is a pretty clear representation of what Oracle gives us in the trace file. I think a source of misunderstanding is that perhaps you are thinking that the main Statements tab should be listing each time a query is executed, but really, it is listing each cursor, and sometimes these cursors are executed multiple times.
In a trace file, you will find PARSING IN CURSOR lines like this:
PARSING IN CURSOR #6 len=308 dep=0 uid=0 oct=47 lid=0 tim=2359794948753 hv=529508656 ad=‘25a904a0’
begin sys.dbms_system.set_bool_param_in_session(133, 25756,‘timed_statistics’, true); sys.dbms_system.set_int_param_in_session(133, 25756,‘timed_os_statistics’, 0); sys.dbms_system.set_int_param_in_session(133, 25756,‘max_dump_file_size’, 2147483647); sys.dbms_system.set_ev(133, 25756, 10046, 12, ‘’); end;
END OF STMT
Each one of these cursors (this one is #6) is represented by a row in the “Statement Details” tab. Each cursor can have any number of parses, executions, waits, fetches. Depending on the type of statement, it may or may not have an explain plan, transaction waits, or deadlock. All of these things are detailed at the bottom half of the Statement Details tab. Toad isn’t really deciding what to “Combine” in the Statement Details tab any more than Oracle has already done in the trace file. The only “combining” that Toad does is show you the sum of the EXEC, PARSE, FETCH lines for each PARSING IN CURSOR. So if you see the same statement listed more than once in the Statement Details tab, it is because that statement has more than one “PARSING IN CURSOR” line in the trace file.
Here are the columns of the Statement Details tab:
Statement – the SQL Statement between “begin” and “END OF STMT” lines after “PARSING IN CURSOR”
Seq – this is a numbering of the statements in the order in which they were executed. This number is not listed in the file.
Rec Stmts – The number of recursive statements. For example, if you execute a CREATE TABLE statement, Oracle will execute many SQL statements behind the scenes to complete the create table statement. All of those “behind the scenes” statements are recursive. A recursive statement can have recursive statements of its own.
Rec Depth – How many recursive levels deep is this statement?
Cmd Type – what type of command is this.
Parse Time – How long did Oracle spend parsing this statement? There can be many parses of a cursor. This is the total time spent on all of the parses.
Parse Count – How many times was this cursor parsed. Ideally, just 1. (How many PARSE lines are there which correspond to PARSING IN CURSOR #x?)
Exec Time – How long did Oracle spend executing this statement? There can be many executions of a cursor. This is the total time spent on all executions.
Exec Count – How many times was this cursor executed? (How many EXEC lines are there which correspond to PARSING IN CURSOR #x?)
Fetch Time – How long did Oracle spend fetching the rows of this statement (if it’s select statement). There can be many fetches for a single execution, and there can be many executions. This is the total time for all fetches of this cursor.
Fetch Count – How many times were fetches performed on this cursor? (How many FETCH lines are there which correspond to PARSING IN CURSOR #x?) Note: there are usually (but not always) multiple rows retrieved per fetch.
Wait Time – Total time of all waits for this cursor. Waits can happen before or after execution, before or after fetches.
Wait Time Inc Rec – Total time of all waits for this cursor and all recursive cursors.
Total Time – Parse Time + Execution Time + Wait Time + Fetch Time. If there is no recursion, then “Total Time Inc Rec” will have the same value.
Total Time Inc Rec – Parse Time + Execution Time + Wait Time + Fetch Time for the statement + time for recursive statements.
Cons Rds – Total consistent reads performed by the cursor. These can happen during Parses, Executions, and Fetches.
Cons Rds Inc Rec – Total consistent reads performed by the cursor and all recursive cursors.
Phys Rds – Total physical reads performed by the cursor. These can happen during Parses, Executions, and Fetches.
Phys Rds Inc Rec – Total physical reads performed by the cursor and all recursive cursors.
Optimizer Goal – The optimizer goal of the statement
Parse Type – Hard/Soft
Error Code – if the statement resulted in an error, what was the ORA- error code
Rows Fetched - # of rows fetched by all executions of the cursor.
Wait Count – Total number of waits by all executions of the cursor.
Wait Count Inc Rec – Total number of waits by all executions of the cursor and all recursive cursors of this statement.
SQL ID = The SQL ID of this cursor.
Top Wait – Of all types of waits that this cursor experienced, which type of wait did the cursor wait the longest on?
Top Wait Total – how much time did the “top wait” wait for this cursor (over all executions and fetches)
Transaction Ended – did this statement end a transaction with a COMMIT or ROLLBACK?
Transaction waits – Total # of waits as a result of the end of the transaction
Transaction wait time – Total time spent on waits as a result of the end of the transaction
Hash Value = Hash value of this statement
Address = memory address of this statement
Now, in the Query Summary tab, we are showing summary of what you see in the Statement Details tab. So when we chart EXEC TIME, for example, it charting the time spent executing each cursor (which, now you understand can be multiple executions per cursor). It does not chart each execution of each cursor. I could add that as an option, and it would result in a different distribution of times in the chart, but the total time spent should remain the same. I could also try to change the wording on the Query Summary tab so maybe it is more clear what is being displayed now.
Hi John,
I have picked up the demo deadlock trace file from the link you supplied - most useful, thanks.
John Dorlon - THANKS SOOO MUCH!!! This information helps me a whole lot in understanding the column within Trace File Browser. I am fairly new to Oracle Tracing and to Toad so I’m learning as I go while trying to create an Intro to Oracle Tracing to my colleagues. I truly appreciate your knowledge!
Afternoon All,
I’ve updated some notes of mine recently for colleagues here at work, and I’ve added a couple of worked examples of using Toad’s Trace File Browser. You can read about it on the Toad For Oracle Blog at http://www.toadworld.com/products/toad-for-oracle/b/weblog/archive/2017/06/28/toad-trace-file-analyser and there’s a zip file attached with two example trace files, and a copy of my document in PDF and Word’s DOCX format.
Help yourselves and feel free to use the files as you see fit.
Any questions, contact me - I don;t work for Quest, nor am I a Toad Developer - I just use and love Toad.
Enjoy.