How does a stored procedure takes 15 seconds to start?
-
The trace attached shows a stored procedure calling another stored procedure.
The statement calling the inner procedure takes 18 seconds while the inner procedure itself only takes 2.5 seconds!
In fact, according to the trace, the start date&time of the statement calling the stored procedure is 15 seconds before the inner procedure itself starts...What can delay the start of a stored procedure 15 seconds?
This behaviour is erratic. Most of the time, there is no such delay and the statement calling the stored procedure shows the same duration as the inner procedure itself.
But this erratic behaviour happens on various servers (TESTs, PROD) with similar databases (copied through backup/restore at various stages).
Any idea where/how to look?
Thanks
-
You'll probably need to look at activity for the tables referenced by the inner procedure, along with looking to see if there's blocking going on, and look at any wait queues that might exist at the time this actually occurs. If it's waiting on resources, then that's where you'll need to focus your efforts.
Steve (aka sgmunson) 🙂 🙂 🙂
Rent Servers for Income (picks and shovels strategy) -
If it was blocking on some table, then it would not affect the start time of the inner procedure.
I suppose I need to look at Wait Stats indeed...Thanks for the hints.
-
99% of the time, the apparent "start delay" is caused simply by compile time.
--Jeff Moden
RBAR is pronounced "ree-bar" and is a "Modenism" for Row-By-Agonizing-Row.
First step towards the paradigm shift of writing Set Based code:
________Stop thinking about what you want to do to a ROW... think, instead, of what you want to do to a COLUMN.Change is inevitable... Change for the better is not.
Helpful Links:
How to post code problems
How to Post Performance Problems
Create a Tally Function (fnTally) -
We use a fair amount of temp tables with sometimes significant amount of rows (up to 100,000s) and I could spot a significant amount of Statement Recompile.
However, could it be as bad as delaying execution of the inner procedure by 15 seconds?
Also it is quite erratic with exactly the same amount of data...
- Eric Mamet - Friday, June 30, 2017 3:47 PM
Oh no. It can be much WORSE! 😉 We recent repaired some ORM code that would compile every time it came across and it came across thousands of times per hour. It had a range of compile times varying from 2 to 22 seconds with an average of 7 seconds. And that was just to update just a single row in a single table. It caused 32 CPUs to maintain elevated usage of about 25% throughout the day. Once we converted that mess (40 columns in the WHERE clause even though one of them was the PK) to a stored procedure with some elegance to it, all of the CPUs dropped to vary between 4 - 8% with an average of 5%. Challenged code on a good TempTable can easily have the same or worse effect.
As a bit of a side bar with the aim of helping...
1. How many CPUs do you have?
2. How many TempDB files do you have?
3. How much memory is available to SQL Server?
4. Do you have Trace Flag 1118 enabled?
5. What are the initial sizes and growth patterns for TempDB?
6. How big is TempDB right now (by file if you have more than 1)--Jeff Moden
RBAR is pronounced "ree-bar" and is a "Modenism" for Row-By-Agonizing-Row.
First step towards the paradigm shift of writing Set Based code:
________Stop thinking about what you want to do to a ROW... think, instead, of what you want to do to a COLUMN.Change is inevitable... Change for the better is not.
Helpful Links:
How to post code problems
How to Post Performance Problems
Create a Tally Function (fnTally) -
What seems the best way to evaluate the cost of recompiles?
Extended events on that session (if I can reproduce) looking at waitstats?
-
Do you have in the code something like this?
DECLARE @var Datatype = dbo.SomeFunction(@params)_____________
Code for TallyGenerator -
I am aware of issues related to Scalar UDFs and I don't think we have any in this procedure
- Eric Mamet - Sunday, July 2, 2017 3:14 PM
I have some code at work that evaluates the procedure cache for such a thing. I'll try to remember to grab it for you.
--Jeff Moden
RBAR is pronounced "ree-bar" and is a "Modenism" for Row-By-Agonizing-Row.
First step towards the paradigm shift of writing Set Based code:
________Stop thinking about what you want to do to a ROW... think, instead, of what you want to do to a COLUMN.Change is inevitable... Change for the better is not.
Helpful Links:
How to post code problems
How to Post Performance Problems
Create a Tally Function (fnTally) - Eric Mamet - Monday, July 3, 2017 2:46 PM
It's not about scalar UDF's.
It's about DECLARE combined with assignment._____________
Code for TallyGenerator -
Thanks 🙂
- Sergiy - Monday, July 3, 2017 7:43 PM
Not entirely sure on this one...
What could be the issue(s) with doing assignment like this? Parameter sniffing?
- Eric Mamet - Tuesday, July 4, 2017 1:59 AM
So, you do have them, right?
DECLARE is executed at compilation time.
The assignment has to be validated - for object(s) availability, data type compatibility, so the code in the assignment must be actually executed "with no output" during the process of the procedure compilation.If the proc using temp objects there are update locks applied to tempdb sysobjects.
If any of the procedures has a long running assignment within DECLARE statement then tempdb objects will remain locked for a long time, and no other proc using temp tables can be recompiled during that time.If you take assignment from DECLARE and put into a separate SET then it will be executed durung run time, not affecting compilation time.
But you need to look not only on this procedure. It might be just a victim of a locking caused by declarations in any other one.
_____________
Code for TallyGenerator - Sergiy - Tuesday, July 4, 2017 2:35 AM
Very interesting!
I suppose this locking of the compilation process would not appear as "blocking" would it?
If it does, it would be easy to detect.Thanks
Viewing 15 posts - 1 through 15 (of 15 total)
You must be logged in to reply to this topic. Login to reply