I'm trying to implement a system-wide logging, which would log all failed Stored Procedure executions in our dabatase and I'm looking at Extended Events.
I've done some research and it seems quite easy to capture failed statements using following code:
--Create an extended event session
CREATE EVENT SESSION what_queries_are_failing ON SERVER
ADD EVENT sqlserver.error_reported (
ACTION (sqlserver.sql_text
, sqlserver.tsql_stack
, sqlserver.database_id
, sqlserver.username
)
WHERE ([severity] > 10)
)
ADD TARGET package0.asynchronous_file_target (
SET filename = 'C:\XEventSessions\what_queries_are_failing.xel'
, metadatafile = 'C:\XEventSessions\what_queries_are_failing.xem'
, max_file_size = 5
, max_rollover_files = 5
)
WITH (MAX_DISPATCH_LATENCY = 5 SECONDS)
GO
-- Start the session
ALTER EVENT SESSION what_queries_are_failing ON SERVER STATE = START
GO
;WITH events_cte
AS (
SELECT DATEADD(mi, DATEDIFF(mi, GETUTCDATE(), CURRENT_TIMESTAMP), xevents.event_data.value('(event/@timestamp)[1]', 'datetime2')) AS [err_timestamp]
, xevents.event_data.value('(event/data[@name="severity"]/value)[1]', 'bigint') AS [err_severity]
, xevents.event_data.value('(event/data[@name="error_number"]/value)[1]', 'bigint') AS [err_number]
, xevents.event_data.value('(event/data[@name="message"]/value)[1]', 'nvarchar(512)') AS [err_message]
, xevents.event_data.value('(event/action[@name="sql_text"]/value)[1]', 'nvarchar(max)') AS [sql_text]
, xevents.event_data
FROM sys.fn_xe_file_target_read_file('S:\XEventSessions\what_queries_are_failing*.xel', 'S:\XEventSessions\what_queries_are_failing*.xem', NULL, NULL)
CROSS APPLY (
SELECT CAST(event_data AS XML) AS event_data
) AS xevents
)
SELECT *
FROM events_cte
ORDER BY err_timestamp;
However I'd like to immediately store failed statement into a table, let's call it Logs.Errors but I couldn't find a way to do it and the upper method would have to work as a scheduled job.
Right now, our procedures look like that:
CREATE PROCEDURE [dbo].[MyProcedure]
AS
BEGIN
SET NOCOUNT ON;
BEGIN TRY
SELECT 1;
END TRY
BEGIN CATCH
EXECUTE Logs.PrintError;
EXECUTE Logs.LogError;
END CATCH
END
Where Logs.LogError procedure is making use of DBCC INPUTBUFFER(); but it doesn't capture parameters, just the exact procedure that was executed. That's all I can get from it:
+----------------------------+-----------+-----------+------------------------------+
| ErrorMessage | EventType | Parameter | Statement |
+----------------------------+-----------+-----------+------------------------------+
| Incorrect syntax near '.'. | RPC Event | 0 | DbName.dbo.FailedProcedure;1 |
+----------------------------+-----------+-----------+------------------------------+
I'm looking for a way to either make DBCC INPUTBUFFER() work by forcing it to capture whole statement or XE to insert records straight into some table, if that's possible.
Any questions - let me know.
I've found that XEvents are great for monitoring events as they happen. However, they don't provide a mechanism to "handle" observed events. To fill that gap, I've used Event Notifications. I often describe them as asynchronous DDL triggers. I'll let you decide if that tl;dr definition is accurate or not.
If you want to give event notifications a try, here is a script that you can start with (sorry, it's really long). Let me know if you have any questions/issues. I'll try to reply as best as I can.
--Create these objects within a database that has service broker enabled.
USE DbaData
GO
--Drop objects first before trying to create them (in specific sequence).
IF EXISTS (
SELECT *
FROM sys.services
WHERE name = 'svcUserErrorReportedNotification'
)
DROP SERVICE svcUserErrorReportedNotification;
GO
IF EXISTS (
SELECT *
FROM sys.service_queues
WHERE name = 'queUserErrorReportedNotification'
)
DROP QUEUE queUserErrorReportedNotification;
GO
IF EXISTS (
SELECT *
FROM sys.server_event_notifications
WHERE name = 'enUserErrorReportedEvents'
)
DROP EVENT NOTIFICATION enUserErrorReportedEvents
ON SERVER
GO
--Create a queue just for user error events.
CREATE QUEUE queUserErrorReportedNotification
GO
--Create a service just for user error events.
CREATE SERVICE svcUserErrorReportedNotification
ON QUEUE queUserErrorReportedNotification ([http://schemas.microsoft.com/SQL/Notifications/PostEventNotification])
GO
-- Create the event notification for user error events on the service.
CREATE EVENT NOTIFICATION enUserErrorReportedEvents
ON SERVER
WITH FAN_IN
FOR USER_ERROR_MESSAGE
TO SERVICE 'svcUserErrorReportedNotification', 'current database';
GO
IF EXISTS (
SELECT *
FROM INFORMATION_SCHEMA.ROUTINES r
WHERE r.ROUTINE_SCHEMA = 'dbo' AND r.ROUTINE_NAME = 'ReceiveUserErrorReportedEvent'
)
DROP PROCEDURE dbo.ReceiveUserErrorReportedEvent
GO
CREATE PROCEDURE dbo.ReceiveUserErrorReportedEvent
/*****************************************************************************
* Name : dbo.ReceiveUserErrorReportedEvent
* Purpose : Runs when there is a USER_ERROR_MESSAGE event.
* Inputs : None
* Outputs : None
* Returns : Nothing
******************************************************************************
* Change History
* 11/28/2016 DMason Created
******************************************************************************/
AS
BEGIN
SET NOCOUNT ON
DECLARE @MsgBody XML
WHILE (1 = 1)
BEGIN
BEGIN TRANSACTION
-- Receive the next available message FROM the queue
WAITFOR (
RECEIVE TOP(1) -- just handle one message at a time
@MsgBody = CAST(message_body AS XML)
FROM queUserErrorReportedNotification
), TIMEOUT 1000 -- if the queue is empty for one second, give UPDATE and go away
-- If we didn't get anything, bail out
IF (@@ROWCOUNT = 0)
BEGIN
ROLLBACK TRANSACTION
BREAK
END
ELSE
BEGIN
--Grab some relevant items from the message body XML (it is EVENTDATA(), btw)
DECLARE @Login SYSNAME;
DECLARE @ErrMsgText VARCHAR(MAX);
DECLARE @ApplicationName VARCHAR(MAX);
DECLARE @Severity INT;
DECLARE @ErrorNumber INT;
DECLARE @DBName SYSNAME;
SET @Login = @MsgBody.value('(/EVENT_INSTANCE/LoginName)[1]', 'VARCHAR(128)' );
SET @ErrMsgText = @MsgBody.value('(/EVENT_INSTANCE/TextData)[1]', 'VARCHAR(MAX)' );
SET @ApplicationName = @MsgBody.value('(/EVENT_INSTANCE/ApplicationName)[1]', 'VARCHAR(MAX)' );
SET @Severity = @MsgBody.value('(/EVENT_INSTANCE/Severity)[1]', 'INT' );
SET @ErrorNumber = @MsgBody.value('(/EVENT_INSTANCE/Error)[1]', 'INT' );
SET @DBName = @MsgBody.value('(/EVENT_INSTANCE/DatabaseName)[1]', 'VARCHAR(128)' );
--Do stuff here.
--Log to a table, etc.
/*
Commit the transaction. At any point before this, we
could roll back -- the received message would be back
on the queue AND the response wouldn't be sent.
*/
COMMIT TRANSACTION
END
END
END
GO
ALTER QUEUE dbo.queUserErrorReportedNotification
WITH
STATUS = ON,
ACTIVATION (
PROCEDURE_NAME = dbo.ReceiveUserErrorReportedEvent,
STATUS = ON,
MAX_QUEUE_READERS = 1,
EXECUTE AS OWNER)
GO