Next Generation IT Consultant My thoughts on SQL Server, SharePoint, .NET…

One of our customers had problems with his custom application. One of the stored procedures caused random timeouts in this application, but in SSMS the stored procedure always completed in just a few seconds. After attaching SQL Server Profiler it turned out that different execution plans were used for SSMS and the application, but the parameter values were exactly the same. The customer had already checked that recompiling the stored procedure or restarting the whole server did help for a while.

There are two cases to consider here:

1. The stored procedure is causing timeouts, so it should probably be optimized
2. The stored procedure always executes quickly in SSMS, so is doesn’t seem to be an optimization problem

Let’s illustrate that with a quick example. For the purpose of this post I’ve prepared a stored procedure that retrieves some data about the products and sales orders from AdventureWorks2008:

USE AdventureWorks2008;
GO
CREATE PROCEDURE dbo.GetOrderedProducts(
	@ProductName dbo.Name,
	@ProductNumber NVARCHAR(25),
	@ProductDaysToManufacture INT,
	@ProductCategoryName dbo.Name,
	@ProductSubcategoryName dbo.Name,
	@OnlineOrderFlag dbo.Flag
)
AS
BEGIN
	SELECT
		ProductName = p.Name, 
		p.ProductNumber,
		p.DaysToManufacture,
		ProductSubcategoryName = ps.Name,
		ProductCategoryName = pc.Name,
		sod.CarrierTrackingNumber,
		sod.OrderQty,
		sod.UnitPrice,
		soh.OrderDate,
		soh.DueDate,
		soh.ShipDate,
		soh.OnlineOrderFlag,
		soh.SalesOrderNumber,
		soh.SubTotal,
		soh.TaxAmt,
		soh.Freight
	FROM
		Sales.SalesOrderHeader soh
		INNER JOIN Sales.SalesOrderDetail sod ON soh.SalesOrderID = sod.SalesOrderID
		INNER JOIN Production.Product p ON sod.ProductID = p.ProductID
		INNER JOIN Production.ProductSubcategory ps ON p.ProductSubcategoryID = ps.ProductSubcategoryID
		INNER JOIN Production.ProductCategory pc ON ps.ProductCategoryID = pc.ProductCategoryID
	WHERE
		((p.Name LIKE @ProductName) OR (@ProductName IS NULL))
		AND ((p.ProductNumber LIKE @ProductNumber) OR (@ProductNumber IS NULL))
		AND ((p.DaysToManufacture = @ProductDaysToManufacture) OR (@ProductDaysToManufacture IS NULL))
		AND ((pc.Name LIKE @ProductCategoryName) OR (@ProductCategoryName IS NULL))
		AND ((ps.Name LIKE @ProductSubcategoryName) OR (@ProductSubcategoryName IS NULL))
		AND ((soh.OnlineOrderFlag = @OnlineOrderFlag) OR (@OnlineOrderFlag IS NULL));
END;

Now, let’s execute this procedure for a particular product and limit the orders to those that were not made online:

USE AdventureWorks2008;
GO
EXEC dbo.GetOrderedProducts NULL, 'BK-T44U-46', NULL, 'Bikes', 'Touring Bikes', 0;

That execution will output just a fraction (186 rows) of the whole result set (121317 rows). Our next step – let’s retrieve the whole result set:

USE AdventureWorks2008;
GO
EXEC dbo.GetOrderedProducts NULL, NULL, NULL, NULL, NULL, NULL;

It took about 10 seconds to retrieve the whole result set on my laptop. Normally it should take about 3 seconds. What’s going on? Actually, this happens because of parameter sniffing.

When the stored procedure is compiled (or recompiled), the query optimizer tries to generate an efficient query plan for the current parameter values (and that’s parameter sniffing – you can read more about it and other related issues in an excellent TechNet article). That query plan is cached and subsequent executions of this procedure will likely try to use the same query plan (but there are cases where another query plan will be generated and used – procedure recompilation, for example).

Sounds good? Well, not exactly. That specific stored procedure will surely receive varying parameter values, so the initial query plan might not be the best one for other parameter values. We can quickly see the actual cached execution plan being used by querying some DMVs:

USE master;
GO
SELECT 
	UseCounts,
	RefCounts, 
	Cacheobjtype, 
	Objtype, 
	DatabaseName = ISNULL(DB_NAME(dest.dbid), 'ResourceDB'), 
	[SQL] = [TEXT],
	QueryPlan = query_plan 
FROM sys.dm_exec_cached_plans 
	CROSS APPLY sys.dm_exec_sql_text(plan_handle) dest
	CROSS APPLY sys.dm_exec_query_plan(plan_handle)
WHERE 
	DB_NAME(dest.dbid) = 'AdventureWorks2008'
ORDER BY 
	UseCounts DESC;

Querying dm_exec_cached_plans will show us a list of all cached execution plans. After joining the results with dm_exec_sql_text and dm_exec_query_plan we receive additional valuable information – the SQL batch text and the graphical query plan.

When we display the query plan that is currently cached, we will notice a Nested Loops operation with an Estimated Number of Rows = 456. That is an efficient operation when the table being iterated is small and the table being scanned is properly indexed. That might be true for the first execution of our procedure, but not for the second, when we want to retrieve the whole result set.

Now, let’s mark this procedure for recompilation:

USE AdventureWorks2008;
GO
EXEC SP_RECOMPILE N'dbo.GetOrderedProducts';

And execute the procedure again:

USE AdventureWorks2008;
GO
EXEC dbo.GetOrderedProducts NULL, NULL, NULL, NULL, NULL, NULL;

Now the execution completes in about 3 seconds. After querying the DMVs again we will find out that the execution plan has changed – instead of a Nested Loops operation we now have a Hash Match operation with an Estimated Number of Rows = 39909. If you need a more detailed analysis of both query plans, another article (by Grant Fritchey) might come in handy.

How to deal with similar issues related to parameter sniffing? The recommended solution is to add the WITH RECOMPILE clause to our stored procedure. We won’t take advantage of caching query plans, but at least the query optimizer will try to generate an efficient execution plan for each set of parameter values that is supplied to the procedure.

What about the problem mentioned in the post title? Well, one of the possible reasons for recompilation is a change in the SET options. Your application connects to SQL Server by using an appropriate provider (OLE DB, ODBC or others). That provider sets six database options by default:

SET ANSI_NULLS ON
SET ANSI_PADDING ON
SET ANSI_WARNINGS ON
SET CONCAT_NULL_YIELDS_NULL ON
SET NUMERIC_ROUNDABORT OFF
SET QUOTED_IDENTIFIER ON

But there is another option (ARITHABORT) which is not set by default. The setting to use is determined from the default database options (for AdventureWorks2008 it will be ON by default, but for a new database it is OFF by default). That might result in a different ARITHABORT setting in your application and in SSMS, because in SSMS ARITHABORT is ON by default for each query window (Tools->Options->Query Execution->SQL Server->Advanced):

When those settings differ between your app and SSMS, your stored procedure could time out in the application and execute quickly in SSMS (or vice versa). When you check out the DMVs, two plans for this procedure will be cached – one for each ARITHABORT setting. And that explains the difference in execution times.