I'm running an Extended Event session in SQL Server 2017 that's only recording module_end
events for a specific database. The reason for this trace is two-fold:
- I'm wanting to see the frequency (or lack-thereof) for which a stored procedure has been called.
- I'm trying to get some specifics for each procedure call (e.g. who called it, from where, how long it took, how many records were returned, etc.).
When looking at some of the results, I noticed that there were a few procedures on the list that had tens of millions of executions, but had never once had a row_count
greater than 0. There were plenty of other recorded events with row_count
seemingly properly populated, so I had initially considered that the ones that had never returned a result had been miscalled by the applications referencing them. However, this turned out not to be the case.
To get a better look at the parameters the procedures had been called with, I started up a Profiler session watching for just those procedure calls. The particular procedure I was checking was being called extremely frequently, and I got a good number of example calls rather quickly, and turned off the Profiler. There were a couple things noticed from this:
- The calls had legitimate parameters.
- Having made no changes to the Extended Event session, the recorded procedure calls during the time that the Profiler was active magically started recording the
row_count
correctly as1
instead of0
.
Below is the definition of the Extended Event that I'm using:
Create Event Session [Test Event] On Server
Add Event sqlserver.module_end
(
Action (sqlserver.database_name, sqlserver.session_id)
Where
(
sqlserver.database_name = N'TestDatabase'
And object_type = 'P'
)
)
Add Target package0.ring_buffer (Set max_events_limit = 10000, max_memory = 51200)
With
(
Max_Memory = 4096KB,
Event_Retention_Mode = Allow_Single_Event_Loss,
Max_Dispatch_Latency = 30 Seconds,
Max_Event_Size = 0KB,
Memory_Partition_Mode = None,
Track_Causality = On,
Startup_State = On
)
Go
And some sample code to test with:
Use TestDatabase
Go
Create Table TestTable
(
ID Int Not Null Identity (1, 1) Primary Key Clustered,
Name Varchar (20)
)
Go
Insert TestTable (Name)
Values ('Alpha'), ('Bravo'), ('Charlie'), ('Delta'), ('Echo'), ('Foxtrot'), ('Golf')
Go
Create Procedure GetTestNameByID (@ID Int)
As Begin
Set NoCount On
Select Name
From TestTable
Where ID = @ID
End
Go
Execute GetTestNameByID @ID = 2
Execute GetTestNameByID @ID = 10
Execute GetTestNameByID @ID = Null
Go
Drop Procedure GetTestNameByID
Drop Table TestTable
Go
Note: the real procedure I'm noticing the odd behavior with is logically equivalent to the testing procedure above.
Running each of the three Execute
statements results in the following in the Extended Event:
In this example, the row_counts
recorded in the Extended Event are correct. However, in the actual environment, all of these are being recorded as 0
, even though they are actually returning results.
Here are my questions:
- Is there something I can add to the Extended Event session to correctly record the
row_count
? - Is there possibly some way these stored procedures are being called where they are actually returning results, but somehow emitting
0
to the Extended Event? - Why would an active SQL Profiler session have suddenly made the Extended Event session record the correct
row_count
data?
Again, I do want to stress that there were no changes made to the Extended Event session, and there are seemingly correct results in the exact same trace file for other stored procedures.
Additional scenarios I've tested:
- Executing the stored procedure from within another procedure.
- Executing the stored procedure from another database on the same server.
- Executing the stored procedure from an
OPENROWSET
session on a different server. - Executing the stored procedure within a
TRANSACTION
that then forced aROLLBACK
. - Executing the stored procedure within an uncommitted
TRANSACTION
. - Use of
SET NOCOUNT ON
- Additional
SELECT
orSET
statements after the actualSELECT
. - Use of
OUTPUT
in the procedure. - Use of
MERGE
orUPDATE
statements exclusively. - Checked for
SERVICE BROKER
usage, and found that the queries were not being recorded withis_system
set toTrue
.
All of the above situations failed to yield a row_count
of 0
when supplied with a valid @ID
parameter.
I'm trying to understand how it can happen, and in turn, also trying to figure out how to remedy it.