SQL Server: TSQL Callstack Emulation

readme.md

MSSQL T-SQL Call-stack Emulation

Motivation

Don't know if anyone else will need this but one of my teams did.

Design Goals

• Error Handler should not its self show up in the message
• un-ambiguous procedure names (include schemas we use them extensively)
• 5 to 6 levels of nesting
• Oldest/top level call on top
• easy to call / setup
• top level should show the original error message

Technical Goals

• don't use any table resources
• minimize variables in calling proc

Credit

Worked with tcartwright

Things I learned

• SESSION_CONTEXT()
• ERROR_LINE() and family
• That MSSQL doesn't have a proper solution for ERROR_SCHEMA() or a with_schema flag for ERROR_PROCEDURE here

Run the Code

Get started by running setup.sql

Initial

Set up TempDB with multiple schemas and a few nested proc calls

This is our MAIN Procedure.
This is our TestA.usp_Proc2
This is our TestB.usp_Proc3
This is our TestB.usp_Proc3
Msg 8134, Level 16, State 1, Line 72
Divide by zero error encountered.

Custom Error Handler

Let's create the error handler procedure.

Now lets try this out

This is our MAIN Procedure.
This is our TestA.usp_Proc2
This is our TestB.usp_Proc3
This is our TestB.usp_Proc4
Msg 50000, Level 16, State 1, Procedure usp_Proc1, Line 19 [Batch Start Line 115]
Error 508134, Level 16, State 1, Procedure [dbo].[usp_Proc1], Line 25, Message: Divide by zero error encountered.,
StackTrace:
    Procedure: [TestA].[usp_Proc2], Line: 25
    Procedure: [TestB].[usp_Proc3], Line: 21
    Procedure: [TestC].[usp_Proc4], Line: 38
    Procedure: [TestC].[usp_Proc4], Line: 19

Cleanup

Just run cleanup.sql

cleanup.sql

IF OBJECT_ID (N'dbo.usp_Proc1') IS NOT NULL BEGIN
  EXEC (N'DROP PROCEDURE dbo.usp_Proc1')
END

IF OBJECT_ID (N'TestA.usp_Proc2') IS NOT NULL BEGIN
  EXEC (N'DROP PROCEDURE TestA.usp_Proc2')
END

IF OBJECT_ID (N'TestB.usp_Proc3') IS NOT NULL BEGIN
  EXEC (N'DROP PROCEDURE TestB.usp_Proc3')
END

IF OBJECT_ID (N'TestC.usp_Proc4') IS NOT NULL BEGIN
  EXEC (N'DROP PROCEDURE TestC.usp_Proc4')
END

IF OBJECT_ID (N'dbo.ErrorHandler') IS NOT NULL BEGIN
  EXEC (N'DROP PROCEDURE dbo.ErrorHandler')
END
GO

DROP SCHEMA [TestA];
GO
DROP SCHEMA [TestB];
GO
DROP SCHEMA [TestC];
GO

ErrorHandler.sql

IF OBJECT_ID('dbo.ErrorHandler') IS NULL BEGIN 
  EXEC ('CREATE PROCEDURE dbo.ErrorHandler AS BEGIN SELECT 1; END;');
END
GO

--our error handling procedure
ALTER PROCEDURE dbo.ErrorHandler @procName NVARCHAR(128), @ErrorMessage NVARCHAR(4000) OUTPUT, @ErrorSeverity INT OUTPUT, @ErrorState INT OUTPUT
AS
BEGIN
  /* declare sessions keys that are safe for multiple sessions on a single connection */
  DECLARE 
    @call_stack_name NVARCHAR(128) = 'call_stack_' + CAST(@@SPID AS NVARCHAR(20)),
    @errornumber_name NVARCHAR(128)= 'errornumber_' + CAST(@@SPID AS NVARCHAR(20)),
    @proc_schema_name NVARCHAR(128) = 'error_schema_' + CAST(@@SPID AS NVARCHAR(20));

  /* get values out of the session context */
  DECLARE
     @ErrorNumber INT =  COALESCE(CAST(SESSION_CONTEXT(@errornumber_name) AS INT), ERROR_NUMBER())
     /* 2017 started adding schema name to ERROR_PROCEDURE */
    ,@last_schema sysname = COALESCE(PARSENAME(ERROR_PROCEDURE(),2),CAST(SESSION_CONTEXT(@proc_schema_name) AS sysname), PARSENAME(@procName,2));
    
  /* every execution prepends the existing call stack with: CR LF TAB "formated msg" */
  DECLARE
    @call_stack VARCHAR(4000) = 
      CONCAT( 
          CHAR(13) + CHAR(10) + CHAR(9),
          FORMATMESSAGE('Procedure: %s, Line: %d' , CONCAT(QUOTENAME(@last_schema),'.',QUOTENAME(PARSENAME(ERROR_PROCEDURE(),1))) ,ERROR_LINE())
          /* concat handles nulls as empty string */
          , CAST(SESSION_CONTEXT(@call_stack_name) AS NVARCHAR(4000)) 
      );

  /* assign the output variables */
  SELECT
     @ErrorMessage = ERROR_MESSAGE()
    ,@ErrorState = ERROR_STATE()
    /* 
      work around for there not being a ERROR_SCHEMA() or ERROR_PROC(@with_schema=1) 
      https://windowsscriptingdotorg.wordpress.com/2011/01/19/errorprocedure-return-schema/
	    apparently this works(-ish) in 2017
    */
    ,@last_schema = PARSENAME(@procName,2)
     /* find the min severity level that we should issues to match the issue but not fail if we don't have sysadmin */
    ,@ErrorSeverity = ( SELECT MIN(val) FROM (VALUES (ERROR_SEVERITY(),1), (18,0)) AS x(val, isSysAdmin) 
              WHERE isSysAdmin >= IS_SRVROLEMEMBER('sysadmin') );
  
  /* The min nesting will be the outer proc plus this one */
  IF @@NESTLEVEL = 2
  BEGIN
    SELECT 
      /* top level error message */
      @ErrorMessage = FORMATMESSAGE(N'Error %d, Level %d, State %d, Procedure %s, Line %d, Message: %s, %sStackTrace: %s',
          @ErrorNumber, @ErrorSeverity, @ErrorState, @procName, ERROR_LINE(), @ErrorMessage, CHAR(13) + CHAR(10) , @call_stack)
      /* assignment to clear the session context information */
      ,@call_stack = NULL
      ,@ErrorNumber = NULL
      ,@last_schema = NULL ;
  END
  
  /* 
    set/clear the session context values before we goto the prior level
    https://docs.microsoft.com/en-us/sql/relational-databases/system-stored-procedures/sp-set-session-context-transact-sql?view=sql-server-ver15
  */
  EXEC dbo.sp_set_session_context @proc_schema_name, @last_schema;
  EXEC dbo.sp_set_session_context @call_stack_name, @call_stack;
  EXEC dbo.sp_set_session_context @errornumber_name, @ErrorNumber;
  
END;
GO

procs_01.sql

/*

This is our MAIN Procedure.
This is our TestA.usp_Proc2
This is our TestB.usp_Proc3
This is our TestB.usp_Proc3
Msg 8134, Level 16, State 1, Line 72
Divide by zero error encountered.

*/

ALTER PROCEDURE dbo.usp_Proc1 AS
BEGIN
  SET NOCOUNT ON;

  PRINT 'This is our MAIN Procedure.'
  EXECUTE TestA.usp_Proc2            --execute the Stored Procedure
  PRINT '*The error halted the procedure, but our MAIN code can continue.'
  PRINT 1/0                           --generate another "Divide By Zero" error.
  PRINT 'We will not make it to this line.'
END;
GO

ALTER PROCEDURE TestA.usp_Proc2 AS
BEGIN
  SET NOCOUNT ON;

  PRINT 'This is our TestA.usp_Proc2'
  /* let's take up some space and change the line number */
  /* let's take up some space and change the line number */
  /* let's take up some space and change the line number */
  EXEC TestB.usp_Proc3;
  PRINT 1/0                       --generate a "Divide By Zero" error.

  /* let's take up some space and change the line number */
  /* let's take up some space and change the line number */
  PRINT 'We will not make it to this line.'
END;
GO

ALTER PROCEDURE TestB.usp_Proc3 AS
BEGIN
  SET NOCOUNT ON;

  PRINT 'This is our TestB.usp_Proc3'
  /* let's take up some space and change the line number */
  /* let's take up some space and change the line number */
  EXEC TestC.usp_Proc4;
  /* let's take up some space and change the line number */
  PRINT 'We will not make it to this line.'
END;
GO

ALTER PROCEDURE TestC.usp_Proc4 AS
BEGIN
  SET NOCOUNT ON;

  PRINT 'This is our TestB.usp_Proc3'

  EXEC sp_executesql N'select 1; select 1/0';

  DECLARE @P1 INT;
  EXEC sp_prepare @P1 OUTPUT,
      N'@P1 NVARCHAR(128), @P2 NVARCHAR(100)',
      N'SELECT database_id, name FROM sys.databases WHERE name=@P1 AND state_desc = @P2';
  EXEC sp_execute @P1, N'tempdb', N'ONLINE';
  EXEC sp_unprepare @P1;

  PRINT 'We will not make it to this line.'
END;
GO

SET XACT_ABORT ON;
EXEC dbo.usp_Proc1

procs_02.sql

/*
 OUTPUT:
   This is our MAIN Procedure.
   This is our TestA.usp_Proc2
   This is our TestB.usp_Proc3
   This is our TestB.usp_Proc4

   Msg 50000 Level 16 State 1 Line 34
   Error 508134, Level 16, State 1, Procedure [dbo].[usp_Proc1], Line 24, Message: Divide by zero error encountered., 
   StackTrace: 
   Procedure: [TestA].[usp_Proc2], Line: 24
      Procedure: [TestB].[usp_Proc3], Line: 20
      Procedure: [TestC].[usp_Proc4], Line: 37
      Procedure: [TestC].[usp_Proc4], Line: 17
*/

ALTER PROCEDURE dbo.usp_Proc1 AS
BEGIN
  SET NOCOUNT ON;

    -- error catch variables
  DECLARE
     @ErrorMessage NVARCHAR(4000), @ErrorNumber INT, @ErrorSeverity INT, @ErrorState INT = 0
    ,@proc_name nvarchar(256) = CONCAT(QUOTENAME(OBJECT_SCHEMA_NAME(@@PROCID)),'.', QUOTENAME(OBJECT_NAME(@@PROCID)));

  BEGIN TRY
    PRINT 'This is our MAIN Procedure.'
    EXECUTE TestA.usp_Proc2            --execute the Stored Procedure
    PRINT '*The error halted the procedure, but our MAIN code can continue.'
    PRINT 1/0                           --generate another "Divide By Zero" error.
    PRINT 'We will not make it to this line.'
  END TRY
  BEGIN CATCH
    EXEC dbo.ErrorHandler @proc_name, @ErrorMessage OUTPUT, @ErrorSeverity OUTPUT, @ErrorState OUTPUT;
    RAISERROR (@ErrorMessage, @ErrorSeverity, @ErrorState);
  END CATCH
END;
GO

ALTER PROCEDURE TestA.usp_Proc2 AS
BEGIN
  SET NOCOUNT ON;

    -- error catch variables
  DECLARE
     @ErrorMessage NVARCHAR(4000), @ErrorNumber INT, @ErrorSeverity INT, @ErrorState INT = 0
    ,@proc_name nvarchar(256) = CONCAT(QUOTENAME(OBJECT_SCHEMA_NAME(@@PROCID)),'.', QUOTENAME(OBJECT_NAME(@@PROCID)));

  BEGIN TRY
    PRINT 'This is our TestA.usp_Proc2'
    /* let's take up some space and chagne the line number */
    /* let's take up some space and chagne the line number */
    /* let's take up some space and chagne the line number */
    EXEC TestB.usp_Proc3;
    PRINT 1/0                       --generate a "Divide By Zero" error.

    /* let's take up some space and change the line number */
    /* let's take up some space and chagne the line number */
    PRINT 'We will not make it to this line.'
  END TRY
  BEGIN CATCH
    EXEC dbo.ErrorHandler @proc_name, @ErrorMessage OUTPUT, @ErrorSeverity OUTPUT, @ErrorState OUTPUT;
    RAISERROR (@ErrorMessage, @ErrorSeverity, @ErrorState);
  END CATCH
END;
GO

ALTER PROCEDURE TestB.usp_Proc3 AS
BEGIN
  SET NOCOUNT ON;

    -- error catch variables
  DECLARE
     @ErrorMessage NVARCHAR(4000), @ErrorNumber INT, @ErrorSeverity INT, @ErrorState INT = 0
    ,@proc_name nvarchar(256) = CONCAT(QUOTENAME(OBJECT_SCHEMA_NAME(@@PROCID)),'.', QUOTENAME(OBJECT_NAME(@@PROCID)));

  BEGIN TRY
    PRINT 'This is our TestB.usp_Proc3'
    /* let's take up some space and change the line number */
    /* let's take up some space and change the line number */
    EXEC TestC.usp_Proc4;
    /* let's take up some space and change the line number */
    PRINT 'We will not make it to this line.'
  END TRY
  BEGIN CATCH
    EXEC dbo.ErrorHandler @proc_name, @ErrorMessage OUTPUT, @ErrorSeverity OUTPUT, @ErrorState OUTPUT;
    RAISERROR (@ErrorMessage, @ErrorSeverity, @ErrorState);
  END CATCH
END;
GO

ALTER PROCEDURE TestC.usp_Proc4 AS
BEGIN
  SET NOCOUNT ON;

    -- error catch variables
  DECLARE
     @ErrorMessage NVARCHAR(4000), @ErrorNumber INT, @ErrorSeverity INT, @ErrorState INT = 0
    ,@proc_name nvarchar(256) = CONCAT(QUOTENAME(OBJECT_SCHEMA_NAME(@@PROCID)),'.', QUOTENAME(OBJECT_NAME(@@PROCID)));

  BEGIN TRY
    PRINT 'This is our TestB.usp_Proc4'
    BEGIN TRY
      EXEC sp_executesql N'select 1; select 1/0';
    END TRY
    BEGIN CATCH
      SELECT @ErrorMessage = ERROR_MESSAGE(), @ErrorNumber = 500000 + ERROR_NUMBER();
      THROW @ErrorNumber, @ErrorMessage, 1;
    END CATCH

    DECLARE @P1 INT;
    BEGIN TRY
      EXEC sp_prepare @P1 OUTPUT,
          N'@P1 NVARCHAR(128), @P2 NVARCHAR(100)',
          N'SELECT database_id, name FROM sys.databases WHERE name=@P1 AND state_desc = @P2';
      EXEC sp_execute @P1, N'tempdb', N'ONLINE';
      EXEC sp_unprepare @P1;
    END TRY
    BEGIN CATCH
        SELECT @ErrorMessage = ERROR_MESSAGE(), @ErrorNumber = 500000 + ERROR_NUMBER();
        THROW @ErrorNumber, @ErrorMessage, 1;
    END CATCH
    PRINT 'We will not make it to this line.'

  END TRY
  BEGIN CATCH
    EXEC dbo.ErrorHandler @proc_name, @ErrorMessage OUTPUT, @ErrorSeverity OUTPUT, @ErrorState OUTPUT;
    RAISERROR (@ErrorMessage, @ErrorSeverity, @ErrorState);
  END CATCH
END;
GO

SET XACT_ABORT ON;
EXEC dbo.usp_Proc1

setup.sql

CREATE SCHEMA [TestA];
GO
CREATE SCHEMA [TestB];
GO
CREATE SCHEMA [TestC];
GO

CREATE PROCEDURE dbo.ErrorHandler AS BEGIN SELECT 1; END;
GO

CREATE PROCEDURE dbo.usp_Proc1 AS BEGIN SELECT 1; END;
GO

CREATE PROCEDURE TestA.usp_Proc2 AS BEGIN SELECT 1; END;
GO

CREATE PROCEDURE TestB.usp_Proc3 AS BEGIN SELECT 1; END;
GO

CREATE PROCEDURE TestC.usp_Proc4 AS BEGIN SELECT 1; END;
GO

--our error handling procedure
ALTER PROCEDURE dbo.ErrorHandler @procName NVARCHAR(128), @ErrorMessage NVARCHAR(4000) OUTPUT, @ErrorSeverity INT OUTPUT, @ErrorState INT OUTPUT
AS
BEGIN
  /* declare sessions keys that are safe for multiple sessions on a single connection */
  DECLARE
    @call_stack_name NVARCHAR(128) = 'call_stack_' + CAST(@@SPID AS NVARCHAR(20)),
    @errornumber_name NVARCHAR(128)= 'errornumber_' + CAST(@@SPID AS NVARCHAR(20)),
    @proc_schema_name NVARCHAR(128) = 'error_schema_' + CAST(@@SPID AS NVARCHAR(20));

  /* get values out of the session context */
  DECLARE
     @ErrorNumber INT =  COALESCE(CAST(SESSION_CONTEXT(@errornumber_name) AS INT), ERROR_NUMBER())
     /* 2017 started adding schema name to ERROR_PROCEDURE */
    ,@last_schema sysname = COALESCE(PARSENAME(ERROR_PROCEDURE(),2),CAST(SESSION_CONTEXT(@proc_schema_name) AS sysname), PARSENAME(@procName,2));

  /* every execution prepends the existing call stack with: CR LF TAB "formated msg" */
  DECLARE
    @call_stack VARCHAR(4000) =
      CONCAT(
          CHAR(13) + CHAR(10) + CHAR(9),
          FORMATMESSAGE('Procedure: %s, Line: %d' , CONCAT(QUOTENAME(@last_schema),'.',QUOTENAME(PARSENAME(ERROR_PROCEDURE(),1))) ,ERROR_LINE())
          /* concat handles nulls as empty string */
          , CAST(SESSION_CONTEXT(@call_stack_name) AS NVARCHAR(4000))
      );

  /* assign the output variables */
  SELECT
     @ErrorMessage = ERROR_MESSAGE()
    ,@ErrorState = ERROR_STATE()
    /*
      work around for there not being a ERROR_SCHEMA() or ERROR_PROC(@with_schema=1)
      https://windowsscriptingdotorg.wordpress.com/2011/01/19/errorprocedure-return-schema/
	    apparently this works(-ish) in 2017
    */
    ,@last_schema = PARSENAME(@procName,2)
     /* find the min severity level that we should issues to match the issue but not fail if we don't have sysadmin */
    ,@ErrorSeverity = ( SELECT MIN(val) FROM (VALUES (ERROR_SEVERITY(),1), (18,0)) AS x(val, isSysAdmin)
              WHERE isSysAdmin >= IS_SRVROLEMEMBER('sysadmin') );

  /* The min nesting will be the outer proc plus this one */
  IF @@NESTLEVEL = 2
  BEGIN
    SELECT
      /* top level error message */
      @ErrorMessage = FORMATMESSAGE(N'Error %d, Level %d, State %d, Procedure %s, Line %d, Message: %s, %sStackTrace: %s',
          @ErrorNumber, @ErrorSeverity, @ErrorState, @procName, ERROR_LINE(), @ErrorMessage, CHAR(13) + CHAR(10) , @call_stack)
      /* assignment to clear the session context information */
      ,@call_stack = NULL
      ,@ErrorNumber = NULL
      ,@last_schema = NULL ;
  END

  /*
    set/clear the session context values before we goto the prior level
    https://docs.microsoft.com/en-us/sql/relational-databases/system-stored-procedures/sp-set-session-context-transact-sql?view=sql-server-ver15
  */
  EXEC dbo.sp_set_session_context @proc_schema_name, @last_schema;
  EXEC dbo.sp_set_session_context @call_stack_name, @call_stack;
  EXEC dbo.sp_set_session_context @errornumber_name, @ErrorNumber;

END;
GO