Understanding the sql_text Action in Extended Events

The sqlserver.sql_text action in Extended Events is one of the worst named objects in Extended Events.  The name suggests that you are going to get back the sql_text that triggered the event being collected to fire, but in reality this is not the case.  I pressed internally with Microsoft to have this action renamed to sqlserver.inputbuffer in SQL Server 2012, which actually reflects what is being returned by the action.  However, there were concerns about this breaking existing scripts (a point I didn’t necessarily buy into since other actions, targets, and even events were renamed in SQL Server 2012, but the timing of recommending this change may have had a lot to do with this as well).  I made this recommendation after seeing a post on the MSDN Forums where the poster didn’t agree with the way this action behaved in their environment.

To demonstrate this, let’s take a look at an Event Session in SQL Server 2012 that captures the sqlserver.sql_batch_completed and sqlserver.sql_statement_completed events along with the sqlserver.sql_text action for both of the events:

— If the Event Session exists Drop it
IF EXISTS (SELECT 1
            FROM sys.server_event_sessions
            WHERE name = 'SQLskills_sql_text_Action')
    DROP EVENT SESSION [SQLskills_sql_text_Action] ON SERVER;

— Create Event Session to find the database with most SP Recompile Events
CREATE EVENT SESSION [SQLskills_sql_text_Action]
ON SERVER
ADD EVENT sqlserver.sql_batch_completed(
    ACTION (sqlserver.sql_text)),
ADD EVENT sqlserver.sql_statement_completed(
    ACTION (sqlserver.sql_text))
ADD TARGET package0.ring_buffer
WITH (TRACK_CAUSALITY = ON);
GO

ALTER EVENT SESSION [SQLskills_sql_text_Action]
ON SERVER
STATE=START;
GO

With this event session created, we can then run a couple of different test scenarios in the environment to show how this action is not the sql_text, but is instead the input_buffer for the event that is being fired:

— Perform some Tests
SELECT PASSWORD = 'bar12345!!';
SELECT 'password' as Secret;
CREATE LOGIN foo WITH PASSWORD = 'bar12345!!';
SELECT 'reallylongstringwithpasswordincludedintext' AS Funny;
EXEC('SELECT ''reallylongstringwithpasswordincludedintext'' AS Funny');
GO

— Perform some additional Tests
SELECT PASSWORD = 'bar12345!!';
GO
SELECT 'password' as Secret;
GO
CREATE LOGIN foo WITH PASSWORD = 'bar12345!!';
GO
SELECT 'reallylongstringwithpasswordincludedintext' AS Funny;
GO
EXEC('SELECT ''reallylongstringwithpasswordincludedintext'' AS Funny');

Once these statements have been executed, we can then drop the events from the event session to allow the ring_buffer target to be queried to show the differences between the statement and batch_text columns from the events, which consequently don’t exist in SQL Server 2008 or SQL Server 2008 R2, and the sql_text action output.

ALTER EVENT SESSION [SQLskills_sql_text_Action]
ON SERVER
DROP EVENT sqlserver.sql_batch_completed,
DROP EVENT sqlserver.sql_statement_completed;
GO

With the events removed, we can now query the target data from the ring_buffer to look at what was actually captured.

— Query the XML to get the Target Data
SELECT
    event.value('(event/@name)[1]', 'varchar(50)') AS event_name,
    DATEADD(hh,
            DATEDIFF(hh, GETUTCDATE(), CURRENT_TIMESTAMP),
            event.value('(event/@timestamp)[1]', 'datetime2')) AS [timestamp],
    ISNULL(event.value('(event/data[@name="statement"]/value)[1]', 'nvarchar(max)'),
            event.value('(event/data[@name="batch_text"]/value)[1]', 'nvarchar(max)')) AS [stmt/btch_txt],
    event.value('(event/action[@name="sql_text"]/value)[1]', 'nvarchar(max)') as [sql_text]
FROM
(   SELECT n.query('.') as event
    FROM
    (
        SELECT CAST(target_data AS XML) AS target_data
        FROM sys.dm_xe_sessions AS s   
        JOIN sys.dm_xe_session_targets AS t
            ON s.address = t.event_session_address
        WHERE s.name = 'SQLskills_sql_text_Action'
          AND t.target_name = 'ring_buffer'
    ) AS sub
    CROSS APPLY target_data.nodes('RingBufferTarget/event') AS q(n)
) AS tab

Looking at the output, we can see that there is a different behavior and output from the sql_text action between the two different sets of tests.

image

The first set of tests, which were run in a single batch, have all of the sql_text output masked because of the inclusion of the work password in the input buffer text.  This is not new behavior in SQL Server, it actually existed in SQL Trace prior to SQL Server 2005 SP2, where the code path used to capture TextData was changed to output the post query parsing text, which only strips the text out for DDL operations that would actually contain password information, like the CREATE LOGIN event in the second set of tests highlighted in the green box above.  The code path used by the sql_text action is the same as the raw input buffer for the session which masks off the entire text if the work password appears anywhere in the text, which is why the last SELECT statement and dynamic string execution of a SELECT don’t return sql_text information in the first set of tests highlighted in red above.  Contrast this with the batch_text and statement column outputs from the events, and you can easily see that sql_text isn’t quite what you’d expect.

So how do you work around/with this information?  If you are on SQL Server 2008, my typical recommendation is to capture the tsql_stack action instead, which gives you the sql_handle and offset information to be able to parse the statements from cache (a topic for another blog post that I’ll write).  If you need the actual statement information or RPC information from a specific execution, the best thing to do in SQL Server 2012 is to use TRACK_CAUSALITY and and the appropriate event, rpc_starting/sql_statement_starting/completed to be able to correlate the activity_id back to the statement that actually triggered the event.

Leave a Reply

Your email address will not be published. Required fields are marked *

Other articles

Imagine feeling confident enough to handle whatever your database throws at you.

With training and consulting from SQLskills, you’ll be able to solve big problems, elevate your team’s capacity, and take control of your data career.