patternsqlMinor
Extended Events, sp_reset_connection and sql_text
Viewed 0 times
sp_reset_connectioneventsextendedsql_textand
Problem
I have extended event sessions running on 3 different servers. I am looking for long running or excessively called stored procedures and in-line queries (ORMs, primarily nHibernate).
The output for rpc_completed event_name shows 'sp_reset_connection' for object_type and statement_text. But, it also has a query captured in sql_text.
Does Extended Events capture the 2 executions --sp_reset_connection and the query -- as a single event? Should I view the duration value to be for the combined time for sp_reset_connection plus the query in sql_text or statement_text? Or, is it capturing sp_reset_connection and simply showing the query that triggered sp_reset_connection?
I was expecting the sp_reset_connection and the queries to be separate events.
CLARIFICATION:
Why does Extended Events return a conflict between fields?
Why is sql_text different? In a typical Extended Events row (XML), the 3 fields are in agreement as to what has been executed. Which leaves me with the question of "What was executed?". Should the duration field value be assigned to sp_reset_connection? Or the in-line sql found in sql_text? Or both?
I understand what sp_reset_connection is and how it works. What I do not understand is how Extended Events is reporting it. Profiler did not have ambiguity when reporting sp_reset_connection.
My conclusion is that Extended Events is returning the results for sp_reset_connection. However, that is a conclusion based on what I observe -- i.e a guess. I need something more concrete: even if only someone else that reached the same conclusion.
This article indicates that I can ignore sql_text.
https://www.sqlskills.com/blogs/jonathan/understanding-the-sql_text-action-in-extended-events/
Thank you for your help.
The output for rpc_completed event_name shows 'sp_reset_connection' for object_type and statement_text. But, it also has a query captured in sql_text.
Does Extended Events capture the 2 executions --sp_reset_connection and the query -- as a single event? Should I view the duration value to be for the combined time for sp_reset_connection plus the query in sql_text or statement_text? Or, is it capturing sp_reset_connection and simply showing the query that triggered sp_reset_connection?
I was expecting the sp_reset_connection and the queries to be separate events.
CLARIFICATION:
Why does Extended Events return a conflict between fields?
1. object_name = 'sp_reset_connection'
2. statement = 'exec sp_reset_connection'
3. sql_text = a query (ex: '(@p0 int)SELECT specificat0_.ScenarioId ...')Why is sql_text different? In a typical Extended Events row (XML), the 3 fields are in agreement as to what has been executed. Which leaves me with the question of "What was executed?". Should the duration field value be assigned to sp_reset_connection? Or the in-line sql found in sql_text? Or both?
I understand what sp_reset_connection is and how it works. What I do not understand is how Extended Events is reporting it. Profiler did not have ambiguity when reporting sp_reset_connection.
My conclusion is that Extended Events is returning the results for sp_reset_connection. However, that is a conclusion based on what I observe -- i.e a guess. I need something more concrete: even if only someone else that reached the same conclusion.
This article indicates that I can ignore sql_text.
https://www.sqlskills.com/blogs/jonathan/understanding-the-sql_text-action-in-extended-events/
Thank you for your help.
Solution
I will preface this by saying that
Furthermore, XEvents and Profiler present it, as well as normal RPC stored procedure calls, in the form
Given that, and judging from my own testing, I think what is going on here is that XEvents is showing each procedure call, as well as a separate call to
So for an ad-hoc batch with parameters, you get
Meanwhile,
And the actual object being called is stored in
To prove my point that there are two events being triggered, and that both show the input batch in
and this one:
sp_reset_connection is not something you normally need to worry about. It is not executed as a full RPC call, it's just a single bit flag in a TDS packet, and executes very quickly.Furthermore, XEvents and Profiler present it, as well as normal RPC stored procedure calls, in the form
exec SomeProc @param1..., but that is not what is actually executing. It is merely a textual representation of what such a call might look like if executed as a T-SQL batch. RPC calls instead use a specific TDS mechanism, which passes just SomeProc, and separately passes the parameters.Given that, and judging from my own testing, I think what is going on here is that XEvents is showing each procedure call, as well as a separate call to
sp_reset_connection, even though they are from the same RPC call.So for an ad-hoc batch with parameters, you get
sql_text = '(@param1 ...)SELECT whatever', because that is the call that has triggered sp_reset_connection (although in testing I don't get this detail). And as mentioned in your linked article, this value should really be called input_buffer which is what it really represents.Meanwhile,
statement = 'exec sp_reset_connection' because that is what the equivalent T-SQL might look like (you can't actually call it directly in T-SQL, although you can with a normal RPC call eg via SqlClient).And the actual object being called is stored in
object_name = 'sp_reset_connection'. This is what you should focus on if you want to know if a stored procedure was called, or if sp_executesql was called (for ad-hoc). And you should add a filter to your XEvent to remove sp_reset_connection....
ADD EVENT sqlserver.rpc_completed(
ACTION(sqlserver.sql_text)
WHERE (object_name <> 'sp_reset_connection')
)
To prove my point that there are two events being triggered, and that both show the input batch in
sql_text, see the following screenshots of a parameterized ad-hoc batch sent from .Net's SqlClientand this one:
Context
StackExchange Database Administrators Q#305632, answer score: 5
Revisions (0)
No revisions yet.