December 27, 2015 at 7:31 am
Investigating a performance issue, I have placed a number of statements like this throughout the Store Proc that is being investigated,
to see which part of queries takes the longest time.
INSERT INTO LOG_spr_test (SOpDesc, STime) VALUES ('Statement 4 completed', getdate())
This is the DDL for the LOG_ table:
CREATE TABLE [dbo].[LOG_spr_test](
[SNum] [int] IDENTITY(1,1) NOT NULL,
[SOpDesc] [varchar](255) NULL,
[STime] [datetime] NULL
)
But my question is not about performance analysis. It is about how can a T-SQL Query be written in order to analyze data in this table,
that look like the attached image.
I can see that our bottleneck is occurring during the time when SOpDesc= 'Statement 2 completed'
So the time length of each 'Statement 2' MINUS 'Statement 1 completed' (as the previous Insert into the log table was immediately before the
'Statement 2 completed'.
HOW can I SELECT AVG (SECONDS) FROM LOG_
that would display average lenth of time between Statement 2 and Statement 1 (previous row to Statement 2) ?
In other words, we want to know the average num seconds that a SQL Statement 2 takes within the SP.
THank you!
Likes to play Chess
December 27, 2015 at 7:56 am
If I'm reading this correctly, it looks like you want the time required for each step.
You're on SQL 2008, so you don't get the LEAD/LAG functions. Instead, you can approach the problem using a self-join offset by 1 row.
SELECT log1.ID, log1.STime StartTime, log2.STime EndTime
FROM LOG_spr_test log1
INNER JOIN Log_spr_test log2 ON log1.ID = log2.ID - 1
ORDER BY log1.ID;
This will give you the start time of the step and the start time of the next step on the same row. We'll treat the start time of the next step as the end time of the current step. The difference can be added in as follows:
SELECT log1.ID, log1.STime StartTime, log2.STime EndTime, DATEDIFF(second, log1.STime, log2.STime) TimeDiff
FROM LOG_spr_test log1
INNER JOIN Log_spr_test log2 ON log1.ID = log2.ID - 1
ORDER BY log1.ID;
I'm not logged on to a SQL Server right now, so I have to call this untested. I apologize if I missed anything, but should be able to correct it tomorrow if necessary. I hope this helps.
December 27, 2015 at 8:28 pm
it was very helpful! thank you!
Likes to play Chess
December 28, 2015 at 6:46 am
Glad to hear it. Thanks for the feedback.
December 28, 2015 at 7:38 am
Be aware that an identity column might have gaps, so you might need to create an artificial key.
Something like this:
WITH cteLog AS(
SELECT ROW_NUMBER() OVER(ORDER BY SNum /*or [STime] depending on indexing*/) AS ID,
[STime],
[SOpDesc]
FROM [LOG_spr_test]
--WHERE SOpDesc IN( 'Statement 1 completed', 'Statement 2 completed')
)
SELECT log1.ID,
log1.STime StartTime,
log2.STime EndTime,
DATEDIFF(second, log1.STime, log2.STime) TimeDiff
FROM cteLog log1
JOIN cteLog log2 ON log1.ID = log2.ID - 1
ORDER BY log1.ID;
December 28, 2015 at 7:44 am
Excellent point, Luis. Thanks.
December 28, 2015 at 7:58 am
Maybe your logging table needs to be different.
Instead of inserting a row at the completion of each step in the proc, do the calculations in the code and insert one row for each execution of the proc.
This would be ok for 5 steps or so, it would probably be a bit cumbersome for a proc with a lot of steps, though.
Michael L John
If you assassinate a DBA, would you pull a trigger?
To properly post on a forum:
http://www.sqlservercentral.com/articles/61537/
December 28, 2015 at 11:32 am
Something like this might (or might not) perform better, if you need to calc time diff for just those two steps:
SELECT lst.SNum, lst.SOpDesc, lst.STime,
CASE WHEN lst.SOpDesc = 'Statement 2 completed'
THEN DATEDIFF(SECOND, lst1_STime.STime, lst.STime)
ELSE NULL END AS Run_Time
FROM dbo.LOG_spr_test lst
LEFT OUTER JOIN (
SELECT TOP (1) STime
FROM dbo.LOG_spr_test lst1
WHERE
lst1.SOpDesc = 'Statement 1 completed'
ORDER BY lst1.SNum DESC
) AS lst1_STime ON lst.SOpDesc = 'Statement 2 completed'
SQL DBA,SQL Server MVP(07, 08, 09) "It's a dog-eat-dog world, and I'm wearing Milk-Bone underwear." "Norm", on "Cheers". Also from "Cheers", from "Carla": "You need to know 3 things about Tortelli men: Tortelli men draw women like flies; Tortelli men treat women like flies; Tortelli men's brains are in their flies".
December 28, 2015 at 1:45 pm
What you mentioned is very cool. We do not have Identity id column gaps (yet..),
while they are indeed possible.
Thus my next question :
How come that the result-set from this query below (the very first reply to my post)
is different from yours? please see the attachment( XL, attaching now...)
SELECT log1.ID, log1.STime StartTime, log2.STime EndTime, DATEDIFF(second, log1.STime, log2.STime) TimeDiff
FROM LOG_spr_test log1
INNER JOIN Log_spr_test log2 ON log1.ID = log2.ID - 1
ORDER BY log1.ID;
I have attached the results of BOTH the above SQL and your SQL on same page in XL.
Thank you!!!
Likes to play Chess
December 28, 2015 at 1:48 pm
full table data is also in XL (spreadsheet 2).
Likes to play Chess
December 28, 2015 at 1:56 pm
You need a WHERE condition on the SELECT from the CTE:
...
SELECT log1.ID,
log1.STime StartTime,
log2.STime EndTime,
DATEDIFF(second, log1.STime, log2.STime) TimeDiff
FROM cteLog log1
JOIN cteLog log2 ON log1.ID = log2.ID - 1
WHERE log1.SOpDESC = 'Statement 1 Completed'
ORDER BY log1.ID;
SQL DBA,SQL Server MVP(07, 08, 09) "It's a dog-eat-dog world, and I'm wearing Milk-Bone underwear." "Norm", on "Cheers". Also from "Cheers", from "Carla": "You need to know 3 things about Tortelli men: Tortelli men draw women like flies; Tortelli men treat women like flies; Tortelli men's brains are in their flies".
Viewing 11 posts - 1 through 10 (of 10 total)
You must be logged in to reply to this topic. Login to reply