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

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.

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 outcome success or failure — and, where useful, with further information. In principle, that is all there is to it. In practice, a little more is needed after all.

Even though creating a log should not be a big deal, there is quite a bit to say about it. This article starts with the result and works backwards from there. 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 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.

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.

Table [LL].[Component]

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

Table [LL].[Execution]

The three process-logging tables — [LL].[Execution], [LL].[Component] and [LL].[Trace] — 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
• Table Description, Declaration and Data Model
• ETL Process Execution Status
• Logging Procedures
• Exception Handling
• Example: Logging and Exception Handling in an ETL Process

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 needs a clearly identifiable 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. In production systems, this granularity should be weighed deliberately against log volume and write load — a single INSERT … SELECT can move millions of rows and still remains exactly one trace 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 belong in the log. 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.

Three notes up front: The duration of an execution derives, at the execution level, from the columns [Start] and [End], and at the component and trace levels from [CreatedOn] (written when the action starts) and [ModifiedOn] (set by the closing update via trigger). The timestamps use datetime with GETUTCDATE() for historical reasons — for a new design, datetime2 with SYSUTCDATETIME() would be the natural choice today, and its higher precision pays off precisely for trace records written in quick succession. And the audit columns [ModifiedOn]/[ModifiedBy] are maintained by an AFTER UPDATE trigger per table: that keeps the logging procedures lean, but costs an additional UPDATE on every status change and is a deliberate trade-off at very high log volumes. With the default database setting RECURSIVE_TRIGGERS OFF, the trigger's self-update does not recurse (measured on SQL Server 2022).

[LL].[Execution]

Columns

The table has the following columns:

Column	Data type	Null?	Description
[Id]	bigint (IDENTITY)	NOT NULL	Primary key, sequential run id.
[Process]	nvarchar(max)	NOT NULL	Name of the ETL process.
[Start]	datetime	NOT NULL	Start time of the run (UTC).
[End]	datetime	NULL	End time of the run.
[DeltaStart]	datetime	NULL	Start of the delta window (for incremental loads).
[DeltaEnd]	datetime	NULL	End of the delta window.
[User]	nvarchar(128)	NULL	Executing DB login (SUSER_SNAME()).
[Machine]	nvarchar(128)	NULL	Host the run was started from.
[Version]	int	NULL	Version number of the ETL process.
[State]	nvarchar(128)	NOT NULL	Status: processing / warning / success / error.
[Success]	bit	NOT NULL	0 = not (successfully) completed, 1 = successful.
[CreatedOn]	datetime	NOT NULL	Creation time, default GETUTCDATE().
[CreatedBy]	nvarchar(100)	NOT NULL	Creating login, default SUSER_SNAME().
[ModifiedOn]	datetime	NULL	Last modification, set by the update trigger.
[ModifiedBy]	nvarchar(100)	NULL	Login of the last modification, set by the update trigger.

Declaration

The table is created with the following statement:

-- ----------------------------------------------------------------------------
-- [LL].[Execution] - logging table (top level): exactly one record per ETL
-- run. Inserted at the start of the entry procedure with [State] = 'processing'
-- and updated to 'success' or 'error' at the end.
-- ----------------------------------------------------------------------------
CREATE TABLE [LL].[Execution]
(
    [Id]           bigint        IDENTITY (1, 1) NOT NULL
   ,[Process]      nvarchar(max)                 NOT NULL
   ,[Start]        datetime                      NOT NULL
   ,[End]          datetime                          NULL
   ,[DeltaStart]   datetime                          NULL
   ,[DeltaEnd]     datetime                          NULL
   ,[User]         nvarchar(128)                     NULL
   ,[Machine]      nvarchar(128)                     NULL
   ,[Version]      int                               NULL
   ,[State]        nvarchar(128)                 NOT NULL
   ,[Success]      bit                           NOT NULL
   ,[CreatedOn]    datetime
       CONSTRAINT [DF_LL_Execution_CreatedOn]
       DEFAULT (GETUTCDATE())                    NOT NULL
   ,[CreatedBy]    nvarchar(100)
       CONSTRAINT [DF_LL_Execution_CreatedBy]
       DEFAULT (SUSER_SNAME())                   NOT NULL
   ,[ModifiedOn]   datetime                          NULL
   ,[ModifiedBy]   nvarchar(100)                     NULL
   ,CONSTRAINT [PK_LL_Execution]
       PRIMARY KEY CLUSTERED ([Id] ASC)
   ,CONSTRAINT [CK_LL_Execution_StateSuccess]
       CHECK (   ([State] = N'processing' AND [Success] = 0)
              OR ([State] = N'warning'    AND [Success] IN (0, 1))
              OR ([State] = N'success'    AND [Success] = 1)
              OR ([State] = N'error'      AND [Success] = 0))
);
GO

CREATE TRIGGER [LL].[TR_LL_Execution_Update]
ON [LL].[Execution]
FOR UPDATE
AS
BEGIN
    SET NOCOUNT ON;

    UPDATE [LL].[Execution]
       SET
           [ModifiedOn] = GETUTCDATE()
          ,[ModifiedBy] = SUSER_SNAME()
       FROM
          [LL].[Execution]
          INNER JOIN inserted
            ON inserted.[Id] = [LL].[Execution].[Id];
END;
GO

[LL].[Component]

Columns

Column	Data type	Null?	Description
[Id]	bigint (IDENTITY)	NOT NULL	Primary key of the component.
[ExecutionId]	bigint	NOT NULL	Foreign key to [LL].[Execution].
[Source]	nvarchar(5)	NOT NULL	Type of source (e.g. SSIS, T-SQL).
[Component]	nvarchar(128)	NOT NULL	Name of the component (procedure, package, job).
[Version]	int	NULL	Version number of the component.
[Entity]	nvarchar(128)	NOT NULL	Target entity the component processes.
[Step]	nvarchar(max)	NOT NULL	Description of the step.
[Description]	nvarchar(max)	NULL	Additional description.
[FileId]	bigint	NULL	Reference to a processed file.
[State]	nvarchar(128)	NOT NULL	Status: processing / warning / success / error.
[Success]	bit	NOT NULL	0 = not (successfully) completed, 1 = successful.
[CreatedOn]	datetime	NOT NULL	Creation time, default GETUTCDATE().
[CreatedBy]	nvarchar(100)	NOT NULL	Creating login, default SUSER_SNAME().
[ModifiedOn]	datetime	NULL	Last modification, set by the update trigger.
[ModifiedBy]	nvarchar(100)	NULL	Login of the last modification, set by the update trigger.

Declaration

-- ----------------------------------------------------------------------------
-- [LL].[Component] - logging table (middle level): exactly one record per
-- component call (stored procedure, SSIS package, Talend job).
-- Foreign key to [LL].[Execution].
-- ----------------------------------------------------------------------------
CREATE TABLE [LL].[Component]
(
    [Id]           bigint        IDENTITY (1, 1) NOT NULL
   ,[ExecutionId]  bigint                        NOT NULL
   ,[Source]       nvarchar(5)                   NOT NULL
   ,[Component]    nvarchar(128)                 NOT NULL
   ,[Version]      int                               NULL
   ,[Entity]       nvarchar(128)                 NOT NULL
   ,[Step]         nvarchar(max)                 NOT NULL
   ,[Description]  nvarchar(max)                     NULL
   ,[FileId]       bigint                            NULL
   ,[State]        nvarchar(128)                 NOT NULL
   ,[Success]      bit                           NOT NULL
   ,[CreatedOn]    datetime
       CONSTRAINT [DF_LL_Component_CreatedOn]
       DEFAULT (GETUTCDATE())                    NOT NULL
   ,[CreatedBy]    nvarchar(100)
       CONSTRAINT [DF_LL_Component_CreatedBy]
       DEFAULT (SUSER_SNAME())                   NOT NULL
   ,[ModifiedOn]   datetime                          NULL
   ,[ModifiedBy]   nvarchar(100)                     NULL
   ,CONSTRAINT [PK_LL_Component]
       PRIMARY KEY CLUSTERED ([Id] ASC)
   ,CONSTRAINT [FK_LL_Component_ExecutionId]
       FOREIGN KEY ([ExecutionId])
       REFERENCES [LL].[Execution] ([Id])
   ,CONSTRAINT [CK_LL_Component_StateSuccess]
       CHECK (   ([State] = N'processing' AND [Success] = 0)
              OR ([State] = N'warning'    AND [Success] IN (0, 1))
              OR ([State] = N'success'    AND [Success] = 1)
              OR ([State] = N'error'      AND [Success] = 0))
);
GO

CREATE TRIGGER [LL].[TR_LL_Component_Update]
ON [LL].[Component]
FOR UPDATE
AS
BEGIN
    SET NOCOUNT ON;

    UPDATE [LL].[Component]
       SET
           [ModifiedOn] = GETUTCDATE()
          ,[ModifiedBy] = SUSER_SNAME()
       FROM
          [LL].[Component]
          INNER JOIN inserted
            ON inserted.[Id] = [LL].[Component].[Id];
END;
GO

[LL].[Trace]

Columns

Column	Data type	Null?	Description
[Id]	bigint (IDENTITY)	NOT NULL	Primary key of the trace record.
[ExecutionId]	bigint	NOT NULL	Foreign key to [LL].[Execution].
[ComponentId]	bigint	NOT NULL	Foreign key to [LL].[Component].
[Source]	nvarchar(5)	NOT NULL	Type of source (e.g. SSIS, T-SQL).
[Component]	nvarchar(128)	NOT NULL	Name of the calling component.
[Task]	nvarchar(128)	NULL	Task name (e.g. SSIS task).
[Entity]	nvarchar(128)	NULL	Target entity of the action.
[Step]	nvarchar(max)	NOT NULL	Description of the step.
[Description]	nvarchar(max)	NULL	Additional description.
[FileId]	bigint	NULL	Reference to a processed file.
[Action]	nvarchar(100)	NULL	Type of action (insert / update / delete / …).
[AffectedRows]	bigint	NULL	Number of rows affected by the action.
[State]	nvarchar(100)	NOT NULL	Status: processing / warning / success / error.
[Success]	bit	NOT NULL	0 = not (successfully) completed, 1 = successful.
[CreatedOn]	datetime	NOT NULL	Creation time, default GETUTCDATE().
[CreatedBy]	nvarchar(100)	NOT NULL	Creating login, default SUSER_SNAME().
[ModifiedOn]	datetime	NULL	Last modification, set by the update trigger.
[ModifiedBy]	nvarchar(128)	NULL	Login of the last modification, set by the update trigger.

Declaration

-- ----------------------------------------------------------------------------
-- [LL].[Trace] - logging table (finest level): exactly one record per single
-- action (INSERT/UPDATE/DELETE, single SQL step, single task). Foreign keys
-- to [LL].[Execution] and [LL].[Component].
-- ----------------------------------------------------------------------------
CREATE TABLE [LL].[Trace]
(
    [Id]           bigint        IDENTITY (1, 1) NOT NULL
   ,[ExecutionId]  bigint                        NOT NULL
   ,[ComponentId]  bigint                        NOT NULL
   ,[Source]       nvarchar(5)                   NOT NULL
   ,[Component]    nvarchar(128)                 NOT NULL
   ,[Task]         nvarchar(128)                     NULL
   ,[Entity]       nvarchar(128)                     NULL
   ,[Step]         nvarchar(max)                 NOT NULL
   ,[Description]  nvarchar(max)                     NULL
   ,[FileId]       bigint                            NULL
   ,[Action]       nvarchar(100)                     NULL
   ,[AffectedRows] bigint                            NULL
   ,[State]        nvarchar(100)                 NOT NULL
   ,[Success]      bit                           NOT NULL
   ,[CreatedOn]    datetime
       CONSTRAINT [DF_LL_Trace_CreatedOn]
       DEFAULT (GETUTCDATE())                    NOT NULL
   ,[CreatedBy]    nvarchar(100)
       CONSTRAINT [DF_LL_Trace_CreatedBy]
       DEFAULT (SUSER_SNAME())                   NOT NULL
   ,[ModifiedOn]   datetime                          NULL
   ,[ModifiedBy]   nvarchar(128)                     NULL
   ,CONSTRAINT [PK_LL_Trace]
       PRIMARY KEY CLUSTERED ([Id] ASC)
   ,CONSTRAINT [FK_LL_Trace_ComponentId]
       FOREIGN KEY ([ComponentId])
       REFERENCES [LL].[Component] ([Id])
   ,CONSTRAINT [FK_LL_Trace_ExecutionId]
       FOREIGN KEY ([ExecutionId])
       REFERENCES [LL].[Execution] ([Id])
   ,CONSTRAINT [CK_LL_Trace_StateSuccess]
       CHECK (   ([State] = N'processing' AND [Success] = 0)
              OR ([State] = N'warning'    AND [Success] IN (0, 1))
              OR ([State] = N'success'    AND [Success] = 1)
              OR ([State] = N'error'      AND [Success] = 0))
);
GO

CREATE TRIGGER [LL].[TR_LL_Trace_Update]
ON [LL].[Trace]
FOR UPDATE
AS
BEGIN
    SET NOCOUNT ON;

    UPDATE [LL].[Trace]
       SET
           [ModifiedOn] = GETUTCDATE()
          ,[ModifiedBy] = SUSER_SNAME()
       FROM
          [LL].[Trace]
          INNER JOIN inserted
            ON inserted.[Id] = [LL].[Trace].[Id];
END;
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

Column	Data type	Null?	Description
[Id]	bigint (IDENTITY)	NOT NULL	Primary key of the error record.
[ExecutionId]	bigint	NOT NULL	Foreign key to [LL].[Execution].
[ComponentId]	bigint	NULL	Foreign key to [LL].[Component] (if known).
[TraceId]	bigint	NULL	Foreign key to [LL].[Trace] (if known).
[ErrorType]	char(1)	NOT NULL	Type of error (exception vs. data error).
[Source]	nvarchar(5)	NOT NULL	Type of source (e.g. SSIS, T-SQL).
[Component]	nvarchar(128)	NOT NULL	Component in which the error occurred.
[TaskName]	nvarchar(128)	NULL	Task name.
[Entity]	nvarchar(128)	NULL	Affected target entity.
[Step]	nvarchar(max)	NULL	Step in which the error occurred.
[Description]	nvarchar(max)	NULL	Error text (ERROR_MESSAGE()).
[Number]	int	NULL	Error number (ERROR_NUMBER()).
[Line]	int	NULL	Error line (ERROR_LINE()).
[State]	nvarchar(max)	NULL	Error state (ERROR_STATE()).
[CreatedOn]	datetime	NOT NULL	Creation time, default GETUTCDATE().
[CreatedBy]	nvarchar(100)	NOT NULL	Creating login, default SUSER_SNAME().

Declaration

-- ----------------------------------------------------------------------------
-- [LL].[Error] - logging table for exceptions and data errors.
-- In the context of this article we only use the exception columns;
-- the data-error columns (ID1Value/ID2Value/ID3Value/ErrorValue,
-- ID*ColumnName, FileName, FileId) are relevant for a follow-up article.
-- ----------------------------------------------------------------------------
CREATE TABLE [LL].[Error]
(
    [Id]              bigint        IDENTITY (1, 1) NOT NULL
   ,[ExecutionId]     bigint                        NOT NULL
   ,[ComponentId]     bigint                            NULL
   ,[TraceId]         bigint                            NULL
   ,[ErrorType]       char(1)                       NOT NULL
   ,[Source]          nvarchar(5)                   NOT NULL
   ,[Component]       nvarchar(128)                 NOT NULL
   ,[TaskName]        nvarchar(128)                     NULL
   ,[Entity]          nvarchar(128)                     NULL
   ,[Step]            nvarchar(max)                     NULL
   ,[SchemaName]      nvarchar(128)                     NULL
   ,[TableName]       nvarchar(128)                     NULL
   ,[FileId]          bigint                            NULL
   ,[ID1Value]        nvarchar(max)                     NULL
   ,[ID1ColumnName]   nvarchar(128)                     NULL
   ,[ID2Value]        nvarchar(max)                     NULL
   ,[ID2ColumnName]   nvarchar(128)                     NULL
   ,[ID3Value]        nvarchar(max)                     NULL
   ,[ID3ColumnName]   nvarchar(128)                     NULL
   ,[ErrorValue]      nvarchar(max)                     NULL
   ,[ErrorColumnName] nvarchar(128)                     NULL
   ,[FileName]        nvarchar(128)                     NULL
   ,[Description]     nvarchar(max)                     NULL
   ,[Number]          int                               NULL
   ,[Line]            int                               NULL
   ,[State]           nvarchar(max)                     NULL
   ,[CreatedOn]       datetime
       CONSTRAINT [DF_LL_Error_CreatedOn]
       DEFAULT (GETUTCDATE())                     NOT NULL
   ,[CreatedBy]       nvarchar(100)
       CONSTRAINT [DF_LL_Error_CreatedBy]
       DEFAULT (SUSER_SNAME())                    NOT NULL
   ,CONSTRAINT [PK_LL_Error]
       PRIMARY KEY CLUSTERED ([Id] ASC)
   ,CONSTRAINT [FK_LL_Error_ExecutionId]
       FOREIGN KEY ([ExecutionId])
       REFERENCES [LL].[Execution] ([Id])
   ,CONSTRAINT [FK_LL_Error_ComponentId]
       FOREIGN KEY ([ComponentId])
       REFERENCES [LL].[Component] ([Id])
   ,CONSTRAINT [FK_LL_Error_TraceId]
       FOREIGN KEY ([TraceId])
       REFERENCES [LL].[Trace] ([Id])
);
GO

Data Model

One deliberate redundancy in [LL].[Trace] stands out: [ExecutionId] sits there in addition to [ComponentId], so that run-level evaluations can skip the join through [LL].[Component]. The database does not enforce the consistency of that pair — a trace record could in theory point to a component of a different run. Anyone who wants to enforce it adds a composite foreign key on [Component]([Id], [ExecutionId]).

ETL Process Execution Status

The three process-log 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
processing	0	Action, component or run has started and is still running.
warning	0	Finished, but with a warning — not counted as success.
warning	1	Finished with a warning, yet counted as success.
success	1	Completed successfully.
error	0	Aborted with an error.

Valid combinations of the [State] and [Success] columns

Other combinations of status values are not allowed. This is enforced twice: the process-logging procedures raise an exception if an invalid combination is passed in, and a CHECK constraint per table additionally rejects invalid combinations at the database level (error 547, measured on SQL Server 2022).

Logging Procedures

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

Procedure	Schema	Purpose
spInsertExecution	LL	Opens the execution log (top level) at the start of the run.
spUpdateExecution	LL	Closes the execution log with status success or error.
spInsertComponent	LL	Opens a component log for a component.
spUpdateComponentSuccess	LL	Closes a component log successfully.
spUpdateComponentError	LL	Closes a component log in the error case.
spInsertTrace	LL	Writes a trace record for a single action.
spUpdateTrace	LL	Updates a trace record (general).
spUpdateTraceSuccess	LL	Updates a trace record to success / 1.
spUpdateTraceError	LL	Updates a trace record to error / 0.
spInsertErrorException	LL	Writes 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]

-- ----------------------------------------------------------------------------
-- [LL].[spInsertTrace] - inserts a trace record into [LL].[Trace]
-- and returns the generated id via @p_traceId.
-- ----------------------------------------------------------------------------
-- Parameters:
--    @p_executionId    bigint        Execution id of the current ETL run
--    @p_componentId    bigint        Component id of the calling component log
--    @p_traceId        bigint OUTPUT Id of the newly inserted trace record
--    @p_source          nvarchar(5)   Source system (SSIS, T-SQL, ...)
--    @p_component       nvarchar(128) Name of the calling component
--    @p_task            nvarchar(128) Task name (e.g. SSIS task), optional
--    @p_entity          nvarchar(128) Target entity, optional
--    @p_step            nvarchar(max) Description of the step
--    @p_description     nvarchar(max) Additional description, optional
--    @p_fileId         bigint        Reference to [LL].[FileList].[Id], optional
--    @p_action          nvarchar(100) Action label (Insert/Update/Delete/...)
--    @p_affectedRows   bigint        Number of rows affected
--    @p_state           nvarchar(100) processing / warning / success / error
--    @p_success         bit           0 = processing/warning/error, 1 = success
-- ----------------------------------------------------------------------------
CREATE OR ALTER PROCEDURE [LL].[spInsertTrace]
    @p_executionId    AS bigint
   ,@p_componentId    AS bigint
   ,@p_traceId        AS bigint OUTPUT
   ,@p_source         AS nvarchar(5)
   ,@p_component      AS nvarchar(128)
   ,@p_task           AS nvarchar(128)   = NULL
   ,@p_entity         AS nvarchar(128)   = NULL
   ,@p_step           AS nvarchar(max)
   ,@p_description    AS nvarchar(max)   = NULL
   ,@p_fileId         AS bigint          = NULL
   ,@p_action         AS nvarchar(100)   = NULL
   ,@p_affectedRows   AS bigint          = NULL
   ,@p_state          AS nvarchar(100)
   ,@p_success        AS bit
AS
BEGIN
    SET NOCOUNT ON;

    DECLARE @component AS nvarchar(128);
    DECLARE @table     AS TABLE ([Id] bigint);
    DECLARE @message   AS nvarchar(max);

    SET @component = OBJECT_SCHEMA_NAME(@@PROCID) + N'.' + OBJECT_NAME(@@PROCID);

    BEGIN TRY
        -- Parameter checks
        IF (@p_executionId IS NULL)
        BEGIN
            EXEC [dbo].[spRaiseError] N'The parameter ''p_executionId'' is NULL.', @component;
            RETURN 0;
        END;

        IF (@p_componentId IS NULL)
        BEGIN
            EXEC [dbo].[spRaiseError] N'The parameter ''p_componentId'' is NULL.', @component;
            RETURN 0;
        END;

        IF ([dbo].[fnIsNullOrEmpty](@p_source, 1) <> 0)
        BEGIN
            EXEC [dbo].[spRaiseError] N'The parameter ''p_source'' is either NULL or an empty string.', @component;
            RETURN 1;
        END;

        IF ([dbo].[fnIsNullOrEmpty](@p_component, 1) <> 0)
        BEGIN
            EXEC [dbo].[spRaiseError] N'The parameter ''p_component'' is either NULL or an empty string.', @component;
            RETURN 1;
        END;

        IF ([dbo].[fnIsNullOrEmpty](@p_step, 1) <> 0)
        BEGIN
            EXEC [dbo].[spRaiseError] N'The parameter ''p_step'' is either NULL or an empty string.', @component;
            RETURN 1;
        END;

        IF ([dbo].[fnIsNullOrEmpty](@p_state, 1) <> 0)
        BEGIN
            EXEC [dbo].[spRaiseError] N'The parameter ''p_state'' is either NULL or an empty string.', @component;
            RETURN 1;
        END;

        IF (@p_success IS NULL)
        BEGIN
            EXEC [dbo].[spRaiseError] N'The parameter ''p_success'' is NULL.', @component;
            RETURN 1;
        END;

        -- Validate the State/Success combination (whitelist)
        IF NOT (   (@p_state = N'processing' AND @p_success = 0)
                OR (@p_state = N'warning'    AND @p_success IN (0, 1))
                OR (@p_state = N'success'    AND @p_success = 1)
                OR (@p_state = N'error'      AND @p_success = 0))
        BEGIN
            SET @message = CONCAT(N'Invalid state ''', @p_state, N''' for p_success = ''', CAST(@p_success AS nvarchar(100)), N'''.');
            EXEC [dbo].[spRaiseError] @message, @component;
            RETURN 1;
        END;

        -- Write the trace record
        INSERT INTO [LL].[Trace]
        (
             [ExecutionId]
            ,[ComponentId]
            ,[Source]
            ,[Component]
            ,[Task]
            ,[Entity]
            ,[Step]
            ,[Description]
            ,[FileId]
            ,[Action]
            ,[AffectedRows]
            ,[State]
            ,[Success]
        )
        OUTPUT Inserted.[Id] INTO @table
        VALUES
        (
             @p_executionId
            ,@p_componentId
            ,@p_source
            ,@p_component
            ,@p_task
            ,@p_entity
            ,@p_step
            ,CASE WHEN @p_description IS NULL OR DATALENGTH(@p_description) = 0
                  THEN NULL ELSE @p_description END
            ,@p_fileId
            ,@p_action
            ,@p_affectedRows
            ,@p_state
            ,@p_success
        );

        SELECT @p_traceId = [Id] FROM @table;

        RETURN 0;
    END TRY
    BEGIN CATCH
        THROW;
    END CATCH;
END;
GO

[LL].[spUpdateTrace]

-- ----------------------------------------------------------------------------
-- [LL].[spUpdateTrace] - updates an existing trace record
-- with Description, Action, AffectedRows, State and Success.
-- ----------------------------------------------------------------------------
-- Parameters:
--    @p_traceId        bigint        Id of the trace record to update
--    @p_description     nvarchar(max) Description of the result
--    @p_action          nvarchar(100) Action label, optional
--    @p_affectedRows   bigint        Number of rows affected
--    @p_state           nvarchar(100) processing / warning / success / error
--    @p_success         bit           0 = processing/warning/error, 1 = success
-- ----------------------------------------------------------------------------
CREATE OR ALTER PROCEDURE [LL].[spUpdateTrace]
    @p_traceId         AS bigint
   ,@p_description     AS nvarchar(max)
   ,@p_action          AS nvarchar(100) = NULL
   ,@p_affectedRows    AS bigint
   ,@p_state           AS nvarchar(100)
   ,@p_success         AS bit
AS
BEGIN
    SET NOCOUNT ON;

    DECLARE @component AS nvarchar(128);
    DECLARE @tempId    AS bigint;
    DECLARE @message   AS nvarchar(max);

    SET @component = OBJECT_SCHEMA_NAME(@@PROCID) + N'.' + OBJECT_NAME(@@PROCID);

    BEGIN TRY
        -- Parameter checks
        IF (@p_traceId IS NULL)
        BEGIN
            EXEC [dbo].[spRaiseError] N'The parameter ''p_traceId'' is NULL.', @component;
            RETURN 1;
        END;

        IF (@p_success IS NULL)
        BEGIN
            SET @message = N'The parameter ''p_success'' is NULL.';
            EXEC [dbo].[spRaiseError] @message, @component;
            RETURN 1;
        END;

        IF ([dbo].[fnIsNullOrEmpty](@p_state, 1) <> 0)
        BEGIN
            SET @message = N'The parameter ''p_state'' is either NULL or an empty string.';
            EXEC [dbo].[spRaiseError] @message, @component;
            RETURN 1;
        END;

        -- Validate the State/Success combination (whitelist)
        IF NOT (   (@p_state = N'processing' AND @p_success = 0)
                OR (@p_state = N'warning'    AND @p_success IN (0, 1))
                OR (@p_state = N'success'    AND @p_success = 1)
                OR (@p_state = N'error'      AND @p_success = 0))
        BEGIN
            SET @message = CONCAT(N'Invalid state ''', @p_state, N''' for p_success = ''', CAST(@p_success AS nvarchar(100)), N'''.');
            EXEC [dbo].[spRaiseError] @message, @component;
            RETURN 1;
        END;

        -- Check that the trace record exists
        SELECT @tempId = [Id]
        FROM   [LL].[Trace]
        WHERE  [Id] = @p_traceId;

        IF (@tempId IS NULL)
        BEGIN
            SET @message = N'A record with [Id] = ''' + CAST(@p_traceId AS nvarchar(max)) + N''' could not be found.';
            EXEC [dbo].[spRaiseError] @message, @component;
            RETURN 1;
        END;

        -- Update the trace record
        UPDATE [LL].[Trace]
           SET
               [Description]  = CASE
                                  WHEN (@p_description IS NULL OR DATALENGTH(@p_description) = 0)
                                   AND ([Description]   IS NULL OR DATALENGTH([Description])   = 0)
                                  THEN NULL ELSE @p_description END
              ,[Action]       = @p_action
              ,[AffectedRows] = @p_affectedRows
              ,[State]        = @p_state
              ,[Success]      = @p_success
         WHERE [Id] = @p_traceId;

        RETURN 0;
    END TRY
    BEGIN CATCH
        THROW;
    END CATCH;
END;
GO

[LL].[spUpdateTraceSuccess]

-- ----------------------------------------------------------------------------
-- [LL].[spUpdateTraceSuccess] - convenience wrapper around spUpdateTrace for
-- the common case "action finished successfully" (State = 'success',
-- Success = 1). Saves setting both fields on every call.
-- ----------------------------------------------------------------------------
CREATE OR ALTER PROCEDURE [LL].[spUpdateTraceSuccess]
    @p_traceId         AS bigint
   ,@p_description     AS nvarchar(max)
   ,@p_action          AS nvarchar(100) = NULL
   ,@p_affectedRows    AS bigint
AS
BEGIN
    SET NOCOUNT ON;

    EXEC [LL].[spUpdateTrace]
         @p_traceId
        ,@p_description
        ,@p_action
        ,@p_affectedRows
        ,N'success'
        ,1;
END;
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.

-- ----------------------------------------------------------------------------
-- [LL].[spInsertExecution] - reference for the remaining logging procedures.
--
-- Structurally identical to [LL].[spInsertTrace]: parameter checks -> INSERT
-- -> id returned via OUTPUT variable. Once you understand the pattern, you can
-- spInsertComponent, spUpdateComponent*, spUpdateTraceError,
-- derive spInsertErrorException, spUpdateExecution analogously - only the
-- column assignment differs.
-- ----------------------------------------------------------------------------
CREATE OR ALTER PROCEDURE [LL].[spInsertExecution]
    @p_executionId    AS bigint OUTPUT
   ,@p_process        AS nvarchar(max)
   ,@p_version        AS int = NULL
AS
BEGIN
    SET NOCOUNT ON;

    DECLARE @component AS nvarchar(128);
    DECLARE @table     AS TABLE ([Id] bigint);

    SET @component = OBJECT_SCHEMA_NAME(@@PROCID) + N'.' + OBJECT_NAME(@@PROCID);

    BEGIN TRY
        IF ([dbo].[fnIsNullOrEmpty](@p_process, 1) <> 0)
        BEGIN
            EXEC [dbo].[spRaiseError] N'The parameter ''p_process'' is either NULL or an empty string.', @component;
            RETURN 1;
        END;

        INSERT INTO [LL].[Execution]
        (
             [Process]
            ,[Start]
            ,[User]
            ,[Machine]
            ,[Version]
            ,[State]
            ,[Success]
        )
        OUTPUT Inserted.[Id] INTO @table
        VALUES
        (
             @p_process
            ,GETUTCDATE()
            ,SUSER_SNAME()
            ,HOST_NAME()
            ,@p_version
            ,N'processing'
            ,0
        );

        SELECT @p_executionId = [Id] FROM @table;

        RETURN 0;
    END TRY
    BEGIN CATCH
        THROW;
    END CATCH;
END;
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:

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].

One point deserves particular attention here: the interplay of logging and transactions. If the ETL work runs inside an open transaction and the logging procedures write in the same session, a ROLLBACK in the CATCH block also rolls back the log records already written — of all cases, it is the failure case that loses its log. If an error additionally puts the transaction into the uncommittable state (XACT_STATE() = -1, the usual case for runtime errors in a TRY block under SET XACT_ABORT ON), an INSERT into the log tables fails in the CATCH block with error 3930 until the ROLLBACK has been executed (measured on SQL Server 2022). The order in the CATCH block is therefore: roll back the transaction first, then log. The example in this article works without an explicit transaction and deliberately sidesteps the problem.

And the error logging itself is not guaranteed to succeed. If one of the logging calls in the CATCH block fails — say, on missing permissions or a full log —, its exception masks the original error. Anyone who wants to guard against that wraps the logging calls in the CATCH block in a TRY/CATCH of their own: the final THROW then re-raises the original exception in every case.

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

-- ----------------------------------------------------------------------------
-- Exception-handling skeleton: shows the complete pattern of
-- TRY/CATCH + insert error + update execution + THROW. The order in the
-- CATCH block is crucial - log first, then THROW.
-- ----------------------------------------------------------------------------
-- Execution logging variables
DECLARE @executionId     AS bigint;
DECLARE @processName     AS nvarchar(max);
DECLARE @version         AS int;

-- Error logging variables
DECLARE @componentId     AS bigint;
DECLARE @traceId         AS bigint;
DECLARE @source          AS nvarchar(5);
DECLARE @component       AS nvarchar(128);
DECLARE @task            AS nvarchar(128);
DECLARE @entity          AS nvarchar(128);
DECLARE @step            AS nvarchar(128);
DECLARE @state           AS nvarchar(128);
DECLARE @success         AS bit;

-- Exception variables (lowercase by convention)
DECLARE @error_message   AS nvarchar(max);
DECLARE @error_number    AS int;
DECLARE @error_line      AS int;
DECLARE @error_state     AS nvarchar(max);

BEGIN TRY
    -- Initialize the execution logging variables
    SET @processName  = N'Name of ETL-Process';
    SET @version      = 123;

    -- Initialize the error logging variables
    SET @componentId  = NULL;
    SET @traceId      = NULL;
    SET @source       = N'sql';
    SET @component    = N'Procedure Name';
    SET @task         = NULL;
    SET @entity       = N'Any Entity';
    SET @step         = N'Do something';

    EXEC [LL].[spInsertExecution] @executionId OUTPUT, @processName, @version;

    -- Workload (the actual ETL work happens here)
    THROW 50001, N'Any Exception', 1;

    SET @state   = N'success';
    SET @success = 1;
    EXEC [LL].[spUpdateExecution] @executionId, @state, @success;
END TRY
BEGIN CATCH
    SET @error_message = ERROR_MESSAGE();
    SET @error_number  = ERROR_NUMBER();
    SET @error_line    = ERROR_LINE();
    SET @error_state   = ERROR_STATE();

    SET @state   = N'error';
    SET @success = 0;

    IF @executionId IS NOT NULL
    BEGIN
        EXEC [LL].[spInsertErrorException]
             @executionId
            ,@componentId
            ,@traceId
            ,@source
            ,@component
            ,@task
            ,@entity
            ,@step
            ,@error_number
            ,@error_message
            ,@error_line
            ,@error_state;

        EXEC [LL].[spUpdateExecution] @executionId, @state, @success;
    END;

    THROW;
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:

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 logs an INSERT, an UPDATE and a DELETE step each, while the second procedure executes two further procedures, [T2].[spDoSomething_2_1] and [T2].[spDoSomething_2_2]. These procedures, too, log an INSERT, an UPDATE and a DELETE step each — the DML statements themselves are deliberately only sketched as placeholder comments in the demo procedures. 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.

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. All remaining worker procedures use the same TRY/CATCH pattern as [T2].[spDoSomething_2_2].

Two decisions in the example are deliberate. The worker procedures re-raise a caught exception via THROW, so that every level can close its own log record. The entry procedure [T2].[spETLProcess], by contrast, consumes the exception after logging is complete — the run ends in an orderly way with [State] = error, without aborting the caller hard. If an orchestrator such as SQL Server Agent is supposed to see the failure, an additional THROW belongs at the end of its CATCH block, otherwise the job ends as spuriously successful from the scheduler's point of view.

And when passing on the row count, order matters: @@ROWCOUNT is captured into the variable @affectedRows immediately after the respective DML statement, and only that variable is passed to [LL].[spUpdateTraceSuccess]. After an EXEC, @@ROWCOUNT does not carry the business row count of the called component but the value of its last executed statement, and even a simple variable assignment sets the value to 1 (measured on SQL Server 2022). The orchestration steps in [T2].[spETLProcess] therefore log no row count of their own — the workers deliver it in their trace records. In the demo workers, SET @affectedRows = @@ROWCOUNT; deliberately remains part of the placeholder comment, and the placeholder steps pass NULL, because without real DML there would be no business row count to capture. For statements beyond 2 billion rows, ROWCOUNT_BIG() takes the place of @@ROWCOUNT. The column [AffectedRows] is sized as bigint for that.

[T2].[spETLProcess]

-- ----------------------------------------------------------------------------
-- [T2].[spETLProcess] - example entry procedure of the ETL process.
-- Calls two worker procedures spDoSomething_1 and spDoSomething_2
-- and logs both calls in [LL].[Trace].
-- ----------------------------------------------------------------------------
CREATE OR ALTER PROCEDURE [T2].[spETLProcess]
AS
BEGIN
    SET NOCOUNT ON;

    -- Error variables
    DECLARE @error_message  AS nvarchar(max);
    DECLARE @error_number   AS int;
    DECLARE @error_line     AS int;
    DECLARE @error_state    AS nvarchar(max);

    -- Logging variables
    DECLARE @component      AS nvarchar(128);
    DECLARE @task           AS nvarchar(128);
    DECLARE @source         AS nvarchar(5);
    DECLARE @step           AS nvarchar(max);
    DECLARE @entity         AS nvarchar(max);
    DECLARE @message        AS nvarchar(max);

    DECLARE @traceId       AS bigint;
    DECLARE @componentId   AS bigint;
    DECLARE @executionId   AS bigint;

    DECLARE @description    AS nvarchar(max);
    DECLARE @affectedRows   AS bigint;
    DECLARE @action         AS nvarchar(100);
    DECLARE @state          AS nvarchar(100);
    DECLARE @success        AS bit;

    SET @message       = NULL;
    SET @description   = NULL;
    SET @affectedRows  = 0;

    SET @component = OBJECT_SCHEMA_NAME(@@PROCID) + N'.' + OBJECT_NAME(@@PROCID);
    SET @source    = N'T-SQL';
    SET @entity    = N'[].[]';

    BEGIN TRY
        -- Open the execution log
        EXEC [LL].[spInsertExecution] @executionId OUTPUT, N'ETL process', 123;

        -- Open the component log
        SET @step        = N'Orchestrate ETL process';
        SET @description = N'';
        EXEC [LL].[spInsertComponent]
             @executionId, @componentId OUTPUT, @source, @component, NULL, @entity, @step, @description;

        -- ----------------------------------------------------------------
        -- Call [T2].[spDoSomething_1]
        -- ----------------------------------------------------------------
        SET @task        = NULL;
        SET @step        = N'Execute [T2].[spDoSomething_1]';
        SET @action      = N'execute';
        SET @description = NULL;
        SET @state       = N'processing';
        SET @success     = 0;
        EXEC [LL].[spInsertTrace]
             @executionId, @componentId, @traceId OUTPUT
            ,@source, @component, @task, @entity, @step, @description
            ,NULL, @action, NULL, @state, @success;

        EXEC [T2].[spDoSomething_1] @executionId;

        -- Orchestration step without a row count of its own - the DML rows
        -- are logged by the workers in their own trace records
        EXEC [LL].[spUpdateTraceSuccess] @traceId, @description, @action, NULL;

        -- ----------------------------------------------------------------
        -- Call [T2].[spDoSomething_2]
        -- ----------------------------------------------------------------
        SET @task        = NULL;
        SET @step        = N'Execute [T2].[spDoSomething_2]';
        SET @action      = N'execute';
        SET @description = NULL;
        SET @state       = N'processing';
        SET @success     = 0;
        EXEC [LL].[spInsertTrace]
             @executionId, @componentId, @traceId OUTPUT
            ,@source, @component, @task, @entity, @step, @description
            ,NULL, @action, NULL, @state, @success;

        EXEC [T2].[spDoSomething_2] @executionId;

        EXEC [LL].[spUpdateTraceSuccess] @traceId, @description, @action, NULL;

        -- Close the component log
        EXEC [LL].[spUpdateComponentSuccess] @componentId, @description;

        -- Close the execution log
        SET @state   = N'success';
        SET @success = 1;
        EXEC [LL].[spUpdateExecution] @executionId, @state, @success;
    END TRY
    BEGIN CATCH
        SET @error_message = ERROR_MESSAGE();
        SET @error_number  = ERROR_NUMBER();
        SET @error_line    = ERROR_LINE();
        SET @error_state   = ERROR_STATE();

        IF @executionId IS NOT NULL
        BEGIN
            EXEC [LL].[spInsertErrorException]
                 @executionId, @componentId, @traceId, @source, @component
                ,NULL, NULL, @step
                ,@error_number, @error_message, @error_line, @error_state;

            IF @traceId     IS NOT NULL EXEC [LL].[spUpdateTraceError]     @traceId,     @description;
            IF @componentId IS NOT NULL EXEC [LL].[spUpdateComponentError] @componentId, @description;

            SET @state   = N'error';
            SET @success = 0;
            EXEC [LL].[spUpdateExecution] @executionId, @state, @success;
        END;
    END CATCH;
END;
GO

[T2].[spDoSomething_2_2]

-- ----------------------------------------------------------------------------
-- [T2].[spDoSomething_2_2] - deepest worker procedure in the example tree.
-- Called by [T2].[spDoSomething_2] (see diagram 041007.png).
-- Simulates an INSERT, an UPDATE and a DELETE - the DELETE raises an
-- exception to demonstrate the exception-handling pattern.
-- ----------------------------------------------------------------------------
CREATE OR ALTER PROCEDURE [T2].[spDoSomething_2_2]
(
    @p_executionId  AS bigint
)
AS
BEGIN
    SET NOCOUNT ON;

    -- Error variables
    DECLARE @error_message  AS nvarchar(max);
    DECLARE @error_number   AS int;
    DECLARE @error_line     AS int;
    DECLARE @error_state    AS nvarchar(max);

    -- Logging variables
    DECLARE @component      AS nvarchar(128);
    DECLARE @task           AS nvarchar(128);
    DECLARE @source         AS nvarchar(5);
    DECLARE @step           AS nvarchar(max);
    DECLARE @entity         AS nvarchar(max);
    DECLARE @message        AS nvarchar(max);

    DECLARE @traceId       AS bigint;
    DECLARE @componentId   AS bigint;

    DECLARE @description    AS nvarchar(max);
    DECLARE @affectedRows   AS bigint;
    DECLARE @action         AS nvarchar(100);
    DECLARE @state          AS nvarchar(100);
    DECLARE @success        AS bit;

    SET @message       = NULL;
    SET @description   = NULL;
    SET @affectedRows  = 0;

    SET @component = OBJECT_SCHEMA_NAME(@@PROCID) + N'.' + OBJECT_NAME(@@PROCID);
    SET @source    = N'T-SQL';
    SET @entity    = N'[].[]';

    BEGIN TRY
        IF (@p_executionId IS NULL)
        BEGIN
            SET @message = N'The parameter ''p_executionId'' is NULL.';
            EXEC [dbo].[spRaiseError] @message, @component;
            RETURN -1;
        END;

        -- Open the component log
        SET @step        = N'Do something';
        SET @description = N'';
        EXEC [LL].[spInsertComponent]
             @p_executionId, @componentId OUTPUT, @source, @component, NULL, @entity, @step, @description;

        -- ----------------------------------------------------------------
        -- INSERT (succeeds)
        -- ----------------------------------------------------------------
        SET @task        = NULL;
        SET @step        = N'Insert data';
        SET @action      = N'insert';
        SET @description = NULL;
        SET @state       = N'processing';
        SET @success     = 0;
        EXEC [LL].[spInsertTrace]
             @p_executionId, @componentId, @traceId OUTPUT
            ,@source, @component, @task, @entity, @step, @description
            ,NULL, @action, NULL, @state, @success;

        -- An INSERT statement would go here, immediately followed by:
        -- SET @affectedRows = @@ROWCOUNT;

        EXEC [LL].[spUpdateTraceSuccess] @traceId, @description, @action, NULL;

        -- ----------------------------------------------------------------
        -- UPDATE (succeeds)
        -- ----------------------------------------------------------------
        SET @task        = NULL;
        SET @step        = N'Update data';
        SET @action      = N'update';
        SET @description = NULL;
        SET @state       = N'processing';
        SET @success     = 0;
        EXEC [LL].[spInsertTrace]
             @p_executionId, @componentId, @traceId OUTPUT
            ,@source, @component, @task, @entity, @step, @description
            ,NULL, @action, NULL, @state, @success;

        -- An UPDATE statement would go here, immediately followed by:
        -- SET @affectedRows = @@ROWCOUNT;

        EXEC [LL].[spUpdateTraceSuccess] @traceId, @description, @action, NULL;

        -- ----------------------------------------------------------------
        -- DELETE (deliberately raises an exception)
        -- ----------------------------------------------------------------
        SET @task        = NULL;
        SET @step        = N'Delete data';
        SET @action      = N'delete';
        SET @description = NULL;
        SET @state       = N'processing';
        SET @success     = 0;
        EXEC [LL].[spInsertTrace]
             @p_executionId, @componentId, @traceId OUTPUT
            ,@source, @component, @task, @entity, @step, @description
            ,NULL, @action, NULL, @state, @success;

        -- A DELETE statement would go here - artificially raised exception:
        THROW 50001, N'Exception in [T2].[spDoSomething_2_2]', 1;

        EXEC [LL].[spUpdateTraceSuccess] @traceId, @description, @action, NULL;

        -- Close the component log
        EXEC [LL].[spUpdateComponentSuccess] @componentId, @description;
    END TRY
    BEGIN CATCH
        SET @error_message = ERROR_MESSAGE();
        SET @error_number  = ERROR_NUMBER();
        SET @error_line    = ERROR_LINE();
        SET @error_state   = ERROR_STATE();

        IF @p_executionId IS NOT NULL
        BEGIN
            EXEC [LL].[spInsertErrorException]
                 @p_executionId, @componentId, @traceId, @source, @component
                ,NULL, NULL, @step
                ,@error_number, @error_message, @error_line, @error_state;

            IF @traceId     IS NOT NULL EXEC [LL].[spUpdateTraceError]     @traceId,     @description;
            IF @componentId IS NOT NULL EXEC [LL].[spUpdateComponentError] @componentId, @description;
        END;

        THROW;
    END CATCH;
END;
GO

The following script contains the statement to execute the ETL process. To obtain a compact process log, the log tables are cleared beforehand. This clearing, including DBCC CHECKIDENT, is a pure demo reset for reproducible ids — in live operation, log tables are not emptied. The closing SELECT statements produce the result shown at the beginning.

-- ----------------------------------------------------------------------------
-- Example run: execute the ETL process and evaluate the log.
--
-- Block 1 clears the log tables (TRUNCATE / DELETE + RESEED),
-- block 2 starts the example ETL process, block 3 shows the result.
-- The SELECT statements return exactly the three result sets shown at the
-- start of the article (tables 041001, 041002, 041003).
-- ----------------------------------------------------------------------------

-- 01: Clear the log tables
TRUNCATE TABLE [LL].[Error];
TRUNCATE TABLE [LL].[Trace];
DELETE FROM    [LL].[Component];
DELETE FROM    [LL].[Execution];
DBCC CHECKIDENT (N'[LL].[Component]', RESEED, 0);
DBCC CHECKIDENT (N'[LL].[Execution]', RESEED, 0);

-- 02: Start the ETL process
EXEC [T2].[spETLProcess];

-- 03: Evaluate the log
SELECT * FROM [LL].[Execution];
SELECT * FROM [LL].[Component];
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 can also be logged. 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 at the same time makes the data quality of a run assessable.

What goes without saying 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.

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 concept is database-neutral: the logging tables and the three-tier structure stay the same. The concrete implementation, however, has to be adapted to PL/pgSQL semantics. 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. One important difference remains: an EXCEPTION block forms an implicit subtransaction in PL/pgSQL. If it catches an error, all changes of the block are rolled back — including log records already written (measured on PostgreSQL 16). The error logging therefore belongs in the EXCEPTION branch — what the handler itself writes is kept. If you want to measure the execution time of individual statements without your own trace table, you can additionally draw on pg_stat_statements, as an aggregated statement statistic without the run-level correlation via execution, component and trace ids.

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

SQL Server Audit and pgAudit are database-side auditing mechanisms: they log database and server events — logins, DDL, also object access such as SELECT or INSERT — at the infrastructure level, without the business correlation of an ETL run via execution, component and trace ids. 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.

Why are log entries missing after an error with a rollback?

Because the log INSERTs ran in the same transaction as the ETL work. A ROLLBACK in the CATCH block then also rolls back the log records already written. If the error puts the transaction into the uncommittable state (XACT_STATE() = -1, the usual case for runtime errors in a TRY block under SET XACT_ABORT ON), an INSERT in the CATCH block even fails with error 3930 as long as the ROLLBACK is outstanding. In the CATCH block, the rule is therefore: roll back the transaction first, then log — or keep the logging outside the surrounding transaction in the first place (see the Exception Handling section).

How do you log the number of rows affected with @@ROWCOUNT?

Capture the value of @@ROWCOUNT into a variable immediately after the INSERT, UPDATE or DELETE statement and pass that variable to the logging procedure — every further statement in between overwrites the value. In this pattern, the number ends up in the [AffectedRows] column of the trace record via [LL].[spUpdateTraceSuccess]. For statements with more than 2 billion rows, ROWCOUNT_BIG() takes the place of @@ROWCOUNT. The column [AffectedRows] is sized as bigint accordingly.

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.

Related Articles

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

• Data Quality in an ETL Process — the root of the article series.
• Design Pattern // The Architecture of an ETL Process — provides the schema T2 used in the example of this article.
• ETL vs. ELT — How to Tell Which Pattern You Actually Built — classifies the pattern logged here as ETL vs. ELT.
• Checking Data Quality with SQL — a Configurable Framework — uses the same error-table idea for generic data quality checks.
• Design Pattern // Safe Type Conversion with T-SQL
• Data Quality // Fundamentals of Type Conversion with T-SQL