Technical: Microsoft – SQL Server – Blocking & Deadlocks

Technical: Microsoft – SQL Server – Blocking & Deadlocks

Background

We have had failing SQL Server Agent jobs and in an attempt to be more proactive we will like to gather more in-depth SQL Server deadlock diagnostic data.

Capture Blocking Diagnostic Data

Using Trace Flags, Capture Blocking Diagnostic Data

Using Trace Flags, one can capture blocking diagnostic data into SQL Server Error Log file.

Here are the applicable Trace Flags:

Trace Flag ID Trace Flag Information
1204 Trace flag 1204 reports deadlock information formatted by each node involved in the deadlock.
1222 Trace flag 1222 formats deadlock information, first by processes and then by resources.

There are a couple of pathways:

  • One involves setting start-up Trace Flags and restarting SQL Server to effect the start-up changes.
  • Another involves setting global trace flags for the current SQL Server process. Keep in mind that changes made during the current session are lost upon SQL Server Instance restart.

Use SQL Server Configuration Manager to add Start-up Trace Flags

  • Start SQL Server Configuration Manager in Administrative Mode
  • From the left window, select “SQL Server Services”
  • From the right window, select the specific SQL Server Engine — SQL Server (MSSQLServer) or SQL Server (<Instance Name>)
  • Right click on the specific SQL Server Engine
  • From the drop-down menu, select the Properties option
  • In the “Properties” window, access the “Startup Parameters” Tab
  • Under the “Existing Parameters” group box, review the current list of Start up parameters
  • If the list does not include -T1204 or -T1222, please enter the missing entries in the “Specify a start-up parameter” entry field, and click on the “Add” button to append the newly entered entry to the list of “Start-up parameters”

Before Changes

SQLServerConfigurationManager


Post Changes
Here is what we look like when we add -T1204 and -T1222.

TraceFlags-SqlInstanceStartup-PostChanges

In our Lab environment, we can restart the MS SQL Server Instance, to effect the changes.


SQL Server Management Studio – Current SQL Server Process

In Production, please effect for the running SQL Server Instance:

 dbcc traceon(1204, -1)
 dbcc traceon(1222, -1)

Review Trace Flags Status

Let us connect to SQL Server and review the status of our Trace Flags.

Issue DBCC TraceStatus:

DBCC tracestatus(-1)

TraceStatus

Simulate SQL Server Blocking

Let us create an environment that we know will lead to Database locks deadlocks.

Database Objects

To simulate blocking we will create a couple of tables:

  • dbo.song
  • dbo.songLyricLine (vote is tallied in-place)
  • dbo.songLyricLineLog (vote records are logged)

Create Database Schema

Create Database Schema – dbo.song



use [DBLab]
go

set noexec off
go

if object_id('dbo.song') is not null
begin

	set noexec on

end
go

create table dbo.[song]
(

	  [songID] bigint not null identity(1,1)
	, [artist] nvarchar(600) not null
	, [album]  nvarchar(600) not null
	, [song]   nvarchar(600) not null

	, [dateReleased] datetime null

	, CONSTRAINT PK_Song primary key
		(
		  [SongID]
		)

)
go

set noexec off
go

if not exists
	(

		select	
			   tblIndex.*
		from   sysindexes tblIndex
		where  tblIndex.id = object_id('dbo.song')
		and    tblIndex.name = 'PK_Song'
	)
begin

	print 'Add Index - Song.PK_Song ...'

		alter table dbo.[Song]
			add CONSTRAINT PK_Song primary key
				(
					[SongID]
				)

	print 'Added Index - Song.PK_Song'	

end
go

/*
	drop index dbo.[Song].idx_Unique_Artist_Album_Song
*/

if not exists
	(

		select	
			   tblIndex.*
		from   sysindexes tblIndex
		where  tblIndex.id = object_id('dbo.song')
		and    tblIndex.name = 'idx_Unique_Artist_Album_Song'
	)
begin

	print 'Add Index - Song.idx_Unique_Artist_Album_Song ...'

		create unique index idx_Unique_Artist_Album_Song
		on dbo.[Song]
			(
				  [artist]
				, [album]
				, [song]
			)

	print 'Added Index - Song.idx_Unique_Artist_Album_Song'	

end
go

Create Database Schema – dbo.songLyricLine


use [DBLab]
go

set noexec off
go

if object_id('dbo.songLyricLine') is not null
begin

	set noexec on

end
go

create table dbo.[songLyricLine]
(

	  [songID] bigint not null 
	, [line] nvarchar(600) not null
	, [lineNumber]  smallint null

	, [voteFor] bigint not null 
			constraint defaultSongLyricLineVoteFor default (0)

	, [voteAgainst] bigint not null 
			constraint defaultSongLyricLineVoteAgainst default (0)

	, CONSTRAINT PK_SongLyricLine primary key
			(
				  [SongID]
				, [line]
			)

	, CONSTRAINT FK_Song_SongID foreign key
			(
				  [SongID]
			)
		references dbo.[Song]
			(
				  [SongID]
			)

)
go

set noexec off
go

if not exists
	(

		select	
			   tblIndex.*
		from   sysindexes tblIndex
		where  tblIndex.id = object_id('dbo.songLyricLine')
		and    tblIndex.name = 'PK_SongLyricLine'
	)
begin

	print 'Add Index - Song.PK_SongLyricLine ...'

		alter table dbo.[SongLyricLine]
			add CONSTRAINT PK_SongLyricLine primary key
				(
					  [SongID]
					, [line]
				)

	print 'Added Index - songLyricLine.PK_SongLyricLine'	

end
go

Create Database Schema – dbo.songLyricLineLog



use [DBLab]
go

set noexec off
go

/*
	drop table dbo.[songLyricLineLog]
*/

if object_id('dbo.songLyricLineLog') is not null
begin

	set noexec on

end
go

create table dbo.[songLyricLineLog]
(

	  [songID] bigint not null 
	, [line] nvarchar(600) not null
	, [lineNumber]  smallint null
	, [id]          bigint not null identity(1,1)
	, [voteFor]     bit
			constraint defaultSongLyricLineLogVoteFor default (0)
	, [voteAgainst] bigint not null 
			constraint defaultSongLyricLineLogVoteAgainst default (0)

	, CONSTRAINT PK_SongLyricLineLog primary key
			(
				  [SongID]
				, [line]
				, [id]
			)

	, CONSTRAINT FK_songLyricLineLog__Song_SongID foreign key
			(
				  [SongID]
			)
		references dbo.[Song]
			(
				  [SongID]
			)

)
go

set noexec off
go

if not exists
	(

		select	
			   tblIndex.*
		from   sysindexes tblIndex
		where  tblIndex.id = object_id('dbo.songLyricLineLog')
		and    tblIndex.name = 'PK_SongLyricLineLog'
	)
begin

	print 'Add Index - Song.PK_SongLyricLineLog ...'

		alter table dbo.[SongLyricLineLog]
			add CONSTRAINT PK_SongLyricLineLog primary key
				(
					  [SongID]
					, [line]
					, [id]
				)

	print 'Added Index - songLyricLine.PK_SongLyricLineLog'	

end
go

Create Database Stored Procedure

Create Stored Procedure – dbo.usp_songLyricLine_Vote



use [DBLab]
go

set noexec off
go

if object_id('dbo.usp_songLyricLine_Vote') is null
begin

	exec('create procedure dbo.usp_songLyricLine_Vote as select 1/0 as shell')

end
go

alter procedure  dbo.usp_songLyricLine_Vote
(
	  @artist	nvarchar(600)
	, @album	nvarchar(600)
	, @song		nvarchar(600)
	, @lyricLine	nvarchar(600)
	, @vote		smallint
	, @inplace	bit = 1
)
as
begin

	set nocount on;

	declare @songID bigint

	declare @tblOutput TABLE
	(
		[songID] bigint not null
	)

	merge dbo.[song] as tblSong

	using 
			(
				select
					  @artist as [artist]
					, @album  as [album]
					, @song   as [song]
					, @vote   as [vote]

		    ) as tblSongRaw

	on
		(
			    tblSong.[artist] = tblSongRaw.[artist]
			and tblSong.[album] = tblSongRaw.[album]
			and tblSong.[song] = tblSongRaw.[song]
		)

	when not matched then

		insert 
		(
			  [artist]
			, [album]
			, [song]
		)
		values
		(
			  @artist
			, @album
			, @song
		)

	output inserted.songID
	into   @tblOutput
		(
			[songID]
		)

	;

	--print 'songID ' + cast(isNull(@songID, -999) as sysname)

	if (@inplace in (0, 1))
	begin

		set @songID = ( select top 1 songID from @tblOutput)

		if (@songID is null)
		begin

			select @songID = [songID]
			from   dbo.[song] tblSong
			where  tblSong.artist = @artist
			and    tblSong.album = @album
			and    tblSong.song = @song

		end

	end

	if (@inplace = 1)
	begin

		merge dbo.[songLyricLine] as tblSongLyricLine

		using 
				(
					select
							  @songID as [songID]
							, @lyricLine as [lyricLine]
							, @vote   as [vote]

				) as tblVoteRaw

		on
			(
			       (tblSongLyricLine.[songID] = tblVoteRaw.[songID])
			   and (tblSongLyricLine.[line] = tblVoteRaw.[lyricLine])
			)

		when not matched then

			insert 
				(
					  [songID]
					, [line]
					, [voteFor]
					, [voteAgainst]
				)
			values
				(
					   @songID
					 , @lyricLine
					 , case
							when @vote = 1 then 1
							else 0
						end

					,	case
							when @vote = -1 then 1
							else 0
						end

				)

		when matched then

				update set

					[voteFor] =  tblSongLyricLine.[voteFor] +
										                                              	case
												                                   when @vote = 1 then	1
												                                   else 0
											                                         end

					  , [voteAgainst] =  
                                                tblSongLyricLine.[voteAgainst] +
										                                                        case
										                                              	    when @vote = -1 then 1
										                                                         else 0
											                                           end

						;

	end --if in place

end

go

Data Manipulate Language (DML) – Add & Vote for song

In the next few sections, we will add and vote for songs.

DML – Vote song lyrics (1)



--vote for song lyrics -1
use [DBlab]
go

set nocount on
go

while (@@trancount > 0)
begin

	print cast(@@trancount as sysname) + ') tran'

	rollback tran

end
go

declare @inplace bit

set @inplace = 1

while 1 = 1
begin

   begin tran

	exec dbo.usp_songLyricLine_Vote
		  @artist = 'Peter Bradley Adams'
		, @album = 'The Foundation'
		, @song	= 'The Longer I Run'	
		, @lyricLine = 'And let me live again'
		, @vote = 1
		, @inplace = @inplace

	exec dbo.usp_songLyricLine_Vote
		  @artist = 'Zac Brown Band'
		, @album = 'The Foundation'
		, @song	= 'Highway 20 Ride'	
		, @lyricLine = 'But son please don''t mistake me'
		, @vote = 1
		, @inplace = @inplace

	exec dbo.usp_songLyricLine_Vote
		  @artist = 'Zac Brown Band'
		, @album = 'The Foundation'
	        , @song	= 'Highway 20 Ride'	
		, @lyricLine = 'For a man that didn''t care at all'
		, @vote = -1
		, @inplace = @inplace

	exec dbo.usp_songLyricLine_Vote
		 @artist = 'Zac Brown Band'
		, @album = 'The Foundation'
		, @song	= 'Highway 20 Ride'	
		, @lyricLine = 
        'and I count the days and the miles back home to you on that Highway 20 ride'
		, @vote = -1
		, @inplace = @inplace

   commit tran

   --waitfor delay '00:00:01'

end

/*

    while (@@trancount > 0)
    begin

	print cast(@@trancount as sysname) + ') tran'

	rollback tran

     end
     go

*/

Create Database Schema – Vote song lyrics (2)

Create a new sql server session, and issue this endless set of sql



/*
  Vote for song lyrics -2
*/

use [DBlab]
go

set nocount on
go

while (@@trancount > 0)
begin

	print cast(@@trancount as sysname) + ') tran'

	rollback tran

end

declare @inplace bit

set @inplace = 1

while 1 = 1
begin

   begin tran

       exec dbo.usp_songLyricLine_Vote
	     @artist = 'Zac Brown Band'
	   , @album = 'The Foundation'
	   , @song	= 'Highway 20 Ride'	
	, @lyricLine = 
     'and I count the days and the miles back home to you on that Highway 20 ride'
	, @vote = -1
	, @inplace = @inplace

	exec dbo.usp_songLyricLine_Vote
	     @artist = 'Kenny Rodgers'
	    , @album = ' She Rides Wild Horses'
	    , @song	= 'Buy me a rose'	
	    , @lyricLine = 'Buy me a rose, call me from work'
	    , @vote = 1
	    , @inplace = @inplace

	exec dbo.usp_songLyricLine_Vote
	      @artist = 'Kenny Rodgers'
	    , @album = ' She Rides Wild Horses'
	    , @song	= 'Buy me a rose'	
	    , @lyricLine = 'Open a door for me, what would it hurt'
	    , @vote = 1
	    , @inplace = @inplace

	exec dbo.usp_songLyricLine_Vote
	      @artist = 'Kenny Rodgers'
	    , @album = ' She Rides Wild Horses'
	    , @song	= 'Buy me a rose'	
	    , @lyricLine = 'Show me you love me by the look in your eyes'
	    , @vote = -1
	    , @inplace = @inplace

	exec dbo.usp_songLyricLine_Vote
	     @artist = 'Kenny Rodgers'
	   , @album = ' She Rides Wild Horses'
	   , @song	= 'Buy me a rose'	
	   , @lyricLine = 'These are the little things I need the most in my life'
	   , @vote = -1
	   , @inplace = @inplace

    commit tran

end
go

/*

	while (@@trancount > 0)
	begin

		print cast(@@trancount as sysname) + ') tran'

		rollback tran

	end

*/
go

DML – Vote song lyrics (3)

Create a third sql server session, and issue this endless set of sql



/*
  Vote for song lyrics - 3
*/

use [DBlab]
go

/*
	truncate table dbo.[songLyricLineLog]
	truncate table dbo.[songLyricLine]
	delete from dbo.[song];
*/

set nocount on
go

declare @inplace bit

set @inplace = 1

while 1 = 1
begin

   begin tran

	exec dbo.usp_songLyricLine_Vote
 	       @artist = 'Zac Brown Band'
	     , @album = 'The Foundation'
	     , @song = 'Highway 20 Ride'	
	     , @lyricLine = 'and I count the days and the miles back home to you on that Highway 20 ride'
	    , @vote = 1
	    , @inplace = @inplace

	exec dbo.usp_songLyricLine_Vote
		  @artist = 'Zac Brown Band'
		, @album = 'The Foundation'
		, @song	= 'Highway 20 Ride'	
		, @lyricLine = 'But son please don''t mistake me'
		, @vote = 1
		, @inplace = @inplace

	exec dbo.usp_songLyricLine_Vote
		  @artist = 'Zac Brown Band'
		, @album = 'The Foundation'
		, @song	= 'Highway 20 Ride'	
		, @lyricLine = 'For a man that didn''t care at all'
		, @vote = -1
		, @inplace = @inplace

	exec dbo.usp_songLyricLine_Vote
		  @artist = 'Peter Bradley Adams'
		, @album = 'The Foundation'
		, @song	= 'The Longer I Run'	
		, @lyricLine = 'And let me live again'
		, @vote = 1
		, @inplace = @inplace

   commit tran

	--waitfor delay '00:00:01'

end

/*

   while (@@trancount > 0)
   begin

	print cast(@@trancount as sysname) + ') tran'

	rollback tran

   end
   go

*/

Deadlock

Deadlock – Screen

It should not take much time before you get register a deadlock.

Seen we are using Transact SQL, we can see it on screen

Screen Text

Msg 1205, Level 13, State 51, Procedure usp_songLyricLine_Vote, Line 96
Transaction (Process ID 54) was deadlocked on lock resources with another process and has been chosen as the deadlock victim. Rerun the transaction.

Screen Image

deadlockViewingOnScreen

Deadlock – SQL Server Profiler

Screen Text

Deadlock graph



2014-02-24 16:00:47.14 spid4s      Deadlock encountered .... Printing deadlock information
2014-02-24 16:00:47.14 spid4s      Wait-for graph
2014-02-24 16:00:47.14 spid4s      
2014-02-24 16:00:47.14 spid4s      Node:1

2014-02-24 16:00:47.14 spid4s      KEY: 5:72057594040156160 (950574ea51c6) CleanCnt:2 Mode:X Flags: 0x1
2014-02-24 16:00:47.14 spid4s       Grant List 3:
2014-02-24 16:00:47.14 spid4s         Owner:0x000000009A12E840 Mode: X        Flg:0x40 Ref:0 Life:02000000 SPID:52 ECID:0 XactLockInfo: 0x0000000099D0EED0
2014-02-24 16:00:47.14 spid4s         SPID: 52 ECID: 0 Statement Type: MERGE Line #: 96
2014-02-24 16:00:47.14 spid4s         Input Buf: Language Event: 

  Interpretation:

Type Data
Header Deadlock encountered .. Printing deadlock information
SPID SPID = 4 (System)
SPID SPID = 52 (User)
Type Merge

Requested By – Grant List and Victim Resource Owner



2014-02-24 16:00:47.14 spid4s      Requested by: 
2014-02-24 16:00:47.14 spid4s        ResType:LockOwner Stype:'OR'Xdes:0x0000000099D0F740 Mode: U SPID:54 BatchID:0 ECID:0 TaskProxy:(0x0000000080E98538) Value:0x9a12e680 Cost:(0/408)
2014-02-24 16:00:47.14 spid4s      
2014-02-24 16:00:47.14 spid4s      Node:2

2014-02-24 16:00:47.14 spid4s      KEY: 5:72057594040156160 (8f0dae4a07b9) CleanCnt:3 Mode:X Flags: 0x1
2014-02-24 16:00:47.14 spid4s       Grant List 3:
2014-02-24 16:00:47.14 spid4s         Owner:0x000000009A12E700 Mode: X        Flg:0x40 Ref:0 Life:02000000 SPID:54 ECID:0 XactLockInfo: 0x0000000099D0F780
2014-02-24 16:00:47.14 spid4s         SPID: 54 ECID: 0 Statement Type: MERGE Line #: 96
2014-02-24 16:00:47.14 spid4s         Input Buf: Language Event: 

2014-02-24 16:00:47.14 spid4s      Requested by: 
2014-02-24 16:00:47.14 spid4s        ResType:LockOwner Stype:'OR'Xdes:0x0000000099D0EE90 Mode: U SPID:52 BatchID:0 ECID:0 TaskProxy:(0x0000000080916538) Value:0x9a12e6c0 Cost:(0/680)
2014-02-24 16:00:47.15 spid4s      
2014-02-24 16:00:47.15 spid4s      Victim Resource Owner:
2014-02-24 16:00:47.15 spid4s       ResType:LockOwner Stype:'OR'Xdes:0x0000000099D0F740 Mode: U SPID:54 BatchID:0 ECID:0 TaskProxy:(0x0000000080E98538) Value:0x9a12e680 Cost:(0/408)

  Interpretation:

Type Data
Requested By (Grant List) SPID = 54
Requested By (Victim Resource Owner) SPID = 52

Deadlock List \ Deadlock Victim



2014-02-24 16:00:47.15 spid26s     deadlock-list
2014-02-24 16:00:47.15 spid26s      deadlock victim=process3eedb88
2014-02-24 16:00:47.15 spid26s       process-list
2014-02-24 16:00:47.15 spid26s        process id=process3eedb88 taskpriority=0 logused=408 waitresource=KEY: 5:72057594040156160 (950574ea51c6) waittime=2413 ownerId=392586109 transactionname=user_transaction lasttranstarted=2014-02-24T16:00:44.733 XDES=0x99d0f740 lockMode=U schedulerid=4 kpid=10840 status=suspended spid=54 sbid=0 ecid=0 priority=0 trancount=2 lastbatchstarted=2014-02-24T16:00:44.697 lastbatchcompleted=2014-02-24T16:00:44.697 lastattention=2014-02-24T15:36:11.540 clientapp=Microsoft SQL Server Management Studio - Query hostname=rachel hostpid=9300 loginname=labdomain\dadeniji isolationlevel=read committed (2) xactid=392586109 currentdb=5 lockTimeout=4294967295 clientoption1=673187936 clientoption2=390200

  Interpretation:

Type Data
Clientapp Microsoft SQL Server Management Studio
Hostname rachel
spid 54
loginname labdomain\dadeniji

Execution Stack



2014-02-24 16:00:47.15 spid26s         executionStack
2014-02-24 16:00:47.15 spid26s          frame procname=DBLAB.dbo.usp_songLyricLine_Vote line=96 stmtstart=2656 stmtend=4678 sqlhandle=0x0300050095e3141a514af200dca200000100000000000000
2014-02-24 16:00:47.15 spid26s     merge dbo.[songLyricLine] as tblSongLyricLine
2014-02-24 16:00:47.15 spid26s     		using 
2014-02-24 16:00:47.15 spid26s     				(
2014-02-24 16:00:47.15 spid26s     					select
2014-02-24 16:00:47.15 spid26s     							  @songID as [songID]
2014-02-24 16:00:47.15 spid26s     							, @lyricLine as [lyricLine]
2014-02-24 16:00:47.15 spid26s     							, @vote   as [vote]
2014-02-24 16:00:47.15 spid26s     				) as tblVoteRaw
2014-02-24 16:00:47.15 spid26s     		on
2014-02-24 16:00:47.15 spid26s     			(
2014-02-24 16:00:47.15 spid26s     					tblSongLyricLine.[songID] = tblVoteRaw.[songID]
2014-02-24 16:00:47.15 spid26s     				and tblSongLyricLine.[line] = tblVoteRaw.[lyricLine]
2014-02-24 16:00:47.15 spid26s     			)
2014-02-24 16:00:47.15 spid26s     		when not matched then
2014-02-24 16:00:47.15 spid26s     			insert 
2014-02-24 16:00:47.15 spid26s     				(
2014-02-24 16:00:47.15 spid26s     					  [songID]
2014-02-24 16:00:47.15 spid26s     					, [line]
2014-02-24 16:00:47.15 spid26s     					, [voteFor]
2014-02-24 16:00:47.15 spid26s     					, [voteAgainst]
2014-02-24 16:00:47.15 spid26s     				)
2014-02-24 16:00:47.15 spid26s     			values
2014-02-24 16:00:47.15 spid26s     				(
2014-02-24 16:00:47.15 spid26s     					   @songID
2014-02-24 16:00:47.15 spid26s     					 , @lyricLine
2014-02-24 16:00:47.15 spid26s     					 , case
2014-02-24 16:00:47.15 spid26s     							when @vote = 1 then	1
2014-02-24 16:00:47.15 spid26s     							else 0
2014-02-24 16:00:47.15 spid26s     						end
2014-02-24 16:00:47.15 spid26s     					,	case
2014-02-24 16:00:47.15 spid26s     							when @vote = -1 then 1
2014-02-24 16:00:47.15 spid26s     							else 0
2014-02-24 16:00:47.15 spid26s     						end
2014-02-24 16:00:47.15 spid26s     				)
2014-02-24 16:00:47.15 spid26s     		when matched then
2014-02-24 16:00:47.15 spid26s     				update set
2014-02-24 16:00:47.15 spid26s     							[voteFor] =  tblSongLyricLine.[voteFor] +
2014-02-24 16:00:47.15 spid26s     											case
2014-02-24 16:00:47.15 spid26s     												when @vote = 1 then	1
2014-02-24 16:00:47.15 spid26s     												else 0
2014-02-24 16:00:47.15 spid26s     											end
2014-02-24 16:00:47.15 spid26s     						  , [voteAgainst] =  tblSongLyricLine.[voteAgainst] +
2014-02-24 16:00:47.15 spid26s     											case
2014-02-24 16:00:47.15 spid26s     												when @vote = -1 then 1
2014-02-24 16:00:47.15 spid26s     												else 0
2014-02-24 16:00:47.15 spid26s     											end
2014-02-24 16:00:47.15 spid26s     						;     

  Interpretation:

Type Data
Header Execution Stack
SQL Handle 0x0300050095e3141a514af200dca200000100000000000000
Statement Start 2656
Statement End 4678

Review the referenced SQL (DBLAB.dbo.usp_songLyricLine_Vote) and try to identify which code-line starts at Statement Start and ends at Statement End.

Or better still, add the SQL Stored Procedure ( http://gallery.technet.microsoft.com/scriptcenter/4df31ad5-227c-495d-9c6c-d91d047e89ee) pasted below to your toolbox.



/*
Retrieve a SQL Statement with a Specified SQL_Handle
http://gallery.technet.microsoft.com/scriptcenter/4df31ad5-227c-495d-9c6c-d91d047e89ee
*/

use master
go

if object_id('sp_GetSQLtext') is null
begin

  exec('create procedure sp_GetSQLText as select 1/0 as [shell]')

end
go

use master
go

create proc sp_GetSQLText
(
      @sql_handle varbinary(64)=NULL 
     ,@stmtstart int=NULL 
     ,@stmtend int =NULL
) 
as 

if @sql_handle is NULL  
    or @stmtstart is NULL  
    or @stmtend is NULL 
begin 
    print 'you must provide sqlhandle, stmtstart, and stmtend' 
    return -999 
end 

select  
         substring(qt.text,s.statement_start_offset/2,  
            (case when s.statement_end_offset = -1  
            then len(convert(nvarchar(max), qt.text)) * 2  
            else s.statement_end_offset end -s.statement_start_offset)/2)  
        as "SQL statement" 
        ,s.statement_start_offset 
        ,s.statement_end_offset 
        ,batch=qt.text 
        ,qt.dbid 
        ,qt.objectid 
        ,s.execution_count 
        ,s.total_worker_time 
        ,s.total_elapsed_time 
        ,s.total_logical_reads 
        ,s.total_physical_reads 
        ,s.total_logical_writes 
from sys.dm_exec_query_stats s 
      cross apply sys.dm_exec_sql_text(s.sql_handle) as qt 
where s.sql_handle = @sql_handle 
and s.statement_start_offset = @stmtstart 
and s.statement_end_offset = @stmtend 

go 

In our particular use case, we invoke the SP as



    declare @sql_handle varbinary(64)=NULL 
    declare @stmtstart int=NULL 
    declare @stmtend int =NULL

    set @sql_handle = 0x0300050095e3141a514af200dca200000100000000000000
    set @stmtstart = 2656
    set @stmtend = 4678

	exec master.dbo.sp_GetSQLText
		  @sql_handle=@sql_handle
		 ,@stmtstart = @stmtstart 
                 ,@stmtend =  @stmtend

and, get back

SQLStatement

Deadlock explanation

The deadlock is being caused by the following:

  • Update statement is causing a hot spot in the dbo.[songLyricLine]  table
  • We have very little records and the merge statement is hitting on the same records

To rectify, we will create a new table dbo.[songLyricLineLog] and simply append new records per each vote.

Remediation

Create table – dbo.[songLyricLineLog]



use [DBLab]
go

set noexec off
go

if object_id('dbo.songLyricLineLog') is not null
begin

	set noexec on

end
go

create table dbo.[songLyricLineLog]
(

	  [songID] bigint not null 
	, [line] nvarchar(600) not null
	, [lineNumber]  smallint null
	, [id]          bigint not null identity(1,1)
	, [voteFor]     bit
			constraint defaultSongLyricLineLogVoteFor default (0)
	, [voteAgainst] bigint not null 
			constraint defaultSongLyricLineLogVoteAgainst default (0)

	, CONSTRAINT PK_SongLyricLineLog primary key
			(
				  [SongID]
				, [line]
				, [id]
			)

	, CONSTRAINT FK_songLyricLineLog__Song_SongID foreign key
			(
				  [SongID]
			)
		references dbo.[Song]
			(
				  [SongID]
			)

)
go

set noexec off
go

if not exists
	(

		select	
			   tblIndex.*
		from   sysindexes tblIndex
		where  tblIndex.id = object_id('dbo.songLyricLineLog')
		and    tblIndex.name = 'PK_SongLyricLineLog'
	)
begin

	print 'Add Index - Song.PK_SongLyricLineLog ...'

		alter table dbo.[SongLyricLineLog]
			add CONSTRAINT PK_SongLyricLineLog primary key
				(
					  [SongID]
					, [line]
					, [id]
				)

	print 'Added Index - songLyricLine.PK_SongLyricLineLog'	

end
go

Re-create Stored Procedure – dbo.usp_songLyricLine_Vote

Let us recreate the usp_SongLyricLine_Vote SP.  This time appending new records and thus alleviate the hot spot created by updates.



use [DBLab]
go

set noexec off
go

if object_id('dbo.usp_songLyricLine_Vote') is null
begin

	exec('create procedure dbo.usp_songLyricLine_Vote as select 1/0 as shell')

end
go

alter procedure  dbo.usp_songLyricLine_Vote
(
	  @artist		nvarchar(600)
	, @album		nvarchar(600)
	, @song			nvarchar(600)
	, @lyricLine	nvarchar(600)
	, @vote			smallint
	, @inplace		bit = 1
)
as
begin

	set nocount on;

	declare @songID bigint

	declare @tblOutput TABLE
	(
		[songID] bigint not null
	)

	merge dbo.[song] as tblSong

	using 
			(
				select
				     @artist as [artist]
				   , @album  as [album]
				   , @song   as [song]
				   , @vote   as [vote]

		    ) as tblSongRaw

	on
		(
			    tblSong.[artist] = tblSongRaw.[artist]
			and tblSong.[album] = tblSongRaw.[album]
			and tblSong.[song] = tblSongRaw.[song]
		)

	when not matched then

		insert 
		(
			  [artist]
			, [album]
			, [song]
		)
		values
		(
			  @artist
			, @album
			, @song
		)

	output inserted.songID
	into   @tblOutput
		(
			[songID]
		)

	;

	--print 'songID ' + cast(isNull(@songID, -999) as sysname)

	if (@inplace in (0, 1))
	begin

		set @songID = ( select top 1 songID from @tblOutput)

		if (@songID is null)
		begin

			select @songID = [songID]
			from   dbo.[song] tblSong
			where  tblSong.artist = @artist
			and    tblSong.album = @album
			and    tblSong.song = @song

		end

	end

	if (@inplace = 1)
	begin

		merge dbo.[songLyricLine] as tblSongLyricLine

		using 
				(
					select
							  @songID as [songID]
							, @lyricLine as [lyricLine]
							, @vote   as [vote]

				) as tblVoteRaw

		on
			(
				tblSongLyricLine.[songID] = tblVoteRaw.[songID]
				and tblSongLyricLine.[line] = tblVoteRaw.[lyricLine]
			)

		when not matched then

			insert 
				(
					  [songID]
					, [line]
					, [voteFor]
					, [voteAgainst]
				)
			values
				(
					   @songID
					 , @lyricLine
					 , case
						when @vote = 1 then	1
						else 0
					   end

					,  case
						when @vote = -1 then 1
						else 0
					   end

				)

		when matched then

			update set

				 [voteFor] =  tblSongLyricLine.[voteFor] +
										           	                              case	
                                         when @vote = 1 then	1
				         else 0
				      end

				 , [voteAgainst] =  tblSongLyricLine.[voteAgainst] +
											                                case
										 		                           when @vote = -1 then 1
										           		                            else 0
										                                     	end

				;

	end --if in place

	else if (@inplace = 0)
	begin

		insert into dbo.[songLyricLineLog]
		(
			  [songID]
			, [line]
			, [voteFor]
			, [voteAgainst]
		)
		values
		(
			  @songID
			, @lyricLine
			, case
					when @vote = 1 then	1
					else 0
			  end
			, case
					when @vote = -1 then	1
					else 0
			  end

		)

	end

end

go

What causes deadlock?

Here are some of the things that causes deadlocks:

  • Insufficient resources (Memory)
  • Missing Indexes
  • Hot tables
  • Triggers
  • Long Transactions
  • Normalized / Tight Table structures

Source Control

Source Control

Posted Sourcecode to githib @ https://github.com/DanielAdeniji/MSSQLServerDeadlocksSimulation


References

References – Microsoft

References – Microsoft – Trace Flags

References – Microsoft – Diagnosis

References – Sample Code – Simulate Deadlock

One thought on “Technical: Microsoft – SQL Server – Blocking & Deadlocks

Leave a Reply

Please log in using one of these methods to post your comment:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s