SQL Fascination

In the previous post we pulled out the raw information relating to a transaction log entry for a deletion of a single row.  In this post we will decode the binary section of the log entry for the deletion performed.

A reminder of the Row Log Contents for the Clustered Index log entry that we need to decode.

0x3000410001000000B90400001000000000000000406700004D004D0000000000CB8900004A15001E004AD0E1AA37C27449B4D593524773771800000000359500001000000003005D008500BD003100340034003100370038003000370061006400760065006E0074007500720065002D0077006F0072006B0073005C006700750079003100500072006F00640075006300740069006F006E00200054006500630068006E0069006300690061006E0020002D0020005700430036003000

So we have 180 bytes of information relating to the deletion, the question is – what is it? The most obvious answer has to be the record that has been deleted – lots of fixed log information has already been exposed as named fields, this generic variable length value must be the row that we deleted.

How to decode it though? applying the structure of a row is a good place,  the format mentioned before is detailed very nicely detailed in Kalen Delaney’s SQL Internal’s book so let’s use that as a guide.

• 2 Byte : Status Bits
• 2 Bytes: Offset to find number of columns
• X Bytes:Fixed Length Columns
• 2 Bytes: Total Number of Columns in the data row
• 1 Bit per column, Rounded up: Nullability Bitmap
• 2 Bytes:Number of Variable Length Columns within the data row
• 2 Bytes per variable length column : Row Offset marking the end of each variable length column
• X Bytes:Variable Length Columns

Ok, let’s start assigning the values from the log hex dump into the fields.

Status Bits (2 Bytes) : 3000
Offset to Find Number of Columns (2 Bytes) : 4100
Because of the endian ordering in effect, the offset should be read as 0041 – 65 in Decimal.  So there must be 61 Bytes of Fixed width data, since we have already used 4 bytes.

Let’s remind ourselves of the table structure:

CREATE TABLE [HumanResources].[Employee](
 [EmployeeID] [int] IDENTITY(1,1) NOT NULL,
 [NationalIDNumber] [nvarchar](15) COLLATE SQL_Latin1_General_CP1_CI_AS NOT NULL,
 [ContactID] [int] NOT NULL,
 [LoginID] [nvarchar](256) COLLATE SQL_Latin1_General_CP1_CI_AS NOT NULL,
 [ManagerID] [int] NULL,
 [Title] [nvarchar](50) COLLATE SQL_Latin1_General_CP1_CI_AS NOT NULL,
 [BirthDate] [datetime] NOT NULL,
 [MaritalStatus] [nchar](1) COLLATE SQL_Latin1_General_CP1_CI_AS NOT NULL,
 [Gender] [nchar](1) COLLATE SQL_Latin1_General_CP1_CI_AS NOT NULL,
 [HireDate] [datetime] NOT NULL,
 [SalariedFlag] [dbo].[Flag] NOT NULL CONSTRAINT [DF_Employee_SalariedFlag]  DEFAULT ((1)),
 [VacationHours] [smallint] NOT NULL CONSTRAINT [DF_Employee_VacationHours]  DEFAULT ((0)),
 [SickLeaveHours] [smallint] NOT NULL CONSTRAINT [DF_Employee_SickLeaveHours]  DEFAULT ((0)),
 [CurrentFlag] [dbo].[Flag] NOT NULL CONSTRAINT [DF_Employee_CurrentFlag]  DEFAULT ((1)),
 [rowguid] [uniqueidentifier] ROWGUIDCOL  NOT NULL CONSTRAINT [DF_Employee_rowguid]  DEFAULT (newid()),
 [ModifiedDate] [datetime] NOT NULL CONSTRAINT [DF_Employee_ModifiedDate]  DEFAULT (getdate()),
 CONSTRAINT [PK_Employee_EmployeeID] PRIMARY KEY CLUSTERED

The fixed columns are as follows:

[EmployeeID] [int]  = 4
[ContactID] [int] = 4
[ManagerID] [int] = 4
[BirthDate] [datetime] = 8
[MaritalStatus] [nchar](1) = 2
[Gender] [nchar](1) = 2
[HireDate] [datetime] = 8
[SalariedFlag] [dbo].[Flag] = 1
[VacationHours] [smallint] = 2
[SickLeaveHours] [smallint] = 2
[CurrentFlag] [dbo].[Flag] = 0 - second bit.
[rowguid] [uniqueidentifier] = 16
[ModifiedDate] [datetime] = 8

Adventure Works uses a user defined type of Flag, which is just declared as a bit. So thats 61 bytes of fixed width storage – which is the value we expected.

We need to know the column order, we could assume it is the same as the table declaration, but we should double check the actual colum ordering to be certain.

select colorder, syscolumns.name
from syscolumns
inner join systypes on syscolumns.xusertype = systypes.xusertype
where id =object_id('HumanResources.Employee') and variable = 0
order by colorder

colorder name
-------- -------------
1        EmployeeID
3        ContactID
5        ManagerID
7        BirthDate
8        MaritalStatus
9        Gender
10       HireDate
11       SalariedFlag
12       VacationHours
13       SickLeaveHours
14       CurrentFlag
15       rowguid
16       ModifiedDate

So the order looks good, let’s start assigning values:

[EmployeeID] [int]  = 01000000 = 00000001 = 1
[ContactID] [int] = B9040000 = 000004B9 = 1209
[ManagerID] [int] = 10000000 = 00000001 = 1
[BirthDate] [datetime] = 0000000040670000 = 0000674000000000 = '1972-05-15 00:00:00.000'  - (Use Select convert(datetime, 0x0000674000000000) to check)
[MaritalStatus] [nchar](1) = 004D = 77 = UniCode for M (Use Select nchar(77) to check)
[Gender] [nchar](1) = 4D00 = 004D = 77 = M
[HireDate] [datetime] = 00000000CB890000 = 000089CB00000000 = '1996-07-31 00:00:00.000'
[SalariedFlag] [dbo].[Flag] = 4A = 01001010 in Binary, which will need further work.
[VacationHours] [smallint] = 1500 = 0015 = 21
[SickLeaveHours] [smallint] = 1E00 = 001E = 30
[CurrentFlag] [dbo].[Flag] = Contained within the First Flag Byte
[rowguid] [uniqueidentifier] = 4AD0E1AA37C27449B4D5935247737718
[ModifiedDate] [datetime] = 0000000035950000 = 0000953500000000 = '2004-07-31 00:00:00.000'
Number of Columns : 1000 = 0010 - = 16 Columns - which is correct.
Nullability Bitmap : 1 bit per Column, so 16/8 = 2 Bytes : 0000
Number of Variable Rows : 0300 = 0003 = 3 Variable Length Columns
Var Column End 1 : 5d00 = 005D = 93
Var Column End 2 : 8500 = 0085 = 133
Var Column End 3 : BD00 = 00BD = 189

The number of columns was at the offset of 65, that used 2 bytes, the nullability was 2, the variable number of rows was 2 bytes and each variable row pointer used a further 2 each, so the data starts at byte after e.g. 65 + 12 = 77. First variable width data ends at 93, so the first variable width column is using 16 bytes of space.

I should mention why the nullability bitmap was 2, all the columns are declared as not null, so the bitmap did not increase in size, if there was a single nullable column, then the bitmap would have a bit per column in the table  – not a bit per nullable column, it is an all or nothing approach.

Raw Values : 3100 3400 3400 3100 3700 3800 3000 3700

Reverse Bytes : 0031 0034 0034 0031 0037 0038 0030 0037
Result : 14417807  (You can use Select NChar(0x0031) etc to check each value.)

Next up is 93 to 133, a gap of 40 bytes.

Raw Values    : 6100 6400 7600 6500 6E00 7400 7500 7200 6500 
2D00 7700 6F00 7200 6B00 7300 5C00 6700 7500 7900 3100
Reverse Bytes : 0061 0064 0076 0065 006E 0074 0075 0072 0065 
002D 0077 006F 0072 006B 0073 005C 0067 0075 0079 0031
Output : adventure-works\guy1

Final column, should be 189 – 133 = 56 bytes long, which it is, and decoding it again in the same way gives the following.

Raw Values    : 5000 7200 6F00 6400 7500 6300 7400 6900 6F00 6E00 2000 5400 6500 6300
6800 6E00 6900 6300 6900 6100 6E00 2000 2D00 2000 5700 4300 3600 3000
Reverse Bytes : 0050 0072 006F 0064 0075 0063 0074 0069 006F 006E 0020 0054 0065 0063
 0068 006E 0069 0063 0069 0061 006E 0020 002D 0020 0057 0043 0036 0030
Result : Production Technician - WC60

That is the row contents decoded, and the deleted row’s original values are now exposed.

As you can see from the complexity of decoding one part of a trivial delete operation within the log, this is not something that you would wish to rely on / use as an audit trail etc. But hopefully it has provided some insight and added to the minimal documentation on how to approach the decoding process. I will try to decode more of the operations as, insert and update shouldn’t be too hard to manage, but sucess is not guarenteed.