December 1, 2015 at 2:21 pm
Hello all,
I ran into the strangest thing this morning. Users reported that something that has been running in less than 1 minute for years is now taking 2.5 hours. I found the problem but I don't understand it.
This runs in about 10 seconds.
Select count(*) from myView where TransactTotal <> OnHandTotal
This used to run in about 10 seconds but now takes 2.5 hours, regardless of what is betwen the Begin/End statements.
if (select count(*) from myView where TransactTotal <> OnHandTotal) > 0
Begin
-- Do stuff
End
But this takes just about 10 seconds.
Declare @vCount int
Select @vCount = count(*) from myView where TransactTotal <> OnHandTotal > 0
if @vCount > 0
Begin
-- Do Stuff
End
I'm puzzled, I made changes to the view 2 months ago and I am guessing that it triggered the issue but still, it does not make sense to me. Why would it take over 2 hours to execute the if statement if it only takes 10 seconds to get the record count ?
** Edited for typos.
December 1, 2015 at 2:35 pm
Gagne (12/1/2015)
Hello all,I ran into the strangest thing this morning. Users reported that something that has been running in less than 1 minute for years is now taking 2.5 hours. I found the problem but I don't understand it.
This runs in about 10 seconds.
Select count(*) from myView where TransactTotal <> OnHandTotal
This used to run in about 10 seconds but now takes 2.5 hours, regardless of what is betwen the Begin/End statements.
if (select count(*) from myView where TransactTotal <> OnHandTotal) > 0
Begin
-- Do stuff
End
But this takes just about 10 seconds.
Declare @vCount int
Select @vCount = count(*) from myView where TransactTotal <> OnHandTotal > 0
if @vCount > 0
Begin
-- Do Stuff
End
I'm puzzled, I made changes to the view 2 months ago and I am guessing that it triggered the issue but still, it does not make sense to me. Why would it take over 2 hours to execute the if statement if only takes 10 seconds get the record count ?
Can you post the view definition along with the underlying table and index definitions? What you are describing sounds odd for sure but without seeing actual objects is guesswork.
_______________________________________________________________
Need help? Help us help you.
Read the article at http://www.sqlservercentral.com/articles/Best+Practices/61537/ for best practices on asking questions.
Need to split a string? Try Jeff Modens splitter http://www.sqlservercentral.com/articles/Tally+Table/72993/.
Cross Tabs and Pivots, Part 1 – Converting Rows to Columns - http://www.sqlservercentral.com/articles/T-SQL/63681/
Cross Tabs and Pivots, Part 2 - Dynamic Cross Tabs - http://www.sqlservercentral.com/articles/Crosstab/65048/
Understanding and Using APPLY (Part 1) - http://www.sqlservercentral.com/articles/APPLY/69953/
Understanding and Using APPLY (Part 2) - http://www.sqlservercentral.com/articles/APPLY/69954/
December 1, 2015 at 2:50 pm
In addition to what Sean said, the execution plans for the queries would be good to have as well.
Beginning in SQL Server 2005, the optimizer converts IF (SELECT COUNT...)>0 to an EXISTS (see http://blogs.technet.com/b/wardpond/archive/2007/08/27/if-exists-select-vs-if-select-count-1-0.aspx), so the SELECT COUNT query embedded in the IF >0 will likely have a very different query plan than the same SELECT outside of that IF construct.
It could just be that the problematic version got compiled with a new, much more unfortunate plan recently.
Cheers!
December 1, 2015 at 3:06 pm
Jacob Wilkins (12/1/2015)
In addition to what Sean said, the execution plans for the queries would be good to have as well.Beginning in SQL Server 2005, the optimizer converts IF (SELECT COUNT...)>0 to an EXISTS (see http://blogs.technet.com/b/wardpond/archive/2007/08/27/if-exists-select-vs-if-select-count-1-0.aspx), so the SELECT COUNT query embedded in the IF >0 will likely have a very different query plan than the same SELECT outside of that IF construct.
It could just be that the problematic version got compiled with a new, much more unfortunate plan recently.
Cheers!
Good point. I meant to mention that changing this to an EXISTS would likely fix the problem once and for all. 😀
_______________________________________________________________
Need help? Help us help you.
Read the article at http://www.sqlservercentral.com/articles/Best+Practices/61537/ for best practices on asking questions.
Need to split a string? Try Jeff Modens splitter http://www.sqlservercentral.com/articles/Tally+Table/72993/.
Cross Tabs and Pivots, Part 1 – Converting Rows to Columns - http://www.sqlservercentral.com/articles/T-SQL/63681/
Cross Tabs and Pivots, Part 2 - Dynamic Cross Tabs - http://www.sqlservercentral.com/articles/Crosstab/65048/
Understanding and Using APPLY (Part 1) - http://www.sqlservercentral.com/articles/APPLY/69953/
Understanding and Using APPLY (Part 2) - http://www.sqlservercentral.com/articles/APPLY/69954/
December 1, 2015 at 3:12 pm
The code for the view is in the like of
Select T1.Col1, T1.Col2, T2.Col1, T3.Col1
From T1
join T2 on <whatever> = <whatever>
join (select whatever from <whatever>) as T3
I don't know how to get the execution plans out or SSMS to post them here but they are quite different and it explains the mistery 😀 I think the culprit is the sub-query.
For some reason
If (Select count(*) from myView) > 0
makes SQL Server go through a nested loop while using a variable does not.
I can only assume that the change I made to the view 2 months ago triggered this.
December 1, 2015 at 3:16 pm
If this is what you 2 meant, it does not help, the execution plan for this also ends up with a Nest Loops in the 3rd step.
if exists (select 1 From vInvAuditTest where transactiontotal <> onhand)
begin
select '123'
end
December 1, 2015 at 3:21 pm
As pointed out in the article I posted, beginning in SQL Server 2005, the optimizer converts IF (SELECT COUNT...)>0 to an EXISTS under the covers, so I would expect those to have the same plan.
On the subject of sharing the plans with us, you should be able to turn on Include Actual Execution plan, run the query, and then when you look at the execution plan, right click and save it as a .sqlplan file. Then you can include the .sqlplan files as attachments in a post here for us to take a look at.
Cheers!
December 1, 2015 at 3:31 pm
Tables InvTransactions, Inventory and StyleItem all have an index on ItemNo.
Table Style has indexes on columns Style and StyleType respectively
Code for the view
Alter View vInvAudit
as
Select it.Warehouse, si.Style, si.Label, si.Color, si.Dimension, si.Size, sum(it.invtrxqty) TransactionTotal,i.QOHQty OnHand
fromInvTransactions it
joinStyleItem si on si.ItemNo = it.ItemNo
join(Select Warehouse, ItemNo, sum(QOHQty) QOHQty from Inventory group by warehouse, itemno) i on i.itemno = it.itemno and i.warehouse = it.warehouse
joinStyle s on s.style = it.style
wheres.styletype='FG'
Group by
it.warehouse, si.Style, si.Label, si.Color, si.Dimension, si.Size, i.QohQty
Go
Attached is the EP for if (select count(*)....)
December 1, 2015 at 3:36 pm
I forgot to post the EP when getting the before the IF, here it is.
It is strange how SQL generate completely different plans for statements that actually do the same thing.
December 1, 2015 at 6:54 pm
Thanks!
Remember, to SQL Server, the queries are not the same. Without the IF, the query is asking for the actual count of rows from the view that meet the WHERE clause criteria. With the IF...>0, you're just asking if 1 such row exists, and you don't need the exact count. The second question should be more easily answered than the first, but sometimes the optimizer's assumptions are very, very wide of the mark.
I know the actual plan for the bad query would be rough to acquire, if it's taking 2.5 hours to run, but that would be nice to have. The estimated plans lack information that could be helpful (discrepancies between estimated and actual rows, and between estimated executions and actual executions, for example).
In this case, I suspect we would see something like those discrepancies at work. Specifically, I would guess that in the actual plan for the long-running query that the outer input for the nested loop operator joining the Sort output to the scan of InvTransactions has well more than 1 row, and that the scan is reading more than 76,000 rows for each execution (note that in the "good" plan the estimated row count for that scan is 2.6 million).
It's probably assuming the implied row goal of 1 from the EXISTS (remember, it's transforming the IF (SELECT COUNT...)>0 to an EXISTS) is going to reduce the rows coming out of some of the operators much more than it actually is in this case. There's a hint of the row goal being at play because of the Sort operator reducing the estimated rows, not something you would otherwise see.
There's been some investigation of this sort of problem (see http://blogs.msdn.com/b/bartd/archive/2012/03/14/row-goals-gone-rogue.aspx for one such discussion), where introducing a row goal via TOP or EXISTS causes the optimizer to make a poor decision that drastically slows down an otherwise acceptable query.
Without digging in much more deeply (looking at the exact data, definitions of the base tables, potential rewrites of the view, actual execution plans and such), the sort of workaround you're using now may be the best short-term fix.
Here's some code using the sample data from the above article that illustrates all this (step through the queries and comments, don't just run it all in one batch):
--Bart Duncan's sample data
USE tempdb;
GO
IF OBJECT_ID('even') IS NOT NULL
DROP TABLE even;
IF OBJECT_ID('odd') IS NOT NULL
DROP TABLE odd;
GO
CREATE TABLE even ( c1 INT, c2 CHAR(30) );
CREATE TABLE odd ( c1 INT, c2 CHAR(30) );
GO
SET NOCOUNT ON;
DECLARE @x INT;
SET @x = 1;
BEGIN TRAN;
WHILE ( @x <= 10000 )
BEGIN
INSERT INTO even
( c1, c2 )
VALUES ( @x * 2, '' );
INSERT INTO odd
( c1, c2 )
VALUES ( @x * 2 - 1, '' );
IF @x % 1000 = 0
BEGIN
RAISERROR ('Inserted %d rows...', 0, 1, @x) WITH NOWAIT;
COMMIT TRAN;
BEGIN TRAN;
END;
SET @x = @x + 1;
END;
WHILE @@TRANCOUNT > 0
COMMIT TRAN;
GO
--This will complete quite speedily
SELECT COUNT(*)
FROM even t1
INNER JOIN odd t2 ON t1.c1 = t2.c1;
--You'll want to go get a coffee, because this next one will take a while.
--If you run this one with Include Actual Execution Plan enabled,
--notice the difference between estimated/actual rows and executions
--for the scan operators
IF ( SELECT COUNT(*)
FROM even t1
INNER JOIN odd t2 ON t1.c1 = t2.c1
) > 0
PRINT 'Aha!';
--To illustrate the effect of the row goal on a Sort operator,
--look at the estimated plan for the below queries.
--Notice how the sorts in IF (SELECT COUNT...)>0
--are estimated to reduce the row counts. That's the row
--goal in action, affecting our estimates.
--If you also run the below queries, you'll notice that
--forcing SQL Server to use a different join type
--brings the duration back down, since it's avoiding
--the costly 10000 executions of one of the scans.
--The estimates for the rows coming into the join
--are still way off, but this plan's a bit
--more resilient here.
SELECT COUNT(*)
FROM even t1
INNER MERGE JOIN odd t2 ON t1.c1 = t2.c1;
IF ( SELECT COUNT(*)
FROM even t1
INNER MERGE JOIN odd t2 ON t1.c1 = t2.c1
) > 0
PRINT 'Aha!';
--Just for fun, here's the slow query again, but
--this time fooling SQL Server by using >0.5.
--It doesn't assume this is an EXISTS anymore.
IF ( SELECT COUNT(*)
FROM even t1
INNER JOIN odd t2 ON t1.c1 = t2.c1
) > 0.5
PRINT 'Aha!';
--Now let's see what happens if we help the optimizer
--out by making its assumptions correct, by putting a
--matching row where it will be quickly found
INSERT INTO odd VALUES (2,'')
IF ( SELECT COUNT(*)
FROM even t1
INNER JOIN odd t2 ON t1.c1 = t2.c1
) > 0
PRINT 'Aha!';
--Clean up after ourselves
DROP TABLE odd, even;
Cheers!
December 1, 2015 at 10:52 pm
Thanks for the code Jacob, I will study it tomorrow. I did not know that the estimated EP was just an estimation :Whistling: and that it could be different at execution time.
I don't want to load the server with tests while users are working but over the week end I can run it with the old code and get the actual plan.
But in the meantime, I optimized the view. I must have created it before "discovering" the isnull() function because I am looking at the code and I am totally unimpressed with my own work :-D. Why did I use a subquery ??
I changed the code to
Select it.Warehouse, si.Style, si.Label, si.Color, si.Dimension, si.Size, sum(it.invtrxqty) TransactionTotal,isnull(i.QOHQty,0) OnHand
fromInvTransactions it
joinStyleItem si on si.ItemNo = it.ItemNo
left outer join Inventory i on i.itemno = it.itemno and i.warehouse = it.warehouse
joinStyle s on s.style = it.style
wheres.styletype='FG'
Group by
it.warehouse, si.Style, si.Label, si.Color, si.Dimension, si.Size, i.QohQty
The estimated execution plan still shows nested loops and a sort (that accounts for 46%) but the execution of if (select count(*)....) >0 now takes the same time as putting the count in a variable so the subquery clearly plays a role in this.
Viewing 11 posts - 1 through 10 (of 10 total)
You must be logged in to reply to this topic. Login to reply