Using SQL Server XEVENTS | 1 of 3
Logging Errors with corresponding T-SQL
by Craig Bellissimo
September 7, 2017
Logging Errors with corresponding T-SQL
by Craig Bellissimo
September 7, 2017
Let's cut to the chase...SQL Profiler is Dead!
As many of you know, Microsoft is moving away from SQL Profiler, and replacing it with a much more flexible and dynamic toolset known as Extended Events or XEVENTS. But as good as this move is, many SQL developers just aren't very familiar with XEVENTS or what can be accomplished with them. To help solve that problem, I decided to do a 3-part series, using XEVENTS to replace (and improve!) a number of common Profiler uses.
So, without further ado...
Part 1: Using SQL Server XEVENTS | Logging Errors with corresponding T-SQL
In Profiler, the “User Error Message” trace event only gives you the error that occurred, without giving you the corresponding T-SQL that caused the error. I have written an XEVENT replacement that will surface the error with the corresponding SQL as follows:
This DDL command will write all XML associated with the T-SQL and corresponding error to the d:\traces\xevents directory.
Create event session xe_User_Errors on server
add event sqlserver.Error_Reported
(Action
( Sqlserver.sql_text, -- SQL associate with the error.
package0.collect_system_time,-- Time when the exception occurred
sqlserver.username, -- Name of the user that reported the error
sqlserver.client_app_name, -- Client application name
sqlserver.client_hostname, -- Host which initiated the query
sqlserver.database_id -- Database against which the query was being executed
)
where severity > 10 )
add target package0.asynchronous_file_target
(set filename = N'D:\Traces\XEvents\xe_xe_Error_Reported.xel',
metadatafile = N'D:\Traces\XEvents\xe_xe_Error_Reported.xem');
After creating the “xe_User_Errors” event then you can manually start the trace to start logging errors with corresponding T-SQL with the following command.
--Start the trace that we setup above.
alter event session xe_User_Errors on server state = start;
Run this command to automatically start the event every time SQL Server starts.
alter event session xe_User_Errors on server with (STARTUP_STATE = ON);
go
Now that everything is working and logging to a file, run a command that will generate an error as follows.
--Create an error
select 1/0
After executing the above command, run the following T-SQL CTE statement to shred your XML data into relational data as follows.
with x as (
SELECT CAST(event_data as XML) AS edx
FROM sys.fn_xe_file_target_read_file( 'D:\Traces\XEvents\xe_xe_Error_Reported*.xel', 'D:\Traces\XEvents\xe_xe_Error_Reported*.xem', NULL, NULL)
)
, c as (
select edx.value('(event/action[@name="collect_system_time"]/value)[1]','Datetime2') as [Time],
edx.value('(event/data[@name="message"]/value)[1]','nvarchar(250)') as [ErrorMessage],
edx.value('(event/action[@name="sql_text"]/value)[1]','nvarchar(4000)') as [BadSQL],
edx.value('(event/action[@name="client_hostname"]/value)[1]','nvarchar(4000)') as [HostName],
edx.value('(event/action[@name="username"]/value)[1]','nvarchar(250)') as [Login],
edx.value('(event/action[@name="client_app_name"]/value)[1]','nvarchar(4000)') as [ApplicationName],
edx.value('(event/action[@name="database_id"]/value)[1]','nvarchar(4000)') as [DatabaseID]
from x
)
select [Time]
, ErrorMessage
, BadSQL
, HostName
, [LOGIN]
, [ApplicationName]
, db_name([DatabaseID]) DatabaseName
from c
--You could even put a where clause on this CTE to limit by login, time, host , etc.
--WHERE [LOGIN] = 'TestUser'
This will return a value that looks as follows:
Remember, just like a trace, it’s possible to turn off this functionality using T-SQL:
--This will stop the event from logging to the file.
alter event session xe_User_Errors on server state = stop;
--This will drop the event and corresponding meta data from the instance.
drop event session xe_user_errors on server;
So, there you have it. Next week I will show you how to rewrite the Profiler
“Blocked Process Report” event into an Xevent routine.
Stay tuned!
As many of you know, Microsoft is moving away from SQL Profiler, and replacing it with a much more flexible and dynamic toolset known as Extended Events or XEVENTS. But as good as this move is, many SQL developers just aren't very familiar with XEVENTS or what can be accomplished with them. To help solve that problem, I decided to do a 3-part series, using XEVENTS to replace (and improve!) a number of common Profiler uses.
So, without further ado...
Part 1: Using SQL Server XEVENTS | Logging Errors with corresponding T-SQL
In Profiler, the “User Error Message” trace event only gives you the error that occurred, without giving you the corresponding T-SQL that caused the error. I have written an XEVENT replacement that will surface the error with the corresponding SQL as follows:
This DDL command will write all XML associated with the T-SQL and corresponding error to the d:\traces\xevents directory.
Create event session xe_User_Errors on server
add event sqlserver.Error_Reported
(Action
( Sqlserver.sql_text, -- SQL associate with the error.
package0.collect_system_time,-- Time when the exception occurred
sqlserver.username, -- Name of the user that reported the error
sqlserver.client_app_name, -- Client application name
sqlserver.client_hostname, -- Host which initiated the query
sqlserver.database_id -- Database against which the query was being executed
)
where severity > 10 )
add target package0.asynchronous_file_target
(set filename = N'D:\Traces\XEvents\xe_xe_Error_Reported.xel',
metadatafile = N'D:\Traces\XEvents\xe_xe_Error_Reported.xem');
After creating the “xe_User_Errors” event then you can manually start the trace to start logging errors with corresponding T-SQL with the following command.
--Start the trace that we setup above.
alter event session xe_User_Errors on server state = start;
Run this command to automatically start the event every time SQL Server starts.
alter event session xe_User_Errors on server with (STARTUP_STATE = ON);
go
Now that everything is working and logging to a file, run a command that will generate an error as follows.
--Create an error
select 1/0
After executing the above command, run the following T-SQL CTE statement to shred your XML data into relational data as follows.
with x as (
SELECT CAST(event_data as XML) AS edx
FROM sys.fn_xe_file_target_read_file( 'D:\Traces\XEvents\xe_xe_Error_Reported*.xel', 'D:\Traces\XEvents\xe_xe_Error_Reported*.xem', NULL, NULL)
)
, c as (
select edx.value('(event/action[@name="collect_system_time"]/value)[1]','Datetime2') as [Time],
edx.value('(event/data[@name="message"]/value)[1]','nvarchar(250)') as [ErrorMessage],
edx.value('(event/action[@name="sql_text"]/value)[1]','nvarchar(4000)') as [BadSQL],
edx.value('(event/action[@name="client_hostname"]/value)[1]','nvarchar(4000)') as [HostName],
edx.value('(event/action[@name="username"]/value)[1]','nvarchar(250)') as [Login],
edx.value('(event/action[@name="client_app_name"]/value)[1]','nvarchar(4000)') as [ApplicationName],
edx.value('(event/action[@name="database_id"]/value)[1]','nvarchar(4000)') as [DatabaseID]
from x
)
select [Time]
, ErrorMessage
, BadSQL
, HostName
, [LOGIN]
, [ApplicationName]
, db_name([DatabaseID]) DatabaseName
from c
--You could even put a where clause on this CTE to limit by login, time, host , etc.
--WHERE [LOGIN] = 'TestUser'
This will return a value that looks as follows:
Remember, just like a trace, it’s possible to turn off this functionality using T-SQL:
--This will stop the event from logging to the file.
alter event session xe_User_Errors on server state = stop;
--This will drop the event and corresponding meta data from the instance.
drop event session xe_user_errors on server;
So, there you have it. Next week I will show you how to rewrite the Profiler
“Blocked Process Report” event into an Xevent routine.
Stay tuned!