Identifying query compile/runtime parameter values using XML SHOWPLAN output.

I recently returned from Convergence 2010; the annual North American Microsoft Dynamics User Conference in Atlanta. It was a really great conference with many Customer, Partner, and Microsoft presentations and success stories. It was inspiring to see what Microsoft Dynamics products are being used for in the real world. I presented a number of sessions focused on Dynamics/SQL performance, and it became very apparent to me that XML SHOWPLAN, a highly useful feature of SQL Server, is not well understood and not being used to identify a common issue related to parameter sniffing. You can find more info regarding parameter sniffing here: (https://blogs.msdn.com/queryoptteam/archive/2006/03/31/565991.aspx)

Basically, the issue revolves around the fact that SQL Server caches the query plan that was first sent to SQL Server and compiled. This helps performance by not recompiling the same query each time it is issued. However, this also means that the execution plans get created taking into account the very first parameter values that were passed to the query. In most cases this works fine, however there are other cases where this has known to cause problems, as the example below will show.

Newer versions of Microsoft Dynamics NAV have solved the parameter sniffing issue by using the new-in SQL Server 2008 ‘OPTIMIZE for UNKNOWN’ hint, which I previous blogged about here: (https://blogs.msdn.com/mssqlisv/archive/2008/11/26/optimize-for-unknown-a-little-known-sql-server-2008-feature.aspx), however I believe that understanding what to look for in the XML SHOWPLAN output helps to better understand and diagnose problems related to cached parameterized query reuse.

NOTE: the information presented below is not specific to Microsoft Dynamics products and is applicable to any SQL DBA that deals with parameterized queries.

The SQL Server optimizer will create query plan specific output in XML that is quite detailed and it contains many more details about the query plan that are not exposed in the simpler SHOWPLAN_ALL or SHOWPLAN_TEXT output, in particular:

<ParameterList>

<ColumnReference Column="@P5" ParameterCompiledValue="'1753-01-01 00:00:00.000'" ParameterRuntimeValue="'2010-04-01 11:01:05.000'" />

As you might imagine, the data above relates to the parameter [Column="@P5"] used to compile a given query execution plan, the value that was used to originally compile the plan [ParameterCompiledValue="'1753… ] and the parameter value that was used during this invocation of the query [ParameterRuntimeValue="'2010… ].

XML SHOWPLAN is fully documented here: (https://msdn.microsoft.com/en-us/library/ms187757.aspx)

Let’s have look at a few examples to see how to use this functionality. I am using the same basic data presented in the ‘OPTIMIZE for UNKNOWN’ blog listed above:

(https://blogs.msdn.com/mssqlisv/archive/2008/11/26/optimize-for-unknown-a-little-known-sql-server-2008-feature.aspx).

The scenario is: I am a DBA interested in understanding why on some days a query runs great, but on other days it runs much slower. In many cases, this is caused by query execution plans being compiled and cached with non-optimal initial parameter values. The outcome of this phenomenon is that SQL Server will compile and cache a ‘good’ plan for the first parameter values. Unfortunately, this can have the unintended side-effect of caching a poor execution plan for all subsequent parameter values. To make this clearer let’s look at the following example;

CREATE PROCEDURE AllFromT

@p1 int,

@p2 int

AS

SELECT * FROM t WHERE col1 > @p1 or col2 > @p2 ORDER BY col1

GO

Let’s assume, for simplicities sake, that the table consists of three columns (col1, col2, col3), col1 is unique, col2 has 1000 distinct values, col3 contains a single default value, there are 10,000,000 rows in the table, the clustered index consists of col1, and a nonclustered index exists on col2.

Imagine the query execution plan created for the following initially passed parameters: @P1= 1 @P2=99

These values would result in an optimal queryplan for the statement contained in the stored procedure using the substituted parameters:

SELECT * FROM t WHERE col1 > 1 or col2 > 99 ORDER BY col1

Now, imagine the query execution plan if the initial parameter values were: @P1 = 9890000 and @P2 = 550.

Likewise, an optimal queryplan would be created after substituting the passed parameters:

SELECT * FROM t WHERE col1 > 9890000 or col2 > 550 ORDER BY col1

These two identical parameterized SQL Statements would potentially create and cache very different execution plans due to the difference of the initially passed parameter values. Both query plans are valid (and in fact; good) for the parameter values that were passed, but may not be optimal for subsequent invocations of the query. This can be a particular problem if the initially passed parameters are such that the query returns no results.

The ways to work-around the issue are described my previously listed blog; the examples below help you detect whether this is the issue by identifying the initial and subsequently passed parameter values.

The test below does the following:

· Creates the table, indexes, and data

· Creates a stored procedure that contains a parameterized query

· Runs the stored procedure using different parameter values

· Has you create an ‘Execution Plan.xml’ file – pay attention to the differences in:

<ParameterList>

<ColumnReference Column="@p2" ParameterCompiledValue="(589)" ParameterRuntimeValue="(1000)" />

<ColumnReference Column="@p1" ParameterCompiledValue="(500000)" ParameterRuntimeValue="(1670000)" />

</ParameterList>

· Clears the Procedure cache

· Runs the stored procedure using the same parameter values as above but in different order

· Has you create an ‘Execution Plan.xml’ file

This example clearly shows how different parameter values can cause vastly different plans to be cached and by looking at and understanding the XML output you can make better decisions about whether parameter sniffing is a source of query performance issues in your databases.

NOTE: the XML output can also be created using various SQL Server Trace events, as well as looking in the SQL Server DMV’s.

TEST:

It’s best to run each step below individually (that is; between the comments). This repro has 1,000,000 rows in the table not 10,000,000 as described above, however the same end-results are demonstrated.

--create the table and the data

--!!!!Please be aware that the data creation

--!!!!may take more than a few minutes

--On my laptop it took approximately 20 minutes to create the data

CREATE TABLE t (col1 int, col2 int, col3 int)

GO

DECLARE @i INT

DECLARE @i2 INT

DECLARE @id INT

DECLARE @id2 INT

SET @i = 1

SET @i2 = 0

SET @id = 0

SET @id2 = 0

WHILE @i < 1001

BEGIN

SET @id2 = @id2 + 1

WHILE @i2 < 1000

BEGIN

SET @id = @id + 1

SET @i2 = @i2 + 1

INSERT INTO t VALUES (@id,@id2,73)

END

SET @i = @i + 1

SET @i2 = 0

END

GO

--create the indexes

CREATE CLUSTERED INDEX clind ON t(col1)

GO

CREATE INDEX ind1 ON t(col2)

GO

--create the stored procedure

CREATE PROCEDURE AllFromT

@p1 int,

@p2 int

AS

SELECT * FROM t WHERE col1 > @p1 or col2 > @p2 ORDER BY col1

GO

--!!!! Make sure you turn on ‘Include actual execution plan’

--!!!! before running the stored procedure

--run the stored procedure with non-typical values

EXEC AllFromT 1670000,1000

--Now look at the actual execution plan it should look like:

clip_image002

--This is a great plan for these parameter values

--Now run the stored procedure with more-typical values

EXEC AllFromT 500000,589

--Now look at the actual execution plan,

--it will be the same as above because it is using the cached plan

--However this time:

--Right click on the execution plan

--Now click on 'Show Execution Plan XML...'

--A new tab will open called 'Execution Plan.xml'

--In here look for the following:

<ParameterList>

<ColumnReference Column="@p2" ParameterCompiledValue="(1000)" ParameterRuntimeValue="(589)" />

<ColumnReference Column="@p1" ParameterCompiledValue="(1670000)" ParameterRuntimeValue="(500000)" />

</ParameterList>

--Another thing to look at, which is exposed in the actual showplan details

--is the detail regarding how many rows the optimizer thought it would

--retrieve vs. the actual number it did retrieve.

--in the case above because the plan was created for non typical values

--the estimated number of rows and actual numeber are way off, that is

--often an indication that this query plan is not optimal and could be

--improved by a recompile, or plan hint

--look for the following values:

EstimateRows and the matching ActualRows

--looking at the XML output for the second query above you will see

-- EstimateRows = "2" or less, but the matching ActualRows are much higher

<RelOp AvgRowSize="19" EstimateCPU="2E-07" EstimateIO="0" EstimateRebinds="0" EstimateRewinds="0" EstimateRows="2" LogicalOp="Concatenation" NodeId="3" Parallel="false" PhysicalOp="Concatenation" EstimatedTotalSubtreeCost="0.0065664">

<OutputList>

<ColumnReference Column="Uniq1002" />

<ColumnReference Database="[master]" Schema="[dbo]" Table="[t]" Column="col1" />

<ColumnReference Database="[master]" Schema="[dbo]" Table="[t]" Column="col2" />

</OutputList>

<RunTimeInformation>

<RunTimeCountersPerThread Thread="0" ActualRows="911000" ActualEndOfScans="1" ActualExecutions="1" />

</RunTimeInformation>

--Now let’s reverse the order, but first lets clear the procedure cache

DBCC FREEPROCCACHE

GO

EXEC AllFromT 500000,589

--Now look at the actual execution plan, it should be very different

clip_image004

--Note that the optimizer determined that it is ‘cheaper’ to do a table scan

--based on the passed parameter values. Based on the number of ActualRows read

--in the second example above, this seems like a good choice

--Now run the stored procedure with non-typical values

EXEC AllFromT 1670000,1000

--Now look at the actual execution plan, it should be the same

--Right click on the execution plan

--Now click on 'Show Execution Plan XML...'

--A new tab will open called 'Execution Plan.xml'

--In here look for the following:

<ParameterList>

<ColumnReference Column="@p2" ParameterCompiledValue="(589)" ParameterRuntimeValue="(1000)" />

<ColumnReference Column="@p1" ParameterCompiledValue="(500000)" ParameterRuntimeValue="(1670000)" />

</ParameterList>

I hope that the examples above give the reader a better understanding of what may be occurring in their SQL Server implementation, and another tool (XML Showplan) to determine differences  in estimated/actual number of rows retrieved as well as pointing out the ability to determine compiled vs. runtime paramater values.