SQL Server Performance

Using SQL Profiler to find Query Costs

Discussion in 'Performance Tuning for DBAs' started by ianneub, Mar 18, 2003.

  1. ianneub New Member

    Hello all,

    I'm trying to find the most costly queries being run on my SQL Server 2000 box as reported by Query Analyzer. First off, is that a good benchmark to be looking for? To find slow queries by duration seems like it wouldn't be as good because during periods of high load the server is bound to take more time to process a query.

    Anyway, I've got a trace running that uses the 'Performance: Show Plan Statistics' event and returns the 'binary data' data column. Is there any way that I can group the results by the highest cost queries? I checked MS's site and couldn't find any details on how to parse that binary data.

    Any help would be great. Thanks in advance.

    -Ian Neubert
  2. Chappy New Member

    As I understand it, duration is not the delta between end and start time. It is the amount of cpu time the query took to complete. I cant back this up with a reference from books online, but im sure its there somewhere.

    So yes, profiling by duration is a good starting point. Of course it wont cover all bases, some performance problems can be caused by a 2ms query being executed 100 times a second. We had a similar problem like this where a client app was grabbing one result set, and then in the client app was executing a secondary query for each row in the result set, when a simple join would have worked.

    Other useful things to keep an eye on are queries with high occurrences of disk read and writes, possibly indicating a table scan or badly designed indices. At this point you can rip the query out of profiler and run it through query analyser, to examine the execution plan in more detail. You can also log execution plans within your profile, which can be useful sometimes, but I generally find it just obfuscates the results im looking at, and often isnt useful to see it for every query occurring.

    I believe some of the predefined trace templates group by duration, you dont need to parse any binary data, as the duration is a seperate field all of its own.

    Hope this helps.
  3. bradmcgehee New Member

    You are on the right track. In Profiler, if you group by duration, it will show results in the order of the shortest to the longest duration queries. I often do this myself to look for long running queries. To make your job a little easier, consider only capturing queries that have a duration of over 5000 miliseconds (5 seconds) so that your screen won't be so cluttered.

    ------------------
    Brad M. McGehee
    Webmaster
    SQL-Server-Performance.Com
  4. josephobrien New Member

    I think finding the totality of service time is more important than finding the one worst performing stored proc.

    The process that I uses is as follows.
    1) Profile to Get the Duration of Stored Procs and SQL Batches saving the Data Elements Textdata, ApplicationName, Duration, CPU, Reads, Writes to a table typically in another database server (My PC). I typically just trace RPC Completed, SQL Batch Completed and perhaps SP-Statement Complete

    2) I run a query like the following - I adjust the width of the convert inorder to summarize similar calls with different arguments and filter on eventclass so that TextData just contains the SQL call..

    select convert(varchar(30), TextData),
    ApplicationName ,
    count(*) as "Execs",
    avg(Duration) as "Avg Duration",
    avg(CPU) as "AVG. CPU" ,
    avg(Reads) as "Avg Reads",
    avg(Writes) as "Avg Writes",
    sum(Reads+Writes) as "Total IO",
    sum(CPU) as "Service Time"
    from [TRACETABLE]
    -- where eventclass = 10 RPC Completed
    group by convert(varchar(30), TextData), ApplicationName
    order by "Service Time" desc


    I find the advantage of summarizing the data by stored procs or batch is that it is easy to find the total stored procedure calls that are using the most resources. For example - you may have a bad stored procedure that is a real pig (the worst in your profiling session), but if it is not called very often - your time would be better spent on the sub-optimal stored proc (one that is not really too bad) that is called very frequently. I had a situation with one of our web pages where three stored procedures were called to populated three status fields in a frame on a page. Each page automatically called the three stored procs every 10 seconds. Thing are ok until we get 20 or 30 users each calling the same stored procs every 10 seconds. So the increased rate of these calls where easily identified and quantified the load. I could show that the three little status fields where be callins the three stored procs 1800 times and hour and performed a ridiculous amount of IO.

    Enjoy,


    Joe E O
  5. ianneub New Member

    Thanks for the feedback everyone.

    Chappy, you sure about the duration not being a simple delta? I just ran a quick profile looking for SQL:BatchStarting, SQL:BatchEnding, and duration. It looks like the duration is the delta in miliseconds. I could be wrong though, I only checked a few (and there isn't too much load on the server right now).

    josephobrien, very cool, just what I needed. I added another column to that table "Weight" to help me pick out the queries I need to check first:

    select convert(varchar(30), TextData),
    ApplicationName ,
    count(*) as "Execs",
    avg(Duration) as "Avg Duration",
    avg(CPU) as "AVG. CPU" ,
    avg(Reads) as "Avg Reads",
    avg(Writes) as "Avg Writes",
    sum(Reads+Writes) as "Total IO",
    sum(CPU) as "Service Time",
    sum(CPU+Reads+Writes)*count(*) as "Weight"
    from [TRACETABLE]
    -- where eventclass = 10 RPC Completed
    group by convert(varchar(30), TextData), ApplicationName
    order by "Weight" desc

    I'm thinking I should weight the cpu time and IO time in order to make IO intesive opperations heavier, but I'm not quite sure how to compare these two values. What do you guys think?

    -Ian Neubert

    EDIT: Typo, should have multiplied to get Weight, not divide hehe
  6. Chappy New Member

    Sorry, it seems I am mistaken.
    I think duration IS simply how long it took until query was complete. There is a seperate CPU field for actual cpu time.

Share This Page