August 1, 2011 at 1:21 pm
I have a stored procedure that periodically deadlocks when 2 users execute at the same time, even though they are updating unrelated transactions. I set a traceflag and found the offending sql, but I'm confused by the log.
The offending sql is:
INSERT INTO @OverfillBbl
SELECTInbBrlKey,
InbBarrelQty,
InbCapacity
FROM@ProdOrd
INNER JOIN
ProdOrdDtl ON (PodPohKey = PohKey)
INNER JOIN
InventoryTran ON (IntPodKey = PodKey)
INNER JOIN
(SELECTDISTINCT
IntLocKeyInbLocKey,
IntLotKeyInbLotKey,
BrlKeyInbBrlKey,
SUM(ItbQtyPerBrl)InbBarrelQty,
BrlCapacityInbCapacity
FROMInventoryTranBarrels
INNER JOIN Barrel ON (BrlKey = ItbBrlKey)
INNER JOIN InventoryTran ON (IntKey = ItbIntKey) <<<<< IntKey is the primary key: PK_InventoryTran
INNER JOIN Location ON (LocKey = IntLocKey)
INNER JOIN Lot ON (LotKey = IntLotKey)
INNER JOIN Item ON (ItmItemCode = LotItemID)
GROUP BY
IntLocKey,
IntLotKey,
BrlKey,
BrlCapacity
HAVING SUM(ItbQtyPerBrl) <> 0) AS InventoryBarrels ON (InbLocKey = IntLocKey AND
InbLotKey = IntLotKey)
WHEREInbBarrelQty > InbCapacity
@OverfillBbl is an in-memory table and @ProdOrd is a table-valued-parameter that contains only the order that the user is updating.
The pertinent data from the error log showing the conflicting spids:
victim: spid=167process id=process45d5fb948
keylock hobtid=72057595069595648 dbid=10 objectname=dv_wrp.dbo.InventoryTran indexname=PK_InventoryTran id=lockfc02bc80 mode=X associatedObjectId=72057595069595648
victor: spid=161process id=process5412988
keylock hobtid=72057595069595648 dbid=10 objectname=dv_wrp.dbo.InventoryTran indexname=PK_InventoryTran id=lock7c8f45380 mode=X associatedObjectId=72057595069595648
According to the error log, both users are trying to acquire an exclusive lock on PK_InventoryTran (IntKey) but I thought exclusive locks are only acquired for INSERT/UPDATE/DELETE operations. IntKey is only referenced in the INNER JOIN in the derived table code so why would SQL Server need an exclusive lock to build the derived table? Or am I reading this wrong?
I cannot use WITH (NOLOCK) because I do not want the results from dirty reads. The results of the derived table are not order specific so both users would be building the same @OverfillBbl data. Could that somehow be my problem?
Any insight would be appreciated.
Thanks,
Gina
August 1, 2011 at 1:23 pm
Post the deadlock graph please
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
August 1, 2011 at 1:28 pm
Select won't take an exclusive lock, just an intent-shared lock, so something is trying to update/insert/delete data and conflicting. Or there's a hint somewhere else in the script/procedure that tells it to take exclusive locks (perhaps READ REPEATABLE or READ SERIALIZABLE?).
Instead of NoLock, have you looked into Snapshot Isolation? That will avoid dirty reads, because it uses row-versioning instead of avoiding locks. It can cause problems in tempdb if you have a lot of concurrent CRUD going on, but not usually.
- Gus "GSquared", RSVP, OODA, MAP, NMVP, FAQ, SAT, SQL, DNA, RNA, UOI, IOU, AM, PM, AD, BC, BCE, USA, UN, CF, ROFL, LOL, ETC
Property of The Thread
"Nobody knows the age of the human race, but everyone agrees it's old enough to know better." - Anon
August 1, 2011 at 3:05 pm
Sorry, I am not able to post the deadlock graph. I was not running the profiler when the deadlock occurred and I am not able to re-create it on demand. I tried turning the profiler on while I tried to re-create the deadlock but it killed our system performance and now the users are lighting torches and looking for me...
August 1, 2011 at 3:31 pm
I find no READ hints in the stored procedure, though it does INSERT and/or DELETE rows in InventoryTran just prior to the offending code I posted earlier. The error log showed the same SQL was being executed by both the victim and the winner when the deadlock occurred. Shouldn't I see an INSERT, UPDATE, or DELETE statement coming from the non-victim?
Here's the entire error log for the deadlock:
08/01/2011 10:12:48,spid19s,Unknown,waiter id=process5412988 mode=S requestType=wait
08/01/2011 10:12:48,spid19s,Unknown,waiter-list
08/01/2011 10:12:48,spid19s,Unknown,owner id=process45d5fb948 mode=X
08/01/2011 10:12:48,spid19s,Unknown,owner-list
08/01/2011 10:12:48,spid19s,Unknown,keylock hobtid=72057595069595648 dbid=10 objectname=dv_wrp.dbo.InventoryTran indexname=PK_InventoryTran id=lockfc02bc80 mode=X associatedObjectId=72057595069595648
08/01/2011 10:12:48,spid19s,Unknown,waiter id=process45d5fb948 mode=S requestType=wait
08/01/2011 10:12:48,spid19s,Unknown,waiter-list
08/01/2011 10:12:48,spid19s,Unknown,owner id=process5412988 mode=X
08/01/2011 10:12:48,spid19s,Unknown,owner-list
08/01/2011 10:12:48,spid19s,Unknown,keylock hobtid=72057595069595648 dbid=10 objectname=dv_wrp.dbo.InventoryTran indexname=PK_InventoryTran id=lock7c8f45380 mode=X associatedObjectId=72057595069595648
08/01/2011 10:12:48,spid19s,Unknown,resource-list
08/01/2011 10:12:48,spid19s,Unknown,Proc [Database Id = 10 Object Id = 1486953415]
08/01/2011 10:12:48,spid19s,Unknown,inputbuf
08/01/2011 10:12:48,spid19s,Unknown,WHEREInbBarrelQty > InbCapacity
08/01/2011 10:12:48,spid19s,Unknown,InbLotKey = IntLotKey)
08/01/2011 10:12:48,spid19s,Unknown,HAVING SUM(ItbQtyPerBrl) <> 0) AS InventoryBarrels ON (InbLocKey = IntLocKey AND
08/01/2011 10:12:48,spid19s,Unknown,BrlCapacity
08/01/2011 10:12:48,spid19s,Unknown,BrlKey<c/>
08/01/2011 10:12:48,spid19s,Unknown,IntLotKey<c/>
08/01/2011 10:12:48,spid19s,Unknown,IntLocKey<c/>
08/01/2011 10:12:48,spid19s,Unknown,GROUP BY
08/01/2011 10:12:48,spid19s,Unknown,INNER JOIN Item ON (ItmItemCode = LotItemID)
08/01/2011 10:12:48,spid19s,Unknown,INNER JOIN Lot ON (LotKey = IntLotKey)
08/01/2011 10:12:48,spid19s,Unknown,INNER JOIN Location ON (LocKey = IntLocKey)
08/01/2011 10:12:48,spid19s,Unknown,INNER JOIN InventoryTran ON (IntKey = ItbIntKey)
08/01/2011 10:12:48,spid19s,Unknown,INNER JOIN Barrel ON (BrlKey = ItbBrlKey)
08/01/2011 10:12:48,spid19s,Unknown,FROMInventoryTranBarrels
08/01/2011 10:12:48,spid19s,Unknown,BrlCapacityInbCapacity
08/01/2011 10:12:48,spid19s,Unknown,SUM(ItbQtyPerBrl)InbBarrelQty<c/>
08/01/2011 10:12:48,spid19s,Unknown,BrlKeyInbBrlKey<c/>
08/01/2011 10:12:48,spid19s,Unknown,IntLotKeyInbLotKey<c/>
08/01/2011 10:12:48,spid19s,Unknown,IntLocKeyInbLocKey<c/>
08/01/2011 10:12:48,spid19s,Unknown,(SELECTDISTINCT
08/01/2011 10:12:48,spid19s,Unknown,INNER JOIN
08/01/2011 10:12:48,spid19s,Unknown,InventoryTran ON (IntPodKey = PodKey)
08/01/2011 10:12:48,spid19s,Unknown,INNER JOIN
08/01/2011 10:12:48,spid19s,Unknown,ProdOrdDtl ON (PodPohKey = PohKey)
08/01/2011 10:12:48,spid19s,Unknown,INNER JOIN
08/01/2011 10:12:48,spid19s,Unknown,FROM@ProdOrd
08/01/2011 10:12:48,spid19s,Unknown,InbCapacity
08/01/2011 10:12:48,spid19s,Unknown,InbBarrelQty<c/>
08/01/2011 10:12:48,spid19s,Unknown,SELECTInbBrlKey<c/>
08/01/2011 10:12:48,spid19s,Unknown,INSERT INTO @OverfillBbl
08/01/2011 10:12:48,spid19s,Unknown,frame procname=dv_wrp.dbo.spdv_ProdOrdUpdate line=952 stmtstart=59826 stmtend=61760 sqlhandle=0x03000a00c71ba158f919e900279f00000100000000000000
08/01/2011 10:12:48,spid19s,Unknown,executionStack
08/01/2011 10:12:48,spid19s,Unknown,process id=process5412988 taskpriority=0 logused=19616 waitresource=KEY: 10:72057595069595648 (16ae097eecb9) waittime=3478 ownerId=900871734 transactionname=user_transaction lasttranstarted=2011-08-01T10:12:44.233 XDES=0x7c545ae80 lockMode=S schedulerid=14 kpid=7152 status=suspended spid=161 sbid=0 ecid=0 priority=0 trancount=1 lastbatchstarted=2011-08-01T10:12:44.233 lastbatchcompleted=2011-08-01T10:12:44.207 clientapp=.Net SqlClient Data Provider hostname=DVM103 hostpid=3268 loginname=CORP\bvannieu isolationlevel=read committed (2) xactid=900871734 currentdb=10 lockTimeout=4294967295 clientoption1=673185824 clientoption2=128056
08/01/2011 10:12:48,spid19s,Unknown,Proc [Database Id = 10 Object Id = 1486953415]
08/01/2011 10:12:48,spid19s,Unknown,inputbuf
08/01/2011 10:12:48,spid19s,Unknown,WHEREInbBarrelQty > InbCapacity
08/01/2011 10:12:48,spid19s,Unknown,InbLotKey = IntLotKey)
08/01/2011 10:12:48,spid19s,Unknown,HAVING SUM(ItbQtyPerBrl) <> 0) AS InventoryBarrels ON (InbLocKey = IntLocKey AND
08/01/2011 10:12:48,spid19s,Unknown,BrlCapacity
08/01/2011 10:12:48,spid19s,Unknown,BrlKey<c/>
08/01/2011 10:12:48,spid19s,Unknown,IntLotKey<c/>
08/01/2011 10:12:48,spid19s,Unknown,IntLocKey<c/>
08/01/2011 10:12:48,spid19s,Unknown,GROUP BY
08/01/2011 10:12:48,spid19s,Unknown,INNER JOIN Item ON (ItmItemCode = LotItemID)
08/01/2011 10:12:48,spid19s,Unknown,INNER JOIN Lot ON (LotKey = IntLotKey)
08/01/2011 10:12:48,spid19s,Unknown,INNER JOIN Location ON (LocKey = IntLocKey)
08/01/2011 10:12:48,spid19s,Unknown,INNER JOIN InventoryTran ON (IntKey = ItbIntKey)
08/01/2011 10:12:48,spid19s,Unknown,INNER JOIN Barrel ON (BrlKey = ItbBrlKey)
08/01/2011 10:12:48,spid19s,Unknown,FROMInventoryTranBarrels
08/01/2011 10:12:48,spid19s,Unknown,BrlCapacityInbCapacity
08/01/2011 10:12:48,spid19s,Unknown,SUM(ItbQtyPerBrl)InbBarrelQty<c/>
08/01/2011 10:12:48,spid19s,Unknown,BrlKeyInbBrlKey<c/>
08/01/2011 10:12:48,spid19s,Unknown,IntLotKeyInbLotKey<c/>
08/01/2011 10:12:48,spid19s,Unknown,IntLocKeyInbLocKey<c/>
08/01/2011 10:12:48,spid19s,Unknown,(SELECTDISTINCT
08/01/2011 10:12:48,spid19s,Unknown,INNER JOIN
08/01/2011 10:12:48,spid19s,Unknown,InventoryTran ON (IntPodKey = PodKey)
08/01/2011 10:12:48,spid19s,Unknown,INNER JOIN
08/01/2011 10:12:48,spid19s,Unknown,ProdOrdDtl ON (PodPohKey = PohKey)
08/01/2011 10:12:48,spid19s,Unknown,INNER JOIN
08/01/2011 10:12:48,spid19s,Unknown,FROM@ProdOrd
08/01/2011 10:12:48,spid19s,Unknown,InbCapacity
08/01/2011 10:12:48,spid19s,Unknown,InbBarrelQty<c/>
08/01/2011 10:12:48,spid19s,Unknown,SELECTInbBrlKey<c/>
08/01/2011 10:12:48,spid19s,Unknown,INSERT INTO @OverfillBbl
08/01/2011 10:12:48,spid19s,Unknown,frame procname=dv_wrp.dbo.spdv_ProdOrdUpdate line=952 stmtstart=59826 stmtend=61760 sqlhandle=0x03000a00c71ba158f919e900279f00000100000000000000
08/01/2011 10:12:48,spid19s,Unknown,executionStack
08/01/2011 10:12:48,spid19s,Unknown,process id=process45d5fb948 taskpriority=0 logused=15732 waitresource=KEY: 10:72057595069595648 (3434d5c5c484) waittime=2979 ownerId=900875886 transactionname=user_transaction lasttranstarted=2011-08-01T10:12:44.907 XDES=0x4975983b0 lockMode=S schedulerid=13 kpid=7516 status=suspended spid=167 sbid=0 ecid=0 priority=0 trancount=1 lastbatchstarted=2011-08-01T10:12:44.903 lastbatchcompleted=2011-08-01T10:12:44.857 clientapp=.Net SqlClient Data Provider hostname=DVM-LT-013 hostpid=5308 loginname=CORP\lholtzclaw isolationlevel=read committed (2) xactid=900875886 currentdb=10 lockTimeout=4294967295 clientoption1=673185824 clientoption2=128056
08/01/2011 10:12:48,spid19s,Unknown,process-list
08/01/2011 10:12:48,spid19s,Unknown,deadlock victim=process45d5fb948
08/01/2011 10:12:48,spid19s,Unknown,deadlock-list
August 3, 2011 at 7:21 am
Since the data modification is on the same resources as the select, it will hold the locks from that. You'll only run into the deadlock in cases of either lock escalation, or the same pages being locked by different instances of the update. So, look into multiple connections running the query with similar input parameter values.
Snapshot isolation will probably undo the deadlock, but you might get different data in two queries of the same rows. Otherwise, you'll need to modify the transactionality of the queries.
- Gus "GSquared", RSVP, OODA, MAP, NMVP, FAQ, SAT, SQL, DNA, RNA, UOI, IOU, AM, PM, AD, BC, BCE, USA, UN, CF, ROFL, LOL, ETC
Property of The Thread
"Nobody knows the age of the human race, but everyone agrees it's old enough to know better." - Anon
August 3, 2011 at 7:25 am
Change transactionality to ???
August 3, 2011 at 10:41 am
The tables in this database have had the pagelock disabled with code like this:
EXEC sp_indexoption N'InventoryTran', N'disallowpagelocks', TRUE;
because users were blocking each other when they were updating different rows that happened to be on the same page. That change dramatically improved the deadlocking issues, but we still periodically get them. In this most recent case, one user was inserting rows into InventoryTran while the other was updating different rows in InventoryTran.
I'm guessing that what's happening is the derived table InventoryBarrels is not specific to any particular transaction so both processes are trying to build the same pseudo-table but they each have a lock on different transactions. Ultimately, the join to the derived table would return a different set of rows but I'm guessing the entire derived table is built first, then the join would filter unnecessary rows. If 2 users hit the OK button at exactly the same time and both processes hit this validation code at the same time, then I'm guessing the deadlock would be guaranteed. I've added multiple tries to this procedure to try to alleviate the problem, but we do still periodically hit it. Perhaps I need to add a pause between tries to give one process a chance to finish before the other re-tries.
August 5, 2011 at 6:49 am
I'd have to see the whole proc to give more specific advice than I already have.
A pause in it will only widen the window for error.
- Gus "GSquared", RSVP, OODA, MAP, NMVP, FAQ, SAT, SQL, DNA, RNA, UOI, IOU, AM, PM, AD, BC, BCE, USA, UN, CF, ROFL, LOL, ETC
Property of The Thread
"Nobody knows the age of the human race, but everyone agrees it's old enough to know better." - Anon
August 5, 2011 at 9:40 am
As long as you have not restared the SQL Server since the deadlock you can get it retrospectivly using this query:
IF OBJECT_ID('tempdb..#ring_buffer_data') IS NOT NULL
DROP TABLE #ring_buffer_data
SELECT CAST(xest.target_data as XML) xml_data, *
INTO #ring_buffer_data
FROM
sys.dm_xe_session_targets xest
INNER JOIN sys.dm_xe_sessions xes on xes.[address] = xest.event_session_address
WHERE
xest.target_name = 'ring_buffer' AND
xes.name = 'system_health'
GO
;WITH CTE( event_name, event_time, deadlock_graph )
AS
(
SELECT
event_xml.value('(./@name)', 'varchar(1000)') as event_name,
event_xml.value('(./@timestamp)', 'datetime') as event_time,
event_xml.value('(./data[@name="xml_report"]/value)[1]', 'varchar(max)') as deadlock_graph
FROM #ring_buffer_data
CROSS APPLY xml_data.nodes('//event[@name="xml_deadlock_report"]') n (event_xml)
WHERE event_xml.value('@name', 'varchar(4000)') = 'xml_deadlock_report'
)
SELECT event_name, event_time,
CAST(
CASE
WHEN CHARINDEX('<victim-list/>', deadlock_graph) > 0 THEN
REPLACE (
REPLACE(deadlock_graph, '<victim-list/>', '<deadlock><victim-list>'),
'<process-list>', '</victim-list><process-list>')
ELSE
REPLACE (
REPLACE(deadlock_graph, '<victim-list>', '<deadlock><victim-list>'),
'<process-list>', '</victim-list><process-list>')
END
AS XML) AS DeadlockGraph
FROM CTE
ORDER BY event_time DESC
GO
MCITP SQL 2005, MCSA SQL 2012
August 5, 2011 at 9:56 am
Anyway to get this to work on 2k5? I'm on CS server so that might just be it but I can't seem to be able to link dm_xe_session_targets and 2005 on google ...
August 5, 2011 at 9:59 am
Extended events are a SQL 2008 feature.
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
August 5, 2011 at 10:03 am
GilaMonster (8/5/2011)
Extended events are a SQL 2008 feature.
TX, one more point for my upgrade request :-D.
August 5, 2011 at 10:24 am
GilaMonster (8/5/2011)
Extended events are a SQL 2008 feature.
Running something by y'all.
Let's say I run a trace for replay on 2K5. Replay on 2K8 R2 dev. Would those events be then populated?
And please, not just add the deadlock event answer ;-). I have a much broader list of needs than that.
August 5, 2011 at 10:46 am
Sure, but what do you need from extended events that you can't get from profiler?
p.s. Not really relevant to OP's question.
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
Viewing 15 posts - 1 through 15 (of 15 total)
You must be logged in to reply to this topic. Login to reply