Oracle Session Tracing Part VI
February 3, 2005
Part VI in our series will show you how to access and generate reports off of the trace files we generated in Part V through the use of the TKPROF and trcsess utilities.
In the last part of this series, we re-visited methods on how to generate trace files. These trace files that were generated were in a raw format that does not allow us to read them very easily. This article will be the last in this series and will show how to take these generated trace files and produce reports in a more readable form.
What does a trace file look like
In Part IV of this series, we discussed how to find where your trace files are generated . These are typically stored in the $ORACLE_BASE/SID/udump directory of the database server. Listing 1 gives the top end of a trace file that I generated so that you could get a flavor, if you have never seen a trace file before. Through out this series we have zeroed in on setting and monitoring the SESSION_ID, CLIENT_IDENTIFIER, SERVICE_NAME, MODULE_NAME, and ACTION_NAME environment variables. At the bottom of this abbreviated trace file listing (Listing 1), you can see exactly how Oracle now stores this in each and every trace file. Note that you can change these environment variables throughout an application and these output lines may be scattered throughout a trace file. In addition, I have explicitly defined each of these client variables through my application. If they were not set, you would end up with an empty string for those variables. If we were to set these variables religiously, you can see how easy it is to issue a Unix GREP command or Windows FIND command to give you all of the trace files generated by a particular user, in a particular module, or performing a certain type of task.
What is the trcsess Utility
After you have determined which trace files include the particular combinations of SID, CLIENT_IDENTIFIER, SERVICE_NAME, ACTION_NAM, or MODULE_NAME variables, you need to be able to pull all of the information together for analysis. The trcsess utility is a java app that is executed through the command line of your O/S and will consolidate trace information in multiple trace files for the information across these SID, CLIENT_IDENTIFIER, SERVICE_NAME, ACTION_NAME, and MODULE_NAME variables. Not to worry about invoking java, Oracle has provided a shell script for your particular operating system that can be executed instead. The output of the trcsess utility is a single file that can be the input into the TKPROF reporting utility. This is of great importance for finding true bottlenecks or an application that is consuming large amounts of resources. It would be nearly impossible to tally all of the trace files for all of the individual times an application or user accessed the database without this utility. In addition, if we set ACTION_NAME and MODULE_NAME properly, it gives us the ability to pick the statistics generated around a certain application or statement type across trace files, out of that trace file.
In addition, if you are in a connection polling environment where the user's session is never the same, this utility gives you the ability to zero in and pick out that user easily from all the trace files generated during the performance tuning time slice you are interested in and giving you a true look into the user's session. Listing 2 gives the syntax for the new trcsess utility and a simple example.
What Can TKPROF Do
Up to this point, we have just generated trace files and consolidated trace files based on a search criterion through the trcsess utility. As stated before, you can edit these trace files and read them by hand but they do tend to be cryptic. Oracle provides us with a reporting mechanism on these trace files in the form of the TKPROF utility. This utility provides for the following mechanisms. Listing 3 also gives the syntax and example on running the TKPROF utility.
1. Formats all the cryptic information in a more readable form that is understandable for you and me.
2. Breaks out each statement executed during the trace period and presents various statistics that enable us to determine where bottlenecks lay and where we might spend our time tuning application code.
3. Can generate a SQL script that allows us to store the captured statistics into a database.
4. Will determine the explain plan for executed SQL statements.
5. Provides for summary as well as detail information for collected statistics
The world of tracing Oracle sessions has changed drastically with Oracle 10g. Not so much the mechanisms but in the way we can initiate a trace for one session or a group of sessions. We are now able to "tag" sessions as they are connected to Oracle and move through applications. We can now accurately pinpoint where in the application a session is, the amount of resources being consumed, and more importantly if the session is having difficulty and is in need of tuning. This is extremely important in a multi-tier environment where connection polling takes place and we would be lost if it where not for these new tracing features.