August 25, 2017 at 6:05 am
I have run into something strange. I have a SQL Server database up in Amazon RDS. It is on a 2012 Standard Edition instance. During recent testing, the database started facing a few deadlocks. On investigation, it seems to be that there is a select query deadlocking another select query! I have no clue how this can be possible. Some help in understanding this matter would be really appreciable!!
Here is the output of the deadlock trace:
2017-08-24 09:39:29.21 spid7s Deadlock encountered .... Printing deadlock information
2017-08-24 09:39:29.21 spid7s Wait-for graph
2017-08-24 09:39:29.21 spid7s
2017-08-24 09:39:29.21 spid7s Node:1
2017-08-24 09:39:29.21 spid7s KEY: 10:72057594069778432 (e1ccbcc72c5a) CleanCnt:2 Mode:X Flags: 0x1
2017-08-24 09:39:29.21 spid7s Grant List 0:
2017-08-24 09:39:29.21 spid7s Owner:0x00000001733F2240 Mode: X Flg:0x40 Ref:0 Life:02000000 SPID:383 ECID:0 XactLockInfo: 0x00000002688D3858
2017-08-24 09:39:29.21 spid7s SPID: 383 ECID: 0 Statement Type: SELECT Line #: 1
2017-08-24 09:39:29.21 spid7s Input Buf: Language Event: (@P0 nvarchar(4000),@P1 nvarchar(4000),@P2 nvarchar(4000))select associatio0_.sagaId as col_0_0_ from ASV associatio0_ where associatio0_.associationKey=@P0 and associatio0_.associationValue=@P1 and associatio0_.sagaType=@P2
2017-08-24 09:39:29.21 spid7s Requested by:
2017-08-24 09:39:29.21 spid7s ResType:LockOwner Stype:'OR'Xdes:0x0000000193B0F048 Mode: S SPID:174 BatchID:0 ECID:0 TaskProxy:(0x00000001237EE608) Value:0x8c37c4c0 Cost:(0/10068)
2017-08-24 09:39:29.21 spid7s
2017-08-24 09:39:29.21 spid7s Node:2
2017-08-24 09:39:29.21 spid7s KEY: 10:72057594069778432 (53b0ac1aef30) CleanCnt:3 Mode:X Flags: 0x1
2017-08-24 09:39:29.21 spid7s Grant List 0:
2017-08-24 09:39:29.21 spid7s Owner:0x00000001733F38C0 Mode: X Flg:0x40 Ref:0 Life:02000000 SPID:174 ECID:0 XactLockInfo: 0x0000000193B0F088
2017-08-24 09:39:29.21 spid7s SPID: 174 ECID: 0 Statement Type: SELECT Line #: 1
2017-08-24 09:39:29.21 spid7s Input Buf: Language Event: (@P0 nvarchar(4000),@P1 nvarchar(4000),@P2 nvarchar(4000))select associatio0_.sagaId as col_0_0_ from ASV associatio0_ where associatio0_.associationKey=@P0 and associatio0_.associationValue=@P1 and associatio0_.sagaType=@P2
2017-08-24 09:39:29.21 spid7s Requested by:
2017-08-24 09:39:29.21 spid7s ResType:LockOwner Stype:'OR'Xdes:0x00000002688D3818 Mode: S SPID:383 BatchID:0 ECID:0 TaskProxy:(0x00000001C6138608) Value:0xb9076ac0 Cost:(0/11240)
2017-08-24 09:39:29.21 spid7s
2017-08-24 09:39:29.21 spid7s Victim Resource Owner:
2017-08-24 09:39:29.21 spid7s ResType:LockOwner Stype:'OR'Xdes:0x0000000193B0F048 Mode: S SPID:174 BatchID:0 ECID:0 TaskProxy:(0x00000001237EE608) Value:0x8c37c4c0 Cost:(0/10068)
2017-08-24 09:39:29.21 spid29s deadlock-list
2017-08-24 09:39:29.21 spid29s deadlock victim=process12913e558
2017-08-24 09:39:29.21 spid29s process-list
2017-08-24 09:39:29.21 spid29s process id=process12913e558 taskpriority=0 logused=10068 waitresource=KEY: 10:72057594069778432 (e1ccbcc72c5a) waittime=3804 ownerId=371855391 transactionname=implicit_transaction lasttranstarted=2017-08-24T09:39:24.780 XDES=0x193b0f048 lockMode=S schedulerid=1 kpid=2508 status=suspended spid=174 sbid=0 ecid=0 priority=0 trancount=1 lastbatchstarted=2017-08-24T09:39:25.403 lastbatchcompleted=2017-08-24T09:39:25.377 lastattention=1900-01-01T00:00:00.377 clientapp=Microsoft JDBC Driver for SQL Server hostname=xxxxxx hostpid=0 loginname=engagement-app isolationlevel=read committed (2) xactid=371855391 currentdb=10 lockTimeout=4294967295 clientoption1=671088672 clientoption2=128058
2017-08-24 09:39:29.21 spid29s executionStack
2017-08-24 09:39:29.21 spid29s frame procname=adhoc line=1 stmtstart=116 sqlhandle=0x020000002f5c3d2750bbacd9ce4a076598d9396bb3cd25f10000000000000000000000000000000000000000
2017-08-24 09:39:29.21 spid29s select associatio0_.sagaId as col_0_0_ from ASV associatio0_ where associatio0_.associationKey=@P0 and associatio0_.associationValue=@P1 and associatio0_.sagaType=@P2
2017-08-24 09:39:29.21 spid29s frame procname=unknown line=1 sqlhandle=0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000
2017-08-24 09:39:29.21 spid29s unknown
2017-08-24 09:39:29.21 spid29s inputbuf
2017-08-24 09:39:29.21 spid29s (@P0 nvarchar(4000),@P1 nvarchar(4000),@P2 nvarchar(4000))select associatio0_.sagaId as col_0_0_ from ASV associatio0_ where associatio0_.associationKey=@P0 and associatio0_.associationValue=@P1 and associatio0_.sagaType=@P2
2017-08-24 09:39:29.21 spid29s process id=process1cb766cf8 taskpriority=0 logused=11240 waitresource=KEY: 10:72057594069778432 (53b0ac1aef30) waittime=3671 ownerId=371855340 transactionname=implicit_transaction lasttranstarted=2017-08-24T09:39:24.107 XDES=0x2688d3818 lockMode=S schedulerid=1 kpid=3584 status=suspended spid=383 sbid=0 ecid=0 priority=0 trancount=1 lastbatchstarted=2017-08-24T09:39:25.540 lastbatchcompleted=2017-08-24T09:39:25.510 lastattention=1900-01-01T00:00:00.510 clientapp=Microsoft JDBC Driver for SQL Server hostname=xxxxxx hostpid=0 loginname=engagement-app isolationlevel=read committed (2) xactid=371855340 currentdb=10 lockTimeout=4294967295 clientoption1=671088672 clientoption2=128058
2017-08-24 09:39:29.21 spid29s executionStack
2017-08-24 09:39:29.21 spid29s frame procname=adhoc line=1 stmtstart=116 sqlhandle=0x020000002f5c3d2750bbacd9ce4a076598d9396bb3cd25f10000000000000000000000000000000000000000
2017-08-24 09:39:29.21 spid29s select associatio0_.sagaId as col_0_0_ from ASV associatio0_ where associatio0_.associationKey=@P0 and associatio0_.associationValue=@P1 and associatio0_.sagaType=@P2
2017-08-24 09:39:29.21 spid29s frame procname=unknown line=1 sqlhandle=0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000
2017-08-24 09:39:29.21 spid29s unknown
2017-08-24 09:39:29.21 spid29s inputbuf
2017-08-24 09:39:29.21 spid29s (@P0 nvarchar(4000),@P1 nvarchar(4000),@P2 nvarchar(4000))select associatio0_.sagaId as col_0_0_ from ASV associatio0_ where associatio0_.associationKey=@P0 and associatio0_.associationValue=@P1 and associatio0_.sagaType=@P2
2017-08-24 09:39:29.21 spid29s resource-list
2017-08-24 09:39:29.21 spid29s keylock hobtid=72057594069778432 dbid=10 objectname=Engagement.dbo.ASV indexname=PK__Associat__3213E83F3AC13B64 id=lock1aa47e880 mode=X associatedObjectId=72057594069778432
2017-08-24 09:39:29.21 spid29s owner-list
2017-08-24 09:39:29.21 spid29s owner id=process1cb766cf8 mode=X
2017-08-24 09:39:29.21 spid29s waiter-list
2017-08-24 09:39:29.21 spid29s waiter id=process12913e558 mode=S requestType=wait
2017-08-24 09:39:29.21 spid29s keylock hobtid=72057594069778432 dbid=10 objectname=Engagement.dbo.ASV indexname=PK__Associat__3213E83F3AC13B64 id=lock1b56c7380 mode=X associatedObjectId=72057594069778432
2017-08-24 09:39:29.21 spid29s owner-list
2017-08-24 09:39:29.21 spid29s owner id=process12913e558 mode=X
2017-08-24 09:39:29.21 spid29s waiter-list
2017-08-24 09:39:29.21 spid29s waiter id=process1cb766cf8 mode=S requestType=wait
2017-08-24 09:39:34.21 spid7s Deadlock encountered .... Printing deadlock information
2017-08-24 09:39:34.21 spid7s Wait-for graph
2017-08-24 09:39:34.21 spid7s
2017-08-24 09:39:34.21 spid7s Node:1
2017-08-24 09:39:34.21 spid7s KEY: 10:72057594069778432 (dca81f96824c) CleanCnt:2 Mode:X Flags: 0x1
2017-08-24 09:39:34.21 spid7s Grant List 0:
2017-08-24 09:39:34.21 spid7s Owner:0x00000001A95E96C0 Mode: X Flg:0x40 Ref:0 Life:02000000 SPID:86 ECID:0 XactLockInfo: 0x00000001CB7003E8
2017-08-24 09:39:34.21 spid7s SPID: 86 ECID: 0 Statement Type: SELECT Line #: 1
2017-08-24 09:39:34.21 spid7s Input Buf: Language Event: (@P0 nvarchar(4000),@P1 nvarchar(4000),@P2 nvarchar(4000))select associatio0_.sagaId as col_0_0_ from ASV associatio0_ where associatio0_.associationKey=@P0 and associatio0_.associationValue=@P1 and associatio0_.sagaType=@P2
2017-08-24 09:39:34.21 spid7s Requested by:
2017-08-24 09:39:34.21 spid7s ResType:LockOwner Stype:'OR'Xdes:0x00000001647A2D28 Mode: S SPID:384 BatchID:0 ECID:0 TaskProxy:(0x00000001C6108608) Value:0x733b4540 Cost:(0/8076)
2017-08-24 09:39:34.21 spid7s
2017-08-24 09:39:34.21 spid7s Node:2
2017-08-24 09:39:34.21 spid7s KEY: 10:72057594069778432 (8256f8665a4b) CleanCnt:2 Mode:X Flags: 0x1
2017-08-24 09:39:34.21 spid7s Grant List 0:
2017-08-24 09:39:34.21 spid7s Owner:0x0000000181DF41C0 Mode: X Flg:0x40 Ref:0 Life:02000000 SPID:384 ECID:0 XactLockInfo: 0x00000001647A2D68
2017-08-24 09:39:34.21 spid7s SPID: 384 ECID: 0 Statement Type: SELECT Line #: 1
2017-08-24 09:39:34.21 spid7s Input Buf: Language Event: (@P0 nvarchar(4000),@P1 nvarchar(4000),@P2 nvarchar(4000))select associatio0_.sagaId as col_0_0_ from ASV associatio0_ where associatio0_.associationKey=@P0 and associatio0_.associationValue=@P1 and associatio0_.sagaType=@P2
2017-08-24 09:39:34.21 spid7s Requested by:
2017-08-24 09:39:34.21 spid7s ResType:LockOwner Stype:'OR'Xdes:0x00000001CB7003A8 Mode: S SPID:86 BatchID:0 ECID:0 TaskProxy:(0x00000001A740C608) Value:0x8c37c4c0 Cost:(0/20672)
2017-08-24 09:39:34.21 spid7s
2017-08-24 09:39:34.21 spid7s Victim Resource Owner:
2017-08-24 09:39:34.21 spid7s ResType:LockOwner Stype:'OR'Xdes:0x00000001647A2D28 Mode: S SPID:384 BatchID:0 ECID:0 TaskProxy:(0x00000001C6108608) Value:0x733b4540 Cost:(0/8076)
2017-08-24 09:39:34.21 spid28s deadlock-list
2017-08-24 09:39:34.21 spid28s deadlock victim=process1c0c0b0c8
2017-08-24 09:39:34.21 spid28s process-list
2017-08-24 09:39:34.21 spid28s process id=process1c0c0b0c8 taskpriority=0 logused=8076 waitresource=KEY: 10:72057594069778432 (dca81f96824c) waittime=4194 ownerId=371855348 transactionname=implicit_transaction lasttranstarted=2017-08-24T09:39:24.310 XDES=0x1647a2d28 lockMode=S schedulerid=1 kpid=2736 status=suspended spid=384 sbid=0 ecid=0 priority=0 trancount=1 lastbatchstarted=2017-08-24T09:39:30.017 lastbatchcompleted=2017-08-24T09:39:29.990 lastattention=1900-01-01T00:00:00.990 clientapp=Microsoft JDBC Driver for SQL Server hostname=xxxxx hostpid=0 loginname=engagement-app isolationlevel=read committed (2) xactid=371855348 currentdb=10 lockTimeout=4294967295 clientoption1=671088672 clientoption2=128058
2017-08-24 09:39:34.21 spid28s executionStack
2017-08-24 09:39:34.21 spid28s frame procname=adhoc line=1 stmtstart=116 sqlhandle=0x020000002f5c3d2750bbacd9ce4a076598d9396bb3cd25f10000000000000000000000000000000000000000
2017-08-24 09:39:34.21 spid28s select associatio0_.sagaId as col_0_0_ from ASV associatio0_ where associatio0_.associationKey=@P0 and associatio0_.associationValue=@P1 and associatio0_.sagaType=@P2
2017-08-24 09:39:34.21 spid28s frame procname=unknown line=1 sqlhandle=0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000
2017-08-24 09:39:34.21 spid28s unknown
2017-08-24 09:39:34.21 spid28s inputbuf
2017-08-24 09:39:34.21 spid28s (@P0 nvarchar(4000),@P1 nvarchar(4000),@P2 nvarchar(4000))select associatio0_.sagaId as col_0_0_ from ASV associatio0_ where associatio0_.associationKey=@P0 and associatio0_.associationValue=@P1 and associatio0_.sagaType=@P2
2017-08-24 09:39:34.21 spid28s process id=process1c508acf8 taskpriority=0 logused=20672 waitresource=KEY: 10:72057594069778432 (8256f8665a4b) waittime=4129 ownerId=371855414 transactionname=implicit_transaction lasttranstarted=2017-08-24T09:39:28.943 XDES=0x1cb7003a8 lockMode=S schedulerid=1 kpid=4000 status=suspended spid=86 sbid=0 ecid=0 priority=0 trancount=1 lastbatchstarted=2017-08-24T09:39:30.080 lastbatchcompleted=2017-08-24T09:39:30.057 lastattention=1900-01-01T00:00:00.057 clientapp=Microsoft JDBC Driver for SQL Server hostname=xxxxx hostpid=0 loginname=engagement-app isolationlevel=read committed (2) xactid=371855414 currentdb=10 lockTimeout=4294967295 clientoption1=671088672 clientoption2=128058
2017-08-24 09:39:34.21 spid28s executionStack
2017-08-24 09:39:34.21 spid28s frame procname=adhoc line=1 stmtstart=116 sqlhandle=0x020000002f5c3d2750bbacd9ce4a076598d9396bb3cd25f10000000000000000000000000000000000000000
2017-08-24 09:39:34.21 spid28s select associatio0_.sagaId as col_0_0_ from ASV associatio0_ where associatio0_.associationKey=@P0 and associatio0_.associationValue=@P1 and associatio0_.sagaType=@P2
2017-08-24 09:39:34.21 spid28s frame procname=unknown line=1 sqlhandle=0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000
2017-08-24 09:39:34.21 spid28s unknown
2017-08-24 09:39:34.21 spid28s inputbuf
2017-08-24 09:39:34.21 spid28s (@P0 nvarchar(4000),@P1 nvarchar(4000),@P2 nvarchar(4000))select associatio0_.sagaId as col_0_0_ from ASV associatio0_ where associatio0_.associationKey=@P0 and associatio0_.associationValue=@P1 and associatio0_.sagaType=@P2
2017-08-24 09:39:34.21 spid28s resource-list
2017-08-24 09:39:34.21 spid28s keylock hobtid=72057594069778432 dbid=10 objectname=Engagement.dbo.ASV indexname=PK__Associat__3213E83F3AC13B64 id=lock1b568b080 mode=X associatedObjectId=72057594069778432
2017-08-24 09:39:34.21 spid28s owner-list
2017-08-24 09:39:34.21 spid28s owner id=process1c508acf8 mode=X
2017-08-24 09:39:34.21 spid28s waiter-list
2017-08-24 09:39:34.21 spid28s waiter id=process1c0c0b0c8 mode=S requestType=wait
2017-08-24 09:39:34.21 spid28s keylock hobtid=72057594069778432 dbid=10 objectname=Engagement.dbo.ASV indexname=PK__Associat__3213E83F3AC13B64 id=lock1b56c6500 mode=X associatedObjectId=72057594069778432
2017-08-24 09:39:34.21 spid28s owner-list
2017-08-24 09:39:34.21 spid28s owner id=process1c0c0b0c8 mode=X
2017-08-24 09:39:34.21 spid28s waiter-list
2017-08-24 09:39:34.21 spid28s waiter id=process1c508acf8 mode=S requestType=wait
August 25, 2017 at 6:21 am
SELECTs alone can't deadlock.
The statements you see in the deadlock graph are the ones that completed the deadlock, not all of the statements involved. From a look at the resources section there, the selects are part of implicit transactions that have some data modification in them as well. That can deadlock (reader-writer deadlock)
What happens is that the data modification starts the transaction (implicit transaction) and takes locks. Those locks have to be held until the end of the transaction.
Then, another session starts a transaction and does some modification.
The first session then runs a select, but it is blocked by the second session
The second session runs a select, it's blocked by the first session, there's your deadlock.
Check whether you really want and intend to have implicit transactions. They're the norm in Oracle, not in SQL Server, and it's very easy to get transactions that run far longer than expected or desired.
See https://www.simple-talk.com/sql/performance/sql-server-deadlocks-by-example/
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 25, 2017 at 9:06 am
Hi Gail,
Would be grt if you can put some light on the influence of the isolation level on this scenario.
Thanks...Arshad
August 25, 2017 at 10:14 am
Nothing I said is affected by isolation level.
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 29, 2017 at 6:22 am
Thanks for the explanation, Gail!
Viewing 5 posts - 1 through 5 (of 5 total)
You must be logged in to reply to this topic. Login to reply
This website stores cookies on your computer.
These cookies are used to improve your website experience and provide more personalized services to you, both on this website and through other media.
To find out more about the cookies we use, see our Privacy Policy