Which Extended Event to Use to Capture Stored Procedures
If you’re a DBA, how many times have developers asked you to check whether a particular stored procedure is hitting SQL Server?
Yes, we’ve all been there. Typically, you either run Profiler or set up an Extended Events session to trace it. But the question is, have you ever been confused about which event action to use?
For example, to capture a stored procedure, you could use rpc_starting
, module_start
, sp_batch_start
, etc., or even rpc_completed
, module_end
, sp_batch_completed
, and so on. Honestly, I’ve been there too, wondering which event is the best fit.
So, in this post, I’ll break down the following actions to help you determine the right event to use based on the situation:
module_start
rpc_starting
sp_batch_start
sp_statement_start
I’ll start by creating and enabling these event sessions. Then, I’ll execute a stored procedure so you can see how each event captures the execution and the differences between them.
Note: It is not recommended to run extended events on production servers during business hours, it can consume a lot of resources and slow down the performance.
Module_start:
This event captures all functions and stored procedures, whether executed locally or via RPC (Remote Procedure Call) from web or application servers.
It captures stored procedure execution but does not capture parameters in some cases.
Let’s create an event session for
module_start
.Include
module_end
only if you want to capture execution duration or check whether the procedure completes successfully.In this case, I’ve added ‘usp_’ as a filter for sql text, you may change the filter according to your needs. It is a good practice to filter as much as you can, so you are using up less resources.
--Create Extended event to capture modules, which are functions and stored procedures. IF EXISTS (SELECT 1 FROM sys.server_event_sessions WHERE name = 'Capture_Stored_Procedures_mod') DROP EVENT SESSION Capture_Stored_Procedures_mod ON SERVER; GO CREATE EVENT SESSION [Capture_Stored_Procedures_mod] ON SERVER ADD EVENT sqlserver.module_start --Capture start of function/procedure (SET collect_statement=(1) --use this to display sql_text ACTION(sqlserver.client_app_name,sqlserver.client_pid,sqlserver.database_name,sqlserver.nt_username,sqlserver.server_principal_name,sqlserver.session_id,sqlserver.sql_text) WHERE ([sql_text] like '%usp_%')), --filter to capture only stored procs that have 'usp_' ADD EVENT sqlserver.module_end --Add module_end only if you're looking for duration (SET collect_statement=(1) ACTION(sqlserver.client_app_name,sqlserver.client_pid,sqlserver.database_name,sqlserver.nt_username,sqlserver.server_principal_name,sqlserver.session_id,sqlserver.sql_text) WHERE ([sql_text] like '%usp_%')) --Save target data in file ADD TARGET package0.event_file(SET filename=N'C:\Backup\StoredProcedureCaptures_mod.xel',max_file_size=(5),max_rollover_files=(2)) 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 -- Start Extended Events session ALTER EVENT SESSION [Capture_Stored_Procedures_mod] ON SERVER STATE = START; GO -- Stop Extended Events session when you're done capturing ALTER EVENT SESSION [Capture_Stored_Procedures_mod] ON SERVER STATE = STOP; GO
Now, execute a stored procedure ‘usp_sql’
USE DBATEST
GO
CREATE OR ALTER PROCEDURE usp_sql
@InputMessage NVARCHAR(100)
AS
BEGIN
SELECT @InputMessage AS Message;
END;
GO
-- Execute the stored procedure
EXEC usp_sql @InputMessage = 'ExtendedEvents';
Checking Data from Target File – Result:
In screenshot below, there are two rows saved:
One for
module_start
, when the stored procedure starts executing.One for
module_end
, when the stored procedure finishes executing.
The statement
and sql_text
columns display the SQL query that was executed.
Additionally, you can view details such as:
The client from which the query was executed.
The user name.
The database name.
The duration and timestamp.
The duration is measured in microseconds for this event. But, the unit of duration varies depending on the event type and is not always in microseconds.
-- Query the Extended Events data from the file
SELECT
event_data.value('(event/@name)[1]', 'nvarchar(50)') AS EventName,
event_data.value('(event/data[@name="statement"]/value)[1]', 'nvarchar(max)') AS Statement,
event_data.value('(event/action[@name="sql_text"]/value)[1]', 'nvarchar(max)') AS sqltext,
event_data.value('(event/action[@name="client_app_name"]/value)[1]', 'NVARCHAR(256)') AS client_app_name,
event_data.value('(event/action[@name="client_pid"]/value)[1]', 'NVARCHAR(256)') AS client_pid,
event_data.value('(event/action[@name="server_principal_name"]/value)[1]', 'NVARCHAR(256)') AS user_name,
event_data.value('(event/action[@name="database_name"]/value)[1]', 'NVARCHAR(256)') AS database_name,
event_data.value('(event/data[@name="duration"]/value)[1]', 'bigint') AS Duration,
event_data.value('(event/@timestamp)[1]', 'datetime') AS [Timestamp]
FROM (
SELECT
CONVERT(XML, event_data) AS event_data
FROM sys.fn_xe_file_target_read_file('C:\Backup\StoredProcedureCaptures_mod*.xel', NULL, NULL, NULL)
) AS data;
GO
Rpc_starting:
This event captures stored procedures executed via an RPC (Remote Procedure Call), meaning those triggered from web or application servers. It does not capture locally executed procedures.
It does capture stored procedure parameters.
RPC captures can sometimes be tricky. If a stored procedure is not being captured, you may need to use
sql_batch_starting
additionally.Let’s create an event session for
rpc_starting
. You don’t need to includerpc_completed
unless you want to capture execution duration or check whether the procedure completes successfully.Additionally, RPC actions do not support
collect_statement = 1
.--Create Extended event to capture stored procedures executed via an RPC (Remote Procedure Call), meaning those triggered from web or application servers IF EXISTS (SELECT 1 FROM sys.server_event_sessions WHERE name = 'Capture_Stored_Procedures_rpc') DROP EVENT SESSION Capture_Stored_Procedures_rpc ON SERVER; GO CREATE EVENT SESSION [Capture_Stored_Procedures_rpc] ON SERVER ADD EVENT sqlserver.rpc_starting( --capture start of SP execution ACTION(sqlserver.client_app_name,sqlserver.client_pid,sqlserver.database_name,sqlserver.nt_username,sqlserver.server_principal_name,sqlserver.session_id,sqlserver.sql_text) WHERE ([sql_text] like '%usp_%')) --filter to capture only stored procs that have 'usp_' ,ADD EVENT sqlserver.rpc_completed( --capture when SP completed ACTION(sqlserver.client_app_name,sqlserver.client_pid,sqlserver.database_name,sqlserver.nt_username,sqlserver.server_principal_name,sqlserver.session_id,sqlserver.sql_text) WHERE ([sql_text] like '%usp_%')) ,ADD EVENT sqlserver.sql_batch_starting( --RPC can be tricky and SPs can sometimes come up as a batch instead of RPC, so adding sql_batch action to not miss any SP ACTION(sqlserver.client_app_name,sqlserver.client_pid,sqlserver.database_name,sqlserver.nt_username,sqlserver.server_principal_name,sqlserver.session_id,sqlserver.sql_text) WHERE ([sql_text] like '%usp_%')) --Save target data in file ADD TARGET package0.event_file(SET filename=N'C:\Backup\StoredProcedureCaptures_rpc.xel',max_file_size=(5),max_rollover_files=(2)) 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 -- Start Extended Events session ALTER EVENT SESSION [Capture_Stored_Procedures_rpc] ON SERVER STATE = START; GO -- Stop Extended Events session when you're done capturing ALTER EVENT SESSION [Capture_Stored_Procedures_rpc] ON SERVER STATE = STOP; GO
Executing Stored Procedures via PowerShell and OStress
Create a stored procedure and execute it from PowerShell to generate an RPC (Remote Procedure Call).
USE DBATEST
GO
CREATE OR ALTER PROCEDURE dbo.usp_rpcSP (
@ID INT
,@Name NVARCHAR(50)
)
AS
BEGIN
SELECT @ID AS ID
,@Name AS Name;
END;
--Execute below in Powershell
$Server = "HARIPRIYA\SQL2022"
$Database = "DBATEST"
# Define parameters
$ID = 1
$Name = "FromPowerShell"
# Concatenate the parameters into the query
$Query = "EXEC dbo.usp_rpcSP @ID = $ID, @Name = N'$Name'"
# Execute using Invoke-SqlCmd
Invoke-SqlCmd -ServerInstance $Server -Database $Database -Query $Query
2. Create another stored procedure and run it using OStress RML command-line utility to check whether it gets captured as an RPC event.
CREATE OR ALTER PROCEDURE usp_sqlrmd @InputMessage NVARCHAR(100)
AS
BEGIN
SELECT @InputMessage AS Message;
END;
-- Execute stored procedure in ostress utility
--ostress.exe -S"HARIPRIYA\SQL2022" -Q"exec dbatest.dbo.usp_sqlrmd @InputMessage = 'Hello, World!'" -n1 -r1 -q
Checking the Results in the Target File:
The stored procedure executed from PowerShell was captured as an RPC event since
rpc_starting
andrpc_completed
got fired. (Rows 1 and 2)sql_batch_starting
is fired as well, since it also counts as a batch execution. (Row 3)
The stored procedure executed from OStress was NOT captured as an RPC event, since no rpc events have been fired. Instead, it was only logged under
sql_batch_starting
. (Row 4)This is the reason why sql_batch_starting is added, so no SP executions are missed. You could also add sql_statement_starting event.
SELECT event_data.value('(event/@name)[1]', 'nvarchar(50)') AS EventName, event_data.value('(event/data[@name="statement"]/value)[1]', 'nvarchar(max)') AS Statement, event_data.value('(event/action[@name="sql_text"]/value)[1]', 'nvarchar(max)') AS sqltext, event_data.value('(event/action[@name="client_app_name"]/value)[1]', 'NVARCHAR(256)') AS client_app_name, event_data.value('(event/action[@name="client_pid"]/value)[1]', 'NVARCHAR(256)') AS client_pid, event_data.value('(event/action[@name="server_principal_name"]/value)[1]', 'NVARCHAR(256)') AS user_name, event_data.value('(event/action[@name="database_name"]/value)[1]', 'NVARCHAR(256)') AS database_name, event_data.value('(event/data[@name="duration"]/value)[1]', 'bigint') AS Duration, event_data.value('(event/@timestamp)[1]', 'datetime') AS [Timestamp] FROM ( SELECT CONVERT(XML, event_data) AS event_data FROM sys.fn_xe_file_target_read_file('C:\Backup\StoredProcedureCaptures_rpc*.xel', NULL, NULL, NULL) ) AS data; GO
This post is getting lengthy, so I’ll keep it brief for sql_statement_starting
and sql_batch_starting
events.
sql_statement_starting
logs an entry for each statement for every query.sql_batch_starting
logs an entry for the entire batch execution rather than individual statements.
Both can generate excessive noise, so filtering them based on your needs is the best approach.
Summary
module_begin/end:
Captures all stored procedures, including the ones executed locally in SSMS.
Using this event will help to check if a stored procedure is hitting the SQL Server.
Add module_end only if you’re interested in duration.
Does not capture adhoc queries.
rpc_starting/completed:
Captures only stored procedures called via RPC.
Always captures parameters.
Using this event will help when you need parameters for further testing.
Add rpc_completed only if you’re interested in duration.
Add sql_batch_starting to be on the safer side to not miss any rpc calls, since rpc calls can be tricky and can show up as a SQL batch and not always get captured via rpc_starting event.
Stored procedures executed directly in SSMS do not generate an RPC event.
I hope this helped you understand how and when to use the rpc_starting/ module_begin/ sql_statement_starting events accordingly.
Note
Always add filters to actions, so XE doesn’t get resource intensive.
It is not recommended to run extended events on production servers during business hours, it can consume a lot of resources and slow down the performance.
Consider running them after-hours or over the weekends.
Thanks for reading,
Haripriya.
My LinkedIn