Monday, April 4, 2011

Extended Events to Capture Errors;

Hi Extended Events were introduced in SQL Server 2008, I just started learning about it, Jonathan Kehayias has an excellent white paper on Extended Events White Paper.  He has also blogged about it extensively.
I have frequently encountered problem where user doesn't have permission to execute something or they have errors running some script. I used to start a trace to monitor for Errors and Warnings. I thought about doing it differently, Extended Events can be used to capture permission denied errors, syntax errors and login failures etc. I have a small script to demonstrate that.

-- Create an Event session named CaptureErrors we are looking for errors between 10 and 20 in severity. I am using a file target. Also capturing sql_text, along with the database id, host computer etc.

Jonathan had mentioned about using max dispatch latency of 1 second ,  since it could impact the dispatcher pool and  it should be used  for demonstration purposes only.

CREATE EVENT SESSION CaptureErrors

ON SERVER
   ADD EVENT sqlserver.error_reported
   (ACTION (sqlserver.sql_text,sqlserver.database_id,sqlserver.client_hostname
   ,sqlserver.username,sqlserver.nt_username,sqlserver.tsql_stack)
     WHERE severity>=10 and severity<20/*anything over20 is captured by System Health Event*/ )
   ADD TARGET package0.asynchronous_file_target
  (SET FILENAME = N'C:\Program Files\Microsoft SQL Server\MSSQL11.V1\MSSQL\Log\CaptureErrors.xel'
  , METADATAFILE = N'C:\Program Files\Microsoft SQL Server\MSSQL11.V1\MSSQL\Log\CaptureErrors.xem')
       WITH (max_dispatch_latency = 1 seconds);
GO
ALTER EVENT SESSION CaptureErrors ON SERVER

STATE = START
GO

--Once its started we could execute some scripts to generate errors

SELECT * from  databases
go
SELECT  from test1
GO

--We could then Query the file target and get the error messages.


IF OBJECT_ID('tempdb..#ErrorData') IS NOT NULL
       DROP TABLE #ErrorData
CREATE TABLE #ErrorData
(event_data xml)

INSERT INTO #ErrorData (event_data)
SELECT  CAST(event_data as XML) FROM sys.fn_xe_file_target_read_file
     ('C:\Program Files\Microsoft SQL Server\MSSQL11.V1\MSSQL\Log\CaptureErrors*.xel'
, 'C:\Program Files\Microsoft SQL Server\MSSQL11.V1\MSSQL\Log\CaptureErrors*.xem', NULL, NULL);

SELECT
       event_data.value('(event/@name)[1]', 'varchar(50)') AS event_name,
   event_data.value('(event/@package)[1]', 'varchar(50)') AS package_name,
   event_data.value('(event/@id)[1]', 'varchar(50)') AS ID,
   event_data.value('(event/@version)[1]', 'varchar(50)') AS Version,
   DATEADD(hh,DATEDIFF(hh, GETUTCDATE(), CURRENT_TIMESTAMP),
           event_data.value('(event/@timestamp)[1]', 'datetime2')) AS [timestamp],
   event_data.value('(event/data[@name="error"]/value)[1]', 'int') as ErrorNumber,
   event_data.value('(event/data[@name="severity"]/value)[1]', 'smallint')  AS Severity,
   event_data.value('(event/data[@name="state"]/value)[1]', 'tinyint')  AS [State],
   event_data.value('(event/data[@name="user_defined"]/value)[1]', 'nvarchar(100)') as User_Defined,
   event_data.value('(event/data[@name="message"]/value)[1]', 'nvarchar(250)') as [Message],
   event_data.value('(event/action[@name="sql_text"]/value)[1]', 'nvarchar(4000)') as sql_text,
   event_data.value('(event/action[@name="database_id"]/value)[1]', 'int') as DatabaseID,
   event_data.value('(event/action[@name="client_hostname"]/value)[1]', 'nvarchar(4000)') as client_hostname,
   event_data.value('(event/action[@name="nt_username"]/value)[1]', 'nvarchar(4000)') as nt_username,
   event_data.value('(event/action[@name="username"]/value)[1]', 'nvarchar(4000)') as username,
   event_data.value('(event/action[@name="tsql_stack"]/value)[1]', 'nvarchar(4000)') as tsql_stack
FROM #ErrorData
ORDER BY [timestamp]

Below is the results from the above query, I ran aT-SQL commands that generated Syntax error  and another was a missing object, Then I had two login failure error messages. Extended Events Captured those information as we can see.




References:
http://sqlblog.com/blogs/jonathan_kehayias/archive/2010/12/15/an-xevent-a-day-15-of-31-tracking-ghost-cleanup.aspx
http://www.sqlskills.com/BLOGS/PAUL/category/Extended-Events.aspx