SP turns slow suddenly without having modified it
Bas
I posted a message a while ago about an SP that had a huge delay all of a
sudden. I hadn't modified any part of it. I've still got this problem but
I've narrowed it down to this script below. '_report_Invoice' is a complex
view, but that's not really important. Here goes:
-- assume we have a stored proc 'report_Invoice' already created, and it was
working fine for weeks
exec report_Invoice 2437
-- the above line takes over a minute to complete all of a sudden!!
--go fix it like this...:
DROP PROCEDURE report_Invoice
GO
--re-create the SP exactly as it was by copy-pasting it's create script
CREATE PROCEDURE dbo.report_Invoice
@Invoice int
AS
SELECT * FROM _report_Invoice
WHERE Invoice_ID = @Invoice
GO
exec report_Invoice 2437
-- the above line takes 1 second to complete!! (like it always was)
Can anyone explain this execution time difference? Seems like black magic to
me. The SP only returns 2 rows, which is what it should do.
Cheers,
Bas
Erland Sommarskog
> -- assume we have a stored proc 'report_Invoice' already created, and it
> was working fine for weeks
> exec report_Invoice 2437
> -- the above line takes over a minute to complete all of a sudden!!
> --go fix it like this...:
>
> DROP PROCEDURE report_Invoice
> GO
>
> --re-create the SP exactly as it was by copy-pasting it's create script
> CREATE PROCEDURE dbo.report_Invoice
> @Invoice int
> AS
> SELECT * FROM _report_Invoice
> WHERE Invoice_ID = @Invoice
> GO
>
> exec report_Invoice 2437
> -- the above line takes 1 second to complete!! (like it always was)
>
> Can anyone explain this execution time difference? Seems like black
> magic to me. The SP only returns 2 rows, which is what it should do.
Yes, this is one of those mysteries that could happen when you have a
cost-based optimizer and a procedure cache. Here is a possible scenario,
of what may have happened.
You create the procedure. First time it's run, SQL Server creates a
query plan for the procedure. This plan will reamin in cache as long
as space permits, or someone restarts SQL Server or issues
DBCC FREEPROCCACHE.
When building the query plan, SQL Server uses the parameter value as
input for the plan. Now, imagine that the plan falls out of the cache
for some reason, and next time it is run, the procedure is by
chance called with some fringe value, which calls for a query plan
that for most input values is not the best one.
Rather than dropping and recreating the procedure, you could have tried
exec report_Invoice 2437 WITH RECOMPILE
which is yet another way of flushing the plan out of the cache.
--
Erland Sommarskog, SQL Server MVP, som...@algonet.se
I support PASS - the definitive global community for SQL Server
professionals - http://www.sqlpass.org
The PASS Community Summit is in Seattle Nov 19-22, I'll be there. And you?
Bas
"Erland Sommarskog" <som...@algonet.se> wrote in message
news:Xns92BEF226A...@127.0.0.1...
> Bas (nomailplease) writes:
<snip>
> > Can anyone explain this execution time difference? Seems like black
> > magic to me. The SP only returns 2 rows, which is what it should do.
>
> Yes, this is one of those mysteries that could happen when you have a
> cost-based optimizer and a procedure cache. Here is a possible scenario,
> of what may have happened.
>
>
> Rather than dropping and recreating the procedure, you could have tried
>
> exec report_Invoice 2437 WITH RECOMPILE
>
> which is yet another way of flushing the plan out of the cache.
Hi Erland,
Thanks for the clear explanation. I forgot to mention in my previous post
that I'm using SQL2000
I've tried the WITH RECOMPILE and sp_updatestats and DBCC DBREINDEX and DBCC
FREEPROCCACHE.
While I'm typing this my one-second SP has just hit 6 minutes execution time
and counting :(
Just dropping the procedure and recreating doesn't help; I have to drop de
procedure, open an new connection (new script in QA) and then recreate it.
Execution time is less than a second after that, like it has been the last
few weeks.
Can you -or anyone else- think of any other suggestions?
I can provide more details if needed.
Thanks,
Bas
Dick Christoph
In your table is Invoice_ID the primary key?
Erland's suggestion was the first thing that occured to me, although it
would seem if Invoice_ID is the Primary Key any value for @Invoice (the
parameter) should result in more or less the same query plan.
Other than that perhaps you could check if the query is being blocked by
other updates that might be going on. (The current Activity node in the Ent
Mgr is a easy way to check this. Check the last two columns (Blocking and
Blocked by))
HTH
_Dick Christoph
"Bas" <nomailplease> wrote in message
news:3dca5648$0$85002$e4fe...@dreader7.news.xs4all.nl...
Bas
Thanks for replying.
Invoice_ID is the Primary Key indeed and I was also under the impression
that the value shouldn't matter much. But hey, I'm open for any suggestion
at the moment. :)
I checked the blocking and I see nothing unusual. I ran a trace and it shows
nothing belonging to my procedure (! must be hanging before doing anything),
only thing is SELECT N'Testing Connection...' and 'EXECUTE
msdb.dbo.sp_sqlagent_get_perf_counters' from 'SQLAgent - Alert Engine'.
Otherwise it's quiet though the windows Task Manager on the SQL server
machine does show 100% CPU usage, and it drops to around zero when I cancel
the execution in QA. Also the 'exec report_Invoice 2437' shows up in the
trace *after* I stop the procedure manually.
This is getting weirder the closer I look...
Bas
"Dick Christoph" <dchr...@mn.rr.com> wrote in message
news:BZsy9.74970$cG.11...@twister.kc.rr.com...
Lachlan M Keown
Then identify which step(s) are slow. Examine to see which indexes are being
(not) used. This should give you some clues.
- Lachlan
"Bas" <nomailplease> wrote in message
news:3dc96143$0$63814$e4fe...@dreader1.news.xs4all.nl...
Erland Sommarskog
> Thanks for the clear explanation. I forgot to mention in my previous post
> that I'm using SQL2000
>
> I've tried the WITH RECOMPILE and sp_updatestats and DBCC DBREINDEX and
> DBCC FREEPROCCACHE.
> While I'm typing this my one-second SP has just hit 6 minutes execution
> time and counting :(
>
> Just dropping the procedure and recreating doesn't help; I have to drop de
> procedure, open an new connection (new script in QA) and then recreate it.
> Execution time is less than a second after that, like it has been the last
> few weeks.
>
> Can you -or anyone else- think of any other suggestions?
Next time, before you drop the procedure, execute:
select objectproperty(object_id('report_Invoice'), 'ExecIsAnsiNullsOn')
select objectproperty(object_id('report_Invoice'), 'ExecIsQuotedIdentOn')
After you have recreated the procedure, perform these commands again.
Please report the result.
This object _report_Invoice you are selecting from, is this by chance
a view?
Dick Christoph
I reread your first post where you wrote:
>I've narrowed it down to this script below.
>'_report_Invoice' is a complex
>view, but that's not really important. Here goes:
I didn't realize _report_Invoice is a view. Depending on what is going on in
the view, querying with a Primary key may be not be as simple as if
_report_Invoice was a table.
Use "Show Execution plan" and I would not be surprised if some Full table
Scans and other time consumiong operations are occuring
HTH
-Dick Christoph
"Dick Christoph" <dchr...@mn.rr.com> wrote in message
news:BZsy9.74970$cG.11...@twister.kc.rr.com...
Bas
Thanks again for the input.
The object "_report_Invoice" (starting with underscore) is a view.
I know the execution plans are different between the slow and the fast
versions. Why and how was not my main surprise, but how it suddenly changes.
I tried Erland's suggestion and it led me to the solution:
>select objectproperty(object_id('report_Invoice'), 'ExecIsAnsiNullsOn')
>select objectproperty(object_id('report_Invoice'), 'ExecIsQuotedIdentOn')
The slow ones have both properties set to 0, the fast ones return have ansi
nulls and quoted identifiers switched on. I recreated all procedures with
ansi nulls on and everything seems fast again. Thanks!
I noticed that procedures I make with EM have both properties set to false,
while these are set to true when I make them in QA (I dunno why, but I found
this later (though I don't have linked server objects)):
http://support.microsoft.com/default.aspx?scid=KB;EN-US;Q296769&
"By default, SQL Server 2000 Enterprise Manager sets ANSI_NULLS to OFF
before creating a stored procedure." ... "SQL Server 2000 Enterprise Manager
can be used to edit existing stored proceduress; it will retain whatever
ANSI_NULLS settings were used when a stored procedure was initially
created."
Microsoft says that it's a bug in SQL Server 2000
It's probably an optimizer thing - as pointed out by many others - that
causes my procedure to go slow with ansi nulls off, but I'm not sure I
follow completely why.
Thanks again,
Bas
"Erland Sommarskog" <som...@algonet.se> wrote in message
news:Xns92BFEED05...@127.0.0.1...
Erland Sommarskog
> It's probably an optimizer thing - as pointed out by many others - that
> causes my procedure to go slow with ansi nulls off, but I'm not sure I
> follow completely why.
Sort of. But not the normal suprises of a cost-based optimizer. This
is highly rule-based.
Since _report_Invoice is a view, and you talk about a primary key is an
indexed view. Now, to able to use indexed views all these settings must be
ON: ANSI_NULLS, QUOTED_IDENTIFIER, ANSI_PADDING, ARITHABORT, ANSI_WARNINGS,
CONCAT_NULLS_YIELDS_NULL. And NUMERIC_ROUNDABORT must be OFF. You must have
these settings when you create the view, and you must have them at
execution time for the optimizer to consider the view.
While all these are settable at run-time some of these are saved with
objects. For a stored procedure the settings for ANSI_NULLS and
QUOTED_IDENTIFIER the create-time settings apply. Likewise for a
table the CREATE-time values for ANSI_NULLS and ANSI_PADDING. (More
it exactly it is the setting for each columns that apply.)