The very worst piece of advice I ever saw on the Internet was in response to someone asking on a SQL newsgroup 'how can I create a corrupt database?'. The first response was:

When I want to corrupt a database to play with, I go into the data center, find a hard-drive and flick the power switch on-and-off quickly a few times.

This was closely followed by a bunch of replies (including mine) saying 'Noooooooooooo!!!!'

So, for a few years now I've provided a zip file with a bunch of pre-corrupted databases in - so you can test your consistency checking jobs, and experiment with corrupt databases without having to create them yourself by destroying hard-drives, or less daft means. You can find the main zip file at the top of our Past Events resources page, along with a link to a blog post which explains the various databases and demo scripts.

Several times I've been asked to provide SQL Server 2008 versions of the two databases which demo system table corruption. Well, that task has finally bubbled to my long-list of blog posts and website updates. There's now a second, smaller zip file which has 2008-only versions of the DemoFatalCorruption1 and DemoFatalCorruption2 databases, which showcase corruptions that prevent DBCC CHECKDB from running.

Let me know if you have any problems (playing with the backups )

Enjoy!

One of the things I love teaching is how the transaction log and logging/recovery work. I presented a session on this at both PASS and SQL Connections in the last two weeks, and in both sessions I promised to write some blog posts about the deep internals of logging operations. This is the first one in the series. Previous blog posts that dive into logging operations are:

• How do checkpoints work and what gets logged (this also explains how crash recovery starts, using the boot page and the most recent checkpoint log record)
• Finding out who dropped a table using the transaction log
• How expensive are page splits in terms of transaction log?
• Inside the Storage Engine: More on the circular nature of the log
• Ghost cleanup redux
• Inside the Storage Engine: Ghost cleanup in depth

Ok, on with the show. 

SQL Server 2005 introduced a feature called 'fast recovery' in Enterprise Edition. This allows a database to become available for use after the first part of recovery (REDO) completes and before the (usually longer running) second part of recovery (UNDO) completes. See my TechNet Magazine article Understanding Logging and Recovery in SQL Server if you don't know what I'm talking about. But how does SQL Server do this?

The answer is lock logging. A log record describes a single change made to a database. For log records describing changes that can be used as part of UNDO (yes, some changes to the database are one-way only - for instance PFS page changes), from 2005 onwards the log record also includes a description of which locks were being held at the time the change was made. These locks were necessary to protect the change being made when the original transaction was running (before the crash) and so the same locks will be necessary to protect the anti-operation which reverses the change. I'll explain more about these anti-operations in one of the next in-depth logging blog posts.

The Storage Engine does two passes through the log as part of crash recovery. The first pass does REDO and also reads the log records that will be processed as part of the second pass (UNDO), looking at the lock description and actually acquiring those locks. For fast recovery, at that point the database is brought online. This is possible because the recovery system knows that it already has the correct locks to guarantee that it can safely generate and perform the anti-operations necessary to perfom UNDO. One side-effect of this is that although the database is available for use, a query may bump into one of the locks being held to allow fast recovery - in which case it will have to wait for that lock to be dropped as UNDO progresses.

Cool eh?

That was the introduction to allow me to do some gratuitous spelunking around the internals :-) I'm going to create a few simple examples to show you lock logging in the log. Now, don't get confused - it's not logging actual locks (the memory used to hold the lock itself), it's just logging a description of which locks were held and in which modes.

Here's the script to create a database with a simple table. I'm using a LOB column and specifically setting it to be stored off row (see Importance of choosing the right LOB storage technique) so we can see some text page locks too. I'm using the SIMPLE recovery model for simplicity (ha ha) - so I can clear the log when a checkpoint occurs rather than having to muck around with log backups. I'll insert the first row and then clear the log.

CREATE DATABASE LockLogging;
GO
USE LockLogging;
GO

CREATE TABLE LockLogTest (c1 INT, c2 INT, c3 VARCHAR (MAX));
GO
EXEC sp_tableoption 'LockLogtest', 'large value types out of row', 'on';
GO

INSERT INTO LockLogTest VALUES (1, 1, 'a');
GO

ALTER DATABASE LockLogging SET RECOVERY SIMPLE;
GO
CHECKPOINT;
GO

Now let's try the first operation - a simple insert - and look at the log records using fn_dblog (and I'm skipping the checkpoint log records):

INSERT INTO LockLogTest VALUES (2, 2, 'b');
GO
SELECT [Operation], [Context], [Page ID], [Slot ID], [Number of Locks] AS Locks, [Lock Information]
FROM fn_dblog (NULL, NULL);
GO

Operation        Context       Page ID        Slot ID  Locks Lock Information
---------------- ------------- -------------- -------- ----- -------------------------------------------------------------------
LOP_BEGIN_XACT   LCX_NULL      NULL           NULL     NULL  NULL
LOP_INSERT_ROWS  LCX_TEXT_MIX  0001:00000098  1        2     ACQUIRE_LOCK_IX PAGE: 18:1:152; ACQUIRE_LOCK_X RID: 18:1:152:1
LOP_INSERT_ROWS  LCX_HEAP      0001:0000009a  1        3     ACQUIRE_LOCK_IX OBJECT: 18:2073058421:0;
                                                                 ACQUIRE_LOCK_IX PAGE: 18:1:154; ACQUIRE_LOCK_X RID: 18:1:154:1
LOP_COMMIT_XACT  LCX_NULL      NULL           NULL     NULL  NULL

We can see page IX and row X locks for the LOB value being inserted into the text page, plus table IX, page IX, and row X locks for the data record being inserted into the heap. The lock resources break out as follows:

• 18:1:152 is page 152 in file 1 of database ID 18
• 18:1:152:1 is slot 1 on page 152 in file 1 of database ID 18
• 18:2073058421:0 is object ID 2073058421 (the object ID of the table LockLogTest) in database ID 18

Notice also the LOP_BEGIN_XACT and LOP_COMMIT_XACT log records - even though I didn't do an explicit transaction, SQL Server has to start one internally for me (called an implicit transaction) so that there's a boundary for where to rollback if something goes wrong during the operation. 

And now an update operation (with a checkpoint first to clear out the log):

CHECKPOINT;
GO
UPDATE LockLogTest SET c1 = 3;
GO
SELECT [Operation], [Context], [Page ID], [Slot ID], [Number of Locks] AS Locks, [Lock Information]
FROM fn_dblog (NULL, NULL);
GO

Operation        Context       Page ID        Slot ID  Locks Lock Information
---------------- ------------- -------------- -------- ----- -------------------------------------------------------------------
LOP_BEGIN_XACT   LCX_NULL      NULL           NULL     NULL  NULL
LOP_MODIFY_ROW   LCX_HEAP      0001:0000009a  0        3     ACQUIRE_LOCK_IX OBJECT: 18:2073058421:0;
                                                                 ACQUIRE_LOCK_IX PAGE: 18:1:154; ACQUIRE_LOCK_X RID: 18:1:154:0
LOP_MODIFY_ROW   LCX_HEAP      0001:0000009a  1        3     ACQUIRE_LOCK_IX OBJECT: 18:2073058421:0;
                                                                 ACQUIRE_LOCK_IX PAGE: 18:1:154; ACQUIRE_LOCK_X RID: 18:1:154:1
LOP_COMMIT_XACT  LCX_NULL      NULL           NULL     NULL  NULL

Just as we expected - a table IX lock, a page IX lock, and two row X locks on that page.

Now, what about something more complicated like a TRUNCATE TABLE? Have you heard the myth about it not being logged? Right - it's a myth:

CHECKPOINT;
GO
TRUNCATE TABLE LockLogTest;
GO
SELECT [Operation], [Context], [Page ID], [Slot ID], [Number of Locks] AS Locks, [Lock Information]
FROM fn_dblog (NULL, NULL);
GO

Operation        Context       Page ID        Slot ID  Locks Lock Information
---------------- ------------- -------------- -------- ----- -------------------------------------------------------------------
LOP_BEGIN_XACT   LCX_NULL      NULL           NULL     NULL  NULL
LOP_LOCK_XACT    LCX_NULL      NULL           NULL     1     ACQUIRE_LOCK_SCH_M OBJECT: 18:2073058421:0
LOP_MODIFY_ROW   LCX_IAM       0001:0000009b  0        1     ACQUIRE_LOCK_X RID: 18:1:155:0
LOP_MODIFY_ROW   LCX_PFS       0001:00000001  0        1     ACQUIRE_LOCK_X PAGE: 18:1:154
LOP_MODIFY_ROW   LCX_PFS       0001:00000001  0        1     ACQUIRE_LOCK_X PAGE: 18:1:155
LOP_MODIFY_ROW   LCX_IAM       0001:00000099  0        1     ACQUIRE_LOCK_X RID: 18:1:153:0
LOP_MODIFY_ROW   LCX_PFS       0001:00000001  0        1     ACQUIRE_LOCK_X PAGE: 18:1:152
LOP_MODIFY_ROW   LCX_PFS       0001:00000001  0        1     ACQUIRE_LOCK_X PAGE: 18:1:153
LOP_SET_BITS     LCX_SGAM      0001:00000003  1        NULL  NULL
LOP_SET_BITS     LCX_GAM       0001:00000002  1        NULL  NULL
LOP_COUNT_DELTA  LCX_CLUSTERED 0001:00000014  89       NULL  NULL
LOP_COUNT_DELTA  LCX_CLUSTERED 0001:00000011  78       NULL  NULL
LOP_COUNT_DELTA  LCX_CLUSTERED 0001:00000014  90       NULL  NULL
LOP_COUNT_DELTA  LCX_CLUSTERED 0001:00000041  164      NULL  NULL
LOP_COUNT_DELTA  LCX_CLUSTERED 0001:00000041  165      NULL  NULL
LOP_COUNT_DELTA  LCX_CLUSTERED 0001:00000041  166      NULL  NULL
LOP_HOBT_DDL     LCX_NULL      NULL           NULL     NULL  NULL
LOP_MODIFY_ROW   LCX_CLUSTERED 0001:00000014  89       2     ACQUIRE_LOCK_IX OBJECT: 18:7:0;
                                                                 ACQUIRE_LOCK_X KEY: 18:458752 (0000c2681664)
LOP_HOBT_DDL     LCX_NULL      NULL           NULL     NULL  NULL
LOP_MODIFY_ROW   LCX_CLUSTERED 0001:00000014  90       2     ACQUIRE_LOCK_IX OBJECT: 18:7:0;
                                                                 ACQUIRE_LOCK_X KEY: 18:458752 (00007a581379)
LOP_MODIFY_ROW   LCX_CLUSTERED 0001:00000011  78       2     ACQUIRE_LOCK_IX OBJECT: 18:5:0;
                                                                 ACQUIRE_LOCK_X KEY: 18:327680 (00001df3833b)
LOP_COMMIT_XACT  LCX_NULL      NULL           NULL     NULL  NULL

Lots of logging and lots of locks. If you look at the Context column, you'll see that the operation is modifying allocation bitmaps (LCX_IAM, LCX_PFS, LCX_SGAM, LCX_GAM) but taking locks on the table pages, not on the allocation bitmaps themselves - they're only ever latched (an internal, much lighter-weight, synchronization mechanism). This is done as the pages comprising the table are deallocated - this is all done because the table's small enough that the Storage Engine chooses to deallocate all the storage immediately, instead of pushing it all onto the task queue for the deferred drop background task. See my previous post Search Engine Q&A #10: When are pages from a truncated table reused? which discusses this too.

There are no actual row operations performed on the table itself. The only table row operations are down at the bottom on table with object IDs 7 and 5 (sysallocunits and sysrowsets, respectively) to update the page counts, first IAM, and first page entries for the table.

So - hopefully this has been useful to you. In the next post in the series, I'll discuss compensation log records and how rollback operations work.

PS Send me an email or put in a comment if there's something in particular about the log (or log records) you'd like to see explained.

This is a blog post I've been meaning to do for a while, and I've recently noticed some info on the web about checkpoints which is a little misleading, so I want to do a quick post to explain how checkpoints work as far as log records are concerned.

When a checkpoint operation occurs, no matter how it's triggered (for instance through a manual CHECKPOINT, from a database or differential backup, or automatically) the same set of operations occurs:

• All dirty data file pages for the database are written to disk (all pages that have changed in memory since they were read from disk or since the last checkpoint), regardless of the state of the transaction that made the change.
• Before a page is written to disk, all log records up to and including the most recent log record describing a change to that page are written to disk (yes, log records can be cached in memory too). This guarantees recovery can work and is called write-ahead logging. Log records are written to the log sequentially, and log records from multiple transactions will be interspersed in the log. The log cannot be selectively written to disk, so writing a dirty page to disk that only has a single log record affecting it may mean writing many more previous log records to disk as well.
• Log records describing the checkpoint are generated.
• The LSN of the checkpoint is recorded in the database boot page in the dbi_checkptLSN field (see Search Engine Q&A #20: Boot pages, and boot page corruption).
• If in the SIMPLE recovery model, the VLFs in the log are checked to see whether they can be marked inactive (called clearing or truncating the log - both of which are terrible misnomers, as nothing is either physically cleared or truncated).

I'm using some terms you may not have come across - for a background primer on logging, recovery, and transaction log architecture see my article in the February 2009 TechNet Magazine - Understanding Logging and Recovery in SQL Server (or come to my Wednesday November 4th PASS Spotlight session with the same title).

Checkpoints are not really tracked in the transaction log - it just serves as a useful repository for information about which transactions are active at the time of the checkpoint. The LSN of the last checkpoint is recorded in the database boot page. This is where recovery starts, and if this page is inaccessible, the database cannot be attached, opened, or processed in any way - partly because it's the boot page that knows whether the database was cleanly shut down or not, and partly because it's the only place that records the LSN of the last checkpoint record. You may say, well it's recorded in the transaction log too, but what if the log is corrupt in some way?

One area of confusion I've seen is that the checkpoint log records are overwritten by subsequent checkpoints. Absolutely not - once written, a log record is NEVER updated or overwritten - it will only be overwritten when the log wraps and the VLFs are re-used (see Inside the Storage Engine: More on the circular nature of the log). This has led to further confusion about when checkpoint information is retrievable from the log, using commands such as fn_dblog.

For the rest of this post, I want to show you what's going on in the transaction log when checkpoints occur under different circumstances.

Consider the following example:

CREATE DATABASE CheckpointTest;
GO
USE CheckpointTest;
GO
CREATE TABLE t1 (c1 INT);
GO
INSERT INTO t1 VALUES (1);
GO
CHECKPOINT;
GO
SELECT [Current LSN], [Operation] FROM fn_dblog (NULL, NULL);
GO

Current LSN             Operation
----------------------- -------------------------------
00000047:00000051:009b  LOP_BEGIN_CKPT
00000047:00000091:0001  LOP_END_CKPT

We see the log records for the checkpoint. In this case the checkpoint is very simple and so there are only two records - beginning and ending the checkpoint.

If we run another checkpoint, what do we see?

CHECKPOINT;
GO
SELECT [Current LSN], [Operation] FROM fn_dblog (NULL, NULL);
GO

Current LSN             Operation
----------------------- -------------------------------
00000047:00000092:0001  LOP_BEGIN_CKPT
00000047:00000093:0001  LOP_END_CKPT

Only information about one checkpoint, but with different LSNs for the log records. It's not that the previous checkpoint was overwritten, it's that we did a checkpoint - so the active portion of the log has moved forward and the log records for the previous checkpoint aren't considered active any more as they're not required (for instance, for database mirroring, an active transaction, a log backup, transactional replication). They're still there in the log though, but just aren't part of the required portion of the log and so aren't dumped by fn_dblog.

Now, what if I create an active transaction? In another connection, I'll do:

USE CheckpointTest;
GO
BEGIN TRAN;
GO
INSERT INTO t1 VALUES (1);
GO

And what if we do a checkpoint and look at the log now?

CHECKPOINT;
GO
SELECT [Current LSN], [Operation] FROM fn_dblog (NULL, NULL);
GO

Current LSN             Operation
----------------------- -------------------------------
00000047:00000094:0001  LOP_BEGIN_XACT
00000047:00000094:0002  LOP_INSERT_ROWS
00000047:00000094:0003  LOP_COUNT_DELTA
00000047:00000094:0004  LOP_COUNT_DELTA
00000047:00000094:0005  LOP_COUNT_DELTA
00000047:00000094:0006  LOP_BEGIN_CKPT
00000047:00000096:0001  LOP_XACT_CKPT
00000047:00000096:0002  LOP_END_CKPT

We see the start of the open transaction, the insert of the record, the update of row counts in metadata, and the checkpoint.

You may notice that there's another log record being generated for the checkpoint - LOP_XACT_CKPT. This is only generated when there are active (uncommitted) transactions and it lists information about all actvie transactions at the time the checkpoint begins. This is used during crash recovery to work out how far back in the transaction log to go to start REDO and UNDO operations (well, technically only UNDO will need to go this far back). Focusing in on this log record, we can see:

SELECT [Current LSN], [Operation], [Num Transactions], [Log Record]
FROM fn_dblog (NULL, NULL) WHERE [Operation] = 'LOP_XACT_CKPT';
GO

Current LSN             Operation                       Num Transactions
----------------------- ------------------------------- ----------------
00000047:00000096:0001  LOP_XACT_CKPT                   1

Log Record
-----------------------------------------------------------------------------------------------------------
0x000018 <snip> 780500000000000047000000940000000100040147000000940000000200000001 <snip> 6621000000000000

This log record contains information about each active (uncommitted) transaction at the time of the checkpoint. Without going into all the details about what's in the payload for this log record, you can see two things in there:

• The LSN of the LOP_BEGIN_XACT log record for the oldest active transaction (the first bold number above - match it against the LOP_BEGIN_XACT in the log dump a little higher up)
• The LSN of the first log record making a database change for that transaction (the second bold number above - match it against the LOP_INSERT_ROWS in the log dump a little higher up)

You'll notice that these LSNs are stored byte-reversed. 

How about if we do another checkpoint?

CHECKPOINT;
GO
SELECT [Current LSN], [Operation] FROM fn_dblog (NULL, NULL);
GO

Current LSN             Operation
----------------------- -------------------------------
00000047:00000094:0001  LOP_BEGIN_XACT
00000047:00000094:0002  LOP_INSERT_ROWS
00000047:00000094:0003  LOP_COUNT_DELTA
00000047:00000094:0004  LOP_COUNT_DELTA
00000047:00000094:0005  LOP_COUNT_DELTA
00000047:00000094:0006  LOP_BEGIN_CKPT
00000047:00000096:0001  LOP_XACT_CKPT
00000047:00000096:0002  LOP_END_CKPT
00000047:00000097:0001  LOP_BEGIN_CKPT
00000047:00000098:0001  LOP_XACT_CKPT
00000047:00000098:0002  LOP_END_CKPT

This time we see the log records for the current checkpoint and the previous one - as the active log stretches all the way back to the start of the oldest active transaction - no matter how many checkpoints we do while there's an active transaction.

Now what if we start another active transaction in a third connection?

USE CheckpointTest;
GO
BEGIN TRAN;
GO
INSERT INTO t1 VALUES (2);
GO

And then go back to the original connection and do another checkpoint and dump the log again:

CHECKPOINT;
GO
SELECT [Current LSN], [Operation] FROM fn_dblog (NULL, NULL);
GO

Current LSN             Operation
----------------------- -------------------------------
00000047:00000094:0001  LOP_BEGIN_XACT
00000047:00000094:0002  LOP_INSERT_ROWS
00000047:00000094:0003  LOP_COUNT_DELTA
00000047:00000094:0004  LOP_COUNT_DELTA
00000047:00000094:0005  LOP_COUNT_DELTA
00000047:00000094:0006  LOP_BEGIN_CKPT
00000047:00000096:0001  LOP_XACT_CKPT
00000047:00000096:0002  LOP_END_CKPT
00000047:00000097:0001  LOP_BEGIN_CKPT
00000047:00000098:0001  LOP_XACT_CKPT
00000047:00000098:0002  LOP_END_CKPT
00000047:00000099:0001  LOP_BEGIN_XACT
00000047:00000099:0002  LOP_INSERT_ROWS
00000047:00000099:0003  LOP_COUNT_DELTA
00000047:00000099:0004  LOP_COUNT_DELTA
00000047:00000099:0005  LOP_COUNT_DELTA
00000047:00000099:0006  LOP_BEGIN_CKPT
00000047:0000009b:0001  LOP_XACT_CKPT
00000047:0000009b:0002  LOP_END_CKPT

You can see that we now have three sets of checkpoint log records, and two active transactions. Only one of these sets of checkpoint log records is the pertinent one - the previous two have been superceded, but the log records haven't been overwritten or removed, as you can clearly see.

Looking inside all the LOP_XACT_CKPT records, we can see (with a bit of creative formatting of the output):

SELECT [Current LSN], [Operation], [Num Transactions], [Log Record]
FROM fn_dblog (NULL, NULL) WHERE [Operation] = 'LOP_XACT_CKPT';
GO

Current LSN             Operation                       Num Transactions
----------------------- ------------------------------- ----------------
00000047:00000096:0001  LOP_XACT_CKPT                   1
00000047:00000098:0001  LOP_XACT_CKPT                   1
00000047:0000009b:0001  LOP_XACT_CKPT                   2

Log Record
-------------------------------------------------------------------------------------------------------------
0x000018 <snip> 780500000000000047000000940000000100040147000000940000000200000001 <snip> 21000000000000
0x000018 <snip> 780500000000000047000000940000000100040147000000940000000200000001 <snip> 21000000000000
0x000018 <snip> 780500000000000047000000940000000100040147000000940000000200000001 <snip> 21000000000000 ...
    ... 79050000000000004700000099000000010004014700000099000000020000000100000002000000DC000000

The first two checkpoints only list one active transaction and the most recent one lists two, as we'd expect. The log record payload for the first two lists the same oldest active transaction (highlighted in bold). The payload for the last checkpoint lists the same oldset active transaction (as that hasn't changed), but now lists an additional transaction (match the 470000009900000001000 with the LSN of the second LOP_BEGIN_XACT in the log dump above), and has a transaction count of two.

Just to finish things off, let's look at the boot page of the database either using DBCC PAGE or DBCC DBINFO:

DBCC TRACEON (3604);
GO
DBCC DBINFO ('CheckpointTest');
GO

DBINFO STRUCTURE:

DBINFO @0x6711EF64

dbi_dbid = 18                        dbi_status = 65536                   dbi_nextid = 2089058478
dbi_dbname = CheckpointTest          dbi_maxDbTimestamp = 2000            dbi_version = 611
dbi_createVersion = 611              dbi_ESVersion = 0                   
dbi_nextseqnum = 1900-01-01 00:00:00.000                                  dbi_crdate = 2009-09-28 07:06:35.873
dbi_filegeneration = 0              
dbi_checkptLSN

m_fSeqNo = 71                        m_blockOffset = 153                  m_slotId = 6
dbi_RebuildLogs = 0                  dbi_dbccFlags = 2                   
dbi_dbccLastKnownGood = 1900-01-01 00:00:00.000                          
<snip>

The dbi_checkptLSN is dumped out in decimal - converting to hex gives us  (47:99:6), which exactly matches the LSN of the most recent LOP_BEGIN_CKPT record in the log dump above.

Hopefully this explains things clearly!

Here's a question that came up recently: if I've upgraded a database from SQL 2000 or before, how can I tell if the data purity checks will be run or not?

As you may know, DBCC CHECKDB in 2005 onwards includes 'data purity' checks. These look for column values where the value is outside the valid range of values for the column's data type. For databases created on SQL 2005 onwards, these checks are always performed by DBCC CHECKDB and cannot be turned off. For databases created on earlier versions, it's a little more complicated.

In SQL Server versions prior to 2005, it was possible to import invalid data values into a database. These invalid values could cause query execution problems, or possibly even wrong results. In 2005, when the import 'holes' were closed, the data purity checks were added to DBCC CHECKDB, but not by default for upgraded databases. Because the possibility existed of upgraded database containing invalid values, the decision was made not to enable the data purity checks by default as this could lead people to suspect that the upgrade had caused corruptions that weren't there on 2000 or before.

So, if you have a database that was upgraded and you want to run the data purity checks, you need to use the WITH DATA_PURITY option for DBCC CHECKDB. This is all documented in Books Online and I put it into the Release Notes for SQL 2005 as well. Back to the question though - at what point do you NOT need to specify the option? Well, for an upgraded database, if the WITH DATA_PURITY option is used and no problems are found, a bit is irrevocably flipped in the boot page (see Search Engine Q&A #20: Boot pages, and boot page corruption) and from that point onwards the data purity checks will be performed on the database whenever DBCC CHECKDB runs.

The problem is though, how can you tell whether the bit has been flipped? You need to look at the boot page. The easiest way to do that is to use the DBCC DBINFO command (undocumented, but perfectly safe). It's the equivalent of using DBCC PAGE ('dbname', 1, 9, 3) to look at the boot page contents, as I explained in the blog post referenced in the previous paragraph.

There are two things you need to look for: what version of SQL Server created the database, and it the 'create version' is 2000 or lower, whether the special 'data purity' flag is set or not.

For a database created on SQL Server 2005:

DBCC TRACEON (3604);
GO
DBCC DBINFO ('master');
GO

DBINFO STRUCTURE:

DBINFO @0x66C8EF64

dbi_dbid = 1                         dbi_status = 65544                   dbi_nextid = 1984726123
dbi_dbname = master                  dbi_maxDbTimestamp = 16000           dbi_version = 611
dbi_createVersion = 611              dbi_ESVersion = 0                   
dbi_nextseqnum = 1900-01-01 00:00:00.000                                  dbi_crdate = 1900-01-01 00:00:00.000
dbi_filegeneration = 0              
dbi_checkptLSN

m_fSeqNo = 7612                      m_blockOffset = 224                  m_slotId = 1
dbi_RebuildLogs = 0                  dbi_dbccFlags = 0                   
dbi_dbccLastKnownGood = 2009-05-12 16:07:15.647                          
dbi_dbbackupLSN

<snip>

If the dbi_createVersion is 611 or higher, the database was created on SQL Server 2005+ and will always have data purity checks performed.

For an upgraded database (this is one of my pre-corrupted databases, you can get it from Conference corruption demo scripts and example corrupt databases):

DBCC TRACEON (3604);
GO
DBCC DBINFO ('DemoCorruptMetadata');
GO

DBINFO STRUCTURE:

DBINFO @0x6855EF64

dbi_dbid = 7                         dbi_status = 16                      dbi_nextid = 2089058478
dbi_dbname = DemoCorruptMetadata     dbi_maxDbTimestamp = 100             dbi_version = 611
dbi_createVersion = 539              dbi_ESVersion = 0                   
dbi_nextseqnum = 1900-01-01 00:00:00.000                                  dbi_crdate = 2009-06-17 15:14:49.490
dbi_filegeneration = 0              
dbi_checkptLSN

m_fSeqNo = 10                        m_blockOffset = 303                  m_slotId = 1
dbi_RebuildLogs = 0                  dbi_dbccFlags = 0                   
dbi_dbccLastKnownGood = 1900-01-01 00:00:00.000                          
dbi_dbbackupLSN

<snip>

This database has a dbi_createVersion lower than 611, so we need to look at the dbi_dbccFlags field. A value of 0 means that the data purity checks are not enabled by default. A value of 2 means they are enabled by default. You can easily check this out for your own databases.

Have fun!

This is a question that comes up every so often, most recently this morning while teaching a private class (and Kimberly's teaching now): how large is the forwarded record back-pointer? (And I haven't posted anything geeky for a while...)

In a heap it is possible to get forwarding and forwarded records. They occur when a record in a heap expands such that it no longer fits on the page it currently resides on. In this case, the record is moved to a new page, and a small forwarding record is left in the original location. The forwarding record points to the new location of the record, which is known as a forwarded record. This is done as a performance optimization so that all the nonclustered indexes on the heap do not have to be altered with the new location of the heap record.

As an aside, when a query uses a nonclustered index to satisfy a query, but needs more columns from the table record to fill the result set column list, it must go to the actual data record to retrieve the extra columns. It does this by using the table record locator that is stored in the nonclustered index record. If the table is a heap, the record locator is the physical location of the data record in the heap.

If the table is a clustered index (remember that a table can be organized as a heap OR a clustered index, not both), the record locator is the set of cluster keys of the data record. Both of these record locators are guaranteed to be unique. For a heap record locator, the record lookup (commonly called a bookmark lookup) goes directly to the physical location of the record. For a clustered index record locator, the record lookup uses the cluster keys to navigate down through the clustered index to the leaf level.

If a forwarding record occurs in a heap, when the record locator points to that location, the Storage Engine gets there and says Oh, the record isn't really here - it's over there! And then it has to do another (potentially physical) I/O to get to the page with the forwarded record on. This can result in a heap being less efficient that an equivalent clustered index.

There has been lots of discussion about whether it's better to have a heap or a clustered index - generally we recommend a clustered index, but there are special cases where a heap may be fine. This post isn't about that and I won't get drawn into a Comments argument about it. Go bug Kimberly :-)

Back to the point of the post. So the record has moved to a new location and there's a small record left in the original location which helps bookmark lookups.

Oh yeah, one more aside. The Storage Engine, when scanning the heap, will not process the forwarded record UNLESS it has reached it by following the forwarding record. This prevents race conditions where the record could be processed twice - if the forwarding operation occurs during a large table scan.

Ok, really back to the point of the post. What happens if the original record grows again and has to move again? Does it leave ANOTHER forwarding record when it moves to the second new location - creating a chain of forwarding records?

The answer is no. The *original* forwarding record is updated with the new location of the forwarded record. This can only be done if the forwarded record points *back* to the forwarding record - which it does.

The question becomes- how big is the forwarding record back-pointer? It's not dumped out by DBCC PAGE (sorry, when I rewrote DBCC PAGE for SQL 2005 I forgot to put that in there). Let's work it out using a script.

First off I'm going to create a database and table to play with.

CREATE DATABASE DBMaint2008;
GO
USE DBMaint2008;
GO

CREATE TABLE DbccPageTest (intCol1  INT IDENTITY,  intCol2  INT, vcharCol VARCHAR (8000),  lobCol  VARCHAR (MAX));
GO

INSERT INTO DbccPageTest VALUES (1, REPLICATE ('Row1', 600), REPLICATE ('Row1Lobs', 1000));
INSERT INTO DbccPageTest VALUES (2, REPLICATE ('Row2', 600), REPLICATE ('Row2Lobs', 1000));
GO

Using DBCC IND ('DBMaint2008', 'DbccPageTest', -1) , I find that the data page is page ID (1:154). If I dump out that page using DBCC PAGE, I can see both of the records fully contained on the page.

Now I'm going to update the second row to make it 8000+ bytes - forcing it to move to a new page.

UPDATE DbccPageTest SET vcharCol = REPLICATE ('LongRow2', 1000) WHERE intCol2 = 2;
GO

And now looking at page (1:154) with DBCC PAGE again, I can see that the second row has been replaced with:

Slot 1 Offset 0x137a Length 9

Record Type = FORWARDING_STUB        Record Attributes =
Memory Dump @0x66F4D37A

00000000:   049d0000 00010000 00†††††††††††††††††.........
Forwarding to  =  file 1 page 157 slot 0

The record has been replaced with a forwarding record - pointing to the new location of the record on page (1:157).

Now DBCC PAGE doesn't dump out the back-pointer in the forwarded record - so how can we tell how large it is? I'm going to see how large the record is, and then create a clustered index on the table. This will remove the back-pointer from the record without changing anything else about the record. The difference in size will be the back-pointer size.

Doing DBCC PAGE on page (1:157) I get (partial results):

Slot 0 Offset 0x60 Length 8057

Record Type = FORWARDED_RECORD       Record Attributes =  NULL_BITMAP VARIABLE_COLUMNS

Now creating a clustered index and then dumping the page with the second row on it (left as an exercise for the reader :-)):

CREATE UNIQUE CLUSTERED INDEX Dbcc_CL ON DbccPageTest (intCol1);
GO

<figure out which page to look at>

DBCC PAGE ('DBMaint2008', 1, 169, 3);
GO

<partial results>
Slot 0 Offset 0x60 Length 8047

Record Type = PRIMARY_RECORD         Record Attributes =  NULL_BITMAP VARIABLE_COLUMNS

Clearly the back-pointer is 10 bytes. And here's how it breaks down:

• 2 bytes for the extra entry in the variable-length column offset array (see Search Engine Q&A #27: How does the storage engine find variable-length columns? for more info)
• 8 bytes for the record location (2-byte file ID, 4-byte page-in-file, 2-byte slot ID)

Hope this helps!

Page splits are always thought of as expensive, but just how bad are they? In this post I want to create an example to show how much more transaction log is created when a page in an index has to split. I'm going to use the sys.dm_tran_database_transactions DMV to show how much more transaction log is generated when a page has to split. You can find the list of columns and a small amount of explanation of each column in Books Online here - I was reminded of its existence by someone on Twitter (sorry, don't remember who it was and I couldn't find it in search).

In the example, I'm going to create a table with approximately 1000-byte long rows:

CREATE DATABASE PageSplitTest;
GO
USE pagesplittest;
GO

CREATE TABLE BigRows (c1 INT, c2 CHAR (1000));
CREATE CLUSTERED INDEX BigRows_CL ON BigRows (c1);
GO

INSERT INTO BigRows VALUES (1, 'a');
INSERT INTO BigRows VALUES (2, 'a');
INSERT INTO BigRows VALUES (3, 'a');
INSERT INTO BigRows VALUES (4, 'a');
INSERT INTO BigRows VALUES (6, 'a');
INSERT INTO BigRows VALUES (7, 'a');
GO

I've engineered the case where the clustered index data page has space for one more row, and I've left a 'gap' at c1=5. Let's add it as part of an explicit transaction and see how much transaction log is generated:

BEGIN TRAN
INSERT INTO BigRows VALUES (8, 'a');
GO

SELECT [database_transaction_log_bytes_used] FROM sys.dm_tran_database_transactions
WHERE [database_id] = DB_ID ('PageSplitTest');
GO

database_transaction_log_bytes_used
-----------------------------------
1228

That's about what I'd expect for that row. Now what about when I cause a page split by inserting the 'missing' c1=5 row into the full page?

-- commit previous transaction
COMMIT TRAN
GO

BEGIN TRAN
INSERT INTO BigRows VALUES (5, 'a');
GO

SELECT [database_transaction_log_bytes_used] FROM sys.dm_tran_database_transactions
WHERE [database_id] = DB_ID ('PageSplitTest');
GO

database_transaction_log_bytes_used
-----------------------------------
6724

Wow. 5.5x more bytes are written to the transaction log as part of the system transaction that does the split.

The ratio gets worse as the row size gets smaller. For a row with an approximately 100-byte long row (use the same code as above, but change to a CHAR (100), insert 67 rows with a 'gap' somewhere then insert the 68th to cause the split), the two numbers are 328 and 5924 - the split cause 18 times more log to be generated! For a row with an approximately 10-byte long row, I got numbers of 240 and 10436, because I created skewed data (about 256 rows with the key value 8) and then inserted key value 5 which forced a (rare) non-middle page split. That's a ratio of more than 43 times more log generated! You can try this yourself if you want: I changed the code to have a CHAR (10), inserted values 1, 2, 3, 4, 6, 7, then inserted 256 key values of 8 and then 2 of 5. The resulting page had only 6 rows - it split after the key value 5 - the Storage Engine doesn't always do a 50/50 page split. And that's not even causing nasty cascading page-splits, or splits that have to split a page multiple times to fit a new (variable-sized) row in.

Bottom line: page splits don't just cause extra IOs and index fragmentation, they generate a *lot* more transaction log. And all that log has to be (potentially) backed up, log shipped, mirrored....

This is a quick follow-on from my Misconceptions around null bitmap size post.

The null bitmap is *always* present in a data record (i.e. records in a heap or the leaf-level of a clustered index), but is optional in index records if all the columns in the index records are not nullable. The misconception is around what happens when a new column is added to the table. The common misconception is that if you have 8 columns in the table (and hence 8 bits in the null bitmap), if you add a ninth column then SQL Server has to go update every record so the null bitmaps all contain 9 bits. (Same misconception applies to adding the 17th, 25th, 33rd, etc column).

This is usually not true. Let's consider the cases:

• New column is nullable, with a NULL default. The table's metadata records the fact that the new column exists but may not be in the record. This is why the null bitmap also has a count of the number of columns in that particular record. SQL Server can work out whether a column is present in the record or not. So - this is NOT a size-of-data operation - the existing table records are not updated when the new column is added. The records will be updated only when they are updated for some other operation.
• New column is nullable, with a non-NULL default. This IS a size-of-data operation. The non-NULL default forces all existing records to be updated when the column is added, and so the null bitmap will be updated too.
• New column is not-nullable (obviously with a non-NULL default). This IS a size-of-data operation, for the same reasons as above.

Hope this helps.

I'm starting a new series called 'Misconceptions' - a series of short posts that debunk some of the many myths and misconceptions that exist about the way SQL Server behaves. I actually already did the first post a couple of weeks back (Misconceptions around TF 1118) but just went back to re-tag it.

In this post I want to debunk the common myth that the null bitmap only contains bits for nullable columns. It doesn't - it has one bit per column in the table definition, as long as at least one column in the table is nullable. The 'unused' bits are always set to 1, which means 'null'.

And now the proof. I'm going to create two tables, with 10 columns each (meaning that the null bitmap has to have two bytes to store all the bits, plus two bytes for the count of columns in the record). The first table will have all nullable columns. The second will have the first 9 columns not nullable, and the tenth column nullable.

CREATE TABLE t1 (
    c1 INT, c2 INT, c3 INT, c4 INT, c5 INT,
    c6 INT, c7 INT, c8 INT, c9 INT, c10 INT);
GO

CREATE TABLE t2 (
    c1 INT NOT NULL, c2 INT NOT NULL, c3 INT NOT NULL,
    c4 INT NOT NULL, c5 INT NOT NULL, c6 INT NOT NULL,
    c7 INT NOT NULL, c8 INT NOT NULL, c9 INT NOT NULL,
    c10 INT);
GO

INSERT INTO t1 VALUES (1, 2, 3, 4, 5, 6, 7, 8, 9, 10);
GO

INSERT INTO t2 VALUES ( 1, 2, 3, 4, 5, 6, 7, 8, 9, NULL);
GO

And now let's look at the pages themselves. I'll get the pages involved using my sp_AllocationMetadata script (see Inside The Storage Engine: sp_AllocationMetadata - putting undocumented system catalog views to work):

EXEC sp_AllocationMetadata 't1';
EXEC sp_allocationMetadata 't2';
GO

Object Name  Index ID  Alloc Unit ID      Alloc Unit Type  First Page  Root Page  First IAM Page
------------ --------- ------------------ ---------------- ----------- ---------- ---------------
t1           0         72057594042318848  IN_ROW_DATA      (1:152)     (0:0)      (1:153)

Object Name  Index ID  Alloc Unit ID      Alloc Unit Type  First Page  Root Page  First IAM Page
------------ --------- ------------------ ---------------- ----------- ---------- ---------------
t2           0          2057594042384384  IN_ROW_DATA      (1:154)     (0:0)      (1:155)

And now dump them with DBCC PAGE to look at the row structure:

DBCC TRACEON (3604);
GO
DBCC PAGE ('NullTest', 1, 152, 3);
DBCC PAGE ('NullTest', 1, 154, 3);
GO

-- Record dump from t1, all ten columns nullable and not NULL

Record Type = PRIMARY_RECORD         Record Attributes =  NULL_BITMAP
Memory Dump @0x684EC060

00000000:   10002c00 01000000 02000000 03000000 †..,.............
00000010:   04000000 05000000 06000000 07000000 †................
00000020:   08000000 09000000 0a000000 0a0000fc †................

-- Record dump from t2, first nine columns not nullable, tenth column nullable and NULL

Record Type = PRIMARY_RECORD         Record Attributes =  NULL_BITMAP
Memory Dump @0x684EC060

00000000:   10002c00 01000000 02000000 03000000 †..,.............
00000010:   04000000 05000000 06000000 07000000 †................
00000020:   08000000 09000000 21212121 0a0000fe †........!!!!....

If you try this yourself, you may get a different bit pattern for the NULL c10 (I got 0x21212121). It's a bit of a crap-shoot depending on what memory SQL Server reuses to create the record in memory before writing to the page - the 4 bytes of the NULL column aren't overwritten from the previous usage of the memory (and don't need to be).

In the first record, you can see that the null bitmap (underlined and in bold) says there's 10 columns (the 0x0a00 gets byte-reversed into 0x000a) and the null bitmap is 0xfc00, which is 1111110000000000 - 6 unused bits all set to 1 and 10 not-NULL column values.

In the first record, you can see that the null bitmap (underlined and in bold) says there's 10 columns again and the null bitmap this time is 0xfe00, which is 1111111000000000 - 6 unused bits all set to 1, 1 column NULL and 9 columns not-NULL. Column 1 is the far right bit, so column 10 is the tenth from right (the first '1').

This clearly shows that all columns are represented in the null bitmap even if only one of the columns is nullable. It's the same if on the first column in the table is nullable, I'll leave that for you to prove to yourself.

Next up: the next misconception I come across!

There's been a recent flurry of confusion and misconceptions about trace flag 1118 in SQL Server 2008. This trace flag switches allocations in tempdb from single-page at a time for the first 8 pages, to immediately allocate an extent (8 pages). It's used to help alleviate allocation bitmap contention in tempdb under a heavy load of small temp table creation and deletion.

There are multiple points of confusion, which I'll address in turn. Then I'll prove that the trace flag still works in SQL Server 2008.

1) Why is the trace flag usually required in 2000? In SQL 2000, whenever a temp table is created in tempdb and a row inserted, an IAM page must be allocated and a single data page must be allocated. These two pages are both 'single-page' allocations, from a mixed extent (see Inside The Storage Engine: Anatomy of an extent for more info). This means that an SGAM allocation bitmap page must be accessed, and a PFS page must be accessed (see Inside The Storage Engine: GAM, SGAM, PFS and other allocation maps for more info).

With lots of very small temp tables being created, this means the very first SGAM page and the very first PFS page in the data file are accessed/changed by all the threads, leading to latch contention problems on these two pages. When the temp tables are deleted again, the various pages are deallocated, which again needs to access and change the PFS page, and potentially the SGAM page.

There are two ways to alleviate this problem. Firstly, create multiple data files in tempdb - which splits the latch contention over multiple allocation bitmaps (from having allocations come from multiple files) and thus reduces the contention. The general rule of thumb was one tempdb data file for each processor core. Secondly, turn on TF1118, which makes the first 8 data pages in the temp table come from a dedicated extent. This means one extent is allocated from the GAM page, rather than 8 single pages (and potentially 8 accesses to the SGAM page). The pages within the extent are reserved and allocated singly from this extent, as needed. This also cuts down on contention and is documented in KB 328551.

2) What does reserved vs. allocated mean? When an extent is allocated to a table, the 8 pages in the extent are not immediately allocated as well. Allocating an extent means those 8 pages are reserved exclusively for subsequent allocation to that table. The pages are allocated individually as needed, but no other table can allocate them. This is why such extents are called 'dedicated' extents (see my blog post link above for more details). You can see the counters of reserved pages vs. allocated pages in the output from sp_spaceused.

3) Why is the trace flag not required so much in 2005 and 2008? In SQL Server 2005, my team changed the allocation system for tempdb to reduce the possibility of contention. There is now a cache of temp tables. When a new temp table is created on a cold system (just after startup) it uses the same mechanism as for SQL 2000. When it is dropped though, instead of all the pages being deallocated completely, one IAM page and one data page are left allocated, and the temp table is put into a special cache. Subsequent temp table creations will look in the cache to see if they can just grab a pre-created temp table 'off the shelf'. If so, this avoids accessing the allocation bitmaps completely. The temp table cache isn't huge (I think it's 32 tables), but this can still lead to a *big* drop in latch contention in tempdb.

4) Does the trace flag still exist in 2005 and 2008? Yes it does - KB 328551 clearly states:

Note Trace flag -T1118 is also available and supported in Microsoft SQL Server 2005 and SQL Server 2008. However, if you are running SQL Server 2005 or SQL Server 2008, you do not have to apply any hotfix.

Just to make extra-sure (as I'm always paranoid about saying absolutes), I checked with my good friend Ryan Stonecipher, who's the dev lead for the team that owns allocation (and a bunch of other stuff, including DBCC). He confirmed the code is exactly the same in 2008 as it was in 2005. And I prove it to you below too.

5) And why is it sill there in 2005 and 2008? It does the same thing in 2005/2008 as it did in 2000. If the temp table creation/deletion workload is high enough, you can still see latch contention, as the temp table cache won't be enough to completely alleviate the need for creating actual new temp tables, rather than just being able to grab one 'off the shelf'. In that case, using the trace flag to change to extent-based allocation (in *exactly* the same way as for 2000) can help, as can creating more tempdb data files.

As far as data files go though, the number has changed. Instead of a 1-1 mapping between processor cores and tempdb data files (*IF* there's latch contention), now you don't need so many - so the recommendation from the SQL team is the number of data files should be 1/4 to 1/2 the number of processor cores (again, only *IF* you have latch contention). The SQL CAT team has also found that in 2005 and 2008, there's usually no gain from having more than 8 tempdb data files, even for systems with larger numbers of processor cores. Warning: generalization - your mileage may vary - don't post a comment saying this is wrong because your system benefits from 12 data files. It's a generalization, to which there are always exceptions.

6) Why does DBCC IND still show two pages, even with the trace flag on? I've heard of some people being confused by the output of DBCC IND in SQL 2008 when the trace flag is turned on. Creating a single row temp table will only show two pages allocated in the DBCC output - one IAM page and one data page. Yes, that's completely correct - as only two pages are allocated, but the data page comes from a dedicated extent, not a mixed extent. (IAM pages are *always* single-page allocations from mixed-extents).

And now the proof, on SQL 2008.

SELECT @@VERSION;
GO

Microsoft SQL Server 2008 (RTM) - 10.0.1600.22 (Intel X86)

First off, I'll create a temp table without the trace flag enabled, and see what pages the table has allocated, by looking at the first IAM. I'll use a temp table with an 8000+ byte row size, and insert two rows - so we have two data pages for clarity.

DBCC TRACEOFF (1118, -1);
GO

USE tempdb;
GO

CREATE TABLE #temp (c1 INT IDENTITY, c2 CHAR (8000) DEFAULT 'a');
GO
INSERT INTO #temp DEFAULT VALUES;
GO 2

Now I'll figure out what is the first IAM page, using my sp_AllocationMetadata script (see here for the script and details), and dump it with DBCC PAGE to see the single-page allocations it's tracking, and which dedicated extents are allocated to the table:

EXEC sp_AllocationMetadata '#temp';
GO

Object Name    Index ID  Alloc Unit ID        Alloc Unit Type  First Page  Root Page  First IAM Page
-------------- --------- -------------------- ---------------- ----------- ---------- ---------------
#temp__<snip>  0         1152921505223016448  IN_ROW_DATA      (1:158)     (0:0)      (1:199)

DBCC TRACEON (3604);
GO
DBCC PAGE ('tempdb', 1, 199, 3);
GO

<snip>

IAM: Single Page Allocations @0x4A35C08E

Slot 0 = (1:158)                     Slot 1 = (1:200)                     Slot 2 = (0:0)
Slot 3 = (0:0)                       Slot 4 = (0:0)                       Slot 5 = (0:0)
Slot 6 = (0:0)                       Slot 7 = (0:0)                      

IAM: Extent Alloc Status Slot 1 @0x4A35C0C2

(1:0)        - (1:1016)     = NOT ALLOCATED   

As you can clearly see from the partial output of the dump of the IAM page, there are two single-page allocations and no extents allocated to the temp table. This is what should happen when the trace flag is not enabled.

Now I'll do the same thing with the trace flag 1118 enabled.

USE tempdb;
GO

DROP TABLE #temp;
GO

DBCC TRACEON (1118, -1);
GO

CREATE TABLE #temp (c1 INT IDENTITY, c2 CHAR (8000) DEFAULT 'a');
GO
INSERT INTO #temp DEFAULT VALUES;
GO 2

EXEC sp_AllocationMetadata '#temp';
GO

Object Name    Index ID  Alloc Unit ID        Alloc Unit Type  First Page  Root Page  First IAM Page
-------------- --------- -------------------- ---------------- ----------- ---------- ---------------
#temp__<snip>  0         1224979099301904384  IN_ROW_DATA      (1:208)     (0:0)      (1:158)

DBCC TRACEON (3604);
GO
DBCC PAGE ('tempdb', 1, 158, 3);
GO

<snip>

IAM: Single Page Allocations @0x4A8FC08E

Slot 0 = (0:0)                       Slot 1 = (0:0)                       Slot 2 = (0:0)
Slot 3 = (0:0)                       Slot 4 = (0:0)                       Slot 5 = (0:0)
Slot 6 = (0:0)                       Slot 7 = (0:0)                      

IAM: Extent Alloc Status Slot 1 @0x4A8FC0C2

(1:0)        - (1:200)      = NOT ALLOCATED                              
(1:208)      -              =     ALLOCATED                              
(1:216)      - (1:1016)     = NOT ALLOCATED                              

Now as you can clearly see, there are no single-page allocations, and there's a single extent allocated to the table. Proof that trace flag 1118 still does exactly what it should in SQL Server 2008.

Now for a DBCC IND on the table: 

DBCC IND ('tempdb', '#temp', -1);
GO

PageFID PagePID     IAMFID IAMPID      ObjectID    IndexID    
------- ----------- ------ ----------- ----------- -----------
1       158         NULL   NULL        293576084   0
1       208         1      158         293576084   0
1       209         1      158         293576084   0

(I've removed some of the trailing columns for clarity.) We see that it still only lists the two data pages (1:208, 1:209) and the IAM page (1:158) - although an entire extent was allocated to the temp table, only two pages from the extent were actually allocated and used - the rest are reserved for use by that table, but remain unallocated. 

Hopefully this post has cleared up a lot of the confusion around this trace flag and what it does.

The database is in the SIMPLE recovery model. Well, to be completely honest, it's in the FULL recovery model, but there hasn't been a full database backup yet, so as far as transaction log behavior is concerned, it behaves as if it was in SIMPLE (the log can be cleared by a CHECKPOINT) - again, if this makes no sense, go read the TechNet Magazine article. 

And then see how many VLFs it has using the DBCC LOGINFO command (and this is the *only* way to see how many VLFs there are):

DBCC LOGINFO ('LogTestDB');
GO

FileId   FileSize   StartOffset   FSeqNo   Status   Parity CreateLSN
-------- ---------- ------------- -------- -------- ------ -----------
2        1245184    8192          31       2        64     0
2        1245184    1253376       0        0        0      0
2        1245184    2498560       0        0        0      0
2        1499136    3743744       0        0        0      0

We've got 4 VLFs. The Status column tells us whether the VLF is active or not. A status of 2 means the VLF is active, 0 means it's not. The sequence number (FSeqNo) is the logical order of the VLFs within the log. The FileSize is in bytes (so each VLF is about 1.25 MB). Right now there's only one active VLF.

Now I'll engineer the situation in the image above. I'm going to fill the log so that VLFs 1, 2, and 3 are active. Then I'm going to start an explicit transaction that will hold VLF 3 and onwards active. Then I'll continue filling the log so it wraps around and starts to fill up VLF 1 again.

USE LogTestDB;
GO
CREATE TABLE BigRows (c1 INT IDENTITY, c2 CHAR (8000) DEFAULT 'a');
GO

SET NOCOUNT ON;
INSERT INTO BigRows DEFAULT VALUES;
GO 300

I've filled up VLFs 1 and 2, and started on 3. Let's check with DBCC LOGINFO:

DBCC LOGINFO ('LogTestDB');
GO

FileId   FileSize   StartOffset   FSeqNo   Status   Parity CreateLSN
-------- ---------- ------------- -------- -------- ------ -----------
2        1245184    8192          31       2        64     0
2        1245184    1253376       32       2        64     0
2        1245184    2498560       33       2        64     0
2        1499136    3743744       0        0        0      0

As you can see, the first 3 VLFs now have a status of 2 (active), and they're in sequence. Now I'll create an explicit transaction that will prevent VLF 3 and onwards being cleared.

BEGIN TRAN
INSERT INTO BigRows DEFAULT VALUES;
GO

If I explicitly do a CHECKPOINT now, VLFs 1 and 2 will clear:

CHECKPOINT
GO

DBCC LOGINFO ('LogTestDB');
GO

FileId   FileSize   StartOffset   FSeqNo   Status   Parity CreateLSN
-------- ---------- ------------- -------- -------- ------ ----------
2        1245184    8192          31       0        64     0
2        1245184    1253376       32       0        64     0
2        1245184    2498560       33       2        64     0
2        1499136    3743744       0        0        0      0

Now I'll carry on filling up the BigRows table so the log wraps around and starts filling up VLFs 1 and two again.

INSERT INTO BigRows DEFAULT VALUES;
GO 300

DBCC LOGINFO ('LogTestDB');
GO

FileId   FileSize   StartOffset   FSeqNo   Status   Parity CreateLSN
-------- ---------- ------------- -------- -------- ------ ----------
2        1245184    8192          35       2        128    0
2        1245184    1253376       32       0        64     0
2        1245184    2498560       33       2        64     0
2        1499136    3743744       34       2        64     0

You can see that the log has wrapped around now, but VLFs 3 and 4 are still active. Look at the sequence numbers of the active VLFs... the active log is VLF 3 then 4 then 1, with sequence numbers 33 then 34 then 35. Now if I carry on filling up the table, what's going to happen when the log bumps up against VLF 3 that is still active? Will it stop or will it grow?

INSERT INTO BigRows DEFAULT VALUES;
GO 300

DBCC LOGINFO ('LogTestDB');
GO

FileId   FileSize   StartOffset   FSeqNo   Status   Parity CreateLSN
-------- ---------- ------------- -------- -------- ------ ------------------
2        1245184    8192          35       2        128    0
2        1245184    1253376       36       2        128    0
2        1245184    2498560       33       2        64     0
2        1499136    3743744       34       2        64     0
2        253952     5242880       37       2        64     36000000049300052
2        270336     5496832       38       2        64     36000000049300052
2        253952     5767168       0        0        0      36000000107500066
2        335872     6021120       0        0        0      36000000107500066
2        253952     6356992       0        0        0      36000000190700020
2        401408     6610944       0        0        0      36000000190700020
2        253952     7012352       0        0        0      37000000037300040
2        466944     7266304       0        0        0      37000000037300040

The answer is that it grew, and kind of skipped the active VLFs! Look at the sequence numbers. The new sequence of the active log is VLF 3 then 4 then 1 then 2 then 5 then 6, as you can see from the sequence numbers. Once the active transaction I created commits or rolls back, VLFs 3, 4, 1, and 2 can clear and then the 'normal' sequencing of VLFs in the log will resume.

Every VLF has a small header which contains the sequence number of the VLF within the transaction log, so the log can kind of do contortions to work around active VLFs in the middle of the log. Very cool.

Ok - that was fun - now I feel better!

PS In the last couple of DBCC LOGINFO dumps, where the log has wrapped around, you can see that the parity bits for the log blocks in the VLFs have changed, as I explained in one of my previous posts Search Engine Q&A #24: Why can't the transaction log use instant initialization?.

(Yes, Kimberly's lecturing again...)

Here's something that I've seen crop up a lot recently on corruption forums:

Server: Msg 602, Level 21, State 50, Line 1
Could not find row in sysindexes for database ID 10, object ID 1, index ID 1. Run DBCC CHECKTABLE on sysindexes.

This isn't corruption - it comes from trying to attach a 2005 database to a 2000 server. If you try to restore a 2005 database on a 2000 server, you'll see:

Server: Msg 3169, Level 16, State 1, Line 1
The backed-up database has on-disk structure version 611. The server supports version 539 and cannot restore or upgrade this database.
Server: Msg 3013, Level 16, State 1, Line 1
RESTORE DATABASE is terminating abnormally.

This gives a more useful error. Basically, SQL Server is not up-level compatible in terms of the database physical structures. A SQL 2000 server cannot understand the new structures that are in a SQL 2005 database. There's a lot of confusion about this, and why setting database compatibility level is not the same as the physical version of the database. My blog post Search Engine Q&A #13: Difference between database version and database compatibility level has more details.

Trying to do the same thing with a 2008 database on a 2005 server is a bit better. For the attach we get:

Msg 1813, Level 16, State 2, Line 1
Could not open new database 'Dbmaint2008'. CREATE DATABASE is aborted.
Msg 948, Level 20, State 1, Line 1
The database 'Dbmaint2008' cannot be opened because it is version 655. This server supports version 612 and earlier. A downgrade path is not supported.

(Note that 611 is the physical version for all SQL Server 2005 builds, but if VARDECIMAL is enabled, the version gets bumped by one to 612 - long story...)

But the restore error is still a little cryptic:

Msg 3241, Level 16, State 7, Line 1
The media family on device 'c:\sqlskills\dbmaint2008.bck' is incorrectly formed. SQL Server cannot process this media family.
Msg 3013, Level 16, State 1, Line 1
RESTORE DATABASE is terminating abnormally.

Bottom line - you can't attach a higher-version database to a lower-version server.

A thread cropped up on SQLServerCentral involving IAM chain corruption (see Inside the Storage Engine: IAM pages, IAM chains, and allocation units for details of IAM chains). The error from DBCC CHECKDB was:

Server: Msg 2576, Level 16, State 1, Line 1
IAM page (0:0) is pointed to by the previous pointer of IAM page (1:394336) object ID 229575856 index ID 4 but was not detected in the scan.

and there was some discussion of what the error meant, and why the initial page ID in the error of (0:0) means something special. There was a further question of how the errors would differ if the IAM page header was partially zero'd out by an I/O subsystem error.

We're on-stage here at SQL Connections doing a pre-con and I'm not on until this afternoon so I can bang out a quick blog post! I'm going to create a small database and show the difference between the two cases. The error above was from a SQL 2000 database, but the behavior is the same on SQL 2005 and 2008. Here's the script to create the database.

CREATE DATABASE CorruptIAMEXample;
GO
USE CorruptIAMExample;
GO

CREATE TABLE test (c1 INT IDENTITY, c2 CHAR (8000) DEFAULT 'a');
GO
CREATE CLUSTERED INDEX test_cl on test (c1);
GO

SET NOCOUNT ON;
GO
INSERT INTO test DEFAULT VALUES;
GO 1000

The error is saying that the first IAM page in the IAM chain (page 1:153) does not have a reference from metadata. The sysallocunits system table contains a link to the first IAM page, the root page, and the first page. You can see these by querying the sys.system_internals_allocation_units catalog view, or you can see this blog post  - Inside The Storage Engine: sp_AllocationMetadata - putting undocumented system catalog views to work. I corrupted the sysallocunits table so that the link to the first IAM page of the test table was removed. The clue is the first page ID in the error - if it's a (0:0), that's the missing metadata case. For SQL 2000, this can happen if someone manually updates the sysindexes table.

Now what about the other case, where the IAM page itself has a corrupt header? I recreated the database again and corrupted the header of the first IAM page of the test table. Here's the output from DBCC CHECKDB:

and a whole bunch of

errors. This is because the IAM page no longer looks like an IAM page and so DBCC CHECKDB can't process it as such. If I zero out the IAM page completely, DBCC CHECKDB returns basically the same errors as above. 

I've created a zipped backup of the SQL 2005 database in each case:

• Corrupt metadata: CorruptIAMExample1.zip (185.51 kb)
• Corrupt IAM page header: CorruptIAMExample2.zip (181.48 kb)
• Zero'd IAM page: CorruptIAMExample3.zip (168.68 kb)

You'll need to do a RESTORE FILELISTONLY and then maybe move the files when you restore. Have fun!

Way back at the start of me blogging here I wrote a comprehensive description of ghost records and the ghost cleanup process - see Inside the Storage Engine: Ghost cleanup in depth. A question came up in the class I'm teaching this week that's worth answering in a blog post - do ghost records occur in heaps? The answer is no, not during normal processing.

When snapshot isolation is enabled, deletes from a heap are ghosted, as part of the overall versioning process, which can lead to some interesting side-effects. A versioned record has an extra 14-bytes tagged on the end, so a heap record that suddenly becomes versioned is 14-bytes longer - which may mean it doesn't fit on the page any longer. This could lead to it being moved, resulting in a forwarding/forwarded record pair - just because the record was deleted! Now, the page has to be full for this time happen, and the Storage Engine will take steps to avoid this happening for rows less than 32 bytes long - but that's getting a little too deep.

Anyway, I digress. I want to show you the difference between deleting from a clustered index and from a heap. I'm going to create two such tables, then delete row from each and roll it back.

Here's a portion of the results from looking in the transaction log. The line of code where I turn off auto-update stats is just to prevent the auto-create transactions from cluttering up my view of the transaction log.

The first (highlighted) transaction is for the delete/rollback in the clustered index. You can clearly see that the third column shows a log context of ghosting for the LOP_DELETE_ROWS log record, plus the setting of the 'this page has at least one ghost record' in the PFS byte for that page.

The second (unhighlighted) transaction is for the delete/rollback in the heap. Here you can see that it just does a straight delete.

If you look at the data page contents before the rollback in both cases, for the clustered index you'll still be able to see the deleted (ghosted) record, and for the heap you'll see the deleted record really is deleted.

Hope this helps.

After writing the FILESTREAM whitepaper for Microsoft, I've had lots of questions about the structure of the FILESTREAM data container. The FILESTREAM data container is the technical term for the NTFS directory structure where all the FILESTREAM data is stored.

When you want to use FILESTREAM data, you first add a filegroup (during or after database creation):

ALTER DATABASE FileStreamTestDB ADD FILEGROUP FileStreamGroup1 CONTAINS FILESTREAM;
GO

ALTER DATABASE FileStreamTestDB ADD FILE (
     NAME = FSGroup1File, FILENAME = 'C:\Metro Labs\FileStreamTestDB\Documents')
TO FILEGROUP FileStreamGroup1;
GO

The 'file' is actually the pathname to what will become the root directory of the FILESTREAM data container. When it's initially created, it will contain a single file, filestream.hdr, and a single directory $FSLOG. Filestream.hdr is a metadata file describing the data container and the $FSLOG directory is the FILESTREAM equivalent of the database transaction log. You can think of them as equivalent, although the FILESTREAM log has some interesting semantics, which I'll cover in a separate post.

The question I most often get is: are all the FILESTREAM files for a database stored in one gigantic directory? The answer is no.

The root directory of the data container contains one sub-directory for each table (or each partition of a partitioned table). Each of those directories contains a further sub-directory for each FILESTREAM column defined in the table. An example is below, with the screen shot taken after running the following code:

CREATE TABLE FileStreamTest1 (
    DocId UNIQUEIDENTIFIER ROWGUIDCOL NOT NULL UNIQUE,
    DocName VARCHAR (25),
    Document VARBINARY(MAX) FILESTREAM);
GO

CREATE TABLE FileStreamTest2 (
    DocId UNIQUEIDENTIFIER ROWGUIDCOL NOT NULL UNIQUE,
    DocName VARCHAR (25),
    Document1 VARBINARY(MAX) FILESTREAM,
    Document2 VARBINARY(MAX) FILESTREAM);
GO

INSERT INTO FileStreamTest1 VALUES (NEWID (), 'Paul Randal', CAST ('SQLskills.com' AS VARBINARY(MAX)));
INSERT INTO FileStreamTest1 VALUES (NEWID (), 'Kimberly Tripp', CAST ('SQLskills.com' AS VARBINARY(MAX)));
GO

This image shows the FILESTREAM data container for our database that has two tables with FILESTREAM columns, each with a single partition. The first table has a two FILESTREAM columns and the second has a single FILESTREAM column. The filenames of all these directories are GUIDs. In the example, you can see two FILESTREAM files in a column-level directory. The FILESTREAM file names are actually the log-sequence number from the database transaction log at the time the files were created. You can correlate these by looking at the data with DBCC PAGE, but first finding the allocated pages using sp_AllocationMetadata (see this blog post):

EXEC sp_AllocationMetadata FileStreamTest1;
GO

Object Name     Index ID Alloc Unit ID     Alloc Unit Type   First Page Root Page First IAM Page
--------------- -------- ----------------- ---------------   ---------- --------- --------------
FileStreamTest1 0        72057594039697408 IN_ROW_DATA       (1:169)    (0:0)     (1:170)
FileStreamTest1 0        72057594039762944 ROW_OVERFLOW_DATA (0:0)      (0:0)     (0:0)
FileStreamTest1 2        72057594039828480 IN_ROW_DATA       (1:171)    (1:171)   (1:172)

(3 row(s) affected)

Notice there's a nonclustered index as well as the heap - that's the index that's enforcing the uniqueness constraint on the UNIQUEIDENTIFIER column. Now we can use DBCC PAGE to look at the first page of the heap, which will have out data records in:

DBCC TRACEON (3604);
DBCC PAGE (FileStreamTestDB, 1, 169, 3);
GO

<snip>

Slot 0 Offset 0x60 Length 88

Record Type = PRIMARY_RECORD         Record Attributes =  NULL_BITMAP VARIABLE_COLUMNS
Record Size = 88
Memory Dump @0x514EC060

00000000:   30001400 140d5047 2ca9f24f 874d35ca †0.....PG,©òO‡M5Ê
00000010:   e9e77649 03000002 00280058 80506175 †éçvI.....(.X.Pau
00000020:   6c205261 6e64616c 03000000 00000080 †l Randal........
00000030:   140d5047 2ca9f24f 874d35ca e9e77649 †..PG,©òO‡M5ÊéçvI
00000040:   01000000 68020000 00000000 17000000 †....h...........
00000050:   79000000 0c000000 †††††††††††††††††††y.......

Slot 0 Column 1 Offset 0x4 Length 16 Length (physical) 16

DocId = 47500d14-a92c-4ff2-874d-35cae9e77649

Slot 0 Column 2 Offset 0x1d Length 11 Length (physical) 11

DocName = Paul Randal

Document = [Filestream column] Slot 0 Column 3 Offset 0x28 Length 48

ColType = 3                          FileId = -2147483648                 UpdateSeq = 1
CreateLSN = 00000017:00000079:000c (23:121:12)                            TxFMiniVer = 0
XdesId = (0:616)

<snip>

You can see that the CreateLSN I've highlighted above matches the filename of the first FILESTREAM file in the example image.

Hopefully this explains how the FILESTREAM files are stored - more on this in the next post where I'll show how updates and garbage collection are implemented.

In SQL Server 2000 and before, the symptoms of database corruption would occasionally manifest themselves as asserts, such as:

SQL Server Assertion: File: <recbase.cpp>, line=1378 Failed Assertion = 'm_offBeginVar < m_sizeRec'.

Error 5243 is exactly the same except that the database couldn't be determined for some reason. Both of the errors above say that the offset of the variable length column offset array is beyond the end of the record.

I've noticed increasing confusion from these errors being reported - sometimes the worry is that maintenance jobs are causing them, or DBCC CHECKDB is causing them. This may appear to be so but is really just an artifact of the fact that DBCC CHECKDB reads all allocated pages in the database and may read a corrupt page that your normal queries just don't happen to cause to be read. The messages may disappear because other maintenance jobs cause indexes to be rebuilt and so corrupt pages may be deallocated from the database - meaning they won't be read by DBCC CHECKDB.

If you have either torn-page detection or page checksums enabled, you may not ever see these 5242 or 5243 errors as you'll likely see an 824 error instead. The 824 error is raised by the buffer pool when the page is read - before the page can be processed by the record-cracking code that would raise the 5242 or 5243 errors. Bottom line is that 5242 and 5243 says you've got corruption in the structure of a record - the reference numbers at the end of error say exactly what kind of corruption there is - for instance that the record size is invalid or the record type is wrong for the type of page it resides. If you see these errors, you need to go through the motions of recovering from corruption and figuring out what's wrong with your I/O subsystem.

Hope this helps.

Wow - today is all about new content. As if I haven't already blogged about enough stuff to keep you reading through next week, the February issue of TechNet Magazine is now available and contains a feature article I wrote about understanding how logging and recovery work inside SQL Server.

The article covers:

• What is logging?
• What is recovery?
• The transaction log (include logical and physical architecture)
• Recovery models and how they affect the behavior of the transaction log

There's also a ten-minute screencast video where I demonstrate a runaway transaction log.

Check it out at http://technet.microsoft.com/en-us/magazine/2009.02.logging.aspx.

(Posted with permission of the dev team)

Here's an interesting bug that people are hitting. I found out about this while here in Barcelona at TechEd when I got roped into a discussion with a couple of Microsoft colleagues. Their customer was seeing errors like the following:

This error says that the PFS page (see this blog post) has the wrong free-space tracking bits for a text page. In SQL Server 2000, the algorithm to keep track of free space in the PFS pages wasn't perfect so CHECKDB never reported these errors - it would silently fix them. In 2005 we fixed the algorithm (supposedly), so I turned on the reporting of these errors again in CHECKDB.

When I first saw the description from the customer, my first reaction was that it was an I/O subsystem problem causing corruption, but the customer has page checksums turned on, so a corruption would result in an 824 error before an 8914 error. My conclusion then was that there's a bug in the new free-space tracking algorithm. After checking with the dev team, it turns out my suspicions were correct - there is a bug in 2005 SP2. It's fixed in 2005 SP3 and in 2008, but you may see these 8914 errors if you're not running one of those.

Here are the technical details of the problem (slightly edited from the dev team explanation):

The issue was that when minimal logging for LOBs was used (under the SIMPLE recovery model, during BULK INSERT/BCP/Large insert with TABLOCK), extents are being pre-allocated and the pages were being marked 100% full in the PFS page when the pages were allocated. The idea was that all pages eventually will be filled up with LOB data, and by marking them full during allocation we avoid an extra update to the PFS pages when the data is actually put on the page.

Suppose now that 64 pages are pre-allocated, and only 40 or so pages are used and have rows on them. When the transaction commits, the Storage Engine is supposed to deallocate the 24 extra pages that were pre-allocated, and marked 100% full, even though they don’t have any rows on them yet. There was a bug where in a certain case the deallocation wouldn't happen, so you end up with empty pages that have a PFS state of 100%, but don’t have any rows on them.

In general, even though this is a bug in the code, functionality wise, there is nothing wrong with the database, besides a number of additional pages that are empty and allocated to the LOB tree, so as long as the message tells you that the page is supposed to be empty, but is actually marked 100%, nothing can really go wrong with that page. Unfortunately, DBCC will keep reporting these errors.

Although I haven't tried this, my guess is that you can get rid of the empty LOB pages using ALTER INDEX ... REORGANIZE WITH (LOB_COMPACTION = ON). So, if you see some of these errors with no other errors, you may have hit this bug and have nothing really to worry about.