Design Pattern // Logging an ETL Process with T-SQL — How to Capture Run, Component and Action in Evaluable Log Tables

Published Feb 20, 2024 · Updated Jun 2, 2026
by

An ETL process finishes without an exception — but was everything really loaded that should have been? The mere fact that a process did not abort says nothing about whether it actually did what was expected of it. A readable, evaluable log is what turns a gut feeling into a defensible statement.

This design pattern logs an ETL run on three levels and answers the questions that success or failure hinge on:

  • How long does the ETL process take overall?
  • How long does a single component take — a stored procedure, an SSIS package or another building block?
  • How long does a specific SQL statement take?
  • How many rows did a SQL statement actually affect?
  • And above all: did the process as a whole, a component or a single statement complete successfully?

TL;DR — what this article covers:

  • Three-tier logging — the tables [LL].[Execution], [LL].[Component] and [LL].[Trace] capture run, component and action at increasing granularity.
  • Stored-procedure toolkit — procedures such as [LL].[spInsertTrace] and [LL].[spUpdateTrace] write and update the log records.
  • Exception handling with [LL].[Error] — a TRY/CATCH pattern ends the run in an orderly way and records every error in an evaluable form.
  • Continuation of the ETL architecture — the example uses schema T2 from the architecture article and adds the logging layer.

Prerequisites. SQL Server and a basic understanding of stored procedures and TRY/CATCH. This article is part of the ETL design-pattern cluster; as a lead-in, see Data Quality in an ETL Process and The Architecture of an ETL Process.

Contents

The Result

At its core the approach is straightforward: at the start of every action a log record is written, and once the action finishes it is updated with the status success or failure — and, where useful, with further information. That’s it! Well, there is a little more to it after all …

Even though creating a log is not — and should not be — a big deal, there is quite a bit to say about it. Let us start with the result and work backwards. The process logging presented here is three-tier and uses the following log tables:

  • [LL].[Execution]
  • [LL].[Component]
  • [LL].[Trace]

These tables log an ETL process and its associated components and steps at increasing granularity — read from top to bottom. The ETL process, the components and the individual steps are each logged with exactly one record.

Closely tied to logging the process is, of course, logging errors. The approach presented here uses the following table for that:

  • [LL].[Error]

The following figures show the result of three-tier logging for a simple, compact, but complete ETL process.

In the table [LL].[Trace] every action is logged with, among other things, the name of the procedure, the target entity the procedure processes, a short description of what was actually done, and further information such as the number of rows affected and the execution time.

Result set of the [LL].[Trace] table: several trace records, one per action, with columns Component, Entity, Action, AffectedRows, State and Success from an example run.
Table [LL].[Trace]

In the table [LL].[Component] the calls of procedures and SSIS packages — or, more generally, components — are logged. Here, too, a short description of the component’s task, the target entity and the execution time are recorded.

Result set of the [LL].[Component] table: one record per called component, with Component, Entity, State and Success.
Table [LL].[Component]

At the top level, every execution of the ETL process is logged with exactly one record in the table [LL].[Execution].

Result set of the [LL].[Execution] table: a single record for the entire ETL run, with Process, Start, End, State and Success.
Table [LL].[Execution]

All process-logging tables contain two columns, [State] and [Success], in which the success or failure of an action, a component or the ETL process is stored.

Now the Derivation…

After this brief preview of the result, the following aspects of the approach need to be clarified:

Three-Tier Logging

The approach logs an ETL process in the three tables [LL].[Execution], [LL].[Component] and [LL].[Trace]. Each table is intended for logging specific artifacts. This section introduces how each table is used, its columns and the code to create it.

[LL].[Execution]

This table logs the execution of an ETL process with exactly one record. An ETL process always has an entry point. That can be a stored procedure, an SSIS package, a Talend job or a SQL Server Agent job. At the start of the entry point’s execution, a log record is inserted into this table. After all tasks have been processed successfully, this record is updated to status success, or to error in the failure case. The table thus provides an overview of all executions of the ETL process, along with information such as the status and the duration of the run.

[LL].[Component]

This table logs the execution of a component with exactly one record. A component can be a stored procedure, an SSIS package or a Talend job. A component is characterized by the fact that it controls and performs one or more data manipulations. As with the [LL].[Execution] table, a log record is inserted at the start of execution and updated to status success or error on completion. The table therefore holds, per ETL run, a list of the executed components, along with information such as the status and the duration of the run.

[LL].[Trace]

The name of this table already hints that it is intended for detailed logging of the ETL process’s actions — it creates a trace. Which actions are logged is a design decision for the developer. It is advisable, however, to log at least every INSERT, UPDATE and DELETE statement with its own record. Besides the status fields already mentioned, the table also stores the number of rows affected, which lets the developer judge whether the statements did exactly what was expected.

[LL].[Error]

Errors detected in an ETL process must of course be logged. A distinction has to be made between logging exceptions and logging data errors. The structure of this table is designed for logging data errors and contains columns in which every data error can be recorded completely and in an evaluable form. This article focuses on logging an ETL process rather than logging data errors. Logging the process is closely tied to explicit exception handling, and a separate section is dedicated to exception handling and the logging of exceptions.

The LL Schema Name

The schema name LL stands for Logging Layer. This schema holds all log tables and the stored procedures used for logging.

Table Description, Declaration and Data Model

The following sections describe the tables for logging the process as well as the table for logging errors. Finally, a diagram shows the data model of these tables.

[LL].[Execution]

Columns

The table has the following columns:

ColumnData typeNull?Description
[Id]bigint (IDENTITY)NOT NULLPrimary key, sequential run id.
[Process]nvarchar(max)NOT NULLName of the ETL process.
[Start]datetimeNOT NULLStart time of the run (UTC).
[End]datetimeNULLEnd time of the run.
[DeltaStart]datetimeNULLStart of the delta window (for incremental loads).
[DeltaEnd]datetimeNULLEnd of the delta window.
[User]nvarchar(128)NULLExecuting DB login (SUSER_SNAME()).
[Machine]nvarchar(128)NULLHost the run was started from.
[Version]intNULLVersion number of the ETL process.
[State]nvarchar(128)NULLStatus: processing / warning / success / error.
[Success]bitNULL0 = not (successfully) completed, 1 = successful.
[CreatedOn]datetimeNOT NULLCreation time, default GETUTCDATE().
[CreatedBy]nvarchar(100)NOT NULLCreating login, default SUSER_SNAME().
[ModifiedOn]datetimeNULLLast modification, set by the update trigger.
[ModifiedBy]nvarchar(100)NULLLogin of the last modification, set by the update trigger.

Declaration

The table is created with the following statement:

  1: -- ----------------------------------------------------------------------------
  2: -- [LL].[Execution] — logging table (top level): exactly one record per ETL
  3: -- run. Inserted at the start of the entry procedure with [State] = 'processing'
  4: -- and updated to 'success' or 'error' at the end.
  5: -- ----------------------------------------------------------------------------
  6: CREATE TABLE [LL].[Execution]
  7: (
  8:     [Id]           bigint        IDENTITY (1, 1) NOT NULL
  9:    ,[Process]      nvarchar(max)                 NOT NULL
 10:    ,[Start]        datetime                      NOT NULL
 11:    ,[End]          datetime                          NULL
 12:    ,[DeltaStart]   datetime                          NULL
 13:    ,[DeltaEnd]     datetime                          NULL
 14:    ,[User]         nvarchar(128)                     NULL
 15:    ,[Machine]      nvarchar(128)                     NULL
 16:    ,[Version]      int                               NULL
 17:    ,[State]        nvarchar(128)                     NULL
 18:    ,[Success]      bit                               NULL
 19:    ,[CreatedOn]    datetime
 20:        CONSTRAINT [DF_LL_Execution_CreatedOn]
 21:        DEFAULT (GETUTCDATE())                    NOT NULL
 22:    ,[CreatedBy]    nvarchar(100)
 23:        CONSTRAINT [DF_LL_Execution_CreatedBy]
 24:        DEFAULT (SUSER_SNAME())                   NOT NULL
 25:    ,[ModifiedOn]   datetime                          NULL
 26:    ,[ModifiedBy]   nvarchar(100)                     NULL
 27:    ,CONSTRAINT [PK_LL_Execution]
 28:        PRIMARY KEY CLUSTERED ([Id] ASC)
 29: );
 30: GO
 31: 
 32: CREATE TRIGGER [LL].[TR_LL_Execution_Update]
 33: ON [LL].[Execution]
 34: FOR UPDATE
 35: AS
 36: BEGIN
 37:     SET NOCOUNT ON;
 38: 
 39:     UPDATE [LL].[Execution]
 40:        SET
 41:            [ModifiedOn] = GETUTCDATE()
 42:           ,[ModifiedBy] = SUSER_SNAME()
 43:        FROM
 44:           [LL].[Execution]
 45:           INNER JOIN inserted
 46:             ON inserted.[Id] = [LL].[Execution].[Id];
 47: END;
 48: GO

[LL].[Component]

Columns

ColumnData typeNull?Description
[Id]bigint (IDENTITY)NOT NULLPrimary key of the component.
[ExecutionId]bigintNOT NULLForeign key to [LL].[Execution].
[Source]nvarchar(5)NOT NULLType of source (e.g. SSIS, T-SQL).
[Component]nvarchar(128)NOT NULLName of the component (procedure, package, job).
[Version]intNULLVersion number of the component.
[Entity]nvarchar(128)NOT NULLTarget entity the component processes.
[Step]nvarchar(max)NOT NULLDescription of the step.
[Description]nvarchar(max)NULLAdditional description.
[FileId]bigintNULLReference to a processed file.
[State]nvarchar(128)NULLStatus: processing / warning / success / error.
[Success]bitNULL0 = not (successfully) completed, 1 = successful.
[CreatedOn]datetimeNOT NULLCreation time, default GETUTCDATE().
[CreatedBy]nvarchar(100)NOT NULLCreating login, default SUSER_SNAME().
[ModifiedOn]datetimeNULLLast modification, set by the update trigger.
[ModifiedBy]nvarchar(100)NULLLogin of the last modification, set by the update trigger.

Declaration

  1: -- ----------------------------------------------------------------------------
  2: -- [LL].[Component] — logging table (middle level): exactly one record per
  3: -- component call (stored procedure, SSIS package, Talend job).
  4: -- Foreign key to [LL].[Execution].
  5: -- ----------------------------------------------------------------------------
  6: CREATE TABLE [LL].[Component]
  7: (
  8:     [Id]           bigint        IDENTITY (1, 1) NOT NULL
  9:    ,[ExecutionId]  bigint                        NOT NULL
 10:    ,[Source]       nvarchar(5)                   NOT NULL
 11:    ,[Component]    nvarchar(128)                 NOT NULL
 12:    ,[Version]      int                               NULL
 13:    ,[Entity]       nvarchar(128)                 NOT NULL
 14:    ,[Step]         nvarchar(max)                 NOT NULL
 15:    ,[Description]  nvarchar(max)                     NULL
 16:    ,[FileId]       bigint                            NULL
 17:    ,[State]        nvarchar(128)                     NULL
 18:    ,[Success]      bit                               NULL
 19:    ,[CreatedOn]    datetime
 20:        CONSTRAINT [DF_LL_Component_CreatedOn]
 21:        DEFAULT (GETUTCDATE())                    NOT NULL
 22:    ,[CreatedBy]    nvarchar(100)
 23:        CONSTRAINT [DF_LL_Component_CreatedBy]
 24:        DEFAULT (SUSER_SNAME())                   NOT NULL
 25:    ,[ModifiedOn]   datetime                          NULL
 26:    ,[ModifiedBy]   nvarchar(100)                     NULL
 27:    ,CONSTRAINT [PK_LL_Component]
 28:        PRIMARY KEY CLUSTERED ([Id] ASC)
 29:    ,CONSTRAINT [FK_LL_Component_ExecutionId]
 30:        FOREIGN KEY ([ExecutionId])
 31:        REFERENCES [LL].[Execution] ([Id])
 32: );
 33: GO
 34: 
 35: CREATE TRIGGER [LL].[TR_LL_Component_Update]
 36: ON [LL].[Component]
 37: FOR UPDATE
 38: AS
 39: BEGIN
 40:     SET NOCOUNT ON;
 41: 
 42:     UPDATE [LL].[Component]
 43:        SET
 44:            [ModifiedOn] = GETUTCDATE()
 45:           ,[ModifiedBy] = SUSER_SNAME()
 46:        FROM
 47:           [LL].[Component]
 48:           INNER JOIN inserted
 49:             ON inserted.[Id] = [LL].[Component].[Id];
 50: END;
 51: GO

[LL].[Trace]

Columns

ColumnData typeNull?Description
[Id]bigint (IDENTITY)NOT NULLPrimary key of the trace record.
[ExecutionId]bigintNOT NULLForeign key to [LL].[Execution].
[ComponentId]bigintNOT NULLForeign key to [LL].[Component].
[Source]nvarchar(5)NOT NULLType of source (e.g. SSIS, T-SQL).
[Component]nvarchar(128)NOT NULLName of the calling component.
[Task]nvarchar(128)NULLTask name (e.g. SSIS task).
[Entity]nvarchar(128)NULLTarget entity of the action.
[Step]nvarchar(max)NOT NULLDescription of the step.
[Description]nvarchar(max)NULLAdditional description.
[FileId]bigintNULLReference to a processed file.
[Action]nvarchar(100)NULLType of action (insert / update / delete / …).
[AffectedRows]intNULLNumber of rows affected by the action.
[State]nvarchar(100)NOT NULLStatus: processing / warning / success / error.
[Success]bitNOT NULL0 = not (successfully) completed, 1 = successful.
[CreatedOn]datetimeNOT NULLCreation time, default GETUTCDATE().
[CreatedBy]nvarchar(100)NOT NULLCreating login, default SUSER_SNAME().
[ModifiedOn]datetimeNULLLast modification, set by the update trigger.
[ModifiedBy]nvarchar(128)NULLLogin of the last modification, set by the update trigger.

Declaration

  1: -- ----------------------------------------------------------------------------
  2: -- [LL].[Trace] — logging table (finest level): exactly one record per single
  3: -- action (INSERT/UPDATE/DELETE, single SQL step, single task). Foreign keys
  4: -- to [LL].[Execution] and [LL].[Component].
  5: -- ----------------------------------------------------------------------------
  6: CREATE TABLE [LL].[Trace]
  7: (
  8:     [Id]           bigint        IDENTITY (1, 1) NOT NULL
  9:    ,[ExecutionId]  bigint                        NOT NULL
 10:    ,[ComponentId]  bigint                        NOT NULL
 11:    ,[Source]       nvarchar(5)                   NOT NULL
 12:    ,[Component]    nvarchar(128)                 NOT NULL
 13:    ,[Task]         nvarchar(128)                     NULL
 14:    ,[Entity]       nvarchar(128)                     NULL
 15:    ,[Step]         nvarchar(max)                 NOT NULL
 16:    ,[Description]  nvarchar(max)                     NULL
 17:    ,[FileId]       bigint                            NULL
 18:    ,[Action]       nvarchar(100)                     NULL
 19:    ,[AffectedRows] int                               NULL
 20:    ,[State]        nvarchar(100)                 NOT NULL
 21:    ,[Success]      bit                           NOT NULL
 22:    ,[CreatedOn]    datetime
 23:        CONSTRAINT [DF_LL_Trace_CreatedOn]
 24:        DEFAULT (GETUTCDATE())                    NOT NULL
 25:    ,[CreatedBy]    nvarchar(100)
 26:        CONSTRAINT [DF_LL_Trace_CreatedBy]
 27:        DEFAULT (SUSER_SNAME())                   NOT NULL
 28:    ,[ModifiedOn]   datetime                          NULL
 29:    ,[ModifiedBy]   nvarchar(128)                     NULL
 30:    ,CONSTRAINT [PK_LL_Trace]
 31:        PRIMARY KEY CLUSTERED ([Id] ASC)
 32:    ,CONSTRAINT [FK_LL_Trace_ComponentId]
 33:        FOREIGN KEY ([ComponentId])
 34:        REFERENCES [LL].[Component] ([Id])
 35:    ,CONSTRAINT [FK_LL_Trace_ExecutionId]
 36:        FOREIGN KEY ([ExecutionId])
 37:        REFERENCES [LL].[Execution] ([Id])
 38: );
 39: GO
 40: 
 41: CREATE TRIGGER [LL].[TR_LL_Trace_Update]
 42: ON [LL].[Trace]
 43: FOR UPDATE
 44: AS
 45: BEGIN
 46:     SET NOCOUNT ON;
 47: 
 48:     UPDATE [LL].[Trace]
 49:        SET
 50:            [ModifiedOn] = GETUTCDATE()
 51:           ,[ModifiedBy] = SUSER_SNAME()
 52:        FROM
 53:           [LL].[Trace]
 54:           INNER JOIN inserted
 55:             ON inserted.[Id] = [LL].[Trace].[Id];
 56: END;
 57: GO

[LL].[Error]

As mentioned above, the structure of this table is designed for logging data errors, which are not the subject of this article. The table is, however, also used for logging exceptions. The following description covers only the columns required for logging an exception.

Columns

ColumnData typeNull?Description
[Id]bigint (IDENTITY)NOT NULLPrimary key of the error record.
[ExecutionId]bigintNOT NULLForeign key to [LL].[Execution].
[ComponentId]bigintNULLForeign key to [LL].[Component] (if known).
[TraceId]bigintNULLForeign key to [LL].[Trace] (if known).
[ErrorType]char(1)NOT NULLType of error (exception vs. data error).
[Source]nvarchar(5)NOT NULLType of source (e.g. SSIS, T-SQL).
[Component]nvarchar(128)NOT NULLComponent in which the error occurred.
[TaskName]nvarchar(128)NULLTask name.
[Entity]nvarchar(128)NULLAffected target entity.
[Step]nvarchar(max)NULLStep in which the error occurred.
[Description]nvarchar(max)NULLError text (ERROR_MESSAGE()).
[Number]intNULLError number (ERROR_NUMBER()).
[Line]intNULLError line (ERROR_LINE()).
[State]nvarchar(max)NULLError state (ERROR_STATE()).
[CreatedOn]datetimeNOT NULLCreation time, default GETUTCDATE().
[CreatedBy]nvarchar(100)NOT NULLCreating login, default SUSER_SNAME().

Declaration

  1: -- ----------------------------------------------------------------------------
  2: -- [LL].[Error] — logging table for exceptions and data errors.
  3: -- In the context of this article we only use the exception columns;
  4: -- the data-error columns (ID1Value/ID2Value/ID3Value/ErrorValue,
  5: -- ID*ColumnName, FileName, FileId) are relevant for a follow-up article.
  6: -- ----------------------------------------------------------------------------
  7: CREATE TABLE [LL].[Error]
  8: (
  9:     [Id]              bigint        IDENTITY (1, 1) NOT NULL
 10:    ,[ExecutionId]     bigint                        NOT NULL
 11:    ,[ComponentId]     bigint                            NULL
 12:    ,[TraceId]         bigint                            NULL
 13:    ,[ErrorType]       char(1)                       NOT NULL
 14:    ,[Source]          nvarchar(5)                   NOT NULL
 15:    ,[Component]       nvarchar(128)                 NOT NULL
 16:    ,[TaskName]        nvarchar(128)                     NULL
 17:    ,[Entity]          nvarchar(128)                     NULL
 18:    ,[Step]            nvarchar(max)                     NULL
 19:    ,[SchemaName]      nvarchar(128)                     NULL
 20:    ,[TableName]       nvarchar(128)                     NULL
 21:    ,[FileId]          bigint                            NULL
 22:    ,[ID1Value]        nvarchar(max)                     NULL
 23:    ,[ID1ColumnName]   nvarchar(128)                     NULL
 24:    ,[ID2Value]        nvarchar(max)                     NULL
 25:    ,[ID2ColumnName]   nvarchar(128)                     NULL
 26:    ,[ID3Value]        nvarchar(max)                     NULL
 27:    ,[ID3ColumnName]   nvarchar(128)                     NULL
 28:    ,[ErrorValue]      nvarchar(max)                     NULL
 29:    ,[ErrorColumnName] nvarchar(128)                     NULL
 30:    ,[FileName]        nvarchar(128)                     NULL
 31:    ,[Description]     nvarchar(max)                     NULL
 32:    ,[Number]          int                               NULL
 33:    ,[Line]            int                               NULL
 34:    ,[State]           nvarchar(max)                     NULL
 35:    ,[CreatedOn]       datetime
 36:        CONSTRAINT [DF_LL_Error_CreatedOn]
 37:        DEFAULT (GETUTCDATE())                     NOT NULL
 38:    ,[CreatedBy]       nvarchar(100)
 39:        CONSTRAINT [DF_LL_Error_CreatedBy]
 40:        DEFAULT (SUSER_SNAME())                    NOT NULL
 41:    ,CONSTRAINT [PK_LL_Error]
 42:        PRIMARY KEY CLUSTERED ([Id] ASC)
 43:    ,CONSTRAINT [FK_LL_Error_ExecutionId]
 44:        FOREIGN KEY ([ExecutionId])
 45:        REFERENCES [LL].[Execution] ([Id])
 46:    ,CONSTRAINT [FK_LL_Error_ComponentId]
 47:        FOREIGN KEY ([ComponentId])
 48:        REFERENCES [LL].[Component] ([Id])
 49:    ,CONSTRAINT [FK_LL_Error_TraceId]
 50:        FOREIGN KEY ([TraceId])
 51:        REFERENCES [LL].[Trace] ([Id])
 52: );
 53: GO

Data Model

Data model of the LL schema: [LL].[Execution], [LL].[Component] and [LL].[Trace] as a 1:n chain from top to bottom; [LL].[Error] with foreign keys to all three tables.

ETL Process Execution Status

All process-logging tables have two columns, [State] and [Success], which store the current status of the ETL process, of a component’s execution or of a specific action — for example an INSERT, UPDATE or DELETE. The current status is held in the [State] column with the values processing, warning, success and error. Success is stored in the [Success] column as 1. Only the combination of both values reveals the current status reliably. The following combinations are valid:

[State][Success]Meaning
processing0Action, component or run has started and is still running.
warning0Finished, but with a warning — not counted as success.
warning1Finished with a warning, yet counted as success.
success1Completed successfully.
error0Aborted with an error.
Valid combinations of the [State] and [Success] columns

Other combinations of status values are not allowed. The procedures used for process logging raise an exception if an invalid combination is passed in.

Logging Procedures

The following procedures (among others) are available for inserting and updating log records in the tables above:

ProcedureSchemaPurpose
spInsertExecutionLLOpens the execution log (top level) at the start of the run.
spUpdateExecutionLLCloses the execution log with status success or error.
spInsertComponentLLOpens a component log for a component.
spUpdateComponentSuccessLLCloses a component log successfully.
spUpdateComponentErrorLLCloses a component log in the error case.
spInsertTraceLLWrites a trace record for a single action.
spUpdateTraceLLUpdates a trace record (general).
spUpdateTraceSuccessLLUpdates a trace record to success / 1.
spUpdateTraceErrorLLUpdates a trace record to error / 0.
spInsertErrorExceptionLLWrites a caught exception to [LL].[Error].
Procedures for process logging

In essence these procedures perform an INSERT or UPDATE on the log tables. The values to be logged are passed as parameters. The procedures validate the parameters passed in and raise an exception in case of invalid parameters. For parameter validation and for raising errors consistently, they use the two helpers [dbo].[spRaiseError] and [dbo].[fnIsNullOrEmpty].

The following code examples show the procedures [LL].[spInsertTrace], [LL].[spUpdateTrace] and [LL].[spUpdateTraceSuccess]. In addition, [LL].[spInsertExecution] stands in for all the remaining procedures, which follow the same pattern: validate the parameters, run the INSERT or UPDATE, return the generated id.

[LL].[spInsertTrace]

  1: -- ----------------------------------------------------------------------------
  2: -- [LL].[spInsertTrace] — inserts a trace record into [LL].[Trace]
  3: -- and returns the generated id via @p_traceId.
  4: -- ----------------------------------------------------------------------------
  5: -- Parameters:
  6: --    @p_executionId    int           Execution id of the current ETL run
  7: --    @p_componentId    int           Component id of the calling component log
  8: --    @p_traceId        int OUTPUT    Id of the newly inserted trace record
  9: --    @p_source          nvarchar(5)   Source system (SSIS, T-SQL, ...)
 10: --    @p_component       nvarchar(128) Name of the calling component
 11: --    @p_task            nvarchar(128) Task name (e.g. SSIS task), optional
 12: --    @p_entity          nvarchar(128) Target entity, optional
 13: --    @p_step            nvarchar(max) Description of the step
 14: --    @p_description     nvarchar(max) Additional description, optional
 15: --    @p_fileId         bigint        Reference to [LL].[FileList].[Id], optional
 16: --    @p_action          nvarchar(100) Action label (Insert/Update/Delete/...)
 17: --    @p_affectedRows   int           Number of rows affected
 18: --    @p_state           nvarchar(100) processing / warning / success / error
 19: --    @p_success         bit           0 = processing/warning/error, 1 = success
 20: -- ----------------------------------------------------------------------------
 21: CREATE OR ALTER PROCEDURE [LL].[spInsertTrace]
 22:     @p_executionId   AS int
 23:    ,@p_componentId   AS int
 24:    ,@p_traceId       AS int OUTPUT
 25:    ,@p_source         AS nvarchar(5)
 26:    ,@p_component      AS nvarchar(128)
 27:    ,@p_task           AS nvarchar(128)   = NULL
 28:    ,@p_entity         AS nvarchar(128)   = NULL
 29:    ,@p_step           AS nvarchar(max)
 30:    ,@p_description    AS nvarchar(max)   = NULL
 31:    ,@p_fileId        AS bigint          = NULL
 32:    ,@p_action         AS nvarchar(100)   = NULL
 33:    ,@p_affectedRows  AS int             = NULL
 34:    ,@p_state          AS nvarchar(100)
 35:    ,@p_success        AS bit
 36: AS
 37: BEGIN
 38:     SET NOCOUNT ON;
 39: 
 40:     DECLARE @component AS nvarchar(128);
 41:     DECLARE @table     AS TABLE ([Id] int);
 42:     DECLARE @message   AS nvarchar(max);
 43: 
 44:     SET @component = OBJECT_SCHEMA_NAME(@@PROCID) + N'.' + OBJECT_NAME(@@PROCID);
 45: 
 46:     BEGIN TRY
 47:         -- Parameter checks
 48:         IF (@p_executionId IS NULL)
 49:         BEGIN
 50:             EXEC [dbo].[spRaiseError] N'The parameter ''p_executionId'' is NULL.', @component;
 51:             RETURN 0;
 52:         END;
 53: 
 54:         IF (@p_componentId IS NULL)
 55:         BEGIN
 56:             EXEC [dbo].[spRaiseError] N'The parameter ''p_componentId'' is NULL.', @component;
 57:             RETURN 0;
 58:         END;
 59: 
 60:         IF ([dbo].[fnIsNullOrEmpty](@p_source, 1) <> 0)
 61:         BEGIN
 62:             EXEC [dbo].[spRaiseError] N'The parameter ''p_source'' is either NULL or an empty string.', @component;
 63:             RETURN 1;
 64:         END;
 65: 
 66:         IF ([dbo].[fnIsNullOrEmpty](@p_component, 1) <> 0)
 67:         BEGIN
 68:             EXEC [dbo].[spRaiseError] N'The parameter ''p_component'' is either NULL or an empty string.', @component;
 69:             RETURN 1;
 70:         END;
 71: 
 72:         IF ([dbo].[fnIsNullOrEmpty](@p_step, 1) <> 0)
 73:         BEGIN
 74:             EXEC [dbo].[spRaiseError] N'The parameter ''p_step'' is either NULL or an empty string.', @component;
 75:             RETURN 1;
 76:         END;
 77: 
 78:         IF ([dbo].[fnIsNullOrEmpty](@p_state, 1) <> 0)
 79:         BEGIN
 80:             EXEC [dbo].[spRaiseError] N'The parameter ''p_state'' is either NULL or an empty string.', @component;
 81:             RETURN 1;
 82:         END;
 83: 
 84:         IF (@p_success IS NULL)
 85:         BEGIN
 86:             EXEC [dbo].[spRaiseError] N'The parameter ''p_success'' is NULL.', @component;
 87:             RETURN 1;
 88:         END;
 89: 
 90:         -- Validate the State/Success combination
 91:         IF ((@p_success = 0 AND @p_state IN (N'success'))
 92:             OR (@p_success = 1 AND @p_state IN (N'processing', N'error')))
 93:         BEGIN
 94:             SET @message = CONCAT(N'Invalid state ''', @p_state, N''' for p_success = ''', CAST(@p_success AS nvarchar(100)), N'''.');
 95:             EXEC [dbo].[spRaiseError] @message, @component;
 96:             RETURN 1;
 97:         END;
 98: 
 99:         -- Write the trace record
100:         INSERT INTO [LL].[Trace]
101:         (
102:              [ExecutionId]
103:             ,[ComponentId]
104:             ,[Source]
105:             ,[Component]
106:             ,[Task]
107:             ,[Entity]
108:             ,[Step]
109:             ,[Description]
110:             ,[FileId]
111:             ,[Action]
112:             ,[AffectedRows]
113:             ,[State]
114:             ,[Success]
115:         )
116:         OUTPUT Inserted.[Id] INTO @table
117:         VALUES
118:         (
119:              @p_executionId
120:             ,@p_componentId
121:             ,@p_source
122:             ,@p_component
123:             ,@p_task
124:             ,@p_entity
125:             ,@p_step
126:             ,CASE WHEN @p_description IS NULL OR DATALENGTH(@p_description) = 0
127:                   THEN NULL ELSE @p_description END
128:             ,@p_fileId
129:             ,@p_action
130:             ,@p_affectedRows
131:             ,@p_state
132:             ,@p_success
133:         );
134: 
135:         SELECT @p_traceId = [Id] FROM @table;
136: 
137:         RETURN 0;
138:     END TRY
139:     BEGIN CATCH
140:         THROW;
141:     END CATCH;
142: END;
143: GO

[LL].[spUpdateTrace]

  1: -- ----------------------------------------------------------------------------
  2: -- [LL].[spUpdateTrace] — updates an existing trace record
  3: -- with Description, Action, AffectedRows, State and Success.
  4: -- ----------------------------------------------------------------------------
  5: -- Parameters:
  6: --    @p_traceId        int           Id of the trace record to update
  7: --    @p_description     nvarchar(max) Description of the result
  8: --    @p_action          nvarchar(100) Action label, optional
  9: --    @p_affectedRows   int           Number of rows affected
 10: --    @p_state           nvarchar(100) processing / warning / success / error
 11: --    @p_success         bit           0 = processing/warning/error, 1 = success
 12: -- ----------------------------------------------------------------------------
 13: CREATE OR ALTER PROCEDURE [LL].[spUpdateTrace]
 14:     @p_traceId        AS int
 15:    ,@p_description     AS nvarchar(max)
 16:    ,@p_action          AS nvarchar(100) = NULL
 17:    ,@p_affectedRows   AS int
 18:    ,@p_state           AS nvarchar(100)
 19:    ,@p_success         AS bit
 20: AS
 21: BEGIN
 22:     SET NOCOUNT ON;
 23: 
 24:     DECLARE @component AS nvarchar(128);
 25:     DECLARE @tempId   AS int;
 26:     DECLARE @message   AS nvarchar(max);
 27: 
 28:     SET @component = OBJECT_SCHEMA_NAME(@@PROCID) + N'.' + OBJECT_NAME(@@PROCID);
 29: 
 30:     BEGIN TRY
 31:         -- Parameter checks
 32:         IF (@p_traceId IS NULL)
 33:         BEGIN
 34:             EXEC [dbo].[spRaiseError] N'The parameter ''p_traceId'' is NULL.', @component;
 35:             RETURN 1;
 36:         END;
 37: 
 38:         IF (@p_success IS NULL)
 39:         BEGIN
 40:             SET @message = N'The parameter ''p_success'' is NULL.';
 41:             EXEC [dbo].[spRaiseError] @message, @component;
 42:             RETURN 1;
 43:         END;
 44: 
 45:         -- Validate the State/Success combination
 46:         IF ((@p_success = 0 AND @p_state IN (N'success'))
 47:             OR (@p_success = 1 AND @p_state IN (N'processing', N'error')))
 48:         BEGIN
 49:             SET @message = CONCAT(N'Invalid state ''', @p_state, N''' for p_success = ''', CAST(@p_success AS nvarchar(100)), N'''.');
 50:             EXEC [dbo].[spRaiseError] @message, @component;
 51:             RETURN 1;
 52:         END;
 53: 
 54:         -- Check that the trace record exists
 55:         SELECT @tempId = [Id]
 56:         FROM   [LL].[Trace]
 57:         WHERE  [Id] = @p_traceId;
 58: 
 59:         IF (@tempId IS NULL)
 60:         BEGIN
 61:             SET @message = N'A record with [Id] = ''' + CAST(@p_traceId AS nvarchar(max)) + N''' could not be found.';
 62:             EXEC [dbo].[spRaiseError] @message, @component;
 63:             RETURN 1;
 64:         END;
 65: 
 66:         -- Update the trace record
 67:         UPDATE [LL].[Trace]
 68:            SET
 69:                [Description]  = CASE
 70:                                   WHEN (@p_description IS NULL OR DATALENGTH(@p_description) = 0)
 71:                                    AND ([Description]   IS NULL OR DATALENGTH([Description])   = 0)
 72:                                   THEN NULL ELSE @p_description END
 73:               ,[Action]       = @p_action
 74:               ,[AffectedRows] = @p_affectedRows
 75:               ,[State]        = @p_state
 76:               ,[Success]      = @p_success
 77:          WHERE [Id] = @p_traceId;
 78: 
 79:         RETURN 0;
 80:     END TRY
 81:     BEGIN CATCH
 82:         THROW;
 83:     END CATCH;
 84: END;
 85: GO

[LL].[spUpdateTraceSuccess]

  1: -- ----------------------------------------------------------------------------
  2: -- [LL].[spUpdateTraceSuccess] — convenience wrapper around spUpdateTrace for
  3: -- the common case "action finished successfully" (State = 'success',
  4: -- Success = 1). Saves setting both fields on every call.
  5: -- ----------------------------------------------------------------------------
  6: CREATE OR ALTER PROCEDURE [LL].[spUpdateTraceSuccess]
  7:     @p_traceId        AS int
  8:    ,@p_description     AS nvarchar(max)
  9:    ,@p_action          AS nvarchar(100) = NULL
 10:    ,@p_affectedRows   AS int
 11: AS
 12: BEGIN
 13:     SET NOCOUNT ON;
 14: 
 15:     EXEC [LL].[spUpdateTrace]
 16:          @p_traceId
 17:         ,@p_description
 18:         ,@p_action
 19:         ,@p_affectedRows
 20:         ,N'success'
 21:         ,1;
 22: END;
 23: GO

[LL].[spInsertExecution]

The procedure below was not shown in detail in the original example, but it stands in for all the remaining logging procedures: once you understand how it is built, you can derive spInsertComponent, spUpdateComponent*, spUpdateTraceError and spInsertErrorException analogously — the only difference is the column assignment.

  1: -- ----------------------------------------------------------------------------
  2: -- [LL].[spInsertExecution] — proof of pattern for the "remaining procedures".
  3: --
  4: -- Structurally identical to [LL].[spInsertTrace]: parameter checks -> INSERT
  5: -- -> id returned via OUTPUT variable. Once you understand the pattern, you can
  6: -- spInsertComponent, spUpdateComponent*, spUpdateTraceError,
  7: -- derive spInsertErrorException, spUpdateExecution analogously — only the
  8: -- column assignment differs.
  9: -- ----------------------------------------------------------------------------
 10: CREATE OR ALTER PROCEDURE [LL].[spInsertExecution]
 11:     @p_executionId   AS int OUTPUT
 12:    ,@p_process        AS nvarchar(max)
 13:    ,@p_version        AS int = NULL
 14: AS
 15: BEGIN
 16:     SET NOCOUNT ON;
 17: 
 18:     DECLARE @component AS nvarchar(128);
 19:     DECLARE @table     AS TABLE ([Id] int);
 20: 
 21:     SET @component = OBJECT_SCHEMA_NAME(@@PROCID) + N'.' + OBJECT_NAME(@@PROCID);
 22: 
 23:     BEGIN TRY
 24:         IF ([dbo].[fnIsNullOrEmpty](@p_process, 1) <> 0)
 25:         BEGIN
 26:             EXEC [dbo].[spRaiseError] N'The parameter ''p_process'' is either NULL or an empty string.', @component;
 27:             RETURN 1;
 28:         END;
 29: 
 30:         INSERT INTO [LL].[Execution]
 31:         (
 32:              [Process]
 33:             ,[Start]
 34:             ,[User]
 35:             ,[Machine]
 36:             ,[Version]
 37:             ,[State]
 38:             ,[Success]
 39:         )
 40:         OUTPUT Inserted.[Id] INTO @table
 41:         VALUES
 42:         (
 43:              @p_process
 44:             ,GETUTCDATE()
 45:             ,SUSER_SNAME()
 46:             ,HOST_NAME()
 47:             ,@p_version
 48:             ,N'processing'
 49:             ,0
 50:         );
 51: 
 52:         SELECT @p_executionId = [Id] FROM @table;
 53: 
 54:         RETURN 0;
 55:     END TRY
 56:     BEGIN CATCH
 57:         THROW;
 58:     END CATCH;
 59: END;
 60: GO

Exception Handling

To ensure that an ETL process ends in an orderly way rather than aborting hard without proper logging, explicit exception handling is required. Orderly means in this case that the process catches a raised exception, performs an UPDATE on the relevant log record in the tables [LL].[Execution], [LL].[Component] and [LL].[Trace] — wherever applicable — setting [State] = error and [Success] = 0, and logs the exception in the table [LL].[Error]. The following diagram shows the basic mechanics of exception handling:

Flowchart of the exception handling: Start, insert log with State processing, workload, branch on exception — the success path updates to success, the error path writes to [LL].[Error], sets State error and optionally re-raises the exception via THROW.
Exception handling

Only after logging has completed may the process re-raise the exception to the caller, which would then abort the calling process hard. Re-raising the exception to the caller is not strictly necessary, however, once the error has been logged and the relevant log records have been updated to [State] = error and [Success] = 0.

Exception handling is required at least at the top level of an ETL process’s execution, which is logged in the table [LL].[Execution].

The code example below shows exception handling including the logging into the tables [LL].[Execution] and [LL].[Error] in line with the diagram above:

  1: -- ----------------------------------------------------------------------------
  2: -- Exception-handling skeleton: shows the complete pattern of
  3: -- TRY/CATCH + insert error + update execution + THROW. The order in the
  4: -- CATCH block is crucial — log first, then THROW.
  5: -- ----------------------------------------------------------------------------
  6: -- Execution logging variables
  7: DECLARE @executionId    AS int;
  8: DECLARE @processName    AS nvarchar(max);
  9: DECLARE @version         AS int;
 10: 
 11: -- Error logging variables
 12: DECLARE @componentId    AS int;
 13: DECLARE @traceId        AS int;
 14: DECLARE @source          AS nvarchar(5);
 15: DECLARE @component       AS nvarchar(128);
 16: DECLARE @task            AS nvarchar(128);
 17: DECLARE @entity          AS nvarchar(128);
 18: DECLARE @step            AS nvarchar(128);
 19: DECLARE @state           AS nvarchar(128);
 20: DECLARE @success         AS bit;
 21: 
 22: -- Exception variables (lowercase by convention)
 23: DECLARE @error_message   AS nvarchar(max);
 24: DECLARE @error_number    AS int;
 25: DECLARE @error_line      AS int;
 26: DECLARE @error_state     AS nvarchar(max);
 27: 
 28: BEGIN TRY
 29:     -- Initialize the execution logging variables
 30:     SET @processName = N'Name of ETL-Process';
 31:     SET @version      = 123;
 32: 
 33:     -- Initialize the error logging variables
 34:     SET @componentId = NULL;
 35:     SET @traceId     = NULL;
 36:     SET @source       = N'sql';
 37:     SET @component    = N'Procedure Name';
 38:     SET @task         = NULL;
 39:     SET @entity       = N'Any Entity';
 40:     SET @step         = N'Do something';
 41: 
 42:     EXEC [LL].[spInsertExecution] @executionId OUTPUT, @processName, @version;
 43: 
 44:     -- Workload (the actual ETL work happens here)
 45:     RAISERROR(N'Any Exception', 15, 1);
 46: 
 47:     SET @state   = N'success';
 48:     SET @success = 1;
 49:     EXEC [LL].[spUpdateExecution] @executionId, @state, @success;
 50: END TRY
 51: BEGIN CATCH
 52:     SET @error_message = ERROR_MESSAGE();
 53:     SET @error_number  = ERROR_NUMBER();
 54:     SET @error_line    = ERROR_LINE();
 55:     SET @error_state   = ERROR_STATE();
 56: 
 57:     SET @state   = N'error';
 58:     SET @success = 0;
 59: 
 60:     IF @executionId IS NOT NULL
 61:     BEGIN
 62:         EXEC [LL].[spInsertErrorException]
 63:              @executionId
 64:             ,@componentId
 65:             ,@traceId
 66:             ,@source
 67:             ,@component
 68:             ,@task
 69:             ,@entity
 70:             ,@step
 71:             ,@error_number
 72:             ,@error_message
 73:             ,@error_line
 74:             ,@error_state;
 75: 
 76:         EXEC [LL].[spUpdateExecution] @executionId, @state, @success;
 77:     END;
 78: 
 79:     THROW;
 80: END CATCH;

Example: Logging and Exception Handling in an ETL Process

After these explanations of the basics of exception handling, the following diagram shows the exception handling of a simple, compact, but complete ETL process:

Diagram of the exception handling in the example ETL process: the entry procedure calls several worker procedures; in the DELETE step of the deepest procedure an exception occurs that is propagated upward and logged at every level.
Example of exception handling and logging for an example ETL process

This example shows the logging of an ETL process built entirely from stored procedures, consisting of five stored procedures. The entry procedure [T2].[spETLProcess] calls the two procedures [T2].[spDoSomething_1] and [T2].[spDoSomething_2]. The first one simulates and logs an INSERT, an UPDATE and a DELETE statement each, while the second procedure executes two further procedures, [T2].[spDoSomething_2_1] and [T2].[spDoSomething_2_2]. These procedures, too, simulate and log an INSERT, an UPDATE and a DELETE statement each. During the execution of the DELETE statement in the procedure [T2].[spDoSomething_2_2], an exception is raised that leads to an orderly termination of the ETL process.

Call hierarchy of the example ETL process: spETLProcess calls spDoSomething_1 and spDoSomething_2; spDoSomething_2 calls spDoSomething_2_1 and spDoSomething_2_2; each worker procedure runs INSERT, UPDATE and DELETE, with the failing DELETE step highlighted.
Procedure calls of the example ETL process

Since showing all procedures would lead to repetition, only the entry procedure [T2].[spETLProcess] and the procedure [T2].[spDoSomething_2_2] are shown here.

[T2].[spETLProcess]

  1: -- ----------------------------------------------------------------------------
  2: -- [T2].[spETLProcess] — example entry procedure of the ETL process.
  3: -- Calls two worker procedures spDoSomething_1 and spDoSomething_2
  4: -- and logs both calls in [LL].[Trace].
  5: -- ----------------------------------------------------------------------------
  6: CREATE OR ALTER PROCEDURE [T2].[spETLProcess]
  7: AS
  8: BEGIN
  9:     SET NOCOUNT ON;
 10: 
 11:     -- Error variables
 12:     DECLARE @error_message  AS nvarchar(max);
 13:     DECLARE @error_number   AS int;
 14:     DECLARE @error_line     AS int;
 15:     DECLARE @error_state    AS nvarchar(max);
 16: 
 17:     -- Logging variables
 18:     DECLARE @component      AS nvarchar(128);
 19:     DECLARE @task           AS nvarchar(128);
 20:     DECLARE @source         AS nvarchar(5);
 21:     DECLARE @step           AS nvarchar(max);
 22:     DECLARE @entity         AS nvarchar(max);
 23:     DECLARE @message        AS nvarchar(max);
 24: 
 25:     DECLARE @traceId       AS int;
 26:     DECLARE @componentId   AS int;
 27:     DECLARE @executionId   AS int;
 28: 
 29:     DECLARE @description    AS nvarchar(max);
 30:     DECLARE @affectedRows  AS int;
 31:     DECLARE @action         AS nvarchar(100);
 32:     DECLARE @state          AS nvarchar(100);
 33:     DECLARE @success        AS bit;
 34: 
 35:     SET @message       = NULL;
 36:     SET @description   = NULL;
 37:     SET @affectedRows = 0;
 38: 
 39:     SET @component = OBJECT_SCHEMA_NAME(@@PROCID) + N'.' + OBJECT_NAME(@@PROCID);
 40:     SET @source    = N'T-SQL';
 41:     SET @entity    = N'[].[]';
 42: 
 43:     BEGIN TRY
 44:         -- Open the execution log
 45:         EXEC [LL].[spInsertExecution] @executionId OUTPUT, N'ETL process', 123;
 46: 
 47:         -- Open the component log
 48:         SET @step        = N'Orchestrate ETL process';
 49:         SET @description = N'';
 50:         EXEC [LL].[spInsertComponent]
 51:              @executionId, @componentId OUTPUT, @source, @component, NULL, @entity, @step, @description;
 52: 
 53:         -- ----------------------------------------------------------------
 54:         -- Call [T2].[spDoSomething_1]
 55:         -- ----------------------------------------------------------------
 56:         SET @task        = NULL;
 57:         SET @step        = N'Execute [T2].[spDoSomething_1]';
 58:         SET @action      = N'execute';
 59:         SET @description = NULL;
 60:         SET @state       = N'processing';
 61:         SET @success     = 0;
 62:         EXEC [LL].[spInsertTrace]
 63:              @executionId, @componentId, @traceId OUTPUT
 64:             ,@source, @component, @task, @entity, @step, @description
 65:             ,NULL, @action, NULL, @state, @success;
 66: 
 67:         EXEC [T2].[spDoSomething_1] @executionId;
 68: 
 69:         EXEC [LL].[spUpdateTraceSuccess] @traceId, @description, @action, @@ROWCOUNT;
 70: 
 71:         -- ----------------------------------------------------------------
 72:         -- Call [T2].[spDoSomething_2]
 73:         -- ----------------------------------------------------------------
 74:         SET @task        = NULL;
 75:         SET @step        = N'Execute [T2].[spDoSomething_2]';
 76:         SET @action      = N'execute';
 77:         SET @description = NULL;
 78:         SET @state       = N'processing';
 79:         SET @success     = 0;
 80:         EXEC [LL].[spInsertTrace]
 81:              @executionId, @componentId, @traceId OUTPUT
 82:             ,@source, @component, @task, @entity, @step, @description
 83:             ,NULL, @action, NULL, @state, @success;
 84: 
 85:         EXEC [T2].[spDoSomething_2] @executionId;
 86: 
 87:         EXEC [LL].[spUpdateTraceSuccess] @traceId, @description, @action, @@ROWCOUNT;
 88: 
 89:         -- Close the component log
 90:         EXEC [LL].[spUpdateComponentSuccess] @componentId, @description;
 91: 
 92:         -- Close the execution log
 93:         SET @state   = N'success';
 94:         SET @success = 1;
 95:         EXEC [LL].[spUpdateExecution] @executionId, @state, @success;
 96:     END TRY
 97:     BEGIN CATCH
 98:         SET @error_message = ERROR_MESSAGE();
 99:         SET @error_number  = ERROR_NUMBER();
100:         SET @error_line    = ERROR_LINE();
101:         SET @error_state   = ERROR_STATE();
102: 
103:         IF @executionId IS NOT NULL
104:         BEGIN
105:             EXEC [LL].[spInsertErrorException]
106:                  @executionId, @componentId, @traceId, @source, @component
107:                 ,NULL, NULL, @step
108:                 ,@error_number, @error_message, @error_line, @error_state;
109: 
110:             IF @traceId     IS NOT NULL EXEC [LL].[spUpdateTraceError]     @traceId,     @description;
111:             IF @componentId IS NOT NULL EXEC [LL].[spUpdateComponentError] @componentId, @description;
112: 
113:             SET @state   = N'error';
114:             SET @success = 0;
115:             EXEC [LL].[spUpdateExecution] @executionId, @state, @success;
116:         END;
117:     END CATCH;
118: END;
119: GO

[T2].[spDoSomething_2_2]

  1: -- ----------------------------------------------------------------------------
  2: -- [T2].[spDoSomething_2_2] — deepest worker procedure in the example tree.
  3: -- Called by [T2].[spDoSomething_2] (see diagram 041007.png).
  4: -- Simulates an INSERT, an UPDATE and a DELETE — the DELETE raises an
  5: -- exception to demonstrate the exception-handling pattern.
  6: -- ----------------------------------------------------------------------------
  7: CREATE OR ALTER PROCEDURE [T2].[spDoSomething_2_2]
  8: (
  9:     @p_executionId  AS int
 10: )
 11: AS
 12: BEGIN
 13:     SET NOCOUNT ON;
 14: 
 15:     -- Error variables
 16:     DECLARE @error_message  AS nvarchar(max);
 17:     DECLARE @error_number   AS int;
 18:     DECLARE @error_line     AS int;
 19:     DECLARE @error_state    AS nvarchar(max);
 20: 
 21:     -- Logging variables
 22:     DECLARE @component      AS nvarchar(128);
 23:     DECLARE @task           AS nvarchar(128);
 24:     DECLARE @source         AS nvarchar(5);
 25:     DECLARE @step           AS nvarchar(max);
 26:     DECLARE @entity         AS nvarchar(max);
 27:     DECLARE @message        AS nvarchar(max);
 28: 
 29:     DECLARE @traceId       AS int;
 30:     DECLARE @componentId   AS int;
 31: 
 32:     DECLARE @description    AS nvarchar(max);
 33:     DECLARE @affectedRows  AS int;
 34:     DECLARE @action         AS nvarchar(100);
 35:     DECLARE @state          AS nvarchar(100);
 36:     DECLARE @success        AS bit;
 37: 
 38:     SET @message       = NULL;
 39:     SET @description   = NULL;
 40:     SET @affectedRows = 0;
 41: 
 42:     SET @component = OBJECT_SCHEMA_NAME(@@PROCID) + N'.' + OBJECT_NAME(@@PROCID);
 43:     SET @source    = N'T-SQL';
 44:     SET @entity    = N'[].[]';
 45: 
 46:     BEGIN TRY
 47:         IF (@p_executionId IS NULL)
 48:         BEGIN
 49:             SET @message = N'The parameter ''p_executionId'' is NULL.';
 50:             EXEC [dbo].[spRaiseError] @message, @component;
 51:             RETURN -1;
 52:         END;
 53: 
 54:         -- Open the component log
 55:         SET @step        = N'Do something';
 56:         SET @description = N'';
 57:         EXEC [LL].[spInsertComponent]
 58:              @p_executionId, @componentId OUTPUT, @source, @component, NULL, @entity, @step, @description;
 59: 
 60:         -- ----------------------------------------------------------------
 61:         -- INSERT (succeeds)
 62:         -- ----------------------------------------------------------------
 63:         SET @task        = NULL;
 64:         SET @step        = N'Insert data';
 65:         SET @action      = N'insert';
 66:         SET @description = NULL;
 67:         SET @state       = N'processing';
 68:         SET @success     = 0;
 69:         EXEC [LL].[spInsertTrace]
 70:              @p_executionId, @componentId, @traceId OUTPUT
 71:             ,@source, @component, @task, @entity, @step, @description
 72:             ,NULL, @action, NULL, @state, @success;
 73: 
 74:         -- An INSERT statement would go here
 75: 
 76:         EXEC [LL].[spUpdateTraceSuccess] @traceId, @description, @action, @@ROWCOUNT;
 77: 
 78:         -- ----------------------------------------------------------------
 79:         -- UPDATE (succeeds)
 80:         -- ----------------------------------------------------------------
 81:         SET @task        = NULL;
 82:         SET @step        = N'Update data';
 83:         SET @action      = N'update';
 84:         SET @description = NULL;
 85:         SET @state       = N'processing';
 86:         SET @success     = 0;
 87:         EXEC [LL].[spInsertTrace]
 88:              @p_executionId, @componentId, @traceId OUTPUT
 89:             ,@source, @component, @task, @entity, @step, @description
 90:             ,NULL, @action, NULL, @state, @success;
 91: 
 92:         -- An UPDATE statement would go here
 93: 
 94:         EXEC [LL].[spUpdateTraceSuccess] @traceId, @description, @action, @@ROWCOUNT;
 95: 
 96:         -- ----------------------------------------------------------------
 97:         -- DELETE (deliberately raises an exception)
 98:         -- ----------------------------------------------------------------
 99:         SET @task        = NULL;
100:         SET @step        = N'Delete data';
101:         SET @action      = N'delete';
102:         SET @description = NULL;
103:         SET @state       = N'processing';
104:         SET @success     = 0;
105:         EXEC [LL].[spInsertTrace]
106:              @p_executionId, @componentId, @traceId OUTPUT
107:             ,@source, @component, @task, @entity, @step, @description
108:             ,NULL, @action, NULL, @state, @success;
109: 
110:         -- A DELETE statement would go here — artificially raised exception:
111:         RAISERROR(N'Exception in [T2].[spDoSomething_2_2]', 15, 1);
112: 
113:         EXEC [LL].[spUpdateTraceSuccess] @traceId, @description, @action, @@ROWCOUNT;
114: 
115:         -- Close the component log
116:         EXEC [LL].[spUpdateComponentSuccess] @componentId, @description;
117:     END TRY
118:     BEGIN CATCH
119:         SET @error_message = ERROR_MESSAGE();
120:         SET @error_number  = ERROR_NUMBER();
121:         SET @error_line    = ERROR_LINE();
122:         SET @error_state   = ERROR_STATE();
123: 
124:         IF @p_executionId IS NOT NULL
125:         BEGIN
126:             EXEC [LL].[spInsertErrorException]
127:                  @p_executionId, @componentId, @traceId, @source, @component
128:                 ,NULL, NULL, @step
129:                 ,@error_number, @error_message, @error_line, @error_state;
130: 
131:             IF @traceId     IS NOT NULL EXEC [LL].[spUpdateTraceError]     @traceId,     @description;
132:             IF @componentId IS NOT NULL EXEC [LL].[spUpdateComponentError] @componentId, @description;
133:         END;
134: 
135:         THROW;
136:     END CATCH;
137: END;
138: GO

The following script contains the statement to execute the ETL process. To obtain a compact process log, the log tables are cleared beforehand. The closing SELECT statements produce the result shown at the beginning.

  1: -- ----------------------------------------------------------------------------
  2: -- Example run: execute the ETL process and evaluate the log.
  3: --
  4: -- Block 1 clears the log tables (TRUNCATE / DELETE + RESEED),
  5: -- block 2 starts the example ETL process, block 3 shows the result.
  6: -- The SELECT statements return exactly the three result sets shown at the
  7: -- start of the article (tables 041001, 041002, 041003).
  8: -- ----------------------------------------------------------------------------
  9: 
 10: -- 01: Clear the log tables
 11: TRUNCATE TABLE [LL].[Error];
 12: TRUNCATE TABLE [LL].[Trace];
 13: DELETE FROM    [LL].[Component];
 14: DELETE FROM    [LL].[Execution];
 15: DBCC CHECKIDENT (N'[LL].[Component]', RESEED, 0);
 16: DBCC CHECKIDENT (N'[LL].[Execution]', RESEED, 0);
 17: 
 18: -- 02: Start the ETL process
 19: EXEC [T2].[spETLProcess];
 20: 
 21: -- 03: Evaluate the log
 22: SELECT * FROM [LL].[Execution];
 23: SELECT * FROM [LL].[Component];
 24: SELECT * FROM [LL].[Trace];

Conclusion

ETL processes are data-driven processes. If data arrives that was not expected, there is a high probability that either not all data — or even wrong data — ends up in the target system. Something this article mentions only in passing: at the lowest logging level the number of rows affected is logged, or at least can be. Knowing the number of expected versus actually processed rows is a good indicator of the success or failure of an ETL process.

This approach thus supports the development of robust ETL processes and also makes it possible to assess data quality.

What is a must in software development is often neglected when building ETL processes: explicit exception handling. The exception handling presented here first ensures that a process ends in an orderly way in the event of an error. But when is there actually an error? And does an error always have to abort the process? Combined with the knowledge of the expected versus actually processed number of rows, genuine error handling can be implemented.

The approach presented here is, in a way, an invitation to engage more with the data and the expected result. The log — and in particular the knowledge of the rows processed — helps the developer judge the correctness of the work already during the development of the ETL process.

The procedures presented here merely provide a toolkit for logging. Used correctly, they produce a readable, evaluable log that makes it possible to assess the correctness of the ETL process’s execution and of the data processed.

FAQ

What is the difference between [LL].[Component] and [LL].[Trace]?

Both log steps of a run, but at different levels of granularity. [LL].[Component] holds exactly one record per called component (stored procedure, SSIS package, Talend job) — that is, “which building block ran when and with what status?”. [LL].[Trace] goes one level deeper and logs the individual actions within a component (typically every INSERT, UPDATE and DELETE) together with the number of rows affected. A component therefore usually has several trace entries.

Why a dedicated [LL] schema instead of putting the logging tables in the default schema?

The LL schema (“Logging Layer”) cleanly separates the logging infrastructure from the business data. This has practical advantages: permissions can be granted precisely (for example, write access to LL only for the ETL procedures), retention and backup of the logs can be controlled separately, and in scripts it is immediately clear that an object belongs to logging. It also prevents the logging tables from colliding with business tables of the same name.

Can the pattern be implemented with Postgres instead of SQL Server?

Yes — the pattern is tool-neutral. The logging tables and the three-tier structure stay identical; only a few T-SQL specifics are replaced. Instead of THROW, you re-raise the exception in PL/pgSQL with RAISE, TRY/CATCH becomes a BEGIN … EXCEPTION WHEN OTHERS THEN … END block, and @@ROWCOUNT corresponds to GET DIAGNOSTICS <var> = ROW_COUNT. If you want to measure the execution time of individual statements without your own trace table, you can additionally draw on pg_stat_statements.

How does this pattern differ from SQL Server Audit or pgAudit?

SQL Server Audit and pgAudit are database-side auditing mechanisms: they log technical events (logins, DDL, data access) at the server level, largely independent of the application code. The pattern presented here, by contrast, is application logging — it records the business view of the ETL process: which run, which component, which action, how many rows, success or failure. The two complement each other; for the question “did the ETL run do the right thing functionally?” application logging is the appropriate tool.

How do I integrate an SSIS package into the pattern?

An SSIS package is treated like any other component: at the start it calls [LL].[spInsertComponent] (for example from an Execute SQL Task or a Script Task), performs its tasks and finishes with [LL].[spUpdateComponentSuccess], or with [LL].[spUpdateComponentError] in the error case. The returned ComponentId is passed along through an SSIS variable so that downstream trace calls can reference it. This way the package appears seamlessly alongside the T-SQL components in the same log.

This article is part of the ETL design-pattern cluster: