Part 2: Enhanced T-SQL Error Handling With Extended Events

In the last post, we explored a couple of examples of using Extended Events to enhance T-SQL error handling. There was some potential there. But a hard-coded SPID was necessary: we couldn't use the code examples for anything automated. It was cumbersome, too. Let's change that, shall we?
To make the code easier to work with, I moved most of it into three stored procs: one each to create an XEvent session, get the XEvent session data, and drop the XEvent session. There's also a table type. This will negate the need to declare a temp table over and over. The four objects can be created in any database you choose. I opted to create them in [tempdb]. The code for each is below in the four tabs.
USE ; GO IF NOT EXISTS ( SELECT * FROM INFORMATION_SCHEMA.ROUTINES r WHERE r.ROUTINE_SCHEMA = 'dbo' AND r.ROUTINE_NAME = 'CreateXESession_ErrorReported' ) BEGIN EXEC('CREATE PROC dbo.CreateXESession_ErrorReported AS PRINT CURRENT_TIMESTAMP;'); END; GO ALTER PROC dbo.CreateXESession_ErrorReported /* Purpose: Creates and starts an Extended Events Session to monitor errors (if any) that occur. The session is filtered by the current SPID. Inputs: none. History: 09/05/2016 DMason Created */ AS BEGIN DECLARE @XESessionName SYSNAME = 'Error Handling Session(SPID ' + CAST(@@SPID AS VARCHAR) + ')'; IF EXISTS( SELECT * FROM master.sys.server_event_sessions s WHERE s.name = @XESessionName ) BEGIN DECLARE @ErrMsg NVARCHAR(MAX) = 'Session ' + @XESessionName + ' already exists.'; RAISERROR(@ErrMsg, 16, 1); RETURN; END --Include SPID within session name for isolation. DECLARE @TSql NVARCHAR(MAX) = 'CREATE EVENT SESSION [' + @XESessionName + '] ON SERVER ADD EVENT sqlserver.error_reported ( ACTION( sqlserver.session_id, sqlserver.sql_text ) WHERE [package0].[not_equal_unicode_string]([message],N'''''''''''') AND [severity]>(10) AND [sqlserver].[session_id]=(' + CAST(@@SPID AS VARCHAR) + ') ) ADD TARGET package0.ring_buffer WITH ( --NO_EVENT_LOSS fails on SQL 2014 SP2 --ALLOW_SINGLE_EVENT_LOSS EVENT_RETENTION_MODE=ALLOW_SINGLE_EVENT_LOSS, MAX_MEMORY=4096 KB, MAX_DISPATCH_LATENCY=1 SECONDS, MAX_EVENT_SIZE=0 KB, MEMORY_PARTITION_MODE=NONE, TRACK_CAUSALITY=ON, STARTUP_STATE=OFF );' --PRINT @TSql; EXEC(@TSql); SET @TSql = 'ALTER EVENT SESSION [' + @XESessionName + '] ON SERVER STATE=START;'; EXEC(@TSql); END GO
USE tempdb; GO IF NOT EXISTS ( SELECT * FROM INFORMATION_SCHEMA.ROUTINES r WHERE r.ROUTINE_SCHEMA = 'dbo' AND r.ROUTINE_NAME = 'GetXESessionData_ErrorReported' ) BEGIN EXEC('CREATE PROC dbo.GetXESessionData_ErrorReported AS PRINT CURRENT_TIMESTAMP;'); END; GO ALTER PROC dbo.GetXESessionData_ErrorReported /* Purpose: Returns Extended Events Session data. Inputs: none. History: 09/15/2016 DMason Created */ AS BEGIN --SPID included within session name for isolation. DECLARE @XESessionName SYSNAME = 'Error Handling Session(SPID ' + CAST(@@SPID AS VARCHAR) + ')'; IF NOT EXISTS( SELECT * FROM master.sys.server_event_sessions s WHERE s.name = @XESessionName ) BEGIN DECLARE @ErrMsg NVARCHAR(MAX) = 'Session ' + @XESessionName + ' does not exist.'; RAISERROR(@ErrMsg, 16, 1); RETURN; END DECLARE @XEData XML SELECT @XEData = CAST(xet.target_data AS XML) FROM sys.dm_xe_session_targets AS xet JOIN sys.dm_xe_sessions AS xe ON (xe.address = xet.event_session_address) WHERE xe.name = @XESessionName; /* Check value of "totalEventsProcessed" to ensure events have been dispatched to event session target (ring_buffer). If no events have been processed, delay for a period > MAX_DISPATCH_LATENCY (in seconds). */ IF @XEData.value('(/RingBufferTarget/@totalEventsProcessed)[1]', 'INT') = 0 BEGIN WAITFOR DELAY '00:00:02'; SELECT @XEData = CAST(xet.target_data AS XML) FROM sys.dm_xe_session_targets AS xet JOIN sys.dm_xe_sessions AS xe ON (xe.address = xet.event_session_address) WHERE xe.name = @XESessionName; END /* SELECT signature must match the [dbo].[ErrorReported] table type: */ SELECT x.c.value(N'(action[@name="session_id"]/value)[1]', N'SMALLINT') AS SessionId, x.c.value(N'(@name)[1]', N'NVARCHAR(MAX)') AS EventName, x.c.value(N'(@timestamp)[1]', N'datetime') AS EventTime, x.c.value(N'(data[@name="error_number"]/value)[1]', N'INT') AS ErrorNumber, x.c.value(N'(data[@name="severity"]/value)[1]', N'INT') AS Severity, x.c.value(N'(data[@name="state"]/value)[1]', N'INT') AS [State], x.c.value(N'(data[@name="user_defined"]/value)[1]', N'NVARCHAR(MAX)') AS UserDefined, x.c.value(N'(data[@name="category"]/text)[1]', N'NVARCHAR(MAX)') AS Category, x.c.value(N'(data[@name="destination"]/text)[1]', N'NVARCHAR(MAX)') AS Destination, x.c.value(N'(data[@name="is_intercepted"]/value)[1]', N'NVARCHAR(MAX)') AS IsIntercepted, x.c.value(N'(data[@name="message"]/value)[1]', N'NVARCHAR(MAX)') AS [Message], x.c.value(N'(action[@name="sql_text"]/value)[1]', N'NVARCHAR(MAX)') AS SqlText FROM @XEData.nodes('//RingBufferTarget/event') AS x(c) END GO
USE tempdb; GO IF NOT EXISTS ( SELECT * FROM INFORMATION_SCHEMA.ROUTINES r WHERE r.ROUTINE_SCHEMA = 'dbo' AND r.ROUTINE_NAME = 'DropXESession_ErrorReported' ) BEGIN EXEC('CREATE PROC dbo.DropXESession_ErrorReported AS PRINT CURRENT_TIMESTAMP;'); END; GO ALTER PROC dbo.DropXESession_ErrorReported /* Purpose: Stops and drops an Extended Events Session that monitor errors. Inputs: none. History: 09/05/2016 DMason Created */ AS BEGIN --SPID included within session name for isolation. DECLARE @XESessionName SYSNAME = 'Error Handling Session(SPID ' + CAST(@@SPID AS VARCHAR) + ')'; IF EXISTS( SELECT * FROM master.sys.server_event_sessions s WHERE s.name = @XESessionName ) BEGIN DECLARE @TSql NVARCHAR(MAX) = 'ALTER EVENT SESSION [' + @XESessionName + '] ON SERVER STATE=STOP;'; EXEC(@TSql); SET @TSql = 'DROP EVENT SESSION [' + @XESessionName + '] ON SERVER;'; EXEC(@TSql); END END GO
USE tempdb; GO IF NOT EXISTS ( SELECT * FROM sys.types WHERE name = 'ErrorReported' AND schema_id = SCHEMA_ID('dbo') ) BEGIN CREATE TYPE dbo.ErrorReported AS TABLE ( SessionId SMALLINT, EventName NVARCHAR(MAX), EventTime DATETIME, ErrorNumber INT, Severity INT, [State] NVARCHAR(MAX), UserDefined NVARCHAR(MAX), Category NVARCHAR(MAX), Destination NVARCHAR(MAX), IsIntercepted NVARCHAR(MAX), [Message] NVARCHAR(MAX), SqlText NVARCHAR(MAX) ) END GO
Now that those objects are created, take a look at a few examples that use them below. It's pretty easy now, right? The first two examples are identical, save for the statement in the TRY block. In the third example, we have to check for the existence of session error data outside of the CATCH block, because DBCC CHECKDB errors don't pass control to the CATCH block. No matter--we can still "catch" them now. The output from SSMS is viewable at the bottom of each tab/script (images edited for viewability).
USE tempdb; GO --Create an Extended Events Session for the current SPID. EXEC dbo.CreateXESession_ErrorReported; BEGIN TRY BACKUP DATABASE master TO DISK = 'master.diff.bak' WITH DIFFERENTIAL; END TRY BEGIN CATCH --Create a temp table (as a table type)... DECLARE @ErrData AS dbo.ErrorReported; --...insert session error data into it. INSERT INTO @ErrData EXEC dbo.GetXESessionData_ErrorReported; SELECT * FROM @ErrData; END CATCH --Drop the Extended Events Session for the current SPID. EXEC dbo.DropXESession_ErrorReported; GO
USE tempdb; GO --Create an Extended Events Session for the current SPID. EXEC dbo.CreateXESession_ErrorReported; BEGIN TRY RESTORE DATABASE Foo FROM DISK = 'Foo.bak'; END TRY BEGIN CATCH --Create a temp table (as a table type)... DECLARE @ErrData AS dbo.ErrorReported; --...insert session error data into it. INSERT INTO @ErrData EXEC dbo.GetXESessionData_ErrorReported; SELECT * FROM @ErrData; END CATCH --Drop the Extended Events Session for the current SPID. EXEC dbo.DropXESession_ErrorReported; GO
USE tempdb; GO --Create an Extended Events Session for the current SPID. EXEC dbo.CreateXESession_ErrorReported; BEGIN TRY DBCC CHECKDB('CorruptionTest') WITH NO_INFOMSGS; END TRY BEGIN CATCH PRINT 'Hello world...'; END CATCH --Create a temp table (as a table type)... DECLARE @ErrData AS dbo.ErrorReported; --...insert session error data into it. INSERT INTO @ErrData EXEC dbo.GetXESessionData_ErrorReported; IF EXISTS (SELECT * FROM @ErrData) BEGIN SELECT * FROM @ErrData; END --Drop the Extended Events Session for the current SPID. EXEC dbo.DropXESession_ErrorReported; GO
Automation
Now let's make something useful. Here's a script that uses a cursor, iterates through a set of database names, and attempts a LOG backup of each database. If the t-log backup fails, we'll append to a string of error numbers and error messages. But instead of failing the batch, we'll move on to the next database name in the loop. At the conclusion of the loop, we check for errors, and if any occurred, an email alert is sent. In this particular example, the cursor was specifically created so that *all* of the LOG backup attempts would fail. In a more realistic scenario, most (if not all) of the LOG backups would succeed. If there was a single failure, the batch would continue, allowing the remaining database logs to get backed up.
USE tempdb; GO EXEC dbo.CreateXESession_ErrorReported; DECLARE @DBName SYSNAME; DECLARE curDB CURSOR FAST_FORWARD READ_ONLY FOR --A transaction log backup will fail for all of these DB's SELECT DB_NAME(database_id) FROM sys.database_recovery_status WHERE last_log_backup_lsn IS NULL DECLARE @ErrOccurred BIT = 0; DECLARE @ErrData AS dbo.ErrorReported; --This will be the body of an HTML-formatted email message. DECLARE @Body NVARCHAR(MAX) = '<table border="1">' + '<tr>' + '<th>Database Name</th>' + '<th>Error Number</th>' + '<th>Error Message</th>' + '</tr>'; OPEN curDB; FETCH NEXT FROM curDB INTO @DBName; WHILE @@FETCH_STATUS = 0 BEGIN DECLARE @Path VARCHAR(255) = @DBName + '.log.bak'; BEGIN TRY BACKUP LOG @DBName TO DISK = @Path; END TRY BEGIN CATCH SET @ErrOccurred = 1; INSERT INTO @ErrData EXEC dbo.GetXESessionData_ErrorReported; --Add "rows" to the HTML <table>. SELECT @Body = @Body + CHAR(13) + CHAR(10) + '<tr>' + '<td>' + @DbName + '</td>' + '<td>' + CAST(e.ErrorNumber AS VARCHAR) + '</td>' + '<td>' + e.[Message] + '</td>' + '</tr>' FROM @ErrData e --Drop & recreate the XEvent session to clear out the ring buffer target. EXEC dbo.DropXESession_ErrorReported; EXEC dbo.CreateXESession_ErrorReported; DELETE FROM @ErrData; END CATCH FETCH NEXT FROM curDB INTO @DBName; END CLOSE curDB DEALLOCATE curDB EXEC dbo.DropXESession_ErrorReported; IF @ErrOccurred = 1 BEGIN DECLARE @Subject NVARCHAR(255) = @@SERVERNAME + ' -- Trx Log Backup Errors'; SET @Body = @Body + '</table>' EXEC msdb.dbo.sp_send_dbmail @recipients = 'You@YourDomain.com', @subject = @Subject, @body = @Body, @body_format = 'HTML' --Optional: RAISERROR() END GO
Lastly, here's a screen shot of our email alert. All of our errors and messages are accounted for:
A humble and heartfelt thank you to SQL Server MVP Erland Sommarskog. In his epic series Error and Transaction Handling in SQL Server, Erland pays me a compliment for my efforts here in this post.
0 comments: