fn_dblog() – DML-Geheimnisse des Transaktionsprotokolls entschlüsseln

Die – nicht dokumentierte und nicht von Microsoft unterstützte – Funktion sys.fn_dblog() zeigt Inhalte des “aktiven” Transaktionsprotokolls einer Datenbank und ist eine wahre Schatztruhe, wenn man die “Geheimnisse” dieser Funktion entschlüsselt. Dieser Artikel beschreibt detailliert die Informationen, die beim Absetzen von DML (Data Manipulation Language) im Transaktionsprotokoll gespeichert werden und wie man sie “sichtbar” machen kann. Alle Beispiele wurden mit Microsoft SQL Server 2012 durchgeführt.

 Funktionalität von fn_dblog()

fn_dblog() ist eine von Microsoft nicht offiziell dokumentierte und freigegebene Funktion; auch die “interne” Beschreibung dieser Funktion ist nicht gerade sehr aussagekräftig:

EXEC sp_helptext 'fn_dblog'

Die Funktion erwartet zwei mögliche Variablen, die eine LSN (Log Sequence Number) als numerischen Wert repräsentieren. Für die nachfolgenden Beispiele werde ich aber benannte Transaktionen verwenden, um die Beispiele “reproduzierbar” zu machen. Ein anderer wichtiger Hinweis, bevor es losgeht; es werden nicht alle Attribute der Funktion beschrieben. Sofern die Attribute eine besondere Bedeutung haben oder ein wesentlicher Bestandteil der Lösung sind, werden sie im Detail beschrieben. Da Microsoft selbst diese Funktion nicht dokumentiert hat, würde das auch bei einigen der insgesamt 129 Attribute (SQL Server 2012) eher einer “Ratestunde” gleichen als fundiertem Wissen. Gleichwohl gilt der gute Rat, die Funktion nicht in einem Produktivsystem einzusetzen, da diese Funktion nicht von Microsoft unterstützt wird.

Testumgebung

Um DML-Transaktionen zu untersuchen, wird eine Relation mit einer einfachen Struktur erstellt, die Attribute der unterschiedlichsten Datentypen beinhaltet. Bezüglich der Datentypen sei angemerkt, dass ich auf komplexere Datentypen zu Gunsten der Vereinfachung verzichtet habe. Bei allen angegebenen Datentypen handelt es sich um Datentypen fester Länge.

IF OBJECT_ID('dbo.dblog_demo', 'U') IS NOT NULL
    DROP TABLE dbo.dblog_demo;
    GO

CREATE TABLE dbo.dblog_demo
(
    Id
    int         NOT NULL  IDENTITY (1, 1),
    col1 
char(20)    NOT NULL,
    col2  nchar(20)   NOT NULL,
    col3 
smallmoney  NOT NULL  DEFAULT (0),
    col4
  datetime    NOT NULL  DEFAULT (getdate()),

    CONSTRAINT pk_dblog_demo_Id PRIMARY KEY CLUSTERED (Id)
);

GO

Transaktion: INSERT

Zunächst wird ein Datensatz in die Relation eingetragen. Um die Transaktion später besser im Transaktionsprotokoll zu finden, wird eine benannte Transaktion für den Vorgang verwendet. Um die Datenseite schneller zu lokalisieren, in der die Daten gespeichert werden, wird mit Hilfe der Funktion sys.fn_PhysLocFormatter die Dateinummer, Datenseite und Slot ausgegeben.

BEGIN TRANSACTION InsertRecord
   
INSERT INTO dbo.dblog_demo
    (col1, col2, col3, col4)
    VALUES
    ('Uwe Ricken', 'Beate Ricken', 21.45, '19920322')
COMMIT TRANSACTION InsertRecord
GO

SELECT sys.fn_PhysLocFormatter(%%physloc%%) AS Location, * FROM dbo.dblog_demo;
GO

Nachdem der Datensatz eingetragen wurde, gilt es, die Aufzeichnungen aus dem Transaktionsprotokoll zu untersuchen. Die ersten wichtigen Informationen für die Analyse können mit dem nachfolgenden SQL-Befehl abgerufen werden:

SELECT Operation,
       Context,
       AllocUnitName,
       [Page ID],
       [Slot ID],
       SPID,
       COALESCE([Begin Time], [End Time]) AS [Time],
       [Transaction SID]
FROM   sys.fn_dblog(NULL, NULL)
WHERE  [Transaction ID] IN
(
    SELECT [Transaction ID] FROM sys.fn_dblog(NULL, NULL)
    WHERE  [Transaction Name] = 'InsertRecord'
);

Die obige Abbildung zeigt den Abschnitt des Transaktionsprotokolls, der für die INSERT-Operation aufgezeichnet wurde. Wichtig ist für JEDE Transaktion, dass sie mit einem LOP_BEGIN_XACT eingeleitet wird. Weiterhin ist zwingend, dass JEDE Transaktion entweder mit einem LOP_COMMIT_XACT oder einem LOP_ABORT_XACT beendet wird (LOP = Log OPeration). Alle physikalischen Operationen, die innerhalb dieser beiden Zeilen beschrieben werden, wurden sequentiell durchgeführt!

Der [Context] beschreibt, welche Ressource von Microsoft SQL Server für die Operation verwendet wird. Aus der obigen Abbildung ist erkennbar das es sich beim Log ConteXt um den Clustered Index handelt (LCX_CLUSTERED). Der Clustered Index ist bekanntlich die Relation selbst!

Sobald eine Ressource von Microsoft SQL Server verwendet wird, kann diese Ressource den meisten Fällen über [AllocUnitName] auch in Klartext ausgelesen werden. Da die Transaktion eine Modifikation in/an der Relation [dbo].[dblog_demo] durchführt, wird als AllocUnitName der Eintrag “dbo.dblog_demo.pk_dblog_demo_Id” angegeben; das entspricht (siehe Definition der Relation) dem Clustered Index. Neben der Relation als Ressource kann – wie im aktuellen Beispiel – so granular unterschieden werden, dass auch die Datenseite angegeben wird, die von der Modifikation betroffen ist. Diese Daten werden hexadezimal angegeben und. Die [Page ID] für die durchgeführte Transaktion ist “0001:00003027”. Schaut man sich den physikalischen Ort für die Speicherung der Daten (siehe SELECT-Statement nach der Transaktion) an, ist zu erkennen, dass der Datensatz in Datei: 1 auf Seite: 12327 in Slot: 0 gespeichert wurde (0x3027 = 12327).

Ebenfalls interessant ist neben der Information über den Beginn und das Ende der Transaktion, wer in der Session die Transaktion ausgeführt hat. Bezugnehmend auf das obige Beispiel war es der Datenbankbenutzer mit dem Login [Transaction SID] in [SPID] 52. Im Attribut [Transaction SID] wird die [principal_id] des zugehörigen Logins gespeichert und kann mit SUSER_SNAME(SId) in Klartext ausgegeben werden.

Ein weitere Möglichkeit besteht darin, die in der Transaktion geschriebenen / gelöschten Daten in Klartext aus dem Transaktionsprotokoll auszulesen. Hier spielen interne Strukturen eines Datensatzes eine entscheidende Rolle, um Inhalt einer Zeile aus dem Transaktionsprotokoll auszulesen. Die Informationen über die Daten, die durch die eine Transaktion manipuliert werden, befinden sich in den Attributen [RowLog Contents 0] bis [RowLog Contents 5]. Bei den Attributen handelt es sich um varbinary(max) Datentypen. Die nachfolgende Abfrage zeigt für die zuvor erstellte Transaktion die Inhalte von [RowLog Contents 0] und [RowLog Contents 1].

SELECT Operation,
       Context,
       [Page ID],
       [Slot ID],
       [RowLog Contents 0],
       [RowLog Contents 1]
FROM   sys.fn_dblog(NULL, NULL)
WHERE  [Transaction ID] IN
(
    SELECT [Transaction ID] FROM sys.fn_dblog(NULL, NULL)
    WHERE  [Transaction Name] = 'InsertRecord'
);

Das Ergebnis wird wie folgt interpretiert: Innerhalb der Transaktion “InsertRecord” wurde ein Datensatz in Datei 1 auf Datenseite 0x3027 = 12327 in Slot 0 eingetragen. Die vollständige Datenstruktur steht als Binärwert im Attribut [RowLog Contents 0] zur Verfügung. Da es sich um eine INSERT-Operation handelt, sind alle weiteren [RowLog Contents x]-Attribute leer (0x). Sehr wichtig in diesem Zusammenhang ist das Verständnis, dass bei einer INSERT-Operation NICHT nur die Daten der Attribute selbst, sondern immer die vollständige Struktur des Datensatzes geschrieben wird! Um diesen Teil des Transaktionslogs zu entschlüsseln, ist es zwingend erforderlich, sich mit den Strukturen zu beschäftigen, die Microsoft SQL Server verwendet, um einen Datensatz zu speichern.

Interne Struktur eines Datensatzes in Microsoft SQL Server

Jeder Datensatz folgt – intern – einer fest vorgegebenen Struktur:

Record Header (4 Bytes) Byte 1 und 2 definieren den Typen des Datensatzes Byte 3 und 4 definieren das Offset zum NULL-Bitmap
Attribute mit fester Länge int, bigint, char, nchar, datetime,…
Anzahl der Attribute in der Relation 2 Bytes
NULL-Bitmap n Byte
Anzahl der Attribute, die variable Größen besitzen 2 Bytes
Offset der Attribute mit variablen Datengrößen n Bytes
Daten der Attribute mit variablen Datengrößen n Bytes

Das alles hört sich sehr kompliziert an, ist aber in Verbindung mit einem Beispiel nicht mehr ganz so schwer. Zunächst wird noch einmal die Datenstruktur der Relation selbst unter Berücksichtigung der internen Offsets für jedes Attribut unter die Lupe genommen.

SELECT  c.column_id,
        c.name,
        t.name        AS    data_type,
        c.max_length,
        c.precision,
        c.scale,
        c.is_nullable,
        pc.leaf_offset
FROM    sys.system_internals_partition_columns pc INNER JOIN sys.partitions p
        ON (pc.partition_id = p.partition_id) INNER JOIN sys.columns
c
        ON (
             p.object_id = c.object_id AND
             c.column_id = pc.partition_column_id
           )
INNER JOIN sys.types t
        ON (c.system_type_id = t.system_type_id)
WHERE  p.object_id = OBJECT_ID('dbo.dblog_demo')
ORDER BY
       c.column_id ASC;

Die Abbildung zeigt die Struktur der Relation [dbo].[dblog_demo]. Insgesamt hat jeder Datensatz eine feste Länge von 76 Bytes. Gleichwohl zeigt die Abfrage im Attribut [leaf_offset], an welcher Position (0-basierend) in der physikalischen Struktur des Datensatzes die Daten gespeichert sind. Diese Informationen sind wichtig für die Analyse des Binärwertes aus dem Transaktionsprotokoll! Der Binärwert aus [RowLog Contents 0] lautet (bereits in Bytes aufteilte) wie folgt:

0x10 00 50 00 01 00 00 00 55 77 65 20 52 69 63 6B 65 6E 20 20 20 20 20 20 20 20 20 20 42 00 65 00 61 00 74 00 65 00 20 00 52 00 69 00 63 00 6B 00 65 00 6E 00 20 00 20 00 20 00 20 00 20 00 20 00 20 00 20 00 E4 45 03 00 00 00 00 00 93 83 00 00 05 00 00

Diese Daten gilt es nun - den internen Strukturen eines Datensatzes folgend – aufzuteilen.

Byte 1 (0x10) beschreibt die Art des Datensatze. Das erste Byte hat Hexadezimalwert von 10 und entspricht dem Dezimalwert 16. Der Dezimalwert 16 wird als Binärwert dargestellt, um die einzelnen Bits zu analysieren. Bei der Zählung der Bits wird mit 0 begonnen.

7

6

5

4

3

2

1

0

128

64

32

16

8

4

2

1

       

4

2

1

 

0

0

0

1

0

0

0

0

Die einzelnen Bits des ersten Bytes im RowHeader haben folgende Bedeutung(en):

Bit 0: Information über die Versionierung. Ist ab Microsoft SQL Server 2008 immer 0
Bit 1:
Bit 2:
Bit 3:
0: PRIMARY RECORD
1: FORWARDED RECORD
2: FORWARDING STUB
3: INDEX RECORD
4: BLOB FRAGMENT oder ROW OVERFLOW DATA
5: GHOST INDEX RECORD
6: GHOST DATA RECORD
7: GHOST VERSION RECORD
Bit 4: Hinweis auf ein existierendes NULL-Bitmap (Ist seit Microsoft SQL Server 2008 immer vorhanden)
Bit 5: Hinweis auf existierende Attribute mit variabler Datenläge (z. B. varchar, nvarchar, …)
Bit 6: Hinweis auf existierende Werte für “Row Versioning”
Bit 7: wird nicht verwendet

Den vorgegebenen Strukturen des ersten Bytes folgend kann für “unseren” Datensatz folgende Aussage getroffen werden:

Es handelt sich um einen PRIMARY RECORD (Bits 1 – 3 sind 0) und es gibt ein NULL-Bitmap im Datensatz. Das NULL-Bitmap ist mindestens ein Byte groß und pro Attribut eines Datensatzes wird jeweils ein Bit mit 0 oder 1 besetzt. 0 entspricht einer NOT NULL Einschränkung und der Wert 1 repräsentiert ein Attribut, in dem NULL-Werte erlaubt sind. Im zweiten Byte (0x00) des RowHeaders wird ausschließlich ein Bit verwendet, das darauf hinweist, ob es sich bei dem Datensatz um einen “GHOST FORWARD RECORD” handelt; die anderen Bits werden nicht verwendet!

Byte 3 und Byte 4 (0x50 00) geben die Position in der Datenstruktur an, in der die Informationen zur Anzahl der Attribute für die Relation gespeichert werden. Der Hexadezimalwert 0x50 00 entspricht dem Dezimalwert 80. Das 80. und 81. Byte gibt Aufschluss darüber, wie viele Attribute der Datensatz besitzt. Von diesen 80 Bytes müssen 4 Bytes für den RowHeader abgezogen werden und es verbleiben exakt 76 Bytes. Vergleicht man diesen Wert mit der Satzlänge (siehe oben), geht die Rechnung wunderbar auf. Die Daten der Bytes 4 – 79 werden nun gemäß der Größendefinition jedes einzelnen Attributs in eine Tabelle übertragen

Attribut Länge Bytes
Id 4 0x01 00 00 00
col1 20 0x55 77 65 20 52 69 63 6B 65 6E 20 20 20 20 20 20 20 20 20 20
col2 40 0x42 00 65 00 61 00 74 00 65 00 20 00 52 00 69 00 63 00 6B 00 65 00 6E 00 20 00 20 00 20 00 20 00 20 00 20 00 20 00 20 00
col3 4

0xE4 45 03 00

col4 8 0x00 00 00 00 93 83 00 00

Die Übersetzung des Wertes für das [ID]-Attribut ist trivial – hierbei handelt es sich um den – dezimal umgewandelten – Wert 1. (Achtung Bytes müssen für numerische von rechts nach links gelesen werden. Big-Endian-Format!). Etwas komplizierter wird es bei col1 und bei col2. Hinter den Werten verbergen sich Zeichenwerte. Für die Konvertierung von Hexadezimalwerte in Zeichenwerte können die einzelnen Hexadezimalwerte den Funktionen CHAR / NCHAR übergeben werden. Bei col1 handelt es sich um den Datentyp char mit einer Länge von 20 – es wird also die Funktion CHAR für die Auswertung verwendet. Damit der Artikel nicht zu lang wird, werden lediglich die ersten 5 Zeichen der 20 Zeichen für [col1] ausgegeben.

SELECT CHAR(0x55) + CHAR(0x77) + CHAR(0x65) + CHAR(0x20) + CHAR(0x52) + '...' AS col1,        NCHAR(0x42) + NCHAR(0x00) + NCHAR(0x65) + NCHAR(0x00) + NCHAR(61) + '...' AS col2;

Bei [col3] handelt es sich um einen smallmoney-Datentypen mit einer Datenlänge von 4 Bytes. Dezimal aufgelöst  ergibt der Hexadezimalwert von [col3] einen Wert von 214500. Die letzten 4 Ziffern des Wertes entfallen auf die Nachkommastellen. Somit wird der Wert 21,45 korrekt abgebildet. Das Attribut [col4] ist vom Datentyp datetime und hat eine Länge von 8 Bytes. 4 Bytes entfallen auf die Speicherung der Uhrzeit (Byte 0 – 3) und 4 Bytes entfallen auf die Speicherung des vergangenen Tage seit dem Startdatum (Byte 4 – 7). Für den Datentypen datetime und smalldatetime beginnt die Zählung der Tage beim 01.01.1900. Dieses Datum entspricht dem Wert 0. Der Hexadezimalwert 0x8393 entspricht einem Dezimalwert von 33683. Addiert man diesen Wert zum 01.01.1900 hinzu, kommt als Ergebnis der 22.03.1992 heraus, wie die nachfolgende Abfrage belegt:

SELECT DATEADD(dd, CAST(0x8393 AS int), '19000101') AS Result;

Nach der Speicherung der Daten mit fester Datenlänge werden die nächsten 2 Bytes (0x05 00)für die Speicherung der Anzahl aller Attribute der Relation verwendet. Der Hexadezimalwert 0x05 entspricht dem Dezimalwert 5. Die Relation besitzt 5 Attribute ([Id], [col1], [col2], [col3], [col4]). Das letzte Byte speichert das NULL-Bitmap, das für das aktuelle Beispiel 0 ist da es keine Attribute gibt, die einen NULL-Wert zulassen die Anzahl der Attribute mit variabler Länge und ist – da die Beispieldaten mit Attributen mit fester Länge arbeiten - 0.

Hinweis:

Einen “Deep Dive” in die Strukturen eines Datensatzes von Microsoft SQL Server gibt Kalen Delany in ihrem Buch “Microsoft SQL Server Internals”. Dort zeigt sie in vielen reproduzierbaren Beispielen Möglichkeiten auf, wie die Strukturen eines Datensatze mit unterschiedlichen Datentypen und Einschränkungen dargestellt werden – sehr lesenswert und ein unabdingbares Muss im Bücherregal eines jeden Microsoft SQL Server Professionals!

Speicherung der Daten in der Datenseite

Zur Rückversicherung wird der Inhalt der Datenseite ausgegeben. Die strukturrelevanten Informationen sind farblich hervorgehoben.

DBCC TRACEON(3604);
DBCC PAGE (2, 1, 12327, 3);

Der [Record Type] wird als “PRIMARY_RECORD” ausgewiesen. Da es keine Attribute mit variablen Datenlängen in der Struktur gibt, wird ausschließlich “NULL_BITMAP” als [Record Attributes] ausgewiesen. Wären weitere Attribute mit variablen Datengrößen vorhanden, würde der Eintrag um “VARIABLE_COLUMNS” erweitert werden. Die [Record Size] des Datensatzes beträgt 83 Bytes.

Die beschreibenden Daten des Datensatzes beginnen unter dem [Memory Dump]. Dabei sind die ersten beiden Bytes der Record Header. Im Anschluss folgt die Information zum Offset der Position, an der sich die Anzahl Attribute für die Datensatzstruktur auslesen lässt. Im Anschluss folgend die eigentlichen Daten, die in den Attributen gespeichert werden. An Offset 79 dokumentieren die nächsten 2 Bytes die Anzahl der Attribute in der Relation und das 2 verbliebenen Bytes sind für die Speicherung des NULL-Bitmaps vorgesehen. Da keine Attribute in der Relation vorhanden sind, die NULL zulassen, ist der Wert für beide Bytes jeweils 0x00

Nach diesem – zugegeben – nicht ganz leichten - Exkurs in die Tiefen des Microsoft SQL Server können basierend auf den obigen Informationen (fast) alle Transaktionsdaten ausgelesen werden, wie gleich bei den weiteren DML-Befehlen erkennbar wird.

Transaktion: UPDATE ein Attribut, identische Datenlänge

Wie oben bereits gezeigt, wird für ein INSERT der einzutragende Datensatz in seiner vollständigen Struktur im Transaktionsprotokoll gespeichert. Bei einem UPDATE müssen nicht nur neue Informationen sondern auch die bereits vorhandenen Informationen im Transaktionsprotokoll im Zugriff sein, um bei einem möglichen ROLLBACK zu gewähren, dass die vor dem – nicht abgeschlossenen – UPDATE im Datensatz vorhandenen Daten zur Verfügung stehen. Hierzu wird erneut eine benannte Transaktion verwendet, um nicht explizit im Transaktionsprotokoll nach Transaktionsnummern zu suchen. Zu beachten ist in diesem Fall, dass der Eintrag aus [col2] durch einen Eintrag identischer Länge ersetzt wird!

BEGIN TRANSACTION UpdateRecord
    UPDATE dbo.dblog_demo
    SET    col2 = 'Susi Sorglos'
    WHERE  Id = 1;
COMMIT TRANSACTION

Die nachfolgende Abfrage zeigt die – für die Erläuterungen – wesentlichen Attribute innerhalb des Transaktionsprotokolls.

SELECT Operation,
       Context,
       AllocUnitName,
       [Slot ID],
       [Offset in Row],
       [Modify Size],
       [RowLog Contents 0],
       [RowLog Contents 1]
FROM   sys.fn_dblog(NULL, NULL)
WHERE  [Transaction ID] IN
(
    SELECT [Transaction ID] FROM sys.fn_dblog(NULL, NULL)
    WHERE  [Transaction Name] = 'UpdateRecord'
)
ORDER BY
    [Previous LSN] ASC;

Anders, als bei einem INSERT muss nicht mehr der komplette Datensatz mit seinen vollständigen Strukturen protokolliert werden. Microsoft SQL Server erkennt basierend auf der Datenstruktur, welches Attribut aktualisiert wird. Sehr interessant ist in diesem Zusammenhang, dass Microsoft SQL Server erkennt, dass nur EIN Attribut einer Aktualisierung unterliegt. Das Offset für den Beginn der Aktualisierung wird in [Offset in Row] gespeichert. Das Datenvolumen, dass der Änderung unterliegt umfasst 24 Bytes. Da es sich um einen Unicode-Datentypen handelt (es werden 2 Bytes pro Charakter gespeichert), muss die Anzahl der “sichtbaren” Zeichen mit 2 multipliziert werden!

4 Bytes für den Header + 4 Bytes für Id + 20 Bytes für [col1] = 28 Bytes. [col2] beginnt bei Offset 28 und diese Information wird im Transaktionsprotokoll festgehalten. Der Inhalt aus [RowLog Contents 0] beinhaltet den Wert aus [col2] vor der Aktualisierung während [RowLog Contents 1] den neuen Wert für [col2] abbildet. Da es sich um den Datentypen NCHAR handelt, müssen jeweils zwei Bytes für die Auflösung eines Zeichens verwendet werden. Die nachfolgende Abfrage zeigt das Ergebnis bis zum jeweils 7. Byte (unter Weglassung der 0-Bytes!).

SELECT  NCHAR(0x42) + NCHAR(0x65) + NCHAR(0x61) + NCHAR(0x74) + NCHAR(0x65) + NCHAR(0x20) + NCHAR(0x52) + '...' AS [RowLog Contents 0],
       
NCHAR(0x53) + NCHAR(0x75) + NCHAR(0x73) + NCHAR(0x69) + NCHAR(0x20) + NCHAR(0x53) + NCHAR(0x6F) + '...' AS [RowLog Contents 1]

Noch wesentlich interessanter ist die Beobachtung des Transaktionslogs, wenn innerhalb eines bestehenden Attributs nur ein Teilbereich ersetzt wird. Die folgende Abfrage ändert nur EIN Zeichen im Wert von [col1] (Aus “Ricken” wird “Recken”).

BEGIN TRANSACTION UpdateRecord
    UPDATE dbo.dblog_demo
    SET    col1 = 'Uwe Recken'
    WHERE  Id = 1;
COMMIT TRANSACTION

 

 

Spätestens jetzt war ich persönlich sehr beeindruckt von der Effizienz der Ressourcennutzung von Microsoft SQL Server. Das System erkennt, dass nicht ein vollständiger Eintrag ersetzt werden muss, sondern die Änderung effektiv nur ein Zeichen betrifft. dieses Zeichen beginnt bei Offset 13 (4 Bytes für Header + 4 Bytes für [Id] + 5 Bytes für den Eintrag “Uwe R” = 13). Ab dieser Position wird EIN Zeichen “i” durch das Zeichen “e” ersetzt.

Transaktion: UPDATE ein Attribut, unterschiedliche Datenlänge

Wie agiert Microsoft SQL Server, wenn ein bestehender Eintrag durch einen gänzlich neuen Wert ersetzt wird, dessen Datenlänge von dem des vorhandenen Eintrags abweicht? Die folgende Abfrage ersetzt den Eintrag “Susi Sorglos” durch einen neuen Eintrag.

BEGIN TRANSACTION UpdateRecord
    UPDATE dbo.dblog_demo
    SET    col2 = 'Marie Schnederpelz'
    WHERE  Id = 1;
COMMIT TRANSACTION

 

 

Der Blick auf das Transaktionsprotokoll zeigt, dass für das Update das Datenvolumen des “längeren” Eintrags als [Modify Size] angegeben wird. Der Name “Susi Sorglos” hat eine Länge von  24 Bytes (12 Zeichen * 2 Bytes) während der Name “Marie Schnederpelz” ein Volumen von 36 Bytes besitzt (18 Zeichen * 2 Bytes). Vergleicht man in diesem Zusammenhang die Hexadezimalwerte, wird schnell klar, was genau passiert:

Susi Sorglos: 0x53 00 75 00 73 00 69 00 20 00 53 00 6F 00 72 00 67 00 6C 00 6F 00 73 00 20 00 20 00 20 00 20 00 20 00 20
Marie Schnederpelz: 0x4D 00 61 00 72 00 69 00 65 00 20 00 53 00 63 00 68 00 6E 00 65 00 64 00 65 00 72 00 70 00 65 00 6C 00 7A

Die obige Gegenüberstellung wird interessant ab dem Byte 25 (rot markiert). Man kann gut erkennen, dass 6 Leerzeichen (0x20) hinter dem Namen “Sorglos” durch den Wert “erpelz” ersetzt werden.Das gleiche Verfahren wird eingesetzt, wenn ein bereits vorhandener Eintrag länger ist als der neue Wert! In dem Fall werden die vorhandenen Zeichen durch Leerzeichen ersetzt.

Transaktion: DELETE

Beim Löschen eines Datensatzes werden in einem Clustered Index – anders als in einem HEAP (siehe “UPDATE in HEAP = DELETE mit nachfolgendem INSERT?” - keine Daten überschrieben oder gelöscht. Der Datensatz wird bei einem Löschvorgang als “GHOSTED_RECORD” gekennzeichnet. Jeder Datenbankentwickler hat sicherlich schon einmal ein System entwickelt, bei dem ein Datensatz nicht gelöscht werden soll sondern lediglich als “inaktiv” gekennzeichnet wird; ähnlich verhält sich Microsoft SQL Server, um möglichst schnell die gesperrten Ressourcen wieder zur Verfügung zu stellen. Zu diesem Thema finden Sie weitere Informationen im Artikel “UPDATE in Clustered Index = DELETE mit nachfolgendem INSERT?”.

Wie sieht das ganze dann im Transaktionsprotokoll aus? Ausgehend von der Tatsache, dass ein Datensatz nicht physikalisch aus der Datenseite gelöscht wird, ist davon auszugehen, dass nicht die Daten überschrieben werden sondern der Datensatz lediglich als GHOSTED_RECORD gekennzeichnet werden muss.

BEGIN TRANSACTION DeleteRecord
    DELETE dbo.dblog_demo
    WHERE  Id = 1;
COMMIT TRANSACTION;

SELECT Operation,
       Context,
       [Lock Information],
       [RowLog Contents 0],
       [RowLog Contents 1]
FROM   sys.fn_dblog(NULL, NULL) WHERE  [Transaction ID] IN
(
    SELECT [Transaction ID] FROM sys.fn_dblog(NULL, NULL)
    WHERE  [Transaction Name] = 'DeleteRecord'
)
ORDER BY
    [Previous LSN] ASC;

Für das Verständnis, was Microsoft SQL Server tatsächlich beim Löschvorgang protokolliert, wurde das Attribut [Lock Information] der Ausgabe hinzugefügt.

Im [Context] ist zu erkennen, dass der Datensatz als GHOSTED_RECORD gekennzeichnet wurde. In [RowLog Contents 0] ist der vollständige Datensatz (Inklusive Strukturinformationen – wie oben beschrieben) hinterlegt, den die Operation [LOP_DELETE_ROWS] betrifft. Ich hätte in [RowLog Contents 1] erwartet, dass der Datensatz mit geändertem RowHeader (0x1C00) hinterlegt wird, da der Datensatz nicht physikalisch gelöscht wird sondern ausschließlich der Status geändert wird.

Die obige Abbildung zeigt den Eintrag auf der Datenseite NACH dem Löschen des Datensatzes. Es ist zu erkennen, dass die Daten noch vorhanden sind; jedoch wurde der RowHeader geändert. Gemäß der Spezifikation des RowHeaders (2 Bytes) ist der Wert (0x1C) wie folgt zu interpretieren 0x1C = 28:

7

6

5

4

3

2

1

0

128

64

32

16

8

4

2

1

       

4

2

1

 

0

0

0

1

1 1

0

0

Bit 2 und 3 sind aktiviert; Bit 1 – 3 bestimmen die Eigenschaft des Datensatzes. Bit 3 und Bit 2 ergeben (binär zu dezimal) den Wert 6 = GHOSTED DATA RECORD.

Wie es jedoch schaut es im Transaktionsprotokoll aus? Würde das Löschen eines Datensatzes in einem Clustered Index einem Update der Eigenschaft der Datenzeile entsprechen, sollte in [RowContents 1] der vollständige Datensatz mit geändertem RowHeader hinterlegt sein – das ist aber nicht der Fall!

[RowContents 0] 0x1000500001000000557765205265636B656E202020202020202020204D00610072006900650020005300630068006E006500640065007200700065006C007A0020002000E44503000000000093830000050000
[RowContents 1] 0x0101000C0000996DB2240000010200040204000A8194443284A0

Bereits auf dem ersten Blick ist klar, dass die getroffene Annahme nicht stimmen kann. Für die – teilweise - Auflösung der hinterlegten Informationen bin ich meinem MCM-Kollegen Pedro Correia aus Portugal sehr dankbar. Er hat mir geholfen, einen Teil des Inhalts zu entschlüsseln.

Um den Inhalt aus [RowContents 1] zu interpretieren, bedarf es der Analyse der [Lock Information], dessen Inhalt sich wie folgt liest (Hierzu füge ich den Inhalt von [RowContents 1] vor dem Text ein und formatiere die zusammenhängenden Informationen farblich):

0x01 01 00 0C 00 00 99 6D B2 24 00 00 01 02 00 04 02 04 00 0A 81 94 44 32 84 A0

“HoBt 72057594049527808:ACQUIRE_LOCK_IX OBJECT: 19:615673241:0 ;ACQUIRE_LOCK_IX PAGE: 19:1:12327 ;ACQUIRE_LOCK_X KEY: 19:72057594049527808 (8194443284a0)”

Bytes Wert Beschreibung
1 0x01 Hexadezimalwert für die Art der Sperre: 0x1 = IX (Intend eXclusive lock
2 0x01 --
3 - 6 0x00 0C 00 00 --
7 - 10 0x99 6D B2 24 ObjectId der Relation, die von dem Löschvorgang betroffen ist SELECT OBJECT_NAME(CAST(0x24B26D99 AS int));
11 – 20 0x00 00 01 02 00 04 02 04 00 0A --
21 - 26 0x81 94 44 32 84 A0 KeyHashValue des entsprechenden Datensatzes

Einige der oben genannten Bytes sind mit “—“ gekennzeichnet; hierzu kann ich momentan noch nicht genau sagen, was diese Werte in der Transaktion bedeuten (ich werde die Informationen aber nachtragen, sobald ich mehr darüber berichten kann).

Wichtig bleibt jedoch der Hinweis, dass nicht der vollständige neue Datensatz in der Transaktion festgehalten wird sondern ausschließlich die Informationen über die notwendigen Sperren, die für den Löschvorgang für den einzelnen Datensatz gesetzt werden müssen. Bytes 21 – 26 definieren den KeyHashValue. Hierbei handelt es sich um einen Text mit fester Länge, der einen Hashvalue für alle Schlüsselattribute des Index bildet. Dieser KeyHashValue wird in anderen DMV (z. B. sys.dm_tran_locks) verwendet.

Fazit

Der Artikel ist sicherlich für den einen oder anderen Leser “hard stuff” und geht relativ tief in die Grundstrukturen von Microsoft SQL Server. Dieser Artikel zeigt aber – neben den vielen Interna – doch sehr klar, wie Microsoft SQL Server mit Ressourcen umgeht. Die – nicht dokumentierte – Funktion fn_dblog() macht es dem interessierten Leser ein wenig einfacher, bei einer Transaktion besser zu verstehen, was “im Hintergrund” ausgeführt wird. fn_dblog() ermöglicht einen interessanten Blick hinter die Kulissen von Microsoft SQL Server. Ein sicherlich hoch interessantes Anwendungsgebiet für diese Funktion ist die Forensik.

  • Wer hat wann welche Daten in der Datenbank geändert?
  • Welche Werte wurden überschrieben / gelöscht?

Hier lassen sich mit fn_dblog() auf jeden Fall Antworten geben. Natürlich setzt das voraus, dass die Datenbank im Wiederherstellungsmodus “FULL” betrieben werden muss (fn_dblog() untersucht nur den aktiven Teil des Transaktionsprotokolls!). Alle Beispiele wurden in einer Datenbank durchgeführt, die im Wiederherstellungsmodus “SIMPLE” betrieben wurde. Auf Grund der Tatsache, dass die Auswertung des Transaktionsprotokolls unmittelbar nach der Transaktion selbst durchgeführt wurde, war die Transaktion noch im aktiven Teil des Transaktionsprotokolls, der erst durch CHECKPOINT wieder freigegeben wird. Sofern aus einem Full- oder Logbackup Informationen über Transaktionen ausgegeben werden sollen, so muss statt fn_dblog() die Funktion fn_dump_dblog() verwendet werden.

Hinweis:

Wie bereits erwähnt, sind nicht alle Informationen zum Löschvorgang vollständig. Hier bin ich für JEDEN Tipp dankbar, der es mir ermöglicht, den Artikeln zu vervollständigen. Sollte also jemand eine verlässliche Referenz zum Eintrag in [RowLog Contents 1] bei einem Löschvorgang haben, würde ich mich sehr über eine kurze Information freuen.

Herzlichen Dank fürs Lesen!

Datentypen in Microsoft SQL Server http://msdn.microsoft.com/en-us/library/ms187752.aspx
Big-Endian-Format! http://de.wikipedia.org/wiki/Endianness
sys.fn_PhysLocFormatter() http://www.sqlskills.com/blogs/paul/sql-server-2008-new-undocumented-physical-row-locator-function/
fn_dump_dblog() http://blogs.msdn.com/b/dfurman/archive/2009/11/05/reading-database-transaction-log-with-fn-dump-dblog.aspx
sys.system_internals_partition_columns http://technet.microsoft.com/de-de/library/ms189600(v=sql.105).aspx
sys.partitions http://technet.microsoft.com/de-de/library/ms175012.aspx
sys.columns http://msdn.microsoft.com/de-de/library/ms176106.aspx
sys.types http://technet.microsoft.com/de-de/library/ms188021.aspx