Capturing Duration in Profiler????

Question

Post reply

Capturing Duration in Profiler????

DBADave

SSChampion

Points: 10962
More actions
February 24, 2006 at 3:37 pm

#113416

I'm puzzled by something I am seeing in profiler. I have one trace configured to profile the following events where Duration >= 1000.
SP:StmtCompleted
SP:Completed
SQL:BatchCompleted
RPC:Completed
SQL:StmtCompleted
I'm capturing EndTime, HostName, LoginName, CPU, Reads, Writes and TextData, plus a two or three other bits of information. When the trace runs I can see a number of stored procedures and SQL statements completing in over 5 seconds.
If I create another trace which includes the corresponding SP, SQL and RPC ...Starting Events, where Duration is > 0 and run it at the same time as the above trace, I rarely see a duration > 1 second.
I can look at the same command on both profiler sessions and see different durations. Why is this happening?
Thanks, Dave
February 27, 2006 at 8:00 am

This was removed by the editor as SPAM

Viewing 5 posts - 1 through 4 (of 4 total)

You must be logged in to reply to this topic. Login to reply

Krishnan Kaniappan Ten Centuries Points: 1051 More actions · Answer 1

capture the

SP:StmtCompleted

SP:Completed

events also in your other trace...

-Krishnan

Shawn Wilson Ten Centuries Points: 1271 More actions · Answer 2

You will almost never see durations > 0 with starting events. The most you can get out of the statement starting event is the time in which the statement started so you can compare where other events start relative to that. IO, CPU, etc will almost always come back as 0's for the starting events.

Completed events give you more accurate picture of how statements perform by giving you IO counts, and duration in milliseconds.

If you trap started and completed events together and take the difference in their start/complete times you will notice that is the time in milliseconds for the event to complete and is reflected in the duration.

if you capture start and completed events it makes it easy to see what was happening between the 2 events to help in troubleshooting performance issues.

for example. you're tracing an update SQL statement that should normally take say 50ms. On every Monday at 12pm that same update takes 10 minutes to complete. You could start a trace on started and completed events to see what's inbetween that may be causing the 10 min delay. It could be some big OLAP cube generation, or index rebuilding, or whatever. Both events when used together can significantly help troubleshoot many issues.

DBADave SSChampion Points: 10962 More actions · Answer 3

Sorry for any confusion. When I say my second trace includes the corresponding "starting" events, that means in addition to the "completed" events, not in place of the "completed" events. I believe I discovered the issue. If I'm looking at live traces, some events are skipped due to the number of events and the amount of memory the set asside for traces. If I run two traces at the same time and have the results written to a file and not the screen, fewer events are skipped and the durations match-up. I'm guessing when I ran my traces the other day I was not seeing a match in duration because the corresponding trace (not being restricted by duration > 1000) was missing events.

Thanks, Dave