June 12, 2012 at 9:15 am
I was looking at SQL Profiler on our production SQL 2008 R2 server this morning and noticed one particular statement, run as part of the invoice printing process, routinely takes 3+ seconds to run. Thinking this odd, I copied the statement over to SSMS and ran it manually, confirming that this is in fact the case. Running the sp_executesql statement pasted below seems to take between 1800 and 3000 ms.
But here's the weird thing. If I open a new tab in SSMS, point it to the same connection, break the statements out of the enclosing sp_executesql and run them by declaring the parameters with the same data type and value, the exact same T-SQL statement takes between 70 and 85 ms to complete.
The execution plan and client statistics look exactly the same
Why would it matter if the batch is enclosed in sp_executesql or not?
Thanks in advance,
Andre Ranieri
exec sp_executesql N'CREATE TABLE #Tmp1 (Counter int PRIMARY KEY CLUSTERED IDENTITY (1,1), AccountKey int, ARDate DateTime, ARDesc varchar(50), ARAmount money, ARTax money)
INSERT INTO #Tmp1 ( AccountKey, ARDate, ARDesc, ARAmount, ARTax )
SELECT tblMainServices.AccountKey, tblMainServices.DateCompleted, tblMainServices.Service, tblMainServices.AmountCompleted, tblMainServices.TaxCompleted
FROM tblMainServices
WHERE tblMainServices.DateCompleted >= @MinDate And (tblMainServices.PriceAdjustmentDescription Is Null Or tblMainServices.PriceAdjustmentDescription <> ''Skipped'')
AND tblMainServices.AccountKey = @AccountKey
ORDER By tblMainServices.DateCompleted;
INSERT INTO #Tmp1 ( AccountKey, ARDate, ARDesc, ARAmount, ARTax )
SELECT tblSupportServiceTransactions.AccountKey, tblSupportServiceTransactions.Date, tblSupportServiceTransactions.TransactionID, tblSupportServiceTransactions.Amount * -1, 0
FROM tblSupportServiceTransactions
WHERE tblSupportServiceTransactions.Date >= @MinDate AND tblSupportServiceTransactions.AccountKey IN (SELECT AccountKey FROM #Tmp1 A
GROUP BY A.AccountKey)
ORDER By tblSupportServiceTransactions.Date
SELECT TOP 5 AccountKey, ARDate, ARDesc, ARAmount, ARTax
FROM #Tmp1
ORDER BY ARDate DESC;
DROP TABLE #Tmp1',N'@AccountKey int,@MinDate datetime',@AccountKey=271272,@MinDate='2012-01-01 00:00:00'
June 12, 2012 at 9:17 am
Could well be inappropriate cached plan.
Please post table definitions, index definitions and execution plan (of the slow one), as per http://www.sqlservercentral.com/articles/SQLServerCentral/66909/
Gail Shaw
Microsoft Certified Master: SQL Server, MVP, M.Sc (Comp Sci)
SQL In The Wild: Discussions on DB performance with occasional diversions into recoverability
June 12, 2012 at 9:32 am
Done - I uploaded a ZIP file.
Here's another weird thing and perhaps a clue: if I modify the sp_executesql statement to explicitly declare the parameters as shown in the snippet pasted below, the statement executes in less than 100 ms.
How would I flush the cache on an execution plan?
Thanks again,
Andre Ranieri
exec sp_executesql N'
DECLARE @AccountKey int, @MinDate datetime
SET @AccountKey = 271272;
SET @MinDate = ''1/1/2012''
CREATE TABLE #Tmp1 (Counter int PRIMARY KEY CLUSTERED IDENTITY (1,1), AccountKey int, ARDate DateTime, ARDesc varchar(50), ARAmount money, ARTax money)
INSERT INTO #Tmp1 ( AccountKey, ARDate, ARDesc, ARAmount, ARTax )
SELECT tblMainServices.AccountKey, tblMainServices.DateCompleted, tblMainServices.Service, tblMainServices.AmountCompleted, tblMainServices.TaxCompleted
FROM tblMainServices
WHERE tblMainServices.DateCompleted >= @MinDate And (tblMainServices.PriceAdjustmentDescription Is Null Or tblMainServices.PriceAdjustmentDescription <> ''Skipped'')
AND tblMainServices.AccountKey = @AccountKey
ORDER By tblMainServices.DateCompleted;
INSERT INTO #Tmp1 ( AccountKey, ARDate, ARDesc, ARAmount, ARTax )
SELECT tblSupportServiceTransactions.AccountKey, tblSupportServiceTransactions.Date, tblSupportServiceTransactions.TransactionID, tblSupportServiceTransactions.Amount * -1, 0
FROM tblSupportServiceTransactions
WHERE tblSupportServiceTransactions.Date >= @MinDate AND tblSupportServiceTransactions.AccountKey IN (SELECT AccountKey FROM #Tmp1 A
GROUP BY A.AccountKey)
ORDER By tblSupportServiceTransactions.Date
SELECT TOP 5 AccountKey, ARDate, ARDesc, ARAmount, ARTax
FROM #Tmp1
ORDER BY ARDate DESC;
DROP TABLE #Tmp1'
June 12, 2012 at 9:38 am
I can't see the need for dynamic sql here.
;WITH MainServices AS (
SELECT m.AccountKey, m.DateCompleted, m.[Service], m.AmountCompleted, m.TaxCompleted
FROM tblMainServices m
WHERE m.DateCompleted >= @MinDate
AND (m.PriceAdjustmentDescription IS NULL OR m.PriceAdjustmentDescription <> 'Skipped')
AND m.AccountKey = @AccountKey)
SELECT TOP 5 AccountKey, ARDate, ARDesc, ARAmount, ARTax
FROM (
SELECT
m.AccountKey,
ARDate= m.DateCompleted,
ARDesc= m.[Service],
ARAmount= m.AmountCompleted,
ARTax= m.TaxCompleted
FROM MainServices m
UNION ALL
SELECT
s.AccountKey,-- may have to CAST as same type as m.AccountKey
s.[Date],-- may have to CAST
s.TransactionID, -- may have to CAST
s.Amount * -1,-- may have to CAST
0-- may have to CAST
FROM tblSupportServiceTransactions s
WHERE s.[Date] >= @MinDate
AND s.AccountKey IN (SELECT AccountKey FROM MainServices)
) d
ORDER BY ARDate DESC;
For fast, accurate and documented assistance in answering your questions, please read this article.
Understanding and using APPLY, (I) and (II) Paul White
Hidden RBAR: Triangular Joins / The "Numbers" or "Tally" Table: What it is and how it replaces a loop Jeff Moden
June 12, 2012 at 9:46 am
Holy smokes - your statement ran in 4-8 ms, compared to the original 'fast' one taking 73-85 ms
I'm still wondering why the exact same statement would have different execution duration whether it's inside an sp_executesql or not, or faster if the parameters are declared dynamically.
June 12, 2012 at 10:02 am
Parameter sniffing.
Gail Shaw
Microsoft Certified Master: SQL Server, MVP, M.Sc (Comp Sci)
SQL In The Wild: Discussions on DB performance with occasional diversions into recoverability
June 12, 2012 at 10:50 am
Possibly; running Chris' T-SQL statement with dynamic parameters shows 1686 reads in Profiler, compared to 388160 reads when the parameters are passed in from the exec sp_ExecuteSQL statement.
Profiler shows the duration being over 15 ms and over 500 ms for the parameters being dynamic and passed in, respectively.
Again, your input is much appreciated. This has become an intellectual curiosity as much as anything.
Andre Ranieri
June 12, 2012 at 11:07 am
Parameter sniffing might have just been what caused a 30X increase in duration for this statement.
Again, out of intellectual curiosity, I changed my code to declare a second datetime parameter at the beginning of the statement.
I then set the new @d parameter value to the same value as the @mindate input parameter.
The rest of the statement references the new @d parameter instead of the input parameter.
My changes were made based on documentation found here: http://www.simple-talk.com/sql/t-sql-programming/parameter-sniffing/[/url]
The execution duration dropped from 500 - 800 ms down to below 15 ms on average.
Wow.
Thanks again for helping point me in the right direction.
Andre Ranieri
exec sp_executesql N'
DECLARE @d datetime
SET @d = @MinDate
;WITH MainServices AS (
SELECT m.AccountKey, m.DateCompleted, m.[Service], m.AmountCompleted, m.TaxCompleted
FROM tblMainServices m
WHERE m.DateCompleted >= @d
AND (m.PriceAdjustmentDescription IS NULL OR m.PriceAdjustmentDescription <> ''Skipped'')
AND m.AccountKey = @Accountkey )
SELECT TOP 5 AccountKey, ARDate, ARDesc, ARAmount, ARTax
FROM (
SELECT
m.AccountKey,
ARDate= m.DateCompleted,
ARDesc= m.[Service],
ARAmount= m.AmountCompleted,
ARTax= m.TaxCompleted
FROM MainServices m
UNION ALL
SELECT
s.AccountKey,-- may have to CAST as same type as m.AccountKey
s.[Date],-- may have to CAST
s.TransactionID, -- may have to CAST
s.Amount * -1,-- may have to CAST
0-- may have to CAST
FROM tblSupportServiceTransactions s
WHERE s.[Date] >= @d
AND s.AccountKey IN (SELECT AccountKey FROM MainServices)
) d
ORDER BY ARDate DESC; ',N'@AccountKey int,@MinDate datetime',@AccountKey=32458,@MinDate='2012-01-01 00:00:00'
June 12, 2012 at 11:15 am
Just a little quibble. CTE's don't start with a statement terminator (;). Here is the code you posted slightly modified.
exec sp_executesql N'
DECLARE @d datetime;
SET @d = @MinDate;
WITH MainServices AS (
SELECT m.AccountKey, m.DateCompleted, m.[Service], m.AmountCompleted, m.TaxCompleted
FROM tblMainServices m
WHERE m.DateCompleted >= @d
AND (m.PriceAdjustmentDescription IS NULL OR m.PriceAdjustmentDescription <> ''Skipped'')
AND m.AccountKey = @Accountkey )
SELECT TOP 5 AccountKey, ARDate, ARDesc, ARAmount, ARTax
FROM (
SELECT
m.AccountKey,
ARDate = m.DateCompleted,
ARDesc = m.[Service],
ARAmount = m.AmountCompleted,
ARTax = m.TaxCompleted
FROM MainServices m
UNION ALL
SELECT
s.AccountKey, -- may have to CAST as same type as m.AccountKey
s.[Date], -- may have to CAST
s.TransactionID, -- may have to CAST
s.Amount * -1, -- may have to CAST
0 -- may have to CAST
FROM tblSupportServiceTransactions s
WHERE s.[Date] >= @d
AND s.AccountKey IN (SELECT AccountKey FROM MainServices)
) d
ORDER BY ARDate DESC; ',N'@AccountKey int,@MinDate datetime',@AccountKey=32458,@MinDate='2012-01-01 00:00:00'
June 12, 2012 at 11:18 am
Thanks - I was wondering about that.
BTW Lynn - I read your blogs religiously. Loved the one about deleting millions of rows in a batch without causing huge table locks. I used that technique to clear out years' worth of old audit logs from our CRM system.
Cheer,s
Andre
Viewing 10 posts - 1 through 9 (of 9 total)
You must be logged in to reply to this topic. Login to reply