Disaster recovery 101: dealing with negative SPIDS (-2 and -3)

Every so often I get asked how to deal with SPID -2 and once in a blue moon I get asked about SPID -3. Neither of these SPIDs will show up in sysprocesses or sys.dm_exec_requests or sys.dm_exec_sessions, but they’re both valid SPIDs.

SPID -2 is an orphaned DTC transaction.

SPID -3 is a deferred transaction.

Both SPIDs will hold locks that can cause blocking, and these are often how they’re noticed in the first place.

SPID -4 is a transaction blocked waiting for a latch but the latch owner can’t be determined. There’s no good way to deal with these.

For a good walkthrough of how to kill an orphaned DTC transaction if you cannot resurrect it any other way, see this excellent post by Ajmer Dhariwal (ex-Product Support, and a student in our London Immersion Event this week).

A deferred transaction is one where the transaction could not be recovered fully because of an I/O error or a gross file system problem like an unavailable file. Books Online has a good description here – so I won’t regurgitate it.

What I’d like to do is show you how to create a deferred transaction so you can actually see SPID -3 and how to tell if you have deferred transactions.

First off I’ll create a database, with an extra file sitting on a USB drive (G:) in my laptop.

CREATE DATABASE [DeferredTran];
GO

ALTER DATABASE [DeferredTran] ADD FILEGROUP [FG_USB];
GO

ALTER DATABASE [DeferredTran] ADD FILE (
    NAME = [FG_USB_1], FILENAME = N'G:\FG_USB_1.ndf')
TO FILEGROUP [FG_USB];
GO

BACKUP DATABASE [DeferredTran] TO DISK = N'C:\SQLskills\DeferredTran.bck' WITH INIT;
GO

Next I’ll create a table on the USB filegroup, and create an explicit transaction and force the log and data to disk.

USE [DeferredTran];
GO

CREATE TABLE [t1] ([c1] INT) ON [FG_USB];
GO

BEGIN TRAN
INSERT INTO [t1] VALUES (1);
GO

CHECKPOINT;
GO

In another window, crash SQL Server using SHUTDOWN WITH NOWAIT. Then unplug the USB drive and restart SQL Server.

Trying to access the database will fail, because the boot page says the database wasn’t shut down cleanly, but the data file necessary to roll back our transaction isn’t available.

USE [DeferredTran];
GO

Msg 945, Level 14, State 2, Line 1
Database 'DeferredTran' cannot be opened due to inaccessible files or insufficient memory or disk space.  See the SQL Server errorlog for details.

ALTER DATABASE [DeferredTran] SET ONLINE;
GO

Msg 5120, Level 16, State 5, Line 1
Unable to open the physical file "G:\FG_USB_1.ndf". Operating system error 2: "2(The system cannot find the file specified.)".
Msg 945, Level 14, State 2, Line 1
Database 'DeferredTran' cannot be opened due to inaccessible files or insufficient memory or disk space.  See the SQL Server errorlog for details.
Msg 5069, Level 16, State 1, Line 1
ALTER DATABASE statement failed.

By explicitly setting that file offline, we can bring the database online, albeit with a deferred transaction. BE CAREFUL! The only way to bring that file online again is to restore it from a backup!

ALTER DATABASE [DeferredTran] MODIFY FILE (NAME = N'FG_USB_1', OFFLINE);
GO

ALTER DATABASE [DeferredTran] SET ONLINE;
GO

From the error log…

2011-06-24 09:54:27.650 spid51       Setting database option ONLINE to ON for database DeferredTran.
2011-06-24 09:54:27.650 spid51       Starting up database 'DeferredTran'.
2011-06-24 09:54:27.680 spid51       Filegroup FG_USB in database DeferredTran is unavailable because it is Offline. Restore or alter the filegroup to be available.
2011-06-24 09:54:27.690 spid22s      Error: 3410, Severity: 16, State: 1.
2011-06-24 09:54:27.690 spid22s      Data in filegroup FG_USB is offline, and deferred transactions exist. Use RESTORE to recover the filegroup, or drop the filegroup if you never intend to recover it. Log truncation cannot occur until this condition is resolved.
2011-06-24 09:54:27.690 spid22s      Error: 3314, Severity: 21, State: 1.
2011-06-24 09:54:27.690 spid22s      During undoing of a logged operation in database 'DeferredTran', an error occurred at log record ID (24:101:23). Typically, the specific failure is logged previously as an error in the Windows Event Log service. Restore the database or file from a backup,
2011-06-24 09:54:27.690 spid22s      Error: 3414, Severity: 21, State: 2.
2011-06-24 09:54:27.690 spid22s      An error occurred during recovery, preventing the database 'DeferredTran' (database ID 22) from restarting. Diagnose the recovery errors and fix them, or restore from a known good backup. If errors are not corrected or expected, contact Technical Support.

Look at the part about log truncation – until we resolve the deferred transaction, it will hold the transaction log active and the log will grow and grow and grow… in this case, the database remains SUSPECT and unusable though, but if the transaction was deferred because of a restore issue, the database may be online and usable.

We can tell if there are deferred transactions using the sys.dm_tran_database_transactions DMV. A deferred transaction will have a transaction status with the 0x80000 bit set (undocumented).

SELECT * FROM sys.dm_tran_database_transactions'
WHERE [database_transaction_status] & 0x80000 = 0x80000;
GO

And if we look in sys.dm_tran_locks we’ll see that it’s holding locks that could cause our applications to block:

SELECT
    [request_session_id] AS [SPID],
    [resource_type] AS [LockType],
    DB_NAME ([resource_database_id]) AS [DB],
    [resource_description] AS [Resource],
    [resource_associated_entity_id] AS [ResourceID],
    [request_mode] AS [Mode],
    [request_status] AS [Status]
FROM sys.dm_tran_locks
WHERE [request_session_id] < 0;
GO

SPID LockType DB           Resource ResourceID        Mode Status
---- -------- ------------ -------- ----------------- ---- ------
-3   RID      DeferredTran 3:8:0    72057594038779904 X    GRANT
-3   PAGE     DeferredTran 3:8      72057594038779904 IX   GRANT
-3   OBJECT   DeferredTran          2105058535        IX   GRANT

Notice that there’s no database S lock as all regular connections have, as this SPID isn’t a regular connection. You won’t be able to see the SPID in any other way.

To recover from this we need to restore the offline file from a backup. We’ll also need to perform a tail-log backup so we can restore it to bring the restored file up-to-date.

BACKUP LOG [DeferredTran] TO DISK = N'C:\SQLskills\DeferredTran_log.bck';
GO

Msg 945, Level 14, State 2, Line 1
Database 'DeferredTran' cannot be opened due to inaccessible files or insufficient memory or disk space.  See the SQL Server errorlog for details.
Msg 3013, Level 16, State 1, Line 1
BACKUP LOG is terminating abnormally.

We have to use WITH NO_TRUNCATE…

BACKUP LOG [DeferredTran] TO DISK = N'C:\SQLskills\DeferredTran_log.bck'
WITH NO_TRUNCATE, INIT;
GO

RESTORE DATABASE [DeferredTran] FILE = N'FG_USB_1'
FROM DISK = N'C:\SQLskills\DeferredTran.bck'
WITH MOVE N'FG_USB_1' TO N'C:\SQLskills\FG_USB_1.ndf', NORECOVERY;
GO

RESTORE LOG [DeferredTran]
FROM DISK = N'C:\SQLskills\DeferredTran_log.bck'
WITH NORECOVERY;
GO

RESTORE DATABASE [DeferredTran] WITH RECOVERY;
GO;

And the output from the final RESTORE statement is:

1 transactions rolled back in database 'DeferredTran' (22). This is an informational message only. No user action is required.

RESTORE DATABASE successfully processed 0 pages in 0.006 seconds (0.000 MB/sec).

So there you are – an easy way to create deferred transactions and negative SPIDs to play with.

Enjoy!