THE SQL Server Blog Spot on the Web

Welcome to SQLblog.com - The SQL Server blog spot on the web Sign in | |
in Search

Adam Machanic

Adam Machanic, Boston-based SQL Server developer, shares his experiences with programming, monitoring, and performance tuning SQL Server. And the occasional battle with the query optimizer.

Is This Normal? (A Month of Activity Monitoring, Part 17 of 30)

This post is part 17 of a 30-part series about the Who is Active stored procedure. A new post will run each day during the month of April, 2011. After April all of these posts will be edited and combined into a single document to become the basis of the Who is Active documentation.


There you are, minding your own business (and that of everyone else on your server) checking out activity with Who is Active.

Some stored procedure is running for what seems like an excessive amount of time—but you’re not quite sure. Should you take a closer look?

The answer can only be my favorite two-word phrase: It Depends.

If a system has been live for quite some time and users are happy enough with performance, I tend to not get too caught up in proactively trying to find things to tune. If, on the other hand, users are complaining, or something has just started taking a lot longer than it used to, then it’s time to step in and do some tuning.

Today’s post is about helping you figure out whether you’ve identified one of these latter cases: a query that was running fine, but is suddenly not doing so well. This can happen due to any number of root causes, the most common of which are outdated statistics and parameter sniffing. Actually fixing the problem is beyond the scope of this post, but identifying it is half the battle.

Who is Active’s @get_avg_time option is designed for this scenario. When enabled, a new column is added to the Who is Active output, [dd hh:mm:ss.mss (avg)]. This column reflects the average run time—if it’s available—of the statement that your request is currently working on. The idea is that if you’re not sure whether the current run time is an anomaly, you can compare it to how long previous runs have taken to figure out whether you have reason for concern. Note that this is only useful if the server happens to have cached statistics about prior runs. If the cache has been cleared recently due to a reboot, memory pressure, or someone changing the server configuration options, all bets are off.

To see the feature in action, we can simulate a basic parameter skew issue. Set up the following stored procedure in AdventureWorks:

USE AdventureWorks
GO

CREATE PROC #sniff_test
    @min_ProductID INT,
    @max_ProductID INT
AS
BEGIN
    SELECT
        p.ProductID,
        COUNT(th.TransactionID),
        COUNT(sod.SalesOrderID)
    FROM Production.Product AS p
    LEFT OUTER JOIN Production.TransactionHistory AS th ON
        th.ProductID = p.ProductID
    LEFT OUTER JOIN Sales.SalesOrderDetail AS sod ON
        sod.ProductID = p.ProductID
    WHERE
        p.ProductID BETWEEN @min_ProductID AND @max_ProductID
    GROUP BY
        p.ProductID
END
GO

Now exercise the procedure a few times to get a baseline:

EXEC #sniff_test
    @min_ProductID = 1,
    @max_ProductID = 700
GO 100

Once the baseline has been established you’ll have a nice set of statistics recorded in the cache. Changing the arguments ever-so-slightly will have an enormous impact on the run time:

EXEC #sniff_test
    @min_ProductID = 1,
    @max_ProductID = 800
GO

While that’s churning away, bring up a new window and run Who is Active using the @get_avg_time option.

EXEC sp_WhoIsActive
    @get_avg_time = 1

The result will be something like the following:

F17_01_avg1

From these results we can see that when I ran Who is Active the procedure had already been running for over two seconds. But the average time is a mere 59 milliseconds. Clearly, something is amiss. (And indeed it is: both an inappropriate plan and a ProductID range with a lot more information than the prior range that was used.)

 

Homework

Based on the number of questions I’ve received—or, more accurately, the complete silence—the @get_avg_time feature hasn’t gotten a lot of attention from many Who is Active users. Admittedly, while I have found it to be useful on a few occasions, I don’t use it much myself. And it is somewhat slow when run on a system with a large number of cached plans. But I do think it’s a worthwhile feature. If you’ve used it, please let me know in the comments below. I would very much like to hear about whether it helped you out, was completely worthless, or anything in-between.

Published Sunday, April 17, 2011 11:00 AM by Adam Machanic

Comment Notification

If you would like to receive an email when updates are made to this post, please register here

Subscribe to this post's comments using RSS

Comments

 

Anders Borum said:

Hi,

given the last paragraph in todays post I thought I'd step forward and thank you for the great work you're doing. Despite the apparent silence in the comments I think a lot people are following your series.

I'm not a DBA personally, although I spend a lot of time on top of SQL Server on a daily basis as a C# software architect; thus, i'm probably more of a casual lurker than actively engaging with questions :)

April 17, 2011 2:30 PM
 

Adam Machanic said:

Hi Anders,

Thank you for reading and for stepping (briefly?) out of the shadows! Enjoy :-)

--Adam

April 17, 2011 10:43 PM
 

Stephen Mandeville said:

Nice Work Adam and yes some DBAs are reading your series

Keep them coming

April 18, 2011 8:23 AM
 

Meher said:

I have been reading all the Posts by Adam and making my own notes. These are highly informative and advanced posts. Every DBA needs to read these posts.

I like to thank Adam for taking the strenuous effort and time to write these posts. This needs so much dedication and diligence to write them.

Thanks Adam.

Meher

April 21, 2011 4:35 PM
 

Adam Machanic said:

This post is part 30 of a 30-part series about the Who is Active stored procedure. A new post will run

April 30, 2011 11:45 AM
 

John Stanley said:

Simply incredible tool and series of posts. Thanks for all of your efforts.

May 17, 2011 10:57 AM
 

DBAGeek said:

Hi Adam,

It looks like classic parameter sniffing problem,

for this case interesting is information about compiled values from execution plan:

<ParameterList>

<ColumnReference

Column="@max_ProductID"

ParameterCompiledValue="(700)" />

<ColumnReference

Column="@min_ProductID"

ParameterCompiledValue="(1)" />

</ParameterList>

What do you think about displaying this additional info (I'm wondering about impact on performance,

It could hurt performance during searching execution plan)?

--

Regards DBAGeek

November 21, 2011 3:00 PM
 

Adam Machanic said:

Hi DBAGeek,

I agree that there is a lot of VERY useful information that could be mined from the query plan. Unfortunately, XQuery is expensive and I wouldn't want anyone doing that on a busy production system--so I've kept that kind of logic out of WIA. Perhaps some day MSFT will give us better XML support and we can do these kinds of things with less fear of causing problems.

November 21, 2011 5:05 PM
 

Wendy Barker said:

And some new DBAs looking through this stuff a year later.   Awesome stuff, thanks.   It will help our house tremendously when I get the power to baseline and monitor.   step by step though

September 11, 2012 11:39 AM

Leave a Comment

(required) 
(required) 
Submit

About Adam Machanic

Adam Machanic is a Boston-based SQL Server developer, writer, and speaker. He focuses on large-scale data warehouse performance and development, and is author of the award-winning SQL Server monitoring stored procedure, sp_WhoIsActive. Adam has written for numerous web sites and magazines, including SQLblog, Simple Talk, Search SQL Server, SQL Server Professional, CoDe, and VSJ. He has also contributed to several books on SQL Server, including "SQL Server 2008 Internals" (Microsoft Press, 2009) and "Expert SQL Server 2005 Development" (Apress, 2007). Adam regularly speaks at conferences and training events on a variety of SQL Server topics. He is a Microsoft Most Valuable Professional (MVP) for SQL Server, a Microsoft Certified IT Professional (MCITP), and an alumnus of the INETA North American Speakers Bureau.

This Blog

Syndication

Powered by Community Server (Commercial Edition), by Telligent Systems
  Privacy Statement