Rahman Agoro, the frontline SQL DBA

Just another WordPress.com weblog

Slow query performance from application but fast from management studio, what is happening ?

Throughout my DBA career, I have had to deal with different kind of issues, one of the weird ones that I have come across is when a query/stored procedure especially runs very slow from an application, but when starting SQL profiler to see the query itself and running it from management studio, its pretty fast. Hmmn, one steps back and thinks, what is going on here ?

Here is my approach to the problem, I have already written articles about parameter sniffing and this one is slightly different.

The first thing I do is check so see what the query plan of the query looks like.

First step is to find the object ID of the stored procedure.


Use Database
select OBJECT_ID('spStoredProcedure')

GO
sp_helpdb
 

I then query the meta data information on the database to pull out the query plan. You can get the dbid by running sp_helpdb and getting the database ID of where the stored procedure is.


USE master;
GO
SELECT refcounts,usecounts,objectid,query_plan,plan_handle
FROM sys.dm_exec_cached_plans cp CROSS APPLY sys.dm_exec_query_plan(cp.plan_handle)
WHERE objectid = 2002106173
and dbid  = 12

 

From here, we can see that 2 query plans has been returned by the query.

Now, when I see 2 query plans for a stored procedure, two things come to my mind.

Parameter sniffing or invalid plans due to set options
The fact that I’m able to run the same query from query analyser and it runs fine, this proves to me that its something to do with set options. But default in management studio certain set options are set when you open up a new query window, this can be seen by following
Tools >> Options >> Query Execution and right under Advanced you can see the options which are checked by default.


But how can I prove this, see below.
There is a DMV table which stores the query plan attributes, this can be queries as follows.

I am passing the plan handle to the DMV below.

A plan_handle is a hash value derived from the compiled plan for a group of SQL statements or “Batch” . It uniquely identifies the Query Plan (steps the SQL Server’s optimization engine has created for executing the SQL). Included in the plan_handle value is a complex type composed of bits representing some of the Set Options (ANSI_NULLS, ANSI_PADDING, ARITH_ABORT, etc.).

select * from sys.dm_exec_plan_attributes(0x050008003DB75577404141DC020000000000000000000000)
select * from sys.dm_exec_plan_attributes(0x050008003DB755774041C4D7000000000000000000000000)

 

One of the major differences that we can see is that the set options are different.

In one case we can see that the set_options is 4347 and in the other query plan the set option is 251. A quick visit to Ms website tells me the meaning of the set options.

There is a one-to-many relationship between sql_handle and sql_plan. Identical SQL will result in the same sql_handle, but differences in set options, etc. can result in different Query Plans and therefore different plan_handle values.

http://msdn.microsoft.com/en-us/library/foodacf3ab3-f214-482e-aab5-0dab9f0a3648.aspx

We can also work this out ourselves as well.

Notice that the only difference is the set_options. In order to see what bit(s) are different between the values 4347 and 251, it helps to open the CALC application and view each in binary. In this case, it is:
1000011111011
0000011111011
This difference in decimal is 4096, as seen in the MS link above, 4096 equates to ARITH_ABORT, since ARITH_ABORT is set to ON by default, I can change this by turning if OFF and then running the stored procedure again to see what the outcome of the query will be.

SET ARITHABORT OFF

exec spStoredProcedure @CustomerNo=28133,@Date='2010-08-24 00:38:09'

 

By running the query I was able to reproduce the problem and see the query return in well over 30 seconds, this is because its using the bad query plan.

Running the same query again with SET ARITHABORT ON, the query completed in no time because it was using the good query plan.


SET ARITHABORT ON
exec spStoredProcedure@CustomerNo=28133,@Date='2010-08-24 00:38:09'
 

Summary

When situations like this occur, one has to really understand what is actually happening and I believe the query above will help towards troubleshooting the problem.

Once you know the query plan which is bad, there are 2 ways to remove the query plan all together, one option is to run dbcc freeproccache
I generally do not recommend it as it then forces all objects to generate a new query plan.

A new option with ships with SQL 2008 allows you to clear the query plan for a specific database or even better a specific query.

I prefer to remove bad specific queries, this means that all the good query plans on my database can be reused without any interruptions. In order to remove a bad query plan, run the code below

— Remove the specific plan from the cache using the plan handle


DBCC FREEPROCCACHE (plan_handle);
 

Other options include adding recompile to the stored procedure such that every time it is called, it generates a new plan, there is a cost to this option as you have to create a new plan. Alternatively the application can be changed such that it uses the correct set option, in this case the application properties can be changed such that it turns on SET ARITHABORT ON by default.

8 Responses to “Slow query performance from application but fast from management studio, what is happening ?”

  1. Brian Davey said

    Awesome article!
    I’ve been trying to figure this out for a day and a half.

    Thank You Very Much!

  2. Raj said

    I’m facing the same problem, my stored procedure runs slow when called by application and fast in management studio, but only one execution plan in my case, what could be the other problem areas ?

    • Raj said

      more-over same duration is captured in profiler for the RPC that is executed by application, not sure wht is happening.

      • Are you saying that when you checked profiler, there duration from both the application duration is thesame as that of SSMS ?

        One thing you can do, run sp_recompile ‘proc_name’ and then run the application first and not from SSMS, lets see if a sub-optimal plan is being used.

  3. Mark said

    This article was awesome. Thank you for sharing. This saved me hours and hours of time, and really peaked my interest in understanding this more. Great job.

  4. Hussain said

    I don’t know if any one is going to reply since it is very old. But, this is awesome article, we just fixed the same problem.

    The only thing we did was re-index and the problem started happening from next day..NET was passing ARITHABORT OFF. My proc took 10 seconds to complete in SSMS but took >2 minutes from application. Having said that , since our maintenance plan (re-indexing happens every weekend). I am assuming i will run into this problem again. How can i mitigate or how can i make sure that the good execution plan(current one) is used for this PROC.

    Thanks,

  5. Roisin said

    Excellent! This worked perfectly, thank you!

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s

 
%d bloggers like this: