Custom logging with Sprockit

Sprockit enables you to record information about process execution in two ways:

• you can add specific values to a process's execution record using sprockit.usp__LogExecutionProperty;
• you can record ad hoc process event messages in sprockit.Event using sprockit.usp__LogExecutionEvent.

sprockit.usp__LogExecutionProperty and sprockit.usp__LogExecutionEvent require you to specify Sprockit's execution ID for the executing process. You can obtain this by defining a SprockitExecutionId parameter for your process:

• in a stored procedure, define parameter @sprockitExecutionId INT;
• in an SSIS package, define a package parameter SprockitExecutionId of type Int32.

If defined, Sprockit automatically provides a value for this parameter at runtime, populated with the process's [ExecutionId] from sprockit.Execution. The execution ID is then available to you for use when calling either of the logging SPs.¹⁾

sprockit.usp__LogExecutionProperty is well-suited to recording common properties you are interested in for a number of different processes, for example if you often wish to record a 'RowsInserted' property:

EXEC SprockitDb.sprockit.usp__LogExecutionProperty
  @sprockitExecutionId = @sprockitExecutionId 
, @propertyName = N'RowsInserted'
, @propertyValue = @rows

Name/value pairs recorded like this are written to sprockit.Execution's [ExecutionConfiguration] field. This is an XML field that supports the definition of custom properties and makes them easier to report in a structured way, even across execution records for different processes, using the function sprockit.tvf_ParsePropertyValue. e.g.:

SELECT 
  e.ExecutionId
, e.[ExecutionConfiguration]
, CAST(tvf.PropertyValue AS INT) AS RowsInserted
FROM [sprockit].[Execution] e
  OUTER APPLY sprockit.tvf_ParsePropertyValue('RowsInserted', e.[ExecutionConfiguration]) tvf

sprockit.usp__LogExecutionEvent is suitable for the recording of other values, particularly less well-structured data like progress messages.

EXEC SprockitDb.sprockit.usp__LogExecutionEvent
  @sprockitExecutionId = @sprockitExecutionId 
, @msg = N'Created working data set in #workInProgress'
, @rows = @@ROWCOUNT

Messages like this can be useful for identifying bottlenecks or failure points in processes, but as such may not be a permanent requirement. You can prevent sprockit.usp__LogExecutionEvent from making log entries on a per-process basis by setting [LogLevel] = 0 as required in sprockit.Process. (This logging SP only writes entries to sprockit.Event for processes having [LogLevel] >= 1).

sprockit.usp__LogExecutionEvent has an optional @isWarning BIT parameter. The value of @isWarning is written into the [IsWarning] fields of the resulting sprockit.Event record for easier event filtering and analysis.

In this very simple example, we have a stored procedure being used to append some records to a table:

CREATE PROCEDURE dbo.usp_InsertRecords
AS
BEGIN
 
  INSERT INTO dbo.AllRecordsEver (
    Id
  )
  SELECT 
    Id
  FROM dbo.NewRecords
 
END

Sprockit has been configured to run this stored procedure, something like this:

EXEC sprockit.usp__ConfigureProcess '
<Process name="MyDb.dbo.usp_InsertRecords">
  <Inputs>
    <Resource name="MyDb.dbo.NewRecords" />
  </Inputs>
  <Outputs>
    <Resource name="MyDb.dbo.AllRecordsEver" />
  </Outputs>
</Process>'

We now alter the SP, defining a @sprockitExecutionId parameter. Sprockit will automatically populate it with the process's runtime execution ID (identifying the corresponding record in sprockit.Execution), and making that values available for use in calls to sprockit.usp__LogExecutionProperty or sprockit.usp__LogExecutionEvent.

ALTER PROCEDURE dbo.usp_InsertRecords (
  @sprockitExecutionId INT = -1
) AS
BEGIN
 
  DECLARE @rows INT
 
  INSERT INTO dbo.AllRecordsEver (
    Id
  )
  SELECT 
    Id
  FROM dbo.NewRecords
 
  SET @rows = @@ROWCOUNT
 
  -- recording the RowsInserted property
  EXEC SprockitDb.sprockit.usp__LogExecutionProperty
    @sprockitExecutionId = @sprockitExecutionId 
  , @propertyName = N'RowsInserted'
  , @propertyValue = @rows
 
  -- recording the INSERT as an event
  EXEC SprockitDb.sprockit.usp__LogExecutionEvent
    @sprockitExecutionId = @sprockitExecutionId 
  , @msg = N'Inserted rows into dbo.AllRecordsEver'
  , @rows = @rows
 
END