{"id":4679,"date":"2017-01-18T17:27:18","date_gmt":"2017-01-19T01:27:18","guid":{"rendered":"http:\/\/3.209.169.194\/blogs\/paul\/?p=4679"},"modified":"2017-01-18T17:27:18","modified_gmt":"2017-01-19T01:27:18","slug":"code-to-show-rolled-back-transactions-after-a-crash","status":"publish","type":"post","link":"https:\/\/www.sqlskills.com\/blogs\/paul\/code-to-show-rolled-back-transactions-after-a-crash\/","title":{"rendered":"Code to show rolled back transactions after a crash"},"content":{"rendered":"

In Monday’s\u00a0Insider newsletter<\/a>\u00a0I discussed an email question I’d been sent about how to identify the transactions that had rolled back because of a crash, and I said I’d blog some code to do it.<\/p>\n

First of all you need to know the time of the crash. We\u00a0can’t\u00a0get this exactly (from SQL Server) unless SQL Server decides to shut itself down for some reason (like tempdb corruption)\u00a0but we can easily get the time that SQL Server restarted, which is good enough, as we just need to know a time that\u2019s after the transactions started before the crash, and before those transactions finished rolling back after a crash. We can get the startup time from the sqlserver_start_time<\/em> column in the output from sys.dm_os_sys_info<\/em>.<\/p>\n

Then we can search in the transaction log, using the fn_dblog<\/em> function, for LOP_BEGIN_XACT<\/em> log records from before the crash point that have a matching LOP_ABORT_XACT<\/em> log record after the crash point, and with the same transaction ID. This is easy because for LOP_BEGIN_XACT<\/em> log records, there’s a Begin Time<\/em> column, and for LOP_ABORT_XACT<\/em> log records (and, incidentally, for LOP_COMMIT_XACT<\/em> log records), there’s an End Time<\/em> column in the TVF output.<\/p>\n

And there’s a trick you need to use: to get the fn_dblog<\/em> function to read log records from before the\u00a0log clears (by the checkpoints that crash recovery does, in the simple recovery model, or by log backups, in other recovery models), you need to enable trace flag 2537. Now, if do all this too long after crash recovery runs, the log may have overwritten itself and so you won’t be able to get the info you need, but if you’re taking log backups, you could restore a copy of the database to the point just after crash recovery has finished, and then do the investigation.<\/p>\n

After that, the tricky part is matching what those transactions were doing back to business operations that your applications were performing. If you don\u2019t name your transactions, that\u2019s going to be pretty hard, as all you\u2019ve got are the generic names that SQL Server gives transactions (like INSERT<\/em>, DELETE<\/em>, DROPOBJ<\/em>). Whatever the reason you might want this information, your applications should be written so they gracefully handle transaction failures and leave the database in a consistent state (as far as your business rules are concerned \u2013 of course SQL Server leaves the database in a transactionally-consistent state after a crash).<\/p>\n

I’ve written some code and encapsulated it in a proc,\u00a0sp_SQLskillsAbortedTransactions<\/em>, which is shown in full at the end of the post. To use it, you go into the context of the database you’re interested in, and just run the proc. It takes care of enabling and disabling the trace flag.<\/p>\n

Here’s an example of a crash situation and using the proc.<\/p>\n

First I’ll create a table and start a transaction:<\/p>\n

\r\nUSE [master];\r\nGO\r\n\r\nIF DATABASEPROPERTYEX (N'Company', N'Version') > 0\r\nBEGIN\r\n    ALTER DATABASE [Company] SET SINGLE_USER WITH ROLLBACK IMMEDIATE;\r\n    DROP DATABASE [Company];\r\nEND\r\nGO\r\n\r\nCREATE DATABASE [Company];\r\nGO\r\nUSE [Company];\r\nGO\r\n\r\nCREATE TABLE [test] ([c1] INT, [c2] INT, [c3] INT);\r\nGO\r\nINSERT INTO [test] VALUES (0, 0, 0);\r\nGO\r\n\r\nBEGIN TRAN FirstTransaction;\r\nINSERT INTO [Test] VALUES (1, 1, 1);\r\nGO\r\n<\/pre>\n
Now in a second window, I’ll start another transaction, and force the log to flush to disk (as I haven’t generated enough log to have the current log block automatically flush to disk):<\/p>\n
\r\nUSE [Company];\r\nGO\r\n\r\nBEGIN TRAN SecondTransaction;\r\nINSERT INTO [Test] VALUES (2, 2, 2);\r\nGO\r\n\r\nEXEC sp_flush_log;\r\nGO\r\n<\/pre>\n
And in a third window, I’ll force a crash:<\/p>\n
\r\nSHUTDOWN WITH NOWAIT;\r\nGO\r\n<\/pre>\n
After restarting the instance, I can use this code to run my proc:<\/p>\n
\r\nUSE [Company];\r\nGO\r\n\r\nEXEC sp_SQLskillsAbortedTransactions;\r\nGO\r\n<\/pre>\n
\r\nBegin Time               Transaction Name   Started By       Transaction ID\r\n------------------------ ------------------ ---------------- --------------\r\n2017\/01\/18 17:09:36:190  FirstTransaction   APPLECROSS\\Paul  0000:00000374\r\n2017\/01\/18 17:09:40:600  SecondTransaction  APPLECROSS\\Paul  0000:00000375\r\n<\/pre>\n
Cool eh?<\/p>\n
Here’s the code – enjoy!<\/p>\n
\r\n\/*============================================================================\r\n  File:     sp_SQLskillsAbortedTransactions.sql\r\n \r\n  Summary:  This script cracks the transaction log and shows which\r\n            transactions were rolled back after a crash\r\n \r\n  SQL Server Versions: 2012 onwards\r\n------------------------------------------------------------------------------\r\n  Written by Paul S. Randal, SQLskills.com\r\n \r\n  (c) 2017, SQLskills.com. All rights reserved.\r\n \r\n  For more scripts and sample code, check out \r\n    http:\/\/www.SQLskills.com\r\n \r\n  You may alter this code for your own *non-commercial* purposes. You may\r\n  republish altered code as long as you include this copyright and give due\r\n  credit, but you must obtain prior permission before blogging this code.\r\n   \r\n  THIS CODE AND INFORMATION ARE PROVIDED "AS IS" WITHOUT WARRANTY OF \r\n  ANY KIND, EITHER EXPRESSED OR IMPLIED, INCLUDING BUT NOT LIMITED \r\n  TO THE IMPLIED WARRANTIES OF MERCHANTABILITY AND\/OR FITNESS FOR A\r\n  PARTICULAR PURPOSE.\r\n============================================================================*\/\r\n \r\nUSE [master];\r\nGO\r\n \r\nIF OBJECT_ID (N'sp_SQLskillsAbortedTransactions') IS NOT NULL\r\n    DROP PROCEDURE [sp_SQLskillsAbortedTransactions];\r\nGO\r\n \r\nCREATE PROCEDURE sp_SQLskillsAbortedTransactions\r\nAS\r\nBEGIN\r\n    SET NOCOUNT ON;\r\n\r\n    DBCC TRACEON (2537);\r\n \r\n    DECLARE @BootTime\tDATETIME;\r\n    DECLARE @XactID     CHAR (13);\r\n\r\n    SELECT @BootTime = [sqlserver_start_time] FROM sys.dm_os_sys_info;\r\n\r\n    IF EXISTS (SELECT * FROM [tempdb].[sys].[objects]\r\n        WHERE [name] = N'##SQLskills_Log_Analysis')\r\n        DROP TABLE [##SQLskills_Log_Analysis];\r\n\r\n    -- Get the list of started and rolled back transactions from the log\r\n    SELECT\r\n        [Begin Time],\r\n        [Transaction Name],\r\n        SUSER_SNAME ([Transaction SID]) AS [Started By],\r\n        [Transaction ID],\r\n        [End Time],\r\n        0 AS [RolledBackAfterCrash],\r\n        [Operation]\r\n    INTO ##SQLskills_Log_Analysis\r\n    FROM fn_dblog (NULL, NULL)\r\n    WHERE ([Operation] = 'LOP_BEGIN_XACT' AND [Begin Time] < @BootTime) OR ([Operation] = 'LOP_ABORT_XACT' AND [End Time] > @BootTime);\r\n\r\n    DECLARE [LogAnalysis] CURSOR FAST_FORWARD FOR\r\n    SELECT\r\n        [Transaction ID]\r\n    FROM\r\n        ##SQLskills_Log_Analysis;\r\n \r\n    OPEN [LogAnalysis];\r\n \r\n    FETCH NEXT FROM [LogAnalysis] INTO @XactID;\r\n \r\n    WHILE @@FETCH_STATUS = 0\r\n    BEGIN\r\n        IF EXISTS (\r\n            SELECT [End Time] FROM ##SQLskills_Log_Analysis\r\n            WHERE [Operation] = 'LOP_ABORT_XACT' AND [Transaction ID] = @XactID)\r\n        UPDATE ##SQLskills_Log_Analysis SET [RolledBackAfterCrash] = 1\r\n            WHERE [Transaction ID] = @XactID\r\n            AND [Operation] = 'LOP_BEGIN_XACT';\r\n\r\n        FETCH NEXT FROM [LogAnalysis] INTO @XactID;\r\n    END;\r\n \r\n    CLOSE [LogAnalysis];\r\n    DEALLOCATE [LogAnalysis];\r\n \r\n    SELECT\r\n        [Begin Time],\r\n        [Transaction Name],\r\n        [Started By],\r\n        [Transaction ID]\r\n    FROM ##SQLskills_Log_Analysis\r\n    WHERE [RolledBackAfterCrash] = 1;\r\n \r\n    DBCC TRACEOFF (2537);\r\n\r\n    DROP TABLE ##SQLskills_Log_Analysis;\r\nEND\r\nGO\r\n \r\nEXEC sys.sp_MS_marksystemobject [sp_SQLskillsAbortedTransactions];\r\nGO\r\n \r\n-- USE [Company]; EXEC sp_SQLskillsAbortedTransactions;\r\n<\/pre>\n","protected":false},"excerpt":{"rendered":"
In Monday’s\u00a0Insider newsletter\u00a0I discussed an email question I’d been sent about how to identify the transactions that had rolled back because of a crash, and I said I’d blog some code to do it. First of all you need to know the time of the crash. We\u00a0can’t\u00a0get this exactly (from SQL Server) unless SQL Server […]<\/p>\n","protected":false},"author":5,"featured_media":0,"comment_status":"open","ping_status":"closed","sticky":false,"template":"","format":"standard","meta":{"footnotes":""},"categories":[38,48,98],"tags":[],"class_list":["post-4679","post","type-post","status-publish","format-standard","hentry","category-example-scripts","category-inside-the-storage-engine","category-transaction-log"],"yoast_head":"\nCode to show rolled back transactions after a crash - Paul S. Randal<\/title>\n<meta name=\"robots\" content=\"index, follow, max-snippet:-1, max-image-preview:large, max-video-preview:-1\" \/>\n<link rel=\"canonical\" href=\"https:\/\/www.sqlskills.com\/blogs\/paul\/code-to-show-rolled-back-transactions-after-a-crash\/\" \/>\n<meta property=\"og:locale\" content=\"en_US\" \/>\n<meta property=\"og:type\" content=\"article\" \/>\n<meta property=\"og:title\" content=\"Code to show rolled back transactions after a crash - Paul S. Randal\" \/>\n<meta property=\"og:description\" content=\"In Monday’s\u00a0Insider newsletter\u00a0I discussed an email question I’d been sent about how to identify the transactions that had rolled back because of a crash, and I said I’d blog some code to do it. First of all you need to know the time of the crash. We\u00a0can’t\u00a0get this exactly (from SQL Server) unless SQL Server […]\" \/>\n<meta property=\"og:url\" content=\"https:\/\/www.sqlskills.com\/blogs\/paul\/code-to-show-rolled-back-transactions-after-a-crash\/\" \/>\n<meta property=\"og:site_name\" content=\"Paul S. Randal\" \/>\n<meta property=\"article:published_time\" content=\"2017-01-19T01:27:18+00:00\" \/>\n<meta name=\"author\" content=\"Paul Randal\" \/>\n<meta name=\"twitter:label1\" content=\"Written by\" \/>\n\t<meta name=\"twitter:data1\" content=\"Paul Randal\" \/>\n\t<meta name=\"twitter:label2\" content=\"Est. reading time\" \/>\n\t<meta name=\"twitter:data2\" content=\"5 minutes\" \/>\n<script type=\"application\/ld+json\" class=\"yoast-schema-graph\">{\"@context\":\"https:\/\/schema.org\",\"@graph\":[{\"@type\":\"WebPage\",\"@id\":\"https:\/\/www.sqlskills.com\/blogs\/paul\/code-to-show-rolled-back-transactions-after-a-crash\/\",\"url\":\"https:\/\/www.sqlskills.com\/blogs\/paul\/code-to-show-rolled-back-transactions-after-a-crash\/\",\"name\":\"Code to show rolled back transactions after a crash - Paul S. Randal\",\"isPartOf\":{\"@id\":\"https:\/\/www.sqlskills.com\/blogs\/paul\/#website\"},\"datePublished\":\"2017-01-19T01:27:18+00:00\",\"author\":{\"@id\":\"https:\/\/www.sqlskills.com\/blogs\/paul\/#\/schema\/person\/ffcec826c18782e1e0adf173826a7fce\"},\"breadcrumb\":{\"@id\":\"https:\/\/www.sqlskills.com\/blogs\/paul\/code-to-show-rolled-back-transactions-after-a-crash\/#breadcrumb\"},\"inLanguage\":\"en-US\",\"potentialAction\":[{\"@type\":\"ReadAction\",\"target\":[\"https:\/\/www.sqlskills.com\/blogs\/paul\/code-to-show-rolled-back-transactions-after-a-crash\/\"]}]},{\"@type\":\"BreadcrumbList\",\"@id\":\"https:\/\/www.sqlskills.com\/blogs\/paul\/code-to-show-rolled-back-transactions-after-a-crash\/#breadcrumb\",\"itemListElement\":[{\"@type\":\"ListItem\",\"position\":1,\"name\":\"Home\",\"item\":\"https:\/\/www.sqlskills.com\/blogs\/paul\/\"},{\"@type\":\"ListItem\",\"position\":2,\"name\":\"Code to show rolled back transactions after a crash\"}]},{\"@type\":\"WebSite\",\"@id\":\"https:\/\/www.sqlskills.com\/blogs\/paul\/#website\",\"url\":\"https:\/\/www.sqlskills.com\/blogs\/paul\/\",\"name\":\"Paul S. Randal\",\"description\":\"In Recovery...\",\"potentialAction\":[{\"@type\":\"SearchAction\",\"target\":{\"@type\":\"EntryPoint\",\"urlTemplate\":\"https:\/\/www.sqlskills.com\/blogs\/paul\/?s={search_term_string}\"},\"query-input\":{\"@type\":\"PropertyValueSpecification\",\"valueRequired\":true,\"valueName\":\"search_term_string\"}}],\"inLanguage\":\"en-US\"},{\"@type\":\"Person\",\"@id\":\"https:\/\/www.sqlskills.com\/blogs\/paul\/#\/schema\/person\/ffcec826c18782e1e0adf173826a7fce\",\"name\":\"Paul Randal\",\"image\":{\"@type\":\"ImageObject\",\"inLanguage\":\"en-US\",\"@id\":\"https:\/\/www.sqlskills.com\/blogs\/paul\/#\/schema\/person\/image\/\",\"url\":\"https:\/\/secure.gravatar.com\/avatar\/0b6a266bba2f088f2551ef529293001bd73bf026bc1908b9866728c062beeeb6?s=96&d=mm&r=g\",\"contentUrl\":\"https:\/\/secure.gravatar.com\/avatar\/0b6a266bba2f088f2551ef529293001bd73bf026bc1908b9866728c062beeeb6?s=96&d=mm&r=g\",\"caption\":\"Paul Randal\"},\"sameAs\":[\"http:\/\/3.209.169.194\/blogs\/paul\"],\"url\":\"https:\/\/www.sqlskills.com\/blogs\/paul\/author\/paul\/\"}]}<\/script>\n<!-- \/ Yoast SEO plugin. -->","yoast_head_json":{"title":"Code to show rolled back transactions after a crash - Paul S. Randal","robots":{"index":"index","follow":"follow","max-snippet":"max-snippet:-1","max-image-preview":"max-image-preview:large","max-video-preview":"max-video-preview:-1"},"canonical":"https:\/\/www.sqlskills.com\/blogs\/paul\/code-to-show-rolled-back-transactions-after-a-crash\/","og_locale":"en_US","og_type":"article","og_title":"Code to show rolled back transactions after a crash - Paul S. Randal","og_description":"In Monday’s\u00a0Insider newsletter\u00a0I discussed an email question I’d been sent about how to identify the transactions that had rolled back because of a crash, and I said I’d blog some code to do it. First of all you need to know the time of the crash. We\u00a0can’t\u00a0get this exactly (from SQL Server) unless SQL Server […]","og_url":"https:\/\/www.sqlskills.com\/blogs\/paul\/code-to-show-rolled-back-transactions-after-a-crash\/","og_site_name":"Paul S. Randal","article_published_time":"2017-01-19T01:27:18+00:00","author":"Paul Randal","twitter_misc":{"Written by":"Paul Randal","Est. reading time":"5 minutes"},"schema":{"@context":"https:\/\/schema.org","@graph":[{"@type":"WebPage","@id":"https:\/\/www.sqlskills.com\/blogs\/paul\/code-to-show-rolled-back-transactions-after-a-crash\/","url":"https:\/\/www.sqlskills.com\/blogs\/paul\/code-to-show-rolled-back-transactions-after-a-crash\/","name":"Code to show rolled back transactions after a crash - Paul S. Randal","isPartOf":{"@id":"https:\/\/www.sqlskills.com\/blogs\/paul\/#website"},"datePublished":"2017-01-19T01:27:18+00:00","author":{"@id":"https:\/\/www.sqlskills.com\/blogs\/paul\/#\/schema\/person\/ffcec826c18782e1e0adf173826a7fce"},"breadcrumb":{"@id":"https:\/\/www.sqlskills.com\/blogs\/paul\/code-to-show-rolled-back-transactions-after-a-crash\/#breadcrumb"},"inLanguage":"en-US","potentialAction":[{"@type":"ReadAction","target":["https:\/\/www.sqlskills.com\/blogs\/paul\/code-to-show-rolled-back-transactions-after-a-crash\/"]}]},{"@type":"BreadcrumbList","@id":"https:\/\/www.sqlskills.com\/blogs\/paul\/code-to-show-rolled-back-transactions-after-a-crash\/#breadcrumb","itemListElement":[{"@type":"ListItem","position":1,"name":"Home","item":"https:\/\/www.sqlskills.com\/blogs\/paul\/"},{"@type":"ListItem","position":2,"name":"Code to show rolled back transactions after a crash"}]},{"@type":"WebSite","@id":"https:\/\/www.sqlskills.com\/blogs\/paul\/#website","url":"https:\/\/www.sqlskills.com\/blogs\/paul\/","name":"Paul S. Randal","description":"In Recovery...","potentialAction":[{"@type":"SearchAction","target":{"@type":"EntryPoint","urlTemplate":"https:\/\/www.sqlskills.com\/blogs\/paul\/?s={search_term_string}"},"query-input":{"@type":"PropertyValueSpecification","valueRequired":true,"valueName":"search_term_string"}}],"inLanguage":"en-US"},{"@type":"Person","@id":"https:\/\/www.sqlskills.com\/blogs\/paul\/#\/schema\/person\/ffcec826c18782e1e0adf173826a7fce","name":"Paul Randal","image":{"@type":"ImageObject","inLanguage":"en-US","@id":"https:\/\/www.sqlskills.com\/blogs\/paul\/#\/schema\/person\/image\/","url":"https:\/\/secure.gravatar.com\/avatar\/0b6a266bba2f088f2551ef529293001bd73bf026bc1908b9866728c062beeeb6?s=96&d=mm&r=g","contentUrl":"https:\/\/secure.gravatar.com\/avatar\/0b6a266bba2f088f2551ef529293001bd73bf026bc1908b9866728c062beeeb6?s=96&d=mm&r=g","caption":"Paul Randal"},"sameAs":["http:\/\/3.209.169.194\/blogs\/paul"],"url":"https:\/\/www.sqlskills.com\/blogs\/paul\/author\/paul\/"}]}},"_links":{"self":[{"href":"https:\/\/www.sqlskills.com\/blogs\/paul\/wp-json\/wp\/v2\/posts\/4679","targetHints":{"allow":["GET"]}}],"collection":[{"href":"https:\/\/www.sqlskills.com\/blogs\/paul\/wp-json\/wp\/v2\/posts"}],"about":[{"href":"https:\/\/www.sqlskills.com\/blogs\/paul\/wp-json\/wp\/v2\/types\/post"}],"author":[{"embeddable":true,"href":"https:\/\/www.sqlskills.com\/blogs\/paul\/wp-json\/wp\/v2\/users\/5"}],"replies":[{"embeddable":true,"href":"https:\/\/www.sqlskills.com\/blogs\/paul\/wp-json\/wp\/v2\/comments?post=4679"}],"version-history":[{"count":0,"href":"https:\/\/www.sqlskills.com\/blogs\/paul\/wp-json\/wp\/v2\/posts\/4679\/revisions"}],"wp:attachment":[{"href":"https:\/\/www.sqlskills.com\/blogs\/paul\/wp-json\/wp\/v2\/media?parent=4679"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"https:\/\/www.sqlskills.com\/blogs\/paul\/wp-json\/wp\/v2\/categories?post=4679"},{"taxonomy":"post_tag","embeddable":true,"href":"https:\/\/www.sqlskills.com\/blogs\/paul\/wp-json\/wp\/v2\/tags?post=4679"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}