This Blog provides information about running SAP Applications on the Microsoft Platform. The Blog is written by people who are working with SAP on the Microsoft Platform for decades.
Today I want to start a small blog series for the deadlock analysis with SQL Server. In the first part we will cover the basics about deadlocks, why and when they occur and how to capture them. The second part which will be more exciting will cover the basic analysis of deadlocks and the different approaches to solve and to avoid them. The last part takes the excitement to the extreme and will be an introduction and discussion of some in-depth SQL Scripts, which will help us to analyze and understand the deadlocks in more detail.
Unless otherwise stated the provided information and scripts run on SQL Server 2005 or higher.
A deadlock occurs, when multiple threads are waiting on each other’s resources. All threads are waiting, for the other thread(s) to release their resources, which they will never do (as they wait for the other resources as well). A deadlock has to contain at least two nodes, but can contain much more than that; the biggest deadlock I saw had 13 nodes. The most common misconception about deadlocks is that they are a problem of the database system - the database should solve them on its own and should not throw any error to the application. But deadlocks are happening in all database systems that are using locks to guarantee the logical integrity of the data. Deadlock detection and cancellation is a database feature to prevent stale locks, which otherwise would never get resolved by their own.
You can easily create a deadlock with two nodes on SQL Server by the following procedure:
IF EXISTS (SELECT * FROM sys.databases WHERE name = N'DL_Analysis')
DROP DATABASE [DL_Analysis]
CREATE DATABASE [DL_Analysis]
ALTER DATABASE [DL_Analysis] SET RECOVERY SIMPLE
SET ANSI_NULLS ON
SET ANSI_PADDING ON
SET QUOTED_IDENTIFIER ON
CREATE TABLE [SAPTABLE](
[NAME] [nvarchar](40) COLLATE SQL_Latin1_General_CP850_BIN2 NOT NULL DEFAULT N' ',
[SPRSL] [nvarchar](1) COLLATE SQL_Latin1_General_CP850_BIN2 NOT NULL DEFAULT N' ',
[TEXT] [nvarchar](70) COLLATE SQL_Latin1_General_CP850_BIN2 NOT NULL DEFAULT N' ',
CONSTRAINT [SAPTABLE~0] PRIMARY KEY CLUSTERED
CREATE NONCLUSTERED INDEX [SAPTABLE~NAM] ON [SAPTABLE]([NAME]) ON [PRIMARY]
-- Insert two rows of test data
INSERT INTO SAPTABLE([NAME],[SPRSL],[TEXT]) VALUES (N'Miller',N'E',N'English name')
INSERT INTO SAPTABLE([NAME],[SPRSL],[TEXT]) VALUES (N'Schulze',N'D',N'Deutscher Name.')
on connection ConA run:
-- Update the first row, starting with Miller
UPDATE SAPTABLE SET SPRSL = N'D' WHERE NAME = N'Miller' AND SPRSL = N'E'
-- Now run the script for the deadlock partner
-- We will wait in this connection for 1 minute....
-- .. and then will execute the next Update here (now Schulze)
UPDATE SAPTABLE SET SPRSL = N'E' WHERE NAME = N'Schulze' AND SPRSL = N'D'
-- Deadlock occurred. ROLLBACK -- to be able to repeat it
This transaction will update column SPRSL, where NAME equals to ‘Miller’, than it will wait for one minute and then it will try to update the row, where NAME = ‘Schulze’
-- Run both updates at once, starting with Schulze
UPDATE SAPTABLE SET SPRSL = N'F' WHERE NAME = N'Schulze' AND SPRSL = N'D'
UPDATE SAPTABLE SET SPRSL = N'F' WHERE NAME = N'Miller' AND SPRSL = N'E'
-- Deadlock occurred.
ROLLBACK -- to be able to repeat it
It will update the row where NAME = ‘Schulze’ and then the row where NAME = ‘Miller’. It can update the row ‘Schulze’, but has to wait on the lock on row ‘Miller’, as the request on connection ConA has already changed it and has an exclusive lock on it.
Msg 1205, Level 13, State 51, Line 3 Transaction (Process ID 60) was deadlocked on lock resources with another process and has been chosen as the deadlock victim. Rerun the transaction.
When a deadlock occurs in a SAP system, we do not get much information in the ST22 dumps or within the SQL Server error log. The database monitor of the SAP system (Transaction DBACOCKPIT) shows the occurred deadlocks, the table on which the deadlock occurs and the work process information. This is only done for the ABAP part of the system (no Java deadlocks are shown here) and it shows only the victims; there is no information about the winning processes.
Therefore SAP provides a note (32129 (login required)) to setup a more detailed deadlock tracing for SQL Server. This note sets several SQL Server trace flags and configures a SQL Server Profiler Trace.
The trace flags that get set are:
Deadlock victim/chain output
This trace flag produces detailed information about deadlocks, including participants and victims.
XML Deadlock Information to the error log
This trace flag pipes XML Deadlock information to the error log
Send trace output to the error log
This trace flag is necessary to get the above debug information into the error log. If it is not set, the other trace flags will not be able to write to the SQL Server Error log.
For the background profiler trace you have to execute the script that is attached to the note. It will create a profiler trace to a local file in your SQL Server log directory (where the Error Log lives), which will only contain the deadlock event of the SQL Server events. The trace will be registered as a startup trace and will be active instantly.
Once all of this (SQL Profiler Trace and Trace flags) is in place, one has to wait, that the deadlock occurs again. When this happens, a deadlock graph is written to the trace file and as XML written to the error log. These two files we need for a first deadlock analysis.
When you open the deadlock trace file (e.g. deadlock01_20130201-120016.trc) in the SQL Server Profiler, you can examine the deadlock in a graphical format:
You can identify the two nodes and some of the locks they held. Each thread is represented with an oval; the one which is crossed is the one that was chooses as deadlock victim. The other one is the deadlock winner. The ovals are showing more information about the thread:
Server process id
The Session ID (SPID) of the request
Server batch id
An internal reference number for the batch, where the statement is running in. In an SAP system it is zero.
Execution context id
When the query is executed in parallel, this shows the ID of one of the parallel running threads. In an SAP system it is mostly zero.
If the thread has an associated deadlock priority, it is shown here. SAP does not use deadlock priority.
The amount of transaction log, that was already generated by this thread
An internal reference number for the transaction.
An internal reference number for the state of the transaction.
In the middle of the graph, in the rectangles, information about the two participating locks is shown:
Type of lock the thread holds or requests. Common values are “Key Lock”, “Page Lock” or ”RID Lock”
Heap or B-Tree ID, the ID of the internal allocation structure of the table or partition
The ObjectID that is associated to the HoBt ID. The name of the object can be retrieved via the OBJECT_NAME function.
The name of the index, on which the locks are held or requested.
The lines between the threads and locks are representing the held and requested locks. In our example the right thread (Winner) holds an X lock (Owner Mode: X) on the upper lock and requests a U lock (Request Mode: U) to the lower lock. The victim thread holds the X lock on the lower lock and requests a U-lock for the upper lock. Following the lines you can circle around between the ovals and will never come to an end – a deadlock occurred.
We now have information about the threads and the locks, but what is about the statement that causes all this? Where can I find it?
It is revealed when you hover over the left and right ovals:
In our example it just shows the script we ran before.
You can extract all information about the deadlock from the SQL Server deadlock trace in XML format. Therefore right click on the line with the deadlock and choose “Extract event data”:
You then can save this event as an XDL file (SQL Server Deadlock File). When you double click the file it gets opened it the SQL Server Management Studio and shown in a graphical format (as in the SQL Profiler). But when you open it with a text editor (e.g. notepad) it is opened as an XML file.
I’d like to describe the content of this XML file in more detail, as it contains quite useful information about the deadlock and the participating processes. The XML has a structure like:
The surrounding bracket around all deadlocks (most of the time only one) deadlocks
First deadlock, with Victim Process ID
The list of involved Processes (most of the time only two)
Process number one, the victim. This section contains many attributes about the Process itself, they will be discussed later
The statement that causes the deadlock, which SQL Handle and (sometimes) as a prepared statement.
The complete input buffer of the process, in an SAP system most of the time only one statement, in our example the complete script of the connection. Has the statement from the ExecutionStack included.
Process number two, the survivor or winner of the deadlock
The same information as for the victim.
All the resources that are involved in the deadlock. Mostly only a list of two KEY locks, but might be other as well (e.g. PAGE locks)
Detailed information about the first lock itself, they will be discussed later.
The list of owner of this resource, mostly one process.
The owner with process id and lock mode (X, U, S etc.)
The list of waiter of this resource; can be more than one.
The waiter with process id and lock mode (X, U, S etc.) and request type (WAIT).
Detailed information about the second lock.
The same information as for the first lock.
Here is an example (fragment), how this looks like in our case:
id="process3f9f4c8" taskpriority="0" logused="684" waitresource="KEY: 11:72057594038779904 (7e576f73234b)" waittime="2185" ownerId="286942698" transactionname="user_transaction" lasttranstarted="2013-02-01T12:00:44.620" XDES="0x86dab950" lockMode="U" schedulerid="1" kpid="3640" status="suspended" spid="59" sbid="0" ecid="0" priority="0" trancount="2" lastbatchstarted="2013-02-01T12:00:44.537" lastbatchcompleted="2013-02-01T11:51:13.350" clientapp="Microsoft SQL Server Management Studio - Query" hostname="MyHostname" hostpid="4868" Loginname="MyDomain\User" isolationlevel="read committed (2)" xactid="286942698" currentdb="11" lockTimeout="4294967295" clientoption1="671090784" clientoption2="390200"
<frame procname="adhoc" line="13" stmtstart="110" sqlhandle="0x0200000060960b1fa1d4f597f9ad060adbabb997bfa96045"> UPDATE [SAPTABLE] set [SPRSL] = @1 WHERE [NAME]=@2 AND [SPRSL]=@3 </frame> <frame procname="adhoc" line="13" stmtstart="724" sqlhandle="0x0200000047ca5e0e3acdcd8f7c7dc91d718edf54ac1624ac"> UPDATE SAPTABLE SET SPRSL = N'E' WHERE NAME = N'Schulze' AND SPRSL = N'D' -- Deadlock occured </frame>
use [DL_Analysis] BEGIN TRANSACTION -- Update the first row, starting with Miller UPDATE SAPTABLE SET SPRSL = N'D' WHERE NAME = N'Miller' AND SPRSL = N'E' -- Now run the script for the deadlock partner -- we will wait in this connection for 10 seconds .... WAITFOR DELAY '00:00:10' -- .. and then will execute the next Update here (now Schulze) UPDATE SAPTABLE SET SPRSL = N'E' WHERE NAME = N'Schulze' AND SPRSL = N'D' -- Deadlock occured
hobtid="72057594038779904" dbid="11" objectname="DL_Analysis.dbo.SAPTABLE" indexname="SAPTABLE~0" id="lockd047c00" mode="X" associatedObjectId="72057594038779904"
id="process3f9f4c8" mode="U" requestType="wait"
hobtid="72057594038779904" dbid="11" objectname="DL_Analysis.dbo.SAPTABLE" indexname="SAPTABLE~0" id="lock28b09180" mode="X" associatedObjectId="72057594038779904"
id="process7041708" mode="U" requestType="wait"
The process attributes are (from the example) :
The ID of the process
The priority of the task, most of the time 0.
The amount of transaction log that was generated through this transaction. The process with the least amount will be the victim.
waitresource="KEY: 11:72057594038779904 (7e576f73234b)"
The resource, the process is waiting on. It is defines as Type (RID, KEY, PAGE etc.):DatabaseID:AllocationUnitID(HashValue of the Key)
How long has the process waited on this resource?
Internal number of the transaction.
The name or type of transaction
When did the last transaction started?
The lock mode the process is waiting for.
The CPU this process is running on.
The Window Kernel Thread ID
The status of the process (suspended, as it is waiting for the lock).
The SQL Server Session ID
The System BatchID or Request ID
The Execution Context, when executed in parallel, otherwise Zero.
The deadlock priority of the process.
How many nested transaction has the process open?
When did the last batch started?
When did the last batch completed?
clientapp="Microsoft SQL Server Management Studio - Query"
The name of the client application.
The hostname where the client application is running on.
The Window Process ID of the application
The user that is connected to the SQL Server.
isolationlevel="read committed (2)"
The transaction isolation level of the process.
The maximum lock timeout.
The client options that are set (e.g. XACT_ABORT, ANSI_NULLS etc.)
The client options that are set (cont).
The resource attributes are (from the example):
The Heap-or-B-Tree ID, the internal ID for the allocation unit of the table
The database ID
The index the resource belongs to
The internal representation of the lock.
The requested or owned lock mode
The object id of the table, most of the time identical with the HoBtID. Only when the table is partitioned the two are different (one ObjectID has then multiple HoBtID).
In the next parts of the deadlock blog series we will make use of some of these attributes.
When the trace flags are set correctly, you will get the exact same information as in the XML file in the SQL Server error log file (see this fragment):
2013-02-01 13:24:23.430 spid9s Deadlock encountered .... Printing deadlock information
2013-02-01 13:24:23.430 spid9s Wait-for graph
2013-02-01 13:24:23.430 spid9s NULL
2013-02-01 13:24:23.430 spid9s Node:1
2013-02-01 13:24:23.430 spid9s KEY: 11:72057594038779904 (7e576f73234b) CleanCnt:2 Mode:X
2013-02-01 13:24:23.430 spid9s Grant List 2:
2013-02-01 13:24:23.430 spid9s Owner:0x000000001E5D4780 Mode: X Flg:0x40 Ref:0 Life:02000000 SPID:58 ECID:0 XactLockInfo 0x0000000099191400
2013-02-01 13:24:23.430 spid9s SPID: 58 ECID: 0 Statement Type: UPDATE Line #: 6
2013-02-01 13:24:23.430 spid9s Input Buf: Language Event: use [DL_Analysis]
-- Run both Updates at once, starting with Schulze
UPDATE SAPTABLE SET SPRSL = N'F' WHERE NAME = N'Schulze'
UPDATE SAPTABLE SET SPRSL = N'F' WHERE NAME = N'Miller' A
2013-02-01 13:24:23.430 spid9s Requested by:
2013-02-01 13:24:23.430 spid9s ResType:LockOwner Stype:'OR'Xdes:0x00000000071299C0 Mode: U SPID:59 BatchID:0 ECID:0 TaskProxy:(0x0000000034AB8540) Value:0x9845dfc0 Cost:(0/684)
2013-02-01 13:24:23.430 spid9s Node:2
2013-02-01 13:24:23.430 spid9s KEY: 11:72057594038779904 (86c3d23ec34f) CleanCnt:2 Mode:X
2013-02-01 13:24:23.430 spid9s Grant List 0:
2013-02-01 13:24:23.430 spid9s Owner:0x000000008913FB80 Mode: X Flg:0x40 Ref:0 Life:02000000 SPID:59 ECID:0 XactLockInfo: 0x0000000007129A0
2013-02-01 13:24:23.430 spid9s SPID: 59 ECID: 0 Statement Type: UPDATE Line #: 13
2013-02-01 13:24:23.430 spid9s Input Buf: Language Event: use [DL_Analysis] ..
If you are on SQL Server 2008 or higher you can select the XML directly from the internal SystemHealth X-Event session:
In newer releases of the SAP Database Monitor you can directly access the XML from within the transaction DBACOCKPIT:
Today we discussed what deadlocks are, when they occur and how to get more information about them. Using a basic and fast approach we have collected as much information as possible. In the next part of the deadlock series, I will show how to use this information in basic analysis methods and describe some ways to solve or to avoid the deadlocks.
"In the next part of the deadlock series, I will show how to use this information in basic analysis methods and describe some ways to solve or to avoid the deadlocks."
Has there ever been a second part of this series? I couldn't find anything. Any hint would be appreciated. Thanks!