Unit Testing Databases with tSQLt Part 4 – testing an INSERT stored procedure

by Greg M Lucas on 2 November 2011

In Part 3, we completed the tests for the Exception table which will store SQL Server exceptions as part of the Log4TSql framework. In Part 4 we are going to put together some unit tests for the stored procedure that will populate the Exception table.

The user stories we are addressing today are “As a developer I want to be able to easily capture information about SQL exceptions and store them for later review without writing reams of repetitive code in every stored procedure.” and “As a developer I want to be able to understand the context in which SQL exceptions occur in my code.“. The ExceptionHandler stored procedure is designed to be called from within a CATCH block and alleviate as much repetitive code as possible for the developer. So it will need to capture and store all the information that SQL Server exposes within the catch block and also expose these values to the developer to save them having to write code to capture those values themselves. In addition we will also be able to pass it an error context string which will be stored along side the exception details so the developer can indicate what the calling sproc was doing at the time the exception occurred.

Let’s start by creating a new class in which to run our ExceptionHandler tests

EXEC tSQLt.NewTestClass 'ExceptionHandlerTests';

Testing Column INSERT Order

Our first test is laid out below. This introduces what for me is one of the tSQLt framework’s most powerful features – the ability to compare tables of results. So in this test, we have two tables: “expected” holds the data we expect to see and “actual” will store the actual data we get. We’ll create and populate these tables using SELECT INTO so all we need to do at the start of the test is to drop those tables if they already exist. In Example 3: assertTableEquals of the tSQLt Tutorial, they don’t specify a schema so the tables are created under dbo – which works fine until you have a table called actual or expected. So I always use the same schema as the test class that I’m working in to keep things clean.

At this point, we don’t even have an ExceptionHandler procedure but we know from the user stories above what kind of parameter signature it’s going to have. So we instantiate some corresponding local variables each of which have unique values (so we can properly evaluate the inserted column order) and dump these into a row in the expected table. Then we call ExceptionHandler passing the local variables in the correct order before retrieving the most recent row from the Exception table and dumping it into our actual table.

CREATE PROCEDURE [ExceptionHandlerTests].[test_ExceptionHandler_inserts_columns_in_correct_order]
AS
BEGIN
    IF OBJECT_ID('[ExceptionHandlerTests].[expected]') IS NOT NULL DROP TABLE [ExceptionHandlerTests].[expected];
    IF OBJECT_ID('[ExceptionHandlerTests].[actual]') IS NOT NULL DROP TABLE [ExceptionHandlerTests].[actual];

    --! Define all inputs
    DECLARE   @ErrorContext      nvarchar  ( 512 ) = 'The load failed at step [BCP data in]'
            , @ErrorNumber       int               = 66666
            , @Severity          int               = 16
            , @State             int               = 10
            , @ErrorProcedure    nvarchar  ( 128 ) = 'TestProcedureName'
            , @ErrorLine         int               = 999
            , @ErrorMessage      nvarchar  ( max ) = 'Failed to read "Death by PowerPoint" with BCP'

    --! Store the expected values for subsequent comparison
    SELECT
          @ErrorContext    AS [ErrorContext]
        , @ErrorNumber     AS [ErrorNumber]
        , @Severity        AS [Severity]
        , @State           AS [State]
        , @ErrorProcedure  AS [ErrorProcedure]
        , @ErrorLine       AS [ErrorLine]
        , @ErrorMessage    AS [ErrorMessage]
    INTO [ExceptionHandlerTests].[expected];

    -- Exercise
    EXEC log4.ExceptionHandler
      @ErrorContext    = @ErrorContext
    , @ErrorProcedure  = @ErrorProcedure
    , @ErrorNumber     = @ErrorNumber
    , @Severity        = @Severity
    , @State           = @State
    , @ErrorLine       = @ErrorLine
    , @ErrorMessage    = @ErrorMessage

    --! Collect the row that was just added
    SELECT TOP 1
          [ErrorContext]
        , [ErrorNumber]
        , [Severity]
        , [State]
        , [ErrorProcedure]
        , [ErrorLine]
        , [ErrorMessage]
    INTO [ExceptionHandlerTests].[actual]
    FROM [log4].[Exception]
    ORDER BY ExceptionId DESC;

    --! Assert
   EXEC tSQLt.assertEqualsTable '[ExceptionHandlerTests].[expected]', '[ExceptionHandlerTests].[actual]';
END

The final step in this code is to call tSQLt.assertEqualsTable passing it the names of the expected and actual tables. One small gotcha in the tSQLt Tutorial example is that they show the actual table name being passed first. This is a typo, you should always pass the name of the expected table first (as confirmed in the tSQLt User Guide). Run the test as follows to get the results below. (UPDATE: The tSQLt team have subsequently corrected this small typo – thanks Dennis)

EXEC tSQLt.RunTestClass 'ExceptionHandlerTests';
[ExceptionHandlerTests].[test_ExceptionHandler_inserts_columns_in_correct_order] failed: Could not find stored procedure 'log4.ExceptionHandler'.{test_ExceptionHandler_inserts_columns_in_correct_order,44}

+---------------------+
|Test Execution Sumary|
+---------------------+

|No|Test Case Name                                                                  |Result|
+--+--------------------------------------------------------------------------------+------+
|1 |[ExceptionHandlerTests].[test_ExceptionHandler_inserts_columns_in_correct_order]|Error |
-----------------------------------------------------------------------------
Msg 50000, Level 16, State 10, Line 1
Test Case Summary: 1 test case(s) executed, 0 succeeded, 0 failed, 1 errored.
-----------------------------------------------------------------------------

No surpises there then! Let’s get on and write some code to pass that test (nothing else at this stage remember, keep it agile)

CREATE PROCEDURE [log4].[ExceptionHandler]
(
  @ErrorContext    nvarchar    (  512 )
, @ErrorProcedure  nvarchar    (  128 )
, @ErrorNumber     int
, @Severity        int
, @State           int
, @ErrorLine       int
, @ErrorMessage    nvarchar    ( 4000 )
)
AS
BEGIN
    SET NOCOUNT ON;
    INSERT [log4].[Exception]
    (
      [ErrorContext]
    , [ErrorNumber]
    , [Severity]
    , [State]
    , [ErrorProcedure]
    , [ErrorLine]
    , [ErrorMessage]
    )
    VALUES
    (
      @ErrorContext
    , @ErrorNumber
    , @State
    , @Severity
    , @ErrorProcedure
    , @ErrorLine
    , @ErrorMessage
    );

    SET NOCOUNT OFF;
    RETURN;
END

There is a deliberate mistake in this stored procedure, the kind of thing that is easily done in the rush to get code out of the door. See if you can spot it with a quick glance – you should do as it’s a fairly simple procedure but it does serve to demonstrate (a) why unit testing is so important and (b) why the tSQLt assertEqualsTable feature is so great. Run the test again and take a look at the results.

[ExceptionHandlerTests].[test_ExceptionHandler_inserts_columns_in_correct_order] failed: unexpected/missing resultset rows!
|_m_|ErrorContext                         |ErrorNumber|Severity|State|ErrorProcedure   |ErrorLine|ErrorMessage                                 |
+---+-------------------------------------+-----------+--------+-----+-----------------+---------+---------------------------------------------+
|<  |The load failed at step [BCP data in]|66666      |16      |10   |TestProcedureName|999      |Failed to read "Death by PowerPoint" with BCP|
|>  |The load failed at step [BCP data in]|66666      |10      |16   |TestProcedureName|999      |Failed to read "Death by PowerPoint" with BCP|

+---------------------+
|Test Execution Sumary|
+---------------------+

|No|Test Case Name                                                                  |Result |
+--+--------------------------------------------------------------------------------+-------+
|1 |[ExceptionHandlerTests].[test_ExceptionHandler_inserts_columns_in_correct_order]|Failure|
-----------------------------------------------------------------------------
Msg 50000, Level 16, State 10, Line 1
Test Case Summary: 1 test case(s) executed, 0 succeeded, 1 failed, 0 errored.
-----------------------------------------------------------------------------

The output from this test tells us that the results were not what we were expecting. It even goes so far as to lay out the expected results (<) and the actual results (>) in a format that we can very quickly spot that the ExceptionHandler is inserting Severity and State the wrong way round. This is the kind of bug that may not be picked up for months and when it does can take hours to track back through the code and find. The 15 minutes it took me to write that test offers a much better return on investment than all that debugging and, if this was part of an application being sold to customers ironing out such bugs before you go to market is good for business too.

Testing Output Parameters

So we’ve proved that ExceptionHandler can take a bunch of inputs and insert them into the Exception table in the correct order. Remember, that this procedure is designed to be used within a CATCH block so that we can reduce the amount of code developers have to write. We can do this by capturing the available error information within the procedure itself rather than relying on the developer having to capture this and pass it in. There is a gotcha here, if there is an open transaction that is considered to be uncommittable at the time the CATCH block fires (see TRY…CATCH…) no other action can occur that involves a transaction log write operation until the uncommittable transaction has been rolled back. This isn’t critical to what we’re doing right now but we may have to deal with it later.

Anyway, lets take a look at the next test. This time we actually create an “expected” table and add a row to it with the values we expect. Then define a collection of @actual… variables in which to collect the OUTPUT values from the ExceptionHandler call that we hope is going to fire. In fact we set both ANSI_WARNINGS and ARITHABORT ON to make sure we get the error we’re expecting. We use the captured output values to create and populate the “actual” table and then we’re ready to execute assertEqualsTable .

CREATE PROCEDURE [ExceptionHandlerTests].[test_ExceptionHandler_outputs_exception_detail]
AS
BEGIN
    SET ANSI_WARNINGS ON;
    SET ARITHABORT ON;

    IF OBJECT_ID('[ExceptionHandlerTests].[expected]') IS NOT NULL DROP TABLE [ExceptionHandlerTests].[expected];
    IF OBJECT_ID('[ExceptionHandlerTests].[actual]') IS NOT NULL DROP TABLE [ExceptionHandlerTests].[actual];

    --! Create a table to store what we expect to see
    CREATE TABLE [ExceptionHandlerTests].[expected]
    (
      [ErrorNumber]     int                NULL
    , [Severity]        int                NULL
    , [State]           int                NULL
    , [ErrorProcedure]  nvarchar  ( 128 )  NULL
    , [ErrorLine]       int                NULL
    , [ErrorMessage]    nvarchar  ( max )  NULL
    )
    ;

    --! Store the expected values for subsequent comparison
    INSERT [ExceptionHandlerTests].[expected]
    VALUES
    (
      8134
    , 16
    , 1
    , 'test_ExceptionHandler_outputs_exception_detail'
    , 44
    , 'Divide by zero error encountered.'
    )

    DECLARE   @ErrorContext          nvarchar    ( 512 )    = 'Oops!'
            , @actualErrorNumber     int
            , @actualSeverity        int
            , @actualState           int
            , @actualErrorProcedure  nvarchar  ( 128 )
            , @actualErrorLine       int
            , @actualErrorMessage    nvarchar  ( max )

    BEGIN TRY
        DECLARE @result float = (SELECT 1.1 / 0);
    END TRY
    BEGIN CATCH
        EXEC log4.ExceptionHandler
              @ErrorContext   = @ErrorContext
            , @ErrorProcedure = @actualErrorProcedure  OUT
            , @ErrorNumber    = @actualErrorNumber     OUT
            , @Severity       = @actualSeverity        OUT
            , @State          = @actualState           OUT
            , @ErrorLine      = @actualErrorLine       OUT
            , @ErrorMessage   = @actualErrorMessage    OUT
    END CATCH

    --! Collect output values
    SELECT
          @actualErrorNumber     AS [ErrorNumber]
        , @actualSeverity        AS [Severity]
        , @actualState           AS [State]
        , @actualErrorProcedure  AS [ErrorProcedure]
        , @actualErrorLine       AS [ErrorLine]
        , @actualErrorMessage    AS [ErrorMessage]
    INTO [ExceptionHandlerTests].[actual]

    --! Assert
    EXEC tSQLt.assertEqualsTable '[ExceptionHandlerTests].[expected]', '[ExceptionHandlerTests].[actual]';
END;

Obviously, the first time we run this new test it will fail, so this is the revised ExceptionHandler procedure to pass this new test. The only difference is that whilst we still allow the caller to specify any of these on input, we fill any NULL values with whatever information we can get about the error. In fact this procedure would now even run outside of a CATCH block.

CREATE PROCEDURE [log4].[ExceptionHandler]
(
  @ErrorContext    nvarchar (  512 )
, @ErrorProcedure  nvarchar (  128 )  = NULL  OUT
, @ErrorNumber     int                = NULL  OUT
, @Severity        int                = NULL  OUT
, @State           int                = NULL  OUT
, @ErrorLine       int                = NULL  OUT
, @ErrorMessage    nvarchar ( 4000 )  = NULL  OUT
)
AS
BEGIN
    SET NOCOUNT ON;

    SET @ErrorContext    = COALESCE(@ErrorContext, '');
    SET @ErrorProcedure  = COALESCE(@ErrorProcedure, ERROR_PROCEDURE(), '');
    SET @ErrorNumber     = COALESCE(@ErrorNumber, ERROR_NUMBER());
    SET @Severity        = COALESCE(@Severity, ERROR_SEVERITY());
    SET @State           = COALESCE(@State, ERROR_STATE());
    SET @ErrorLine       = COALESCE(@ErrorLine, ERROR_LINE());
    SET @ErrorMessage    = COALESCE(@ErrorMessage, ERROR_MESSAGE()
                             , 'ERROR_MESSAGE() Not Found for @@ERROR: '
                                 + COALESCE(CAST(@ErrorNumber AS varchar), 'ERROR_NUMBER()'));

    --! Record what we have
    INSERT [log4].[Exception]
    (
      [ErrorContext]
    , [ErrorNumber]
    , [Severity]
    , [State]
    , [ErrorProcedure]
    , [ErrorLine]
    , [ErrorMessage]
    )
    VALUES
    (
      @ErrorContext
    , @ErrorNumber
    , @Severity
    , @State
    , @ErrorProcedure
    , @ErrorLine
    , @ErrorMessage
    );

    SET NOCOUNT OFF;
    RETURN;
END
GO

Testing Internally Modified Parameters Are Correctly Inserted to a Table

The only thing which I don’t like about our [test_ExceptionHandler_outputs_exception_detail] test is that one of the values we’re checking “ErrorLine” is subject to the layout of the code in the test procedure itself – thus making the code more fragile. So for the final test in this section we are going to write a more robust test to check that all the information available as output parameters is also correctly added to the Exception table. In this test, as before, we create then populate the “expected” table with the values we are expecting to see. Then we build a CREATE PROCEDURE statement, execute it to create the sproc then execute the sproc itself which should exercise the code we are trying to test. As we are creating a stored procedure in which to test the call to ExceptionHandler things like ErrorProcedure and ErrorLine are unlikely to change unless we are actually changing ExceptionGenerator itself.

We don’t need to make any changes to the ExceptionHandler code to pass this test but having both of these tests ensure that all key aspects of this module are covered by re-runnable tests.

CREATE PROCEDURE [ExceptionHandlerTests].[test_ExceptionHandler_stores_exception_detail]
AS
BEGIN
    IF OBJECT_ID('[ExceptionHandlerTests].[expected]') IS NOT NULL DROP TABLE [ExceptionHandlerTests].[expected];
    IF OBJECT_ID('[ExceptionHandlerTests].[actual]') IS NOT NULL DROP TABLE [ExceptionHandlerTests].[actual];

    --! Create a table to store what we expect to see
    CREATE TABLE [ExceptionHandlerTests].[expected]
    (
      [ErrorContext]    nvarchar  ( 512 )  NULL
    , [ErrorNumber]     int                NULL
    , [Severity]        int                NULL
    , [State]           int                NULL
    , [ErrorProcedure]  nvarchar  ( 128 )  NULL
    , [ErrorLine]       int                NULL
    , [ErrorMessage]    nvarchar  ( max )  NULL
    )
    ;

    DECLARE @ErrorContext        nvarchar  (  512 )  = 'Oops!';
    DECLARE @NEW_LINE            char      (    1 )  = CHAR(10);
    DECLARE @CreateProcedureCmd  nvarchar  ( 2000 );

    --! Store the expected values for subsequent comparison
    INSERT [ExceptionHandlerTests].[expected]
    VALUES
    (
      @ErrorContext
    , 8134
    , 16
    , 1
    , 'ExceptionGenerator'
    , 9
    , 'Divide by zero error encountered.'
    )

    SET @CreateProcedureCmd    = 'CREATE PROCEDURE [ExceptionHandlerTests].[ExceptionGenerator]'
                            + @NEW_LINE + 'AS'
                            + @NEW_LINE + + 'BEGIN'
                            + @NEW_LINE + + '    SET ANSI_WARNINGS ON;'
                            + @NEW_LINE + + '    SET ARITHABORT ON;'
                            + @NEW_LINE + + ''
                            + @NEW_LINE + + '    BEGIN TRY'
                            + @NEW_LINE + + '        --! Force an exception that we can catch'
                            + @NEW_LINE + + '        DECLARE @result float = (SELECT 1.1 / 0);'
                            + @NEW_LINE + + '    END TRY'
                            + @NEW_LINE + + '    BEGIN CATCH'
                            + @NEW_LINE + + ''
                            + @NEW_LINE + + '        EXEC log4.ExceptionHandler ' + COALESCE('''' + @ErrorContext + '''', 'NULL') + ';'
                            + @NEW_LINE + + ''
                            + @NEW_LINE + + '    END CATCH'
                            + @NEW_LINE + + 'END'

    IF OBJECT_ID(N'[ExceptionHandlerTests].[ExceptionGenerator]', 'P') > 0
        DROP PROCEDURE [ExceptionHandlerTests].[ExceptionGenerator];

    --! Create the procedure
    EXEC (@CreateProcedureCmd);

    --! Now run the sproc
    EXEC (N'EXEC [ExceptionHandlerTests].[ExceptionGenerator];');

    --! Collect the row that was just added
    SELECT TOP 1
          [ErrorContext]
        , [ErrorNumber]
        , [Severity]
        , [State]
        , [ErrorProcedure]
        , [ErrorLine]
        , [ErrorMessage]
    INTO [ExceptionHandlerTests].[actual]
    FROM [log4].[Exception]
    ORDER BY ExceptionId DESC;

    --! Assert
    EXEC tSQLt.assertEqualsTable '[ExceptionHandlerTests].[expected]', '[ExceptionHandlerTests].[actual]';
END

Notice that in this test, like all the others we don’t need to do any cleanup. This is because the tSQLt framework runs each test in it’s own transaction which is always rolled back on completion of the test. And very helpfully, SQL Server will also revert DDL changes (like CREATE PROC) as part of that rollback.

In this session we looked at ways of testing the results of executing a stored procedure that is intended to insert data and return multiple values as output parameters. In the next post in this series, Part 5, we will look at how to test that one stored procedure calls another. This is another great feature of tSQLt that supports the mocking of stored procedures.

Log4TSql is an open source logging framework for SQL Server 2005+ written by Greg M Lucas on behalf of data-centric solutions ltd and licensed for public use under the GNU Lesser General Public License. You can download the latest version of this library along with all the source code and unit tests from sourceforge. Please feel free to use and modify the library as you wish under the terms of the license. I am always interested in hearing how other people or organisations have put this framework to use.

{ 2 comments }

Dennis November 2, 2011 at 23:05

Hey Greg,
I’ve really been enjoying this series – it looks like you’re really getting into tSQLt and I’m looking forward to giving Log4TSql a try! I fixed the typo in the tSQLt tutorial just now (where expected and actual were reversed). Feel free to send me an email if you notice those types of things or put them on the tSQLt mailing list: http://groups.google.com/group/tsqlt/
Thanks for using and writing about it!
-Dennis

Greg M Lucas November 3, 2011 at 23:15

Hi Dennis, thank you for your feed back, I’m glad that you’re enjoying my posts. I’ve updated this post to note your typo fix. I also see that there is a new version of the framework just released too. Good stuff!

Comments on this entry are closed.

Previous post:

Next post: