SQL Server Print logging message function

I use this to log duration information when I am writing stored procedures with long running code.
I find this useful when testing how long things are taking in big procedures

This procedure returns a message with a duration of how long it took to run something

CREATE OR ALTER FUNCTION [dbo].[udfGetDurationMsg]
(@msg nvarchar(max), @start datetime, @end datetime) RETURNS VARCHAR(100)
AS
BEGIN
	declare @duration time
	set @duration = Convert(time, @end - @start)
	return @msg + ' - ' + Convert(varchar, @duration)
END
GO

I then have two other supporting procedures.

prcPrintMessage

This outputs the message immediately using the NOWAIT statement, with a leading timestamp

CREATE OR ALTER PROCEDURE [dbo].[prcPrintMessage]
    @msg nvarchar(max)
AS
BEGIN
    set @msg = '[' + Convert(varchar, GetDate(), 121) + '] ' + @msg
    RAISERROR(@msg, 0, 0) WITH NOWAIT
    RETURN 0
END

prcPrintDurationMessage

CREATE OR ALTER PROCEDURE [dbo].[prcPrintDurationMessage]
    @msg nvarchar(max),
    @start datetime
AS
BEGIN
    set @msg = dbo.udfGetDurationMsg(@msg, @start, GetDate())
    exec prcPrintMessage @msg
    RETURN 0
END

This gives you the ability to create print messages immediately that output with a standard format and the duration. Here is an example of how you would call it.

Declare @msg nvarchar(max)
Declare @rows int
Declare @start datetime = getdate()

-- Do some work
-- simulate a delay
WAITFOR DELAY '00:00:01.324'

-- you would maybe do this after an update or merge statement
--set @rows = @@ROWCOUNT;
set @rows = 10;
set @msg = 'Process Completed - ' + Convert(varchar, @rows) + ' rows changed'
exec prcPrintDurationMessage @msg, @start;

This would output a printed statement like:

[2023-06-02 20:15:18.813] Process Completed - 10 rows changed - 00:00:01.3566667

I hope these are useful.

Leave a Reply

Your email address will not be published. Required fields are marked *

This site uses Akismet to reduce spam. Learn how your comment data is processed.