method-r.com

Is there a way to display the events of a trace file by time? I think this would be roughly analogous to the OEM graph for Average Active Sessions, except it would only be for a particular traced interval. What I'm after is being able to identify the time skew for events within the trace file. In other words, if all of the CPU time was consumed in the first 10 minutes of an 18 minute trace and then the rest of the time was spent waiting on SQL*Net message from client I would like to know that. On the other hand these events might be evenly spaced out over the entire time period. As part of an ASH report in OEM you kind of get something similar in a chart format, but it can only display the event counts over periods of time and doesn't seem to match up very well with actual times. I assume that this is due to the relatively coarse sampling interval, but the general idea is still valid.

The easy solution is to slice the trace file by using key SQL*Net message from client events as separators. We have software that does that.

The difficult solution is relevant only if I correctly interpreted "display[ing] events...by time", which I take to mean aggregating response time for uniform subintervals. In other words, given a trace file that represents the time of day interval 10:00:00 to 10:00:29, what happened in the following subintervals:

10:00:00.000000 to 10:00:09.999999
10:00:10.000000 to 10:00:19.999999
10:00:20.000000 to 10:00:29.999999

The two most significant problems with choosing any uniform subinterval length are manifested by "events" that span subintervals. The simplest one is a single event (e.g., db file scattered read) that starts in one subinterval and ends in another. The more complicated one is a SQL statement with recursive children. There are plenty of examples in my head that make uniform subintervals a nightmare.

You could then take the non-uniform subinterval approach. If you do that, then you very quickly come to the conclusion that slicing the trace file is easiest if you do it at recursive depth zero. And that takes us back to slicing it by SQL*Net message from client.

Hi Jeff, it's been a while. I hope things are good with you. I agree that it would be easiest to use non-uniform intervals, which I don't think would affect a "graph" type display very much. So, how about using dep=0 PARSE|EXEC|FETCH statement cpu values and WAIT event ela= values as the "events". Intervals could then be split on either "event" boundaries (that would seem to be the preferred method) or between events if really long running (i.e. exceeding some threshold). If the running timeline is used as the reference and if we're only interested in the entire timeline (i.e. only for the entire trace file timeline) then it seems that most of the recursive problems go away. What I'm really after is to just take the "Profile by Subroutine" in the "Task-Level Profiles" section and plot it over time. My hesitation on using SQL*Net message from client is that there will be cases where that interval is just too long. In my simplistic view I'm thinking of intervals on the order of 10s of seconds for a several minute trace file.

There will be cases where both methods will be result in coarse aggregation. Not only can SQL*Net message from client have a long duration but so can parse, exec, and fetch calls. But it is probably true that one would more often see long SQL*Net message from client durations.

To attribute CPU consumption for, say, a fetch call to multiple subintervals requires assumptions I'm not willing to make.

It assumes time not spent in an event (e.g., db file sequential read) is time spent on the CPU. In other words it assumes that all of the RDBMS is properly instrumented.

It assumes measurement intrusion is zero, particularly writes to the trace file.

It assumes the ending time of an event is known, which is true only for 11g onwards.