August 11, 2011 at 11:14 am
Our reporting team has a reporting procedure that normally runs in approximately 10 seconds.
In our reporting enviornment, we have a report queue type model where serveral instances select the next available report from the queue and begin processing it either using rs.exe or bcp.exe to generate the report.
This morning 2 instances picked up the report and executed them at the exact time (down to the milisecond) 2011-08-11 06:39:37.213 and 2011-08-11 06:39:37.213
Basically the same report, being sent to two different people.
The result of this was the procedure ran for 21 minutes!
My question is, could executing the same procedure that uses the exact same objects to fetch it's data cause such an issue?
______________________________________________________________________________Never argue with an idiot; Theyll drag you down to their level and beat you with experience
August 11, 2011 at 11:26 am
I would say. No.
They come from different sessions.
August 11, 2011 at 11:32 am
I wouldn't expect it to behave like that, no. Yeah, I'd expect a slow-down as there absolutely would be contention on the resources, but not something at that magnitude. That seems like an odd circumstance. No chances of other contention on resources? Do you have monitoring in place so you can look at CPU, Memory & I/O around that same time?
"The credit belongs to the man who is actually in the arena, whose face is marred by dust and sweat and blood"
- Theodore Roosevelt
Author of:
SQL Server Execution Plans
SQL Server Query Performance Tuning
August 11, 2011 at 11:34 am
Easy test....
Open 2 windows in ssms
WAITFOR TIME 'x'
EXEC dbo.MyProc SameParamsThat failed
They'll fire at the same time and see what happens.
August 11, 2011 at 11:40 am
Depends if you have the concurrency set up correctly. I could see this happening, if the SQL code that picks up the next to process isn't careful about isolation and transactions.
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
August 11, 2011 at 1:00 pm
I tried the test but they still didn't execute at the same time:
Window 1:
WAITFOR TIME '13:42:00:000'
SELECT GETDATE()
-- exec reporting procedure here
Returns: 2011-08-11 13:42:00.003
Window 2:
WAITFOR TIME '13:42:00:000'
SELECT GETDATE()
-- exec reporting procedure here
Returns: 2011-08-11 13:42:00.010
Am I missing something in the syntax?
Regarding how these reports get pulled from the queue: each are wrapped in it's own seprate transaction.
______________________________________________________________________________Never argue with an idiot; Theyll drag you down to their level and beat you with experience
August 11, 2011 at 1:07 pm
FYI, the memory and CPU don't really move much during these reporting execution times...the CPU hovers around 30%, and the memory stays even. The disk reads spike up to +5000 and the disk is 98-100% busy, with an average disk queue length around 300
Only thing I can figure is something else is causing it ot occur and it's just a fluke that this happened.
This is all running on decent hardware: 8CPU, 16GB RAM, fast backplane, MD-1200 storage array (12-disks @15K RPM in RAID 10), split 6 disk to one drive and 6 to the other - used, one for logging, one for just the data and index files.
I appreciate everyone's help. It's one of those situations where the blame is shifting from the Reporting guys stating something's wrong with the server and the DBA's stating it's the massive queries that generate such high reads and that it's not the server or all the other reports running at the same time would also be adveresly affected (which they don't appear to be)
______________________________________________________________________________Never argue with an idiot; Theyll drag you down to their level and beat you with experience
August 11, 2011 at 1:10 pm
Hmm I would have expected a little more precision. Anyhow, how long did it take to run this time?
August 11, 2011 at 1:26 pm
A disk queue of 300? YIKES!
"The credit belongs to the man who is actually in the arena, whose face is marred by dust and sweat and blood"
- Theodore Roosevelt
Author of:
SQL Server Execution Plans
SQL Server Query Performance Tuning
August 11, 2011 at 1:45 pm
MyDoggieJessie (8/11/2011)
Regarding how these reports get pulled from the queue: each are wrapped in it's own seprate transaction.
A transaction alone does not guarantee that the two are properly isolated. Try this example:
CREATE TABLE JobsToProcess (
ID INT IDENTITY PRIMARY KEY,
JobName VARCHAR(10),
ProcessedBy VARCHAR(10)
);
GO
CREATE PROCEDURE ProcessJob (@ProcessedBy VARCHAR(10))
AS
DECLARE @JobID INT, @JobName VARCHAR(10);
BEGIN TRANSACTION
SELECT TOP (1) @JobID = ID, @JobName = JobName
FROM JobsToProcess WHERE ProcessedBy IS NULL
ORDER BY ID;
WAITFOR DELAY '00:00:00.01' -- to simulate a server under load
UPDATE JobsToProcess SET ProcessedBy = @ProcessedBy
WHERE ID = @JobID;
SELECT @JobID, @JobName;
COMMIT TRANSACTION
GO
Looks fine?
I ran 2 instances of that procedure. Both processed Job 1...
Transaction or no, nothing is stopping both from selecting the same value from the table in the first statement
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
August 11, 2011 at 1:59 pm
They they ran (on 8 different tries) from 10-15 seconds
______________________________________________________________________________Never argue with an idiot; Theyll drag you down to their level and beat you with experience
August 11, 2011 at 2:07 pm
What can of monitoring do you have in place? That's you best bet at this time...
August 11, 2011 at 2:20 pm
Transaction or no, nothing is stopping both from selecting the same value from the table in the first statement
Gail, in your test yes this is true, however in the queuing method I've set up, a few tweaks are needed to your example to emulate how it's running over here (that will prevent the procs from picking up the same record:
Need to Add:
SELECT TOP (1) @JobID = ID, @JobName = JobName
FROM JobsToProcess WITH(UPDLOCK, READPAST) WHERE ProcessedBy IS NULL
ORDER BY ID;
And create a non-clustered index on the JobID column to prevent it from running/selecting the same record twice:
CREATE NONCLUSTERED INDEX [idx_jobID] ON [dbo].[JobsToProcess]
(
[ID] ASC
)
Doing so allows it to select only the next record that isn't locked:
ID JobName ProcessedBy
----------- ---------- -----------
1 Job 1 Process 1
2 Job 2 Process 2
Ninja, we are currently using Idera's SQL Diagnostic Manager, some custom scripts I've written similar to sp_whom2, and periodic profiler traces (which I will set up to fire one off in the morning when our corporate reporting starts)
Thanks everyone for the replies!
______________________________________________________________________________Never argue with an idiot; Theyll drag you down to their level and beat you with experience
August 11, 2011 at 2:26 pm
At this point you have all the cards. Start those process and dig through the logs for that time period.
Come back if you need more help.
The most I can offer at this point is that you had a bottleneck... which is just a little better than totally useless ;-).
August 11, 2011 at 3:43 pm
Is it the SQL Server process or the extraction causing the issue? I can't say that I've played with running multiple competing instances of RS or BCP, but being command-line based, they often play in the "same playground" resource-wise.
----------------------------------------------------------------------------------
Your lack of planning does not constitute an emergency on my part...unless you're my manager...or a director and above...or a really loud-spoken end-user..All right - what was my emergency again?
Viewing 15 posts - 1 through 14 (of 14 total)
You must be logged in to reply to this topic. Login to reply