June 11, 2015 at 1:13 pm
Is there a way to keep track in real time on how long a stored procedure is running for? So what I want to do is fire off a trace in a stored procedure if that stored procedure is running for over like 5 minutes. Is this possible? Appreciate the help.
June 11, 2015 at 1:25 pm
If a stored procedure is a single query, then the basic answer is no. However, that doesn't mean that what the query accesses might not be able to create a condition that some kind of trace might be able to detect, although I don't know exactly how that could occur. However, if the proc is composed of multiple queries, and especially if each takes a significant fraction of the total execution time, then you could find a particular spot between queries to insert code to kick it off. The only other decent alternative would be the idea of having a DBA readily available to start a trace "on command", so to speak.
Steve (aka sgmunson) 🙂 🙂 🙂
Rent Servers for Income (picks and shovels strategy)
June 11, 2015 at 1:29 pm
You could capture that amount of time that a stored procedure executes using Extended Events. "
-- Itzik Ben-Gan 2001
June 11, 2015 at 1:40 pm
Alan, your saying for the total time it took to execute and not in real time correct?
June 11, 2015 at 7:02 pm
JP10 (6/11/2015)
Alan, your saying for the total time it took to execute and not in real time correct?
I don't know if I understand your question so I'm not sure if this will help or not. I don't know how I would turn this on if a stored proc was running for 5 minutes but you could just kick off an Extended Events session running and collect all the metrics for that proc until you turn the EE session off.
Below is some sample code that will create a stored proc and executes it five times. I kick off an Extended Events session before it runs and turn it off after (you would just leave it running).
USE tempdb
GO
SET NOCOUNT ON;
-- (1) create a getnums function
IF OBJECT_ID('dbo.GetNums') IS NOT NULL DROP FUNCTION dbo.GetNums;
GO
CREATE FUNCTION dbo.GetNums(@rows int)
RETURNS TABLE WITH SCHEMABINDING AS RETURN
WITH
L1(N) AS (SELECT 1 FROM (VALUES (1),(1),(1),(1),(1),(1),(1),(1),(1)) t(N)),
L3(N) AS (SELECT 1 FROM L1 a, L1 b, L1 c),
Nums AS (SELECT N = ROW_NUMBER() OVER (ORDER BY (SELECT NULL)) FROM L3 a, L3 b, L3 c)
SELECT TOP(@rows) N
FROM Nums;
GO
-- (2) Create a sample proc
IF OBJECT_ID('tempdb..someproc') IS NOT NULL DROP PROC someproc;
GO
CREATE PROC someproc AS SELECT x = newid() INTO #x10M FROM dbo.GetNums(10000000);
GO
-- (3) Create and start an EE session
CREATE EVENT SESSION [queryperf] ON SERVER
ADD EVENT sqlserver.sql_statement_completed
ADD TARGET package0.event_file(SET filename=N'S:\sprocExes.xel',max_file_size=(20),max_rollover_files=(10))
WITH
(
MAX_MEMORY=4096 KB, EVENT_RETENTION_MODE=ALLOW_MULTIPLE_EVENT_LOSS,
MAX_DISPATCH_LATENCY=120 SECONDS, MAX_EVENT_SIZE=0 KB,
MEMORY_PARTITION_MODE=NONE, TRACK_CAUSALITY=OFF, STARTUP_STATE=ON
);
-- (4) Start EE and kick of sproc test
ALTER EVENT SESSION [queryperf] ON SERVER STATE = START;
GO
-- run it 20 times
EXEC someproc
GO 5
-- (4) Drop the session
DROP EVENT SESSION [queryperf] ON SERVER;
The above code will create an Extended Events file that you can query as shown below. Timestamp would tell you when it ran, [duration(sec)] will tell you how long the function ran (in seconds).
-- (5) Get results
SELECT [duration(sec)],[cpu_time(sec)],q.physical_reads,q.logical_reads,q.writes,/*event_data_XML,*/statement,timestamp
FROM
(
SELECT
[duration(sec)]=e.event_data_XML.value('(//data[@name="duration"]/value/text())[1]','int')/1000000.,
[cpu_time(sec)]=e.event_data_XML.value('(//data[@name="cpu_time"]/value/text())[1]','int')/1000000.,
physical_reads=e.event_data_XML.value('(//data[@name="physical_reads"]/value/text())[1]','int'),
logical_reads=e.event_data_XML.value('(//data[@name="logical_reads"]/value/text())[1]','int'),
writes=e.event_data_XML.value('(//data[@name="writes"]/value/text())[1]','int'),
statement=e.event_data_XML.value('(//data[@name="statement"]/value/text())[1]','nvarchar(50)'),
TIMESTAMP=e.event_data_XML.value('(//@timestamp)[1]','datetime2(7)'), *
FROM
(
SELECT CAST(event_data AS XML) AS event_data_XML
FROM sys.fn_xe_file_target_read_file('S:\sprocExes*.xel', NULL, NULL, NULL)
)e
)q
WHERE q.[statement] LIKE 'EXEC someproc%' --Filters out all the detritus that we're not interested in!
ORDER BY q.[timestamp] ASC;
-- Itzik Ben-Gan 2001
June 12, 2015 at 7:24 am
Yes, it is possible, but I have never done it. You'll need to use the built-in Dynamic Management Views (DMV), specifically sys.dm_exec_requests which gives you information about currently running requests. You can then follow the information in http://www.toadworld.com/platforms/sql-server/w/wiki/9827.running-traces-with-tsql.aspx to create and run a trace. You can even return the session_id from the DMV for use in filtering the trace.
SELECT DATEDIFF(MINUTE, r.start_time, SYSDATETIME()) AS running_for,
r.session_id,
st.text
FROM sys.dm_exec_requests AS r
CROSS APPLY sys.dm_exec_sql_text(r.sql_handle) AS st
WHERE r.database_id = DB_ID()
AND st.text LIKE '%your_procedure_name%'
Drew
J. Drew Allen
Business Intelligence Analyst
Philadelphia, PA
Viewing 6 posts - 1 through 5 (of 5 total)
You must be logged in to reply to this topic. Login to reply