Design Pattern // Protokollierung eines ETL-Prozesses — wie sich Lauf, Komponente und Aktion auswertbar protokollieren lassen

Ein ETL-Prozess endet ohne Exception — aber wurde wirklich alles geladen, was hätte geladen werden müssen? Allein der Umstand, dass ein Prozess nicht abgebrochen ist, sagt noch nichts darüber, ob er auch das getan hat, was von ihm erwartet wurde. Ein les- und auswertbares Protokoll macht den Unterschied zwischen Bauchgefühl und belastbarer Aussage.

Dieses Design Pattern protokolliert einen ETL-Lauf auf drei Ebenen und beantwortet damit die Fragen, an denen sich Erfolg oder Misserfolg festmachen lassen:

  • Wie lange dauert der ETL-Prozess insgesamt?
  • Wie lange dauert die Ausführung einer Komponente — einer gespeicherten Prozedur, eines SSIS-Pakets oder eines anderen Bausteins?
  • Wie lange dauert die Ausführung eines konkreten SQL-Statements?
  • Wie viele Datensätze hat ein SQL-Statement tatsächlich bearbeitet?
  • Und über allem: Wurde der Prozess als Ganzes, eine Komponente oder ein einzelnes Statement erfolgreich ausgeführt?

TL;DR — was dieser Artikel zeigt:

  • Dreistufige Protokollierung — die Tabellen [LL].[Execution][LL].[Component] und [LL].[Trace] halten Lauf, Komponente und Aktion mit wachsender Granularität fest.
  • Stored-Procedure-Werkzeugkasten — Prozeduren wie [LL].[spInsertTrace] und [LL].[spUpdateTrace] schreiben und aktualisieren die Protokolldatensätze.
  • Exception-Handling mit [LL].[Error] — ein TRY/CATCH-Pattern beendet den Lauf geordnet und legt jeden Fehler auswertbar ab.
  • Fortsetzung der ETL-Architektur — das Beispiel nutzt das Schema T2 aus dem Architektur-Artikel und ergänzt es um die Logging-Schicht.

Voraussetzung. SQL Server, Grundverständnis von gespeicherten Prozeduren und TRY/CATCH. Der Artikel gehört zum ETL-Design-Pattern-Cluster; als Vorlauf empfehlen sich Datenqualität in einem ETL-Prozess und Architektur eines ETL-Prozesses.

Inhalt

Das Ergebnis

Die Vorgehensweise ist im Kern geradeheraus: Zu Beginn jeder Aktion wird ein Protokolldatensatz geschrieben, nach ihrer Beendigung wird dieser mit dem Status Erfolg oder Misserfolg — und gegebenenfalls weiteren hilfreichen Informationen — aktualisiert. That’s it! Ein bisschen mehr darf es dann aber doch noch sein …

Auch wenn die Erstellung eines Protokolls an sich keine große Sache ist bzw. sein sollte, gibt es doch einiges dazu zu schreiben. Fangen wir mit dem Ergebnis an und zäumen das Pferd von hinten auf. Die hier vorgestellte Prozessprotokollierung ist dreistufig und verwendet die folgenden Protokoll-Tabellen:

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

In diesen Tabellen werden ein ETL-Prozess und die damit verbundenen Komponenten und Arbeitsschritte mit wachsender Granularität – von oben nach unten gelesen – protokolliert. Der ETL-Prozess, die Komponenten und die einzelnen Arbeitsschritte werden mit genau einem Datensatz protokolliert.

Eng mit der Protokollierung des Prozesses verbunden ist natürlich auch die Protokollierung von Fehlern. Die hier vorgestellte Vorgehensweise verwendet dafür die folgende Tabelle:

  • [LL].[Error]

Die folgenden Abbildungen zeigen das Ergebnis der dreistufigen Protokollierung eines einfachen, kompakten, aber vollständigen ETL-Prozesses.

In der Tabelle [LL].[Trace] wird jede Aktion unter anderem mit dem Namen der Prozedur, der Zielentität, die von der Prozedur bearbeitet wird, einer kurzen Beschreibung, was konkret gemacht wurde, und weiteren Informationen wie der Anzahl der betroffenen Datensätze und der Dauer der Ausführung protokolliert.

Result-Set der Tabelle [LL].[Trace]: mehrere Trace-Datensätze je einer Aktion, mit Spalten Component, Entity, Action, AffectedRows, State und Success aus einem Beispiel-Lauf.
Tabelle [LL].[Trace]

In der Tabelle [LL].[Component] werden die Aufrufe von Prozeduren und SSIS-Paketen oder – allgemein ausgedrückt – Komponenten protokolliert. Auch hier werden eine kurze Beschreibung der Aufgabe der Komponente, die Zielentität und die Dauer der Ausführung protokolliert.

Result-Set der Tabelle [LL].[Component]: ein Datensatz pro aufgerufener Komponente mit Component, Entity, State und Success.
Tabelle [LL].[Component]

Auf der obersten Ebene wird jede Ausführung des ETL-Prozesses in der Tabelle [LL].[Execution] mit genau einem Datensatz protokolliert.

Result-Set der Tabelle [LL].[Execution]: ein einzelner Datensatz für den gesamten ETL-Lauf mit Process, Start, End, State und Success.
Tabelle [LL].[Execution]

Alle Tabellen für die Prozessprotokollierung enthalten zwei Spalten [State] und [Success], in denen der Erfolg oder Misserfolg der Ausführung einer Aktion, einer Komponente oder des ETL-Prozesses gespeichert wird.

Und nun die Herleitung…

Nach der kurzen Einführung des Ergebnisses sind die folgenden Aspekte der Vorgehensweise zu klären:

Dreistufige Protokollierung

Die Vorgehensweise sieht die Protokollierung eines ETL-Prozesses in den drei Tabellen [LL].[Execution][LL].[Component] und [LL].[Trace] vor. Jede der Tabellen ist für die Protokollierung von bestimmten Artefakten vorgesehen. Dieser Abschnitt stellt die Verwendung der jeweiligen Tabellen, ihre Spalten und den Code für ihre Erstellung vor.

[LL].[Execution]

In dieser Tabelle wird die Ausführung eines ETL-Prozesses mit genau einem Datensatz protokolliert. Ein ETL-Prozess hat immer eine Einstiegsfunktion. Das kann eine gespeicherte Prozedur, ein SSIS-Paket, ein Talend-Job oder ein SQL Server Agent-Job sein. Zu Beginn der Ausführung der Einstiegsfunktion wird ein Protokolldatensatz in diese Tabelle eingefügt. Nach erfolgreicher Verarbeitung aller Aufgaben wird dieser Datensatz mit dem Status success aktualisiert, im Fehlerfall mit dem Status error. Damit enthält diese Tabelle eine Übersicht über alle Ausführungen des ETL-Prozesses und stellt Informationen wie den Status und die Dauer der Ausführung bereit.

[LL].[Component]

In dieser Tabelle wird die Ausführung einer Komponente mit genau einem Datensatz protokolliert. Eine Komponente kann eine gespeicherte Prozedur, ein SSIS-Paket oder ein Talend-Job sein. Eine Komponente zeichnet sich dadurch aus, dass sie eine oder mehrere Datenmanipulationen steuert und ausführt. Wie schon bei der Tabelle [LL].[Execution] wird zu Beginn der Ausführung ein Protokolldatensatz in diese Tabelle eingefügt und nach Beendigung mit dem Status success oder dem Status error aktualisiert. Damit enthält diese Tabelle je Ausführung des ETL-Prozesses eine Liste der ausgeführten Komponenten und stellt Informationen wie den Status und die Dauer der Ausführung bereit.

[LL].[Trace]

Die Bezeichnung dieser Tabelle enthält schon den Hinweis, dass die Tabelle für die detaillierte Protokollierung der Aktionen des ETL-Prozesses vorgesehen ist, eben einen Trace erstellt. Welche Aktionen protokolliert werden, ist eine Design-Entscheidung des Entwicklers. Es empfiehlt sich aber, mindestens jedes INSERT-, UPDATE- und DELETE-Statement mit einem eigenen Protokolldatensatz zu protokollieren. Die Tabelle sieht neben den bereits oben erwähnten Status-Feldern auch die Speicherung der Anzahl der betroffenen Datensätze vor und gibt dem Entwickler damit die Möglichkeit zu beurteilen, ob die Statements genau das gemacht haben, was erwartet wurde.

[LL].[Error]

Fehler, die in einem ETL-Prozess erkannt wurden, sind natürlich zu protokollieren. Zu unterscheiden ist die Protokollierung von Exceptions und Datenfehlern. Die Struktur dieser Tabelle ist auf die Protokollierung von Datenfehlern ausgelegt und enthält Spalten, in denen jeder Datenfehler vollständig, les- und auswertbar protokolliert werden kann. Dieser Artikel legt den Fokus auf die Protokollierung eines ETL-Prozesses und nicht auf die Protokollierung von Datenfehlern. Die Protokollierung des Prozesses ist eng mit einem expliziten Exception-Handling verbunden. Dem Exception-Handling und der Protokollierung von Exceptions ist ein separater Abschnitt gewidmet.

Der Schemaname LL

Der Schemaname LL steht für Logging Layer. In diesem Schema sind alle Protokolltabellen und die gespeicherten Prozeduren, die für die Protokollierung verwendet werden, abgelegt.

Tabellenbeschreibung, Deklaration und Datenmodell

Die folgenden Abschnitte beschreiben die Tabellen für die Protokollierung des Prozesses sowie die Tabelle für die Protokollierung von Fehlern. Abschließend findet sich ein Diagramm mit dem Datenmodell zu diesen Tabellen.

[LL].[Execution]

Spalten

Die Tabelle enthält die folgenden Spalten:

SpalteDatentypNull?Beschreibung
[Id]bigint (IDENTITY)NOT NULLPrimärschlüssel, fortlaufende Lauf-Id.
[Process]nvarchar(max)NOT NULLName des ETL-Prozesses.
[Start]datetimeNOT NULLStartzeitpunkt des Laufs (UTC).
[End]datetimeNULLEndzeitpunkt des Laufs.
[DeltaStart]datetimeNULLBeginn des Delta-Zeitfensters (für inkrementelle Loads).
[DeltaEnd]datetimeNULLEnde des Delta-Zeitfensters.
[User]nvarchar(128)NULLAusführender DB-Login (SUSER_SNAME()).
[Machine]nvarchar(128)NULLHost, von dem der Lauf gestartet wurde.
[Version]intNULLVersionsnummer des ETL-Prozesses.
[State]nvarchar(128)NULLStatus: processing / warning / success / error.
[Success]bitNULL0 = nicht (erfolgreich) abgeschlossen, 1 = erfolgreich.
[CreatedOn]datetimeNOT NULLAnlage-Zeitpunkt, Default GETUTCDATE().
[CreatedBy]nvarchar(100)NOT NULLAnlegender Login, Default SUSER_SNAME().
[ModifiedOn]datetimeNULLLetzte Änderung, per Update-Trigger gesetzt.
[ModifiedBy]nvarchar(100)NULLLogin der letzten Änderung, per Update-Trigger gesetzt.

Deklaration

Die Tabelle wird über die folgende Anweisung erstellt:

  1: -- ----------------------------------------------------------------------------
  2: -- [LL].[Execution] — Logging-Tabelle (oberste Ebene): pro ETL-Lauf genau ein
  3: -- Datensatz. Wird zu Beginn der Einstiegs-Procedure mit [State] = 'processing'</
  4: -- eingefuegt und am Ende mit 'success' oder 'error' aktualisiert.
  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]

Spalten

SpalteDatentypNull?Beschreibung
[Id]bigint (IDENTITY)NOT NULLPrimärschlüssel der Komponente.
[ExecutionId]bigintNOT NULLFremdschlüssel auf [LL].[Execution].
[Source]nvarchar(5)NOT NULLArt der Quelle (z. B. SSIST-SQL).
[Component]nvarchar(128)NOT NULLName der Komponente (Prozedur, Paket, Job).
[Version]intNULLVersionsnummer der Komponente.
[Entity]nvarchar(128)NOT NULLZielentität, die die Komponente bearbeitet.
[Step]nvarchar(max)NOT NULLBeschreibung des Arbeitsschritts.
[Description]nvarchar(max)NULLZusätzliche Beschreibung.
[FileId]bigintNULLVerweis auf eine verarbeitete Datei.
[State]nvarchar(128)NULLStatus: processing / warning / success / error.
[Success]bitNULL0 = nicht (erfolgreich) abgeschlossen, 1 = erfolgreich.
[CreatedOn]datetimeNOT NULLAnlage-Zeitpunkt, Default GETUTCDATE().
[CreatedBy]nvarchar(100)NOT NULLAnlegender Login, Default SUSER_SNAME().
[ModifiedOn]datetimeNULLLetzte Änderung, per Update-Trigger gesetzt.
[ModifiedBy]nvarchar(100)NULLLogin der letzten Änderung, per Update-Trigger gesetzt.

Deklaration

  1: -- ----------------------------------------------------------------------------
  2: -- [LL].[Component] — Logging-Tabelle (mittlere Ebene): pro Komponenten-Aufruf
  3: -- (gespeicherte Prozedur, SSIS-Paket, Talend-Job) genau ein Datensatz.
  4: -- Fremdschluessel auf [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]

Spalten

SpalteDatentypNull?Beschreibung
[Id]bigint (IDENTITY)NOT NULLPrimärschlüssel des Trace-Datensatzes.
[ExecutionId]bigintNOT NULLFremdschlüssel auf [LL].[Execution].
[ComponentId]bigintNOT NULLFremdschlüssel auf [LL].[Component].
[Source]nvarchar(5)NOT NULLArt der Quelle (z. B. SSIST-SQL).
[Component]nvarchar(128)NOT NULLName der aufrufenden Komponente.
[Task]nvarchar(128)NULLTask-Name (z. B. SSIS-Task).
[Entity]nvarchar(128)NULLZielentität der Aktion.
[Step]nvarchar(max)NOT NULLBeschreibung des Arbeitsschritts.
[Description]nvarchar(max)NULLZusätzliche Beschreibung.
[FileId]bigintNULLVerweis auf eine verarbeitete Datei.
[Action]nvarchar(100)NULLArt der Aktion (insert / update / delete / …).
[AffectedRows]intNULLAnzahl der von der Aktion betroffenen Datensätze.
[State]nvarchar(100)NOT NULLStatus: processing / warning / success / error.
[Success]bitNOT NULL0 = nicht (erfolgreich) abgeschlossen, 1 = erfolgreich.
[CreatedOn]datetimeNOT NULLAnlage-Zeitpunkt, Default GETUTCDATE().
[CreatedBy]nvarchar(100)NOT NULLAnlegender Login, Default SUSER_SNAME().
[ModifiedOn]datetimeNULLLetzte Änderung, per Update-Trigger gesetzt.
[ModifiedBy]nvarchar(128)NULLLogin der letzten Änderung, per Update-Trigger gesetzt.

Deklaration

  1: -- ----------------------------------------------------------------------------
  2: -- [LL].[Trace] — Logging-Tabelle (feinste Ebene): pro einzelner Aktion
  3: -- (INSERT/UPDATE/DELETE, einzelner SQL-Schritt, einzelner Task) genau ein
  4: -- Datensatz. Fremdschluessel auf [LL].[Execution] und [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]

Wie oben bereits erwähnt, ist die Struktur dieser Tabelle auf die Protokollierung von Datenfehlern ausgelegt, die nicht Gegenstand dieses Artikels ist. Die Tabelle wird jedoch auch für die Protokollierung von Exceptions verwendet. Die folgende Beschreibung berücksichtigt nur jene Spalten, die für die Protokollierung einer Exception erforderlich sind.

Spalten

SpalteDatentypNull?Beschreibung
[Id]bigint (IDENTITY)NOT NULLPrimärschlüssel des Fehler-Datensatzes.
[ExecutionId]bigintNOT NULLFremdschlüssel auf [LL].[Execution].
[ComponentId]bigintNULLFremdschlüssel auf [LL].[Component] (sofern bekannt).
[TraceId]bigintNULLFremdschlüssel auf [LL].[Trace] (sofern bekannt).
[ErrorType]char(1)NOT NULLArt des Fehlers (Exception vs. Datenfehler).
[Source]nvarchar(5)NOT NULLArt der Quelle (z. B. SSIST-SQL).
[Component]nvarchar(128)NOT NULLKomponente, in der der Fehler aufgetreten ist.
[TaskName]nvarchar(128)NULLTask-Name.
[Entity]nvarchar(128)NULLBetroffene Zielentität.
[Step]nvarchar(max)NULLArbeitsschritt, in dem der Fehler aufgetreten ist.
[Description]nvarchar(max)NULLFehlertext (ERROR_MESSAGE()).
[Number]intNULLFehlernummer (ERROR_NUMBER()).
[Line]intNULLFehlerzeile (ERROR_LINE()).
[State]nvarchar(max)NULLFehler-State (ERROR_STATE()).
[CreatedOn]datetimeNOT NULLAnlage-Zeitpunkt, Default GETUTCDATE().
[CreatedBy]nvarchar(100)NOT NULLAnlegender Login, Default SUSER_SNAME().

Deklaration

  1: -- ----------------------------------------------------------------------------
  2: -- [LL].[Error] — Logging-Tabelle fuer Exceptions und Datenfehler.
  3: -- Im Kontext dieses Artikels nutzen wir nur die Exception-Spalten;
  4: -- die Datenfehler-Spalten (ID1Value/ID2Value/ID3Value/ErrorValue,
  5: -- ID*ColumnName, FileName, FileId) sind fuer einen Folge-Artikel relevant.
  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

Datenmodell

Datenmodell des LL-Schemas: [LL].[Execution], [LL].[Component] und [LL].[Trace] als 1:n-Kette von oben nach unten; [LL].[Error] mit Fremdschlüsseln auf alle drei Tabellen.

Status der Ausführung des ETL-Prozesses

Alle Tabellen für die Prozessprotokollierung verfügen über zwei Spalten [State] und [Success], in denen der aktuelle Status des ETL-Prozesses, der Ausführung einer Komponente oder einer konkreten Aktion – zum Beispiel ein INSERT, UPDATE oder DELETE – gespeichert wird. Der aktuelle Status wird in der Spalte [State] mit den Texten processingwarningsuccess und error festgehalten. Der Erfolg wird in der Spalte [Success] mit 1 gespeichert. Erst durch die Kombination beider Status-Werte lässt sich der aktuelle Status zuverlässig ermitteln. Folgende Kombinationen sind zulässig:

[State][Success]Bedeutung
processing0Aktion, Komponente oder Lauf wurde gestartet und läuft noch.
warning0Beendet, aber mit Warnung — nicht als Erfolg gewertet.
warning1Beendet mit Warnung, dennoch als Erfolg gewertet.
success1Erfolgreich abgeschlossen.
error0Mit Fehler abgebrochen.
Zulässige Kombinationen der Spalten [State] und [Success]

Andere Kombinationen von Statuswerten sind nicht zulässig. Die Prozeduren, die für die Prozessprotokollierung verwendet werden, lösen im Falle einer ungültigen übergebenen Kombination eine Exception aus.

Prozeduren für die Protokollierung

Für das Einfügen und Aktualisieren von Protokolldatensätzen in die oben genannten Tabellen stehen (unter anderem) die folgenden Prozeduren zur Verfügung:

ProzedurSchemaZweck
spInsertExecutionLLÖffnet das Execution-Log (oberste Ebene) zu Beginn des Laufs.
spUpdateExecutionLLSchließt das Execution-Log mit Status success oder error.
spInsertComponentLLÖffnet ein Component-Log für eine Komponente.
spUpdateComponentSuccessLLSchließt ein Component-Log erfolgreich ab.
spUpdateComponentErrorLLSchließt ein Component-Log im Fehlerfall ab.
spInsertTraceLLSchreibt einen Trace-Datensatz für eine einzelne Aktion.
spUpdateTraceLLAktualisiert einen Trace-Datensatz (allgemein).
spUpdateTraceSuccessLLAktualisiert einen Trace-Datensatz auf success / 1.
spUpdateTraceErrorLLAktualisiert einen Trace-Datensatz auf error / 0.
spInsertErrorExceptionLLSchreibt eine abgefangene Exception nach [LL].[Error].
Prozeduren für die Prozessprotokollierung

Im Wesentlichen führen diese Prozeduren ein INSERT oder UPDATE auf den Protokolltabellen aus. Die zu protokollierenden Werte werden als Parameter an die Prozeduren übergeben. Die Prozeduren prüfen die übergebenen Parameter und lösen im Fall ungültiger Parameter eine Exception aus. Für die Parameter-Prüfung und das einheitliche Auslösen von Fehlern verwenden sie die beiden Helfer [dbo].[spRaiseError] und [dbo].[fnIsNullOrEmpty].

Die folgenden Code-Beispiele zeigen die Prozeduren [LL].[spInsertTrace][LL].[spUpdateTrace] und [LL].[spUpdateTraceSuccess]. Ergänzend zeigt [LL].[spInsertExecution] stellvertretend, dass alle übrigen Prozeduren nach demselben Muster aufgebaut sind: Parameter prüfen, INSERT bzw. UPDATE ausführen, die erzeugte Id zurückgeben.

[LL].[spInsertTrace]

  1: -- ----------------------------------------------------------------------------
  2: -- [LL].[spInsertTrace] — fuegt einen Trace-Datensatz in [LL].[Trace] ein
  3: -- und liefert die generierte Id ueber @p_traceId zurueck.
  4: -- ----------------------------------------------------------------------------
  5: -- Parameter:
  6: --    @p_executionId    int           Execution-Id des laufenden ETL-Laufs
  7: --    @p_componentId    int           Component-Id des aufrufenden Komponenten-Logs
  8: --    @p_traceId        int OUTPUT    Id des neu eingefuegten Trace-Datensatzes
  9: --    @p_source          nvarchar(5)   Source-System (SSIS, T-SQL, ...)
 10: --    @p_component       nvarchar(128) Name der aufrufenden Komponente
 11: --    @p_task            nvarchar(128) Task-Name (z. B. SSIS-Task), optional
 12: --    @p_entity          nvarchar(128) Ziel-Entitaet, optional
 13: --    @p_step            nvarchar(max) Beschreibung des Arbeitsschritts
 14: --    @p_description     nvarchar(max) Zusatz-Beschreibung, optional
 15: --    @p_fileId         bigint        Verweis auf [LL].[FileList].[Id], optional
 16: --    @p_action          nvarchar(100) Action-Label (Insert/Update/Delete/...)
 17: --    @p_affectedRows   int           Anzahl bearbeiteter Datensaetze
 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-Pruefung
 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:         -- Zulaessige State/Success-Kombination pruefen
 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:         -- Trace-Datensatz schreiben
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
144: 
145: -- Beispiel-Aufruf
146: -- DECLARE @executionId  AS int = 1;
147: -- DECLARE @componentId  AS int = 1;
148: -- DECLARE @traceId      AS int;
149: -- EXEC [LL].[spInsertTrace]
150: --      @p_executionId   = @executionId
151: --     ,@p_componentId   = @componentId
152: --     ,@p_traceId       = @traceId OUTPUT
153: --     ,@p_source        = N'T-SQL'
154: --     ,@p_component     = N'test script'
155: --     ,@p_entity        = N'[LL].[spInsertTrace]'
156: --     ,@p_step          = N'[LL].[spInsertTrace] — Test'
157: --     ,@p_action        = N'Insert'
158: --     ,@p_affectedRows  = 55
159: --     ,@p_state         = N'processing'
160: --     ,@p_success       = 0;
161: -- SELECT * FROM [LL].[Trace] WHERE [Id] = @traceId;

[LL].[spUpdateTrace]

  1: -- ----------------------------------------------------------------------------
  2: -- [LL].[spUpdateTrace] — aktualisiert einen bestehenden Trace-Datensatz
  3: -- mit Description, Action, AffectedRows, State und Success.
  4: -- ----------------------------------------------------------------------------
  5: -- Parameter:
  6: --    @p_traceId        int           Id des zu aktualisierenden Trace-Datensatzes
  7: --    @p_description     nvarchar(max) Beschreibung des Ergebnisses
  8: --    @p_action          nvarchar(100) Action-Label, optional
  9: --    @p_affectedRows   int           Anzahl bearbeiteter Datensaetze
 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-Pruefung
 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:         -- Zulaessige State/Success-Kombination pruefen
 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:         -- Existenz des Trace-Datensatzes pruefen
 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:         -- Trace-Datensatz aktualisieren
 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 um spUpdateTrace fuer
  3: -- den haeufigen Fall "Aktion erfolgreich beendet" (State = 'success',
  4: -- Success = 1). Erspart das Setzen der beiden Felder bei jedem Aufruf.
  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]

Die folgende Prozedur ist nicht im ursprünglichen Beispiel ausführlich gezeigt worden, steht hier aber stellvertretend für alle übrigen Logging-Prozeduren: Wer ihren Aufbau verstanden hat, kann spInsertComponentspUpdateComponent*spUpdateTraceError und spInsertErrorException analog ableiten — der einzige Unterschied liegt in der Spalten-Belegung.

  1: -- ----------------------------------------------------------------------------
  2: -- [LL].[spInsertExecution] — Pattern-Beweis fuer die "uebrigen Procedures".
  3: --
  4: -- Strukturell identisch zu [LL].[spInsertTrace]: Parameter-Pruefung -> INSERT
  5: -- -> Id-Rueckgabe per OUTPUT-Variable. Wer den Pattern verstanden hat, kann
  6: -- spInsertComponent, spUpdateComponent*, spUpdateTraceError,
  7: -- spInsertErrorException, spUpdateExecution analog ableiten — die
  8: -- Spalten-Belegung ist die einzige Variante.
  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

Um sicherzustellen, dass ein ETL-Prozess geordnet beendet und nicht ohne entsprechende Protokollierung hart abgebrochen wird, ist ein explizites Exception-Handling erforderlich. Geordnet bedeutet in diesem Fall, dass der Prozess eine ausgelöste Exception abfängt, ein UPDATE auf den jeweiligen Protokolldatensatz in den Tabellen [LL].[Execution][LL].[Component] und [LL].[Trace] – sofern jeweils anwendbar – mit [State] = error und [Success] = 0 durchführt und die Exception in der Tabelle [LL].[Error] protokolliert. Das folgende Diagramm zeigt die grundlegende Systematik des Exception-Handlings:

Flussdiagramm des Exception-Handlings: Start, Insert-Log mit State processing, Workload, Verzweigung bei Exception — Erfolgspfad aktualisiert auf success, Fehlerpfad schreibt nach [LL].[Error], setzt State error und reicht die Exception optional per THROW weiter.
Exception-Handling

Erst nach erfolgter Protokollierung kann der Prozess die Exception an den Aufrufer weiterreichen, so dass der aufrufende Prozess hart abgebrochen würde. Eine Weitergabe der Exception an den Aufrufer ist jedoch nicht erforderlich, wenn der Fehler protokolliert und die relevanten Protokolldatensätze mit [State] = error und [Success] = 0 aktualisiert wurden.

Das Exception-Handling ist mindestens auf der obersten Ebene der Ausführung eines ETL-Prozesses, der in der Tabelle [LL].[Execution] protokolliert wird, erforderlich.

Das nachfolgende Code-Beispiel zeigt ein Exception-Handling inklusive der Protokollierung in den Tabellen [LL].[Execution] und [LL].[Error] entsprechend des obigen Diagramms:

  1: -- ----------------------------------------------------------------------------
  2: -- Exception-Handling-Skelett: zeigt das vollstaendige Pattern aus
  3: -- TRY/CATCH + Insert-Error + Update-Execution + THROW. Die Reihenfolge im
  4: -- CATCH-Block ist entscheidend — erst protokollieren, dann THROW.
  5: -- ----------------------------------------------------------------------------
  6: -- Execution-Logging-Variablen
  7: DECLARE @executionId    AS int;
  8: DECLARE @processName    AS nvarchar(max);
  9: DECLARE @version         AS int;
 10: 
 11: -- Error-Logging-Variablen
 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-Variablen (lowercase per Konvention)
 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:     -- Initialisierung der Execution-Logging-Variablen
 30:     SET @processName = N'Name of ETL-Process';
 31:     SET @version      = 123;
 32: 
 33:     -- Initialisierung der Error-Logging-Variablen
 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 (hier passiert die eigentliche ETL-Arbeit)
 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;

Beispiel für die Protokollierung und das Exception-Handling in einem ETL-Prozess

Nach diesen Erläuterungen zu den Grundzügen des Exception-Handlings zeigt das folgende Diagramm das Exception-Handling eines einfachen, kompakten, aber vollständigen ETL-Prozesses:

Diagramm des Exception-Handlings im Beispiel-ETL-Prozess: die Einstiegsprozedur ruft mehrere Worker-Prozeduren auf; im DELETE-Schritt der tiefsten Prozedur tritt eine Exception auf, die nach oben durchgereicht und auf jeder Ebene protokolliert wird.
Beispiel für das Exception-Handling und die Protokollierung eines Beispiel-ETL-Prozesses

Dieses Beispiel zeigt die Protokollierung eines ETL-Prozesses, der ausschließlich über gespeicherte Prozeduren entwickelt wurde und aus fünf gespeicherten Prozeduren besteht. Die Einstiegsprozedur [T2].[spETLProcess] ruft die beiden Prozeduren [T2].[spDoSomething_1] und [T2].[spDoSomething_2] auf. Die erste simuliert und protokolliert jeweils ein INSERT-, UPDATE- und DELETE-Statement, während die zweite Prozedur zwei weitere Prozeduren [T2].[spDoSomething_2_1] und [T2].[spDoSomething_2_2] ausführt. Auch diese Prozeduren simulieren und protokollieren jeweils ein INSERT-, UPDATE- und DELETE-Statement. Während der Ausführung des DELETE-Statements in der Prozedur [T2].[spDoSomething_2_2] wird eine Exception ausgelöst, die zu einer geordneten Beendigung des ETL-Prozesses führt.

Aufruf-Hierarchie des Beispiel-ETL-Prozesses: spETLProcess ruft spDoSomething_1 und spDoSomething_2 auf; spDoSomething_2 ruft spDoSomething_2_1 und spDoSomething_2_2 auf; jede Worker-Prozedur führt INSERT, UPDATE und DELETE aus, der fehlerhafte DELETE-Schritt ist hervorgehoben.
Prozedur-Aufrufe des Beispiel-ETL-Prozesses

Da die Abbildung aller Prozeduren zu Wiederholungen führen würde, werden hier nur die Einstiegsprozedur [T2].[spETLProcess] und die Prozedur [T2].[spDoSomething_2_2] abgebildet.

[T2].[spETLProcess]

  1: -- ----------------------------------------------------------------------------
  2: -- [T2].[spETLProcess] — Beispiel-Einstiegs-Procedure des ETL-Prozesses.
  3: -- Ruft zwei Worker-Procedures spDoSomething_1 und spDoSomething_2 auf
  4: -- und protokolliert beide Aufrufe in [LL].[Trace].
  5: -- ----------------------------------------------------------------------------
  6: CREATE OR ALTER PROCEDURE [T2].[spETLProcess]
  7: AS
  8: BEGIN
  9:     SET NOCOUNT ON;
 10: 
 11:     -- Error-Variablen
 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-Variablen
 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:         -- Execution-Log oeffnen
 45:         EXEC [LL].[spInsertExecution] @executionId OUTPUT, N'ETL process', 123;
 46: 
 47:         -- Component-Log oeffnen
 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:         -- Aufruf [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:         -- Aufruf [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:         -- Component-Log schliessen
 90:         EXEC [LL].[spUpdateComponentSuccess] @componentId, @description;
 91: 
 92:         -- Execution-Log schliessen
 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] — Tiefste Worker-Procedure im Beispiel-Baum.
  3: -- Wird von [T2].[spDoSomething_2] aufgerufen (siehe Diagramm 041007.png).
  4: -- Simuliert ein INSERT, ein UPDATE und ein DELETE — beim DELETE wird eine
  5: -- Exception ausgeloest, um das Exception-Handling-Pattern vorzufuehren.
  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-Variablen
 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-Variablen
 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:         -- Component-Log oeffnen
 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 (erfolgreich)
 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:         -- Hier wuerde ein INSERT-Statement stehen
 75: 
 76:         EXEC [LL].[spUpdateTraceSuccess] @traceId, @description, @action, @@ROWCOUNT;
 77: 
 78:         -- ----------------------------------------------------------------
 79:         -- UPDATE (erfolgreich)
 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:         -- Hier wuerde ein UPDATE-Statement stehen
 93: 
 94:         EXEC [LL].[spUpdateTraceSuccess] @traceId, @description, @action, @@ROWCOUNT;
 95: 
 96:         -- ----------------------------------------------------------------
 97:         -- DELETE (loest absichtlich eine Exception aus)
 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:         -- Hier wuerde ein DELETE-Statement stehen — kuenstlich ausgeloeste Exception:
111:         RAISERROR(N'Exception in [T2].[spDoSomething_2_2]', 15, 1);
112: 
113:         EXEC [LL].[spUpdateTraceSuccess] @traceId, @description, @action, @@ROWCOUNT;
114: 
115:         -- Component-Log schliessen
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

Das folgende Skript enthält die Anweisung für die Ausführung des ETL-Prozesses. Um ein kompaktes Prozessprotokoll zu erhalten, werden vorher die Protokolltabellen geleert. Die abschließenden SELECT-Statements produzieren das eingangs gezeigte Ergebnis.

  1: -- ----------------------------------------------------------------------------
  2: -- Beispiel-Lauf: ETL-Prozess ausfuehren und das Protokoll auswerten.
  3: --
  4: -- Block 1 raeumt die Protokoll-Tabellen leer (TRUNCATE / DELETE + RESEED),
  5: -- Block 2 startet den Beispiel-ETL-Prozess, Block 3 zeigt das Ergebnis.
  6: -- Die SELECT-Statements liefern exakt die drei Result-Sets, die zu Beginn
  7: -- des Artikels (Tabellen 041001, 041002, 041003) gezeigt werden.
  8: -- ----------------------------------------------------------------------------
  9: 
 10: -- 01: Protokoll-Tabellen leeren
 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: ETL-Prozess starten
 19: EXEC [T2].[spETLProcess];
 20: 
 21: -- 03: Protokoll auswerten
 22: SELECT * FROM [LL].[Execution];
 23: SELECT * FROM [LL].[Component];
 24: SELECT * FROM [LL].[Trace];

Fazit

ETL-Prozesse sind daten­getriebene Prozesse. Werden Daten geliefert, die nicht erwartet werden, dann ist die Wahrscheinlichkeit hoch, dass in das Zielsystem entweder nicht alle Daten oder sogar falsche Daten geschrieben werden. Was in diesem Artikel nur beiläufig erwähnt wird: Auf der untersten Ebene der Protokollierung wird auch die Anzahl der betroffenen Datensätze protokolliert bzw. kann protokolliert werden. Die Kenntnis der Anzahl der erwarteten und tatsächlich verarbeiteten Datensätze ist ein gutes Indiz für den Erfolg oder Nicht-Erfolg eines ETL-Prozesses.

Damit unterstützt diese Vorgehensweise die Entwicklung robuster ETL-Prozesse, die auch eine Beurteilung der Datenqualität sicherstellt.

Was in der Software-Entwicklung ein Muss ist, wird bei der Entwicklung von ETL-Prozessen gerne vernachlässigt: ein explizites Exception-Handling. Das vorgestellte Exception-Handling stellt zunächst sicher, dass ein Prozess im Fehlerfall geordnet beendet wird. Wann aber liegt ein Fehler vor? Und muss ein Fehler tatsächlich immer zum Abbruch des Prozesses führen? In Verbindung mit der Kenntnis über die erwartete und tatsächlich verarbeitete Anzahl Datensätze kann eine echte Behandlung von Fehlern implementiert werden.

Die hier vorgestellte Vorgehensweise ist quasi eine Einladung, sich mehr mit den Daten und dem erwarteten Ergebnis zu befassen. Das Protokoll und insbesondere die Kenntnis über die verarbeiteten Datensätze unterstützen schon während der Entwicklung des ETL-Prozesses den Entwickler dabei, die Richtigkeit der Entwicklung beurteilen zu können.

Die vorgestellten Prozeduren stellen lediglich einen Werkzeugkasten für die Protokollierung bereit. Bei richtiger Anwendung produzieren sie ein les- und auswertbares Protokoll, das die Beurteilung der Korrektheit der Ausführung des ETL-Prozesses und der verarbeiteten Daten ermöglicht.

FAQ

Was ist der Unterschied zwischen [LL].[Component] und [LL].[Trace]?

Beide protokollieren Schritte eines Laufs, aber auf unterschiedlichen Granularitätsebenen. [LL].[Component] hält genau einen Datensatz pro aufgerufener Komponente (gespeicherte Prozedur, SSIS-Paket, Talend-Job) — also „welcher Baustein lief wann und mit welchem Status?“. [LL].[Trace] geht eine Ebene tiefer und protokolliert die einzelnen Aktionen innerhalb einer Komponente (typischerweise jedes INSERT, UPDATE und DELETE) samt der Anzahl betroffener Datensätze. Eine Komponente hat also in der Regel mehrere Trace-Einträge.

Warum ein eigenes Schema [LL], statt die Logging-Tabellen ins Standard-Schema zu legen?

Das Schema LL („Logging Layer“) trennt die Protokoll-Infrastruktur sauber von den fachlichen Daten. Das hat praktische Vorteile: Berechtigungen lassen sich gezielt vergeben (etwa nur Schreibrecht auf LL für die ETL-Prozeduren), Aufbewahrung und Backup der Protokolle können getrennt gesteuert werden, und in Skripten ist sofort erkennbar, dass ein Objekt zur Protokollierung gehört. Außerdem kollidieren die Logging-Tabellen so nicht mit gleichnamigen fachlichen Tabellen.

Lässt sich das Pattern auch mit Postgres statt SQL Server umsetzen?

Ja — das Pattern ist tool-neutral. Die Logging-Tabellen und der dreistufige Aufbau bleiben identisch; nur einige T-SQL-Spezifika werden ersetzt. Statt THROW reicht man die Exception in PL/pgSQL mit RAISE weiter, TRY/CATCH wird zum BEGIN … EXCEPTION WHEN OTHERS THEN … END-Block, und @@ROWCOUNT entspricht GET DIAGNOSTICS <var> = ROW_COUNT. Wer die Ausführungszeit einzelner Statements ohne eigene Trace-Tabelle messen möchte, kann ergänzend pg_stat_statements heranziehen.

Wie unterscheidet sich dieses Pattern von SQL Server Audit oder pgAudit?

SQL Server Audit und pgAudit sind datenbankseitige Auditing-Mechanismen: Sie protokollieren technische Ereignisse (Logins, DDL, Datenzugriffe) auf Server-Ebene, weitgehend unabhängig vom Anwendungs-Code. Das hier vorgestellte Pattern ist dagegen ein Anwendungs-Logging — es protokolliert die fachliche Sicht des ETL-Prozesses: welcher Lauf, welche Komponente, welche Aktion, wie viele Datensätze, Erfolg oder Fehler. Beides ergänzt sich; für die Frage „hat der ETL-Lauf fachlich das Richtige getan?“ ist das Anwendungs-Logging das passende Werkzeug.

Wie binde ich ein SSIS-Paket in das Pattern ein?

Ein SSIS-Paket wird wie jede andere Komponente behandelt: Zu Beginn ruft es [LL].[spInsertComponent] auf (zum Beispiel aus einem Execute-SQL-Task oder einem Script-Task), führt seine Aufgaben aus und schließt mit [LL].[spUpdateComponentSuccess] bzw. im Fehlerfall mit [LL].[spUpdateComponentError] ab. Die zurückgegebene ComponentId wird über eine SSIS-Variable durchgereicht, damit nachgelagerte Trace-Aufrufe sie referenzieren können. So erscheint das Paket nahtlos neben den T-SQL-Komponenten im selben Protokoll.

Verwandte Artikel

Dieser Artikel ist Teil des ETL-Design-Pattern-Clusters: