One interesting problem I am asked to troubleshoot sometimes is when a developer tells me that a stored procedure is timing out or taking too long to execute on a web application but returning immediately when executed directly in Management Studio. Even for the same parameters. Although there could be a few reasons for a problem like this to happen, including blocking, the most frequent one is related to a behavior in which the plan used by the web application was optimized using a combination of parameters which produced a “bad” plan for some other executions of the same stored procedure with different parameters. Although you may be tempted to just run sp_recompile to force a new optimization and allow the application to continue working, this does not really fix the problem and it may eventually come back. You could have also seen some similar scenarios where you have updated statistics, rebuild an index or changed something else to find out that suddenly the problem seems to be fixed. It is not. Those changes probably just forced a new optimization with the “good” parameter you were just testing. Obviously the best thing to do for this kind of problem is capturing the “bad” plan for further analysis in order to provide a permanent solution. In this post I will show you how to do that.
But first, a little bit of background. Remember that in general query optimization is an expensive operation and, in order to avoid this optimization cost, the plan cache will try to keep the generated execution plans in memory so they can be reused. So, if the stored procedure is executed thousands of times, only one optimization is needed. However, if a new connection running the same stored procedure has different SET options it may generate a new plan instead of reusing the one already on the plan cache. This new plan can be reused by later executions of the same stored procedure with the same connection settings. A new plan is needed as these SET options can impact the choice of an execution plan because they affect the results of evaluating constant expressions during the optimization process (a process known as constant folding and explained here). Another connection setting, FORCEPLAN, acts in a similar way to a hint, requesting the Query Optimizer both to preserve the join order as specified on the query syntax and to use nested loop joins only. As indicated in the Microsoft white paper Plan Caching in SQL Server 2008, the following SET options will affect the reuse of execution plans.
ANSI_NULL_DFLT_OFF
ANSI_NULL_DFLT_ON
ANSI_NULLS
ANSI_PADDING
ANSI_WARNINGS
ARITHABORT
CONCAT_NULL_YIELDS_NULL
DATEFIRST
DATEFORMAT
FORCEPLAN
LANGUAGE
NO_BROWSETABLE
NUMERIC_ROUNDABORT
QUOTED_IDENTIFIER
Unfortunately different management or development tools, like Management Studio, ADO.NET, or even sqlcmd, may have different SET options in their default configuration. You will find that mostly the problem is that one of the options, ARITHABORT, is OFF in ADO.NET and ON in Management Studio. So it may be possible that, in our example, Management Studio and the web application are using distinct cached plans and that the web application initially got a good plan for the parameters used during the optimization, but this plan is not good for some other executions of the same stored procedure with different parameters.
But now let us see how to prove that parameter sniffing is in fact the problem for your specific instance of the issue, and how to extract the plans to inspect both the parameters and the SET options used during optimization. Since AdventureWorks does not have the default SET options of a new database, let us create our own and copy some data from AdventureWorks
CREATE DATABASE Test GO
Create a new table and a stored procedure to test
USE Test GO SELECT * INTO dbo.SalesOrderDetail FROM AdventureWorks.Sales.SalesOrderDetail GO CREATE NONCLUSTERED INDEX IX_SalesOrderDetail_ProductID ON dbo.SalesOrderDetail(ProductID) GO CREATE PROCEDURE test (@pid int) AS SELECT * FROM dbo.SalesOrderDetail WHERE ProductID = @pid
Let us test two different applications, executing the stored procedure from a .NET application (C# code included at the end) and from Management Studio. For the purpose of this test we want to assume that a plan with a table scan is a bad plan and a plan using an index seek/RID lookup is the optimal one.
Start with a clean plan cache by running
DBCC FREEPROCCACHE
Run the .NET application from a command prompt window and provide the value 870 as a parameter (note that this application is only running the test stored procedure)
C:\TestApp\test Enter ProductID: 870
At this moment we can start inspecting the plan cache to see the plans available in memory. Run the following script from the Test database (we will be running this script again later during this exercise)
SELECT plan_handle, usecounts, pvt.set_options FROM ( SELECT plan_handle, usecounts, epa.attribute, epa.value FROM sys.dm_exec_cached_plans OUTER APPLY sys.dm_exec_plan_attributes(plan_handle) AS epa WHERE cacheobjtype = 'Compiled Plan') AS ecpa PIVOT (MAX(ecpa.value) FOR ecpa.attribute IN ("set_options", "objectid")) AS pvt where pvt.objectid = object_id('dbo.test')
You should get an output similar to this
plan_handle usecounts set_options 0x05000700210F0207B8C09007000000000000000000000000 1 251
The output shows that we have one execution plan in the plan cache, it has been used once (as indicated by the usecounts value), and the set_options value, taken from the sys.dm_exec_plan_attributes DMF, is 251. Since this was the first execution of the stored procedure, it was optimized using the parameter 870 which in this case created a plan using a table scan (consider here a “bad” plan). Now run the application again using a parameter that returns only a few records and will benefit from an index seek/RID lookup plan:
C:\TestApp\test Enter ProductID: 898
If you inspect the plan cache again you will notice that the plan has been used twice and unfortunately this time it was not good for the second parameter used
plan_handle usecounts set_options 0x05000700210F0207B8C09007000000000000000000000000 2 251
At this moment the developer may try to troubleshoot this problem by running the stored procedure in Management Studio using something like this
EXEC test @pid = 898
Now the developer is surprised to find that SQL Server is returning a good execution plan and the query is returning immediately. Inspecting the plan cache again will show something similar to this
plan_handle usecounts set_options 0x05000700210F0207B8C09007000000000000000000000000 2 251 0x05000700210F0207B860650B000000000000000000000000 1 4347
You can see that a new plan was added for the Management Studio execution, with a different value for set_options.
What to do next? It is time to inspect the plans and look at the SET options and parameters used during the optimization. Select the plan_handle of the first plan created (the one with set_options 251 in your own example) and use it to run the following query
select * from sys.dm_exec_query_plan (0x05000700210F0207B8C09007000000000000000000000000)
You can find the SET options at the beginning of the plan
<StatementSetOptions QUOTED_IDENTIFIER="true" ARITHABORT="false" CONCAT_NULL_YIELDS_NULL="true" ANSI_NULLS="true" ANSI_PADDING="true" ANSI_WARNINGS="true" NUMERIC_ROUNDABORT="false" />
And the used parameters at the end
<ParameterList> <ColumnReference Column="@pid" ParameterCompiledValue="(870)" /> </ParameterList>
Do the same for the second plan and you will get the following information for the SET options
<StatementSetOptions QUOTED_IDENTIFIER="true" ARITHABORT="true" CONCAT_NULL_YIELDS_NULL="true" ANSI_NULLS="true" ANSI_PADDING="true" ANSI_WARNINGS="true" NUMERIC_ROUNDABORT="false" />
and the following parameter information
<ParameterList> <ColumnReference Column="@pid" ParameterCompiledValue="(898)" /> </ParameterList>
This information shows that the ARITHABORT SET option has different value on these plans and that the parameter used to optimize the query on the web application was 870. (The same information is available from the Properties window of a graphical plan). You can also verify the operators used in the plan, the first one using a table scan and the second one an index seek/RID lookup combination.
Now that you have captured the plans you can force a new optimization so the application can use a better plan immediately (keeping in mind that this is not a permanent solution). Try this
sp_recompile test
So now you know that you have a problem related to parameter sniffing. What to do next? I have a few recommendations on previous posts here and here. I have another one here but usually you should not be doing this.
Finally, you can use the following script to display SET options for a specific set_options value
declare @set_options int = 251 if ((1 & @set_options) = 1) print 'ANSI_PADDING' if ((4 & @set_options) = 4) print 'FORCEPLAN' if ((8 & @set_options) = 8) print 'CONCAT_NULL_YIELDS_NULL' if ((16 & @set_options) = 16) print 'ANSI_WARNINGS' if ((32 & @set_options) = 32) print 'ANSI_NULLS' if ((64 & @set_options) = 64) print 'QUOTED_IDENTIFIER' if ((128 & @set_options) = 128) print 'ANSI_NULL_DFLT_ON' if ((256 & @set_options) = 256) print 'ANSI_NULL_DFLT_OFF' if ((512 & @set_options) = 512) print 'NoBrowseTable' if ((4096 & @set_options) = 4096) print 'ARITH_ABORT' if ((8192 & @set_options) = 8192) print 'NUMERIC_ROUNDABORT' if ((16384 & @set_options) = 16384) print 'DATEFIRST' if ((32768 & @set_options) = 32768) print 'DATEFORMAT' if ((65536 & @set_options) = 65536) print 'LanguageID'
C# Code
using System; using System.Data; using System.Data.SqlClient; class Test { static void Main() { SqlConnection cnn = null; SqlDataReader reader = null; try { Console.Write("Enter ProductID: "); string pid = Console.ReadLine(); cnn = new SqlConnection("Data Source=(local);Initial Catalog=Test; Integrated Security=SSPI"); SqlCommand cmd = new SqlCommand(); cmd.Connection = cnn; cmd.CommandText = "dbo.test"; cmd.CommandType = CommandType.StoredProcedure; cmd.Parameters.Add("@pid", SqlDbType.Int).Value = pid; cnn.Open(); reader = cmd.ExecuteReader(); while (reader.Read()) { Console.WriteLine(reader[0]); } return; } catch (Exception e) { throw e; } finally { if (cnn != null) { if (cnn.State != ConnectionState.Closed) cnn.Close(); } } } }