Logging Stored Procedure Parameter Values

Question

I've worked in an SQL Server environment before where logging was made part of our stored procedures to capture execution start/end, parameter values and error messages which I found very useful and is something I'm looking to introduce in a new environment.

The tables used for this logging looked like something below, parameters were captured using INSERT statements into a table with the with values being implicitly cast to NVARCHAR.

CREATE TABLE dbo.Execution
(
    Id                  INT IDENTITY(1,1)           NOT NULL
,   SchemaName          NVARCHAR(128)               NOT NULL
,   ProcedureName       NVARCHAR(128)               NOT NULL
,   ExecutionStart      DATETIME                    NOT NULL
,   ExecutionEnd        DATETIME                    NULL
,   ExecutionFailed     BIT                         NOT NULL
)

CREATE TABLE dbo.ExecutionError
(
    Id                  INT IDENTITY(1,1)           NOT NULL
,   ExecutionId         INT                         NOT NULL
,   CustomErrorMessage  NVARCHAR(8000)              NULL
,   SqlErrorMessage     NVARCHAR(8000)              NULL
)

CREATE TABLE dbo.ExecutionParameter
(
    Id                  INT IDENTITY(1,1)           NOT NULL
,   ExecutionId         INT                         NOT NULL
,   ParameterName       NVARCHAR(128)               NOT NULL
,   ParameterValue      NVARCHAR(MAX)               NULL
)

I've been reconsidering the ExecutionParameter table with the possibility of using an SQL_VARIANT data type so I could get the base data type if ever needed for analysis and reporting purposes without having to guess based on the name/value.

However this wouldn't work for parameters that have a data type of NVARCHAR(MAX) or VARCHAR(MAX) and would therefore need to still have the NVARCHAR(MAX) column there which would be NULL the majority of the time.

The use of SQL_VARIANT is tempting but I feel the original table structure works fine and can't really be made any better without making the process more complicated.

Is this something you have done previously, if so how did you implement it? Can you see room for improvement in the above schema without making it overly complicated?

Perhaps an additional table with details of the stored procedure and their parameters which can be referenced? Though I feel this would be difficult to maintain and become confusing as stored procedures are modified over time.

Answer 1

Yes, we did this type of thing at a company I worked at a few years ago. Even though we did it only for error logging, it was the same general concept. You just need to write the SELECT statement that includes all of the input parameters, use FOR XML, and store that in a variable that can be inserted into your Execution table in a new field: Parameters XML NULL. And then you can scrap the ExecutionParameter table.

Try the following as it shows three ways of generating the XML: Attribute-based, Element-based, and Element-based including NULL elements. The default behavior of FOR XML is to indicate NULL values by not including the attribute or element. But if you are doing Element-based XML and want the parameters to show even if they are NULL, then you need to specify XSINIL in the FOR XML clause. The ability to include an indicator for NULL is not available in Attribute-based XML.

Please note that there is not a huge difference between Attributed-based XML and the default Element-based XML (default = does not include NULL items) in terms of storage size (as shown in the example below). When viewing the XML it does appear that there is a lot more "bloat" with Element-based, and that would be the case if storing the data in an NVARCHAR field or text file. But the XML datatype uses an optimized method of storing the data internally, in a way that cannot be seen, but is clearly indicated in the resulting DATALENGTH output.

There is, however, a slight increase in size when using the XSINIL option for Element-based XML and it needs to keep track of NULL elements which are excluded from the other two types. The increase in size is due to a one-time hit for declaring the xsi namespace in the root element, and then a per-NULL element hit.

DECLARE @Param1 INT = 5,
        @Param2 DATETIME = NULL,
        @Param3 NVARCHAR(50) = N'Test < some & XML chars "',
        @Param4 DATETIME = '2016-04-09';

DECLARE @Parameters XML;

SELECT @Parameters = (
   SELECT @Param1 AS [Param1],
          @Param2 AS [Param2],
          @Param3 AS [Param3],
          @Param4 AS [Param4]
   FOR XML RAW(N'Params') -- Attribute-based XML (NULL attributes are missing)
);

SELECT @Parameters, DATALENGTH(@Parameters); -- 183

SELECT @Parameters = (
   SELECT @Param1 AS [Param1],
          @Param2 AS [Param2],
          @Param3 AS [Param3],
          @Param4 AS [Param4]
   FOR XML RAW(N'Params'), ELEMENTS -- Element-based XML (NULL elements are missing)
);

SELECT @Parameters, DATALENGTH(@Parameters); -- 185

SELECT @Parameters = (
   SELECT @Param1 AS [Param1],
          @Param2 AS [Param2],
          @Param3 AS [Param3],
          @Param4 AS [Param4]
   FOR XML PATH(N'Params'), ELEMENTS XSINIL -- Element-based XML (NULL elements included)
);

SELECT @Parameters, DATALENGTH(@Parameters); -- 434

Returned XML values:

<!-- Attribute-based -->
<Params Param1="5" Param3="Test &lt; some &amp; XML chars &quot;"
 Param4="2016-04-09T00:00:00" />


<!-- Element-based -->
<Params>
  <Param1>5</Param1>
  <Param3>Test &lt; some &amp; XML chars "</Param3>
  <Param4>2016-04-09T00:00:00</Param4>
</Params>


<!-- Element-based including NULL elements -->
<Params xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance">
  <Param1>5</Param1>
  <Param2 xsi:nil="true" />
  <Param3>Test &lt; some &amp; XML chars "</Param3>
  <Param4>2016-04-09T00:00:00</Param4>
</Params>

---

Additional notes:

• For SchemaName and ProcedureName columns, I would use sysname as the datatype since that is how it is defined in the system tables. And be sure to use lower-case for sysname as it is an alias that lives in master and servers with a default collation that is binary or case-sensitive won't be able to find that alias if it is not all lower-case. Your current server might be case-insensitive, but it is still a good habit to get into when using sysname.

• For the ExecutionError table, be sure to include INT columns to capture: ERROR_LINE(), ERROR_NUMBER(), ERROR_STATE(), and ERROR_SEVERITY().

• No, you don't want to use SQL_VARIANT as that prevents you from storing the LOB types: VARCHAR(MAX), NVARCHAR(MAX), VARBINARY(MAX), and XML.

• No, you can't use NVARCHAR(8000) because NVARCHAR has a top size of 4000, unless you use MAX.