December 8, 2009 at 8:59 am
Hi,
I've a very strange deadlock problem. I'm having a table with a clustered index (identity) and some other columns, where another column contains a grouping (so multiple PK are contained within one groupid).
This is a test table: example:
CREATE TABLE [dbo].[TestLock](
[ID] [bigint] IDENTITY(1,1) NOT NULL,
[GroupID] [bigint] NOT NULL,
[StatusID] [smallint] NOT NULL CONSTRAINT [DF_TestLock_StatusID] DEFAULT ((0)),
CONSTRAINT [PK_TestLock] PRIMARY KEY CLUSTERED
([ID] ASC)
) ON [PRIMARY]
Session1:
begin transaction
insert into testlock(groupid, statusid) values (1,0)
Session2:
begin transaction
insert into testlock(groupid, statusid) values (2,0)
Then in Session1:
update testlock set statusid = 90 where groupid = 1
-> Session1 is waiting on a U KEY lock on the row inserted by session2. I do not understand this. Why is this?
If I commit first Session2, then session1 does not take an U key lock. It's just like session1 locks all records that will be in the same page and not yet committed? (we're using sql 2005 sp 4034, read_committed_with_snapshot isolation model)
Your input should be fantastic.
December 8, 2009 at 10:49 am
Switch traceflag 1222 on. That will result in a deadlock graph been written to the error log every time a deadlock occurs. Post the result of that graph here.
DBCC TRACEON(1222,-1)
Gail Shaw
Microsoft Certified Master: SQL Server, MVP, M.Sc (Comp Sci)
SQL In The Wild: Discussions on DB performance with occasional diversions into recoverability
December 10, 2009 at 2:35 am
2009-12-08 00:13:20.38 spid4s Node:1
2009-12-08 00:13:20.38 spid4s KEY: 6:72057595571732480 (3300bbfdce97) CleanCnt:3 Mode:X Flags: 0x0
2009-12-08 00:13:20.38 spid4s Grant List 3:
2009-12-08 00:13:20.38 spid4s Owner:0x000000008B088A40 Mode: X Flg:0x0 Ref:0 Life:02000000 SPID:103 ECID:0 XactLockInfo: 0x00000000809DD148
2009-12-08 00:13:20.38 spid4s SPID: 103 ECID: 0 Statement Type: UPDATE Line #: 85
2009-12-08 00:13:20.38 spid4s Input Buf: RPC Event: Proc [Database Id = 6 Object Id = 262890091]
2009-12-08 00:13:20.38 spid4s Requested By:
2009-12-08 00:13:20.38 spid4s ResType:LockOwner Stype:'OR'Xdes:0x0000000080048A30 Mode: U SPID:91 BatchID:0 ECID:0 TaskProxy:(0x00000003B107A598) Value:0xbc4d8080 Cost:(5/3608)
2009-12-08 00:13:20.38 spid4s
2009-12-08 00:13:20.38 spid4s Node:2
2009-12-08 00:13:20.38 spid4s KEY: 6:72057595571732480 (320025fd645b) CleanCnt:2 Mode:X Flags: 0x0
2009-12-08 00:13:20.38 spid4s Grant List 1:
2009-12-08 00:13:20.38 spid4s Owner:0x00000000BC4D9980 Mode: X Flg:0x0 Ref:0 Life:02000000 SPID:91 ECID:0 XactLockInfo: 0x0000000080048A68
2009-12-08 00:13:20.38 spid4s SPID: 91 ECID: 0 Statement Type: UPDATE Line #: 85
2009-12-08 00:13:20.38 spid4s Input Buf: RPC Event: Proc [Database Id = 6 Object Id = 262890091]
2009-12-08 00:13:20.38 spid4s Requested By:
2009-12-08 00:13:20.38 spid4s ResType:LockOwner Stype:'OR'Xdes:0x00000000809DD110 Mode: U SPID:103 BatchID:0 ECID:0 TaskProxy:(0x00000003785E4598) Value:0x45efec00 Cost:(0/20212)
2009-12-08 00:13:20.38 spid4s
2009-12-08 00:13:20.38 spid4s Victim Resource Owner:
2009-12-08 00:13:20.38 spid4s ResType:LockOwner Stype:'OR'Xdes:0x0000000080048A30 Mode: U SPID:91 BatchID:0 ECID:0 TaskProxy:(0x00000003B107A598) Value:0xbc4d8080 Cost:(5/3608)
2009-12-08 00:13:20.38 spid4s End deadlock search 97995 ... a deadlock was found.
2009-12-08 00:13:20.38 spid4s ----------------------------------
2009-12-08 00:13:20.38 spid4s ----------------------------------
2009-12-08 00:13:20.38 spid4s Starting deadlock search 97996
2009-12-08 00:13:20.38 spid4s Target Resource Owner:
2009-12-08 00:13:20.38 spid4s ResType:LockOwner Stype:'OR'Xdes:0x00000000809DD110 Mode: U SPID:103 BatchID:0 ECID:0 TaskProxy:(0x00000003785E4598) Value:0x45efec00
2009-12-08 00:13:20.38 spid4s 0:Insert new node: Node:1 ResType:LockOwner Stype:'OR'Xdes:0x00000000809DD110 Mode: U SPID:103 BatchID:0 ECID:0 TaskProxy:(0x00000003785E4598) Value:0x45efec00
2009-12-08 00:13:20.38 spid4s 1:SearchOR Considering new blocker - task: 0000000003C27978, Worker 000000000515C1C0
2009-12-08 00:13:20.38 spid4s 1:SearchOR search result: No deadlock
2009-12-08 00:13:20.38 spid4s End deadlock search 97996 ... a deadlock was not found.
2009-12-08 00:13:20.38 spid4s ----------------------------------
2009-12-08 00:13:20.38 spid34s deadlock-list
2009-12-08 00:13:20.38 spid34s deadlock victim=process3c27978
2009-12-08 00:13:20.38 spid34s process-list
2009-12-08 00:13:20.38 spid34s process id=process3c27978 taskpriority=5 logused=3608 waitresource=KEY: 6:72057595571732480 (3300bbfdce97) waittime=437 ownerId=2541589519 transactionname=user_transaction lasttranstarted=2009-12-08T00:13:19.760 XDES=0x80048a30 lockMode=U schedulerid=4 kpid=26536 status=suspended spid=91 sbid=0 ecid=0 priority=-5 transcount=2 lastbatchstarted=2009-12-08T00:12:36.040 lastbatchcompleted=2009-12-08T00:12:36.040 clientapp=SQLAgent - TSQL JobStep (Job 0x9623F1BF9099D64F97E8477983A8FA90 : Step 4) hostname=SRVSQL01 hostpid=644 loginname=GSC01\svc_clu_sqlagent isolationlevel=read committed (2) xactid=2541589519 currentdb=6 lockTimeout=4294967295 clientoption1=673186080 clientoption2=128056
2009-12-08 00:13:20.38 spid34s executionStack
2009-12-08 00:13:20.38 spid34s frame procname=DSVW42F01.dbo.spi__print_release line=85 stmtstart=6560 stmtend=7260 sqlhandle=0x0300060077aaaa76b8350e01d29c00000100000000000000
2009-12-08 00:13:20.38 spid34s UPDATE printing_header
2009-12-08 00:13:20.38 spid34s SET print_status = '0',
2009-12-08 00:13:20.38 spid34s last_change_dt = GETDATE()
2009-12-08 00:13:20.38 spid34s WHERE session_trans_id = @i_session_trans_id
2009-12-08 00:13:20.38 spid34s AND print_status = 'B'
2009-12-08 00:13:20.38 spid34s AND confirm_requested = 0;
2009-12-08 00:13:20.38 spid34s process id=process3c45ac8 taskpriority=0 logused=20212 waitresource=KEY: 6:72057595571732480 (320025fd645b) waittime=437 ownerId=2541586493 transactionname=user_transaction lasttranstarted=2009-12-08T00:13:19.307 XDES=0x809dd110 lockMode=U schedulerid=7 kpid=13828 status=suspended spid=103 sbid=0 ecid=0 priority=0 transcount=2 lastbatchstarted=2009-12-08T00:13:19.210 lastbatchcompleted=2009-12-08T00:13:19.210 clientapp=.Net SqlClient Data Provider hostname=VMSRVPLC01 hostpid=1976 loginname=ibs isolationlevel=read committed (2) xactid=2541586493 currentdb=6 lockTimeout=4294967295 clientoption1=671088928 clientoption2=128056
2009-12-08 00:13:20.38 spid34s executionStack
2009-12-08 00:13:20.38 spid34s frame procname=DSVW42F01.dbo.spi__print_release line=85 stmtstart=6560 stmtend=7260 sqlhandle=0x0300060077aaaa76b8350e01d29c00000100000000000000
2009-12-08 00:13:20.38 spid34s UPDATE printing_header
2009-12-08 00:13:20.38 spid34s SET print_status = @c_print_status_TO_PRINT,
2009-12-08 00:13:20.38 spid34s last_change_dt = GETDATE()
2009-12-08 00:13:20.38 spid34s WHERE session_trans_id = @i_session_trans_id
2009-12-08 00:13:20.38 spid34s AND print_status = @c_print_status_BLANK
2009-12-08 00:13:20.38 spid34s AND confirm_requested = 0;
2009-12-08 00:13:20.38 spid34s inputbuf
2009-12-08 00:13:20.38 spid34s Proc [Database Id = 6 Object Id = 262890091]
2009-12-08 00:13:20.38 spid34s resource-list
2009-12-08 00:13:20.38 spid34s keylock hobtid=72057595571732480 dbid=6 objectname=DSVW42F01.dbo.printing_header indexname=PK__DOCPRHD__1BA13207 id=lock4cd1c00 mode=X associatedObjectId=72057595571732480
2009-12-08 00:13:20.38 spid34s owner-list
2009-12-08 00:13:20.38 spid34s owner id=process3c27978 mode=X
2009-12-08 00:13:20.38 spid34s waiter-list
2009-12-08 00:13:20.38 spid34s waiter id=process3c45ac8 mode=U requestType=wait
2009-12-08 00:13:20.38 spid34s keylock hobtid=72057595571732480 dbid=6 objectname=DSVW42F01.dbo.printing_header indexname=PK__DOCPRHD__1BA13207 id=lock2677a2900 mode=X associatedObjectId=72057595571732480
2009-12-08 00:13:20.38 spid34s owner-list
2009-12-08 00:13:20.38 spid34s owner id=process3c45ac8 mode=X
2009-12-08 00:13:20.38 spid34s waiter-list
2009-12-08 00:13:20.38 spid34s waiter id=process3c27978 mode=U requestType=wait
2009-12-08 00:13:21.15 spid4s ----------------------------------
December 10, 2009 at 5:53 am
Can you post the code for the procedure dbo.spi__print_release and the structure (with indexes) of the table dbo.printing_header.
btw, you can switch traceflag 1204 off. On SQL 2005, 1222 prints a superset of the info that 1204 prints. No need to have them both on.
Gail Shaw
Microsoft Certified Master: SQL Server, MVP, M.Sc (Comp Sci)
SQL In The Wild: Discussions on DB performance with occasional diversions into recoverability
December 10, 2009 at 7:02 am
CREATE TABLE [dbo].[printing_header](
[print_batch_number] [bigint] IDENTITY(1,1) NOT NULL,
[creation_dt] [datetime] NULL,
[last_change_dt] [datetime] NULL,
[requester_user_code] [varchar](10) NULL,
[owner_code] [varchar](10) NULL,
[warehouse_code] [varchar](10) NULL,
[language_code] [varchar](10) NULL,
[printing_code] [varchar](10) NULL,
[session_trans_id] [bigint] NULL,
[printing_id] [bigint] NULL,
[confirm_requested] [bit] NOT NULL,
[printing_handler] [varchar](5) NOT NULL,
[print_status] [varchar](1) NOT NULL,
CONSTRAINT [PK__DOCPRHD__1BA13207] PRIMARY KEY CLUSTERED
(
[print_batch_number] ASC
)WITH (PAD_INDEX = OFF, STATISTICS_NORECOMPUTE = OFF, IGNORE_DUP_KEY = OFF, ALLOW_ROW_LOCKS = ON, ALLOW_PAGE_LOCKS = ON) ON [PRIMARY]
) ON [PRIMARY]
code in spi__print_release
UPDATE printing_header
SET print_status = @c_print_status_TO_PRINT,
last_change_dt = GETDATE()
WHERE session_trans_id = @i_session_trans_id
AND print_status = 'B'
AND confirm_requested = 0
)
December 10, 2009 at 9:02 am
Would you mind posting the entire definition of the proc, not just the updates that are involved in the deadlock. I'd like to see the data types of the parameters, any other queries that are in the proc, any control flow, etc.
Gail Shaw
Microsoft Certified Master: SQL Server, MVP, M.Sc (Comp Sci)
SQL In The Wild: Discussions on DB performance with occasional diversions into recoverability
December 15, 2009 at 6:57 am
look at the execution plan for session 1, it does a clustered Index scan. The scan hits the locked key for the new row in session 2 and is blocked from completing the scan. If you add an index on GroupID you will get a Index Seek instead.
December 21, 2009 at 1:45 am
indeed, that worked. Tx
Viewing 8 posts - 1 through 7 (of 7 total)
You must be logged in to reply to this topic. Login to reply