I frequently see questions about the best way to log events in T-SQL processing, including success and failure messages. This method has the following advantages:
- Minimal code needs to be added to your procedures.
- Can log both informational status messages and error messages.
- Events go into a log table, and are displayed in the SSMS messages pane, and if it has an error it “throws” the error to the calling program with error detail info.
- Error messages include the following:
- Date and time
- Application that is running the procedure
- User that is running the procedure
- Server name
- Database name
- Schema name
- Procedure name (this is the calling procedure where the even happened)
- Message to record, e.g. “Start of MyProc”, “Insert sales”
- Line number of the error
- Error Message
- Error number
- Error severity
- Error state
- (optionally) the SQL command causing the error
Start by creating the following table to log events:
CREATE TABLE DW.EventLog (
id int IDENTITY(1,1) NOT NULL,
DateLogged datetime NOT NULL DEFAULT (GETDATE()),
AppName nvarchar(240),
UserName nvarchar(128) DEFAULT (USER_NAME()),
ServerName nvarchar(240),
DBName nvarchar(240),
SchemaName nvarchar(128),
ProcName nvarchar(128),
[Message] varchar(240),
ErrorLine int,
ErrorMessage nvarchar(4000),
ErrorNumber int,
ErrorSeverity int,
ErrorState int
)
Create the following procedure to log the event:
--Procedure to log error and success information.
--Call this using: EXEC DW.LogEvent 'Description of next step', @@PROCID
ALTER PROCEDURE [DW].[LogEvent] @Message VARCHAR(240) = '', @ProcID int = NULL
AS
BEGIN
DECLARE
@AppName NVARCHAR(128)
, @UserName NVARCHAR(128)
, @ServerName NVARCHAR(128)
, @DBName NVARCHAR(128)
, @SchemaName NVARCHAR(128)
, @ProcName NVARCHAR(128)
, @ErrorLine INT
, @ErrorMessage NVARCHAR(4000)
, @ErrorNumber INT
, @ErrorSeverity INT
, @ErrorState INT
, @FullMessage NVARCHAR(max);
SET @AppName = APP_NAME()
SET @UserName = USER_NAME()
SET @ServerName = @@SERVERNAME
SET @DBName = DB_NAME()
SET @SchemaName = COALESCE(LEFT(ERROR_PROCEDURE(),CHARINDEX('.',ERROR_PROCEDURE())-1), OBJECT_SCHEMA_NAME(@ProcID), OBJECT_SCHEMA_NAME(@@PROCID))
SET @ProcName = COALESCE(SUBSTRING(ERROR_PROCEDURE(),CHARINDEX('.',ERROR_PROCEDURE())+1,128), OBJECT_NAME(@ProcID), OBJECT_NAME(@@PROCID))
SET @ErrorLine = ERROR_LINE()
SET @ErrorMessage = ERROR_MESSAGE()
SET @ErrorNumber = ERROR_NUMBER()
SET @ErrorSeverity = ERROR_SEVERITY()
SET @ErrorState = ERROR_STATE()
--Log the error.
INSERT INTO [DW].[EventLog](
AppName,
ServerName,
DBName,
SchemaName,
ProcName,
[Message],
ErrorLine,
ErrorMessage,
ErrorNumber,
ErrorSeverity,
ErrorState
)
SELECT
@AppName,
@ServerName,
@DBName,
@SchemaName,
@ProcName,
@Message,
@ErrorLine,
@ErrorMessage,
@ErrorNumber,
@ErrorSeverity,
@ErrorState;
SET @FullMessage = CONCAT
( '[' , @ServerName
, '].[' , @DBName
, '].[' , @SchemaName
, '].[' , @ProcName
, ']: ' , @Message
);
IF @ErrorNumber IS NOT NULL
SET @FullMessage = LEFT(CONCAT
( @FullMessage
, '. ErrorLine: ' , TRIM(STR(@ErrorLine))
, '. ErrorMessage: ' , @ErrorMessage
, '. ErrorNumber: ' , TRIM(STR(@ErrorNumber))
, '. ErrorSeverity: ' , TRIM(STR(@ErrorSeverity))
, '. ErrorState: ' , TRIM(STR(@ErrorState))
, '. Application: ' , @AppName
, '. User: ' , @UserName
), 2048);
--Display the message.
PRINT @FullMessage;
--If this is an error then throw the error to the calling application, otherwise return to calling application.
IF @ErrorNumber IS NOT NULL
THROW 50000, @FullMessage, @ErrorState;
ELSE
RETURN
END
Here is an example of a procedure that is modified to log
these events. The changes you need to
make to your code are:
- Add “DECLARE @step VARCHAR(240); ”
- Add the TRY/CATCH. Note: the @@PROCID is needed to accurately record the name of the current procedure.
- Add the “EXEC DW.LogEvent…” lines to announce information that you want recorded.
- Add “SET @step = 'what is next'” prior to each SQL command to describe where it failed.
CREATE PROCEDURE [DW].[test_error]
AS
BEGIN TRY
DECLARE @step VARCHAR(240);
EXEC DW.LogEvent 'Starting error test', @@PROCID; --announce start of run
--Body of the procedure follows
SET @step = 'second step' --describe each coming step
SELECT 1/0
EXEC DW.LogEvent 'Error test completed', @@PROCID; --announce end of run
RETURN
END TRY
BEGIN CATCH
EXEC DW.LogEvent @step, @@PROCID;
END CATCH
The only thing missing is the actual text of the SQL command that caused the error. If that is needed you can execute your commands using the following procedure:
CREATE PROCEDURE [DW].[ExecuteSQL] @SQL NVARCHAR(max), @ProcID int = NULL
AS
--Procedure to execute a sql command and log the error and the offending sql text.
--Call this using: EXEC DW.ExecuteSQL 'SQL Command here', @@PROCID
BEGIN
BEGIN TRY
DECLARE @SqlCommand NVARCHAR(240)
SET @SqlCommand = LEFT(CONCAT('SQL: ', @SQL), 240)
--execute the sql command
EXECUTE sp_executesql @SQL
END TRY
BEGIN CATCH
PRINT 'ERROR WITH THE FOLLOWING COMMAND:'
PRINT @SQL
-- Log the error.
EXECUTE DW.LogEvent @SqlCommand, @ProcID;
END CATCH;
END;
