SQL Server – Capture Long Running Stored Procedures and Execution Count using Extended Events

I always use SQL profiler to capture query performance. I’ve read about Extended Events somewhere but I just don’t use it because I’m just too comfortable using SQL profiler. Then one day, I attended a SQL Server User Group session. The speaker talked about Extended Events and encouraged us to use it because of the following reasons:

• SQL profiler will be deprecated.
• Extended events less resource-intensive.
• There are a lot of enhancements done to the extended events since it was introduced. On the other hand, SQL profiler has not been enhanced for a long time.
• Extended events is easier to use.

After listening to the presentation, I was inspired to use Extended Events.

Below is how I use it to capture Query Performance.

1. Create extended event to capture query performance. Indicate the username and DatabaseName that you want to monitor.

CREATE EVENT SESSION [QueryPerformance] ON SERVER 

ADD EVENT sqlserver.rpc_completed(SET collect_statement=(1)

    ACTION(sqlserver.database_name,sqlserver.session_id,sqlserver.sql_text,sqlserver.username)

    WHERE ([sqlserver].[equal_i_sql_unicode_string]([sqlserver].[username],N'username') AND [sqlserver].[equal_i_sql_unicode_string]([sqlserver].[database_name],N'DatabaseName') AND [duration]>=(500000))),

ADD EVENT sqlserver.sql_batch_completed(

    ACTION(sqlserver.database_name,sqlserver.session_id,sqlserver.sql_text,sqlserver.username)

    WHERE ([sqlserver].[equal_i_sql_unicode_string]([sqlserver].[username],N' username ') AND [sqlserver].[equal_i_sql_unicode_string]([sqlserver].[database_name],N'DatabaseName') AND [duration]>=(500000))) 

ADD TARGET package0.event_file(SET filename=N'D:\DBA\ExtendedEvents\QueryPerformance\QueryPerformance.xel')

WITH (MAX_MEMORY=4096 KB,EVENT_RETENTION_MODE=ALLOW_SINGLE_EVENT_LOSS,MAX_DISPATCH_LATENCY=30 SECONDS,MAX_EVENT_SIZE=0 KB,MEMORY_PARTITION_MODE=NONE,TRACK_CAUSALITY=OFF,STARTUP_STATE=OFF)

GO


2. Start extended event (Session Name: QueryPerformance)

To start extended event session via T-SQL:

ALTER EVENT SESSION [QueryPerformance] 
ON SERVER STATE = START 

3. Stop Extended Events.

Via T-SQL:

ALTER EVENT SESSION [QueryPerformance] 
ON SERVER STATE = STOP

Note: We can schedule Extended Events Session Start or Stop by creating SQL Agent Jobs. You may refer to this link https://www.concurrency.com/blog/december-2015/schedule-extended-events-session-start-or-stop

Now, a file has been generated in your server.

4. Load the data captured from extended events to a table. Preferrably to a utility database. Execute the script below on your utility database. You may change the name of the target table where you want to load the data captured.

WITH xEvents
AS (SELECT object_name AS xEventName,
CAST (event_data AS XML) AS xEventData
FROM sys.fn_xe_file_target_read_file('D:\DBA\ExtendedEvents\QueryPerformance\QueryPerformance*.xel',
NULL, NULL, NULL)
)
SELECT xEventName,
xEventData.value('(/event/data[@name=''duration'']/value)[1]','bigint') Duration,
xEventData.value('(/event/data[@name=''physical_reads'']/value)[1]','bigint') PhysicalReads,
xEventData.value('(/event/data[@name=''logical_reads'']/value)[1]','bigint') LogicalReads,
xEventData.value('(/event/data[@name=''cpu_time'']/value)[1]','bigint') CpuTime,
CASE xEventName
 WHEN 'sql_batch_completed'
 THEN xEventData.value('(/event/data[@name=''batch_text'']/value)[1]',
 'varchar(max)')
 WHEN 'rpc_completed'
 THEN xEventData.value('(/event/data[@name=''statement'']/value)[1]',
 'varchar(max)')
END AS SQLText,
xEventData.value('(/event/data[@name=''object_name'']/value)[1]','varchar(max)') Object_Name
INTO Table_Name
FROM xEvents;
 


5. Execute the script below to get the Stored Procedure names and their run duration and total execution count.

SELECT 
 Object_name,
 MIN(st.Duration)/1000 AS MIN_Duration_ms,
 AVG(st.Duration)/1000 AS AVG_Duration_ms,
 MAX(st.Duration)/1000 AS MAX_Duration_ms,
 COUNT(*) AS TotalExecutions
FROM Table_Name AS st
GROUP BY   Object_name
ORDER BY AVG(st.Duration) DESC;

Note: The duration captured from extended events is in microseconds. That is why in my script, I divided it by 1000 to convert it to milliseconds (ms). It is easier to read in ms.