Deadlock

  • hi I have applied 1204 and 1222 as a startup parameters in my environment and I can see the deadlock evevnts in error logs. Seems like more than 2 processes are blocking and at some points

    we can read "Unknown,Log Viewer could not read information for this log entry. Cause: Data is Null.

    " so what that indicates?? any ideas??Thanks in advance

    stmtstart=30052 stmtend=30608 sqlhandle=0x03000700f37b751114005f01cb9a00000100000000000000

    06/30/2008 12:25:01,spid23s,Unknown,executionStack

    06/30/2008 12:25:01,spid23s,Unknown,process id=processfbb1f8 taskpriority=5 logused=19696 waitresource=PAGE: 7:1:1594571 waittime=105515 ownerId=650440632 transactionguid=0x216c433f079bed4ba0df783acba3734e transactionname=DTCXact lasttranstarted=2008-07-02T10:09:16.107 XDES=0x4a3d5480 lockMode=IU schedulerid=3 kpid=11040 status=suspended spid=51 sbid=0 ecid=0 priority=-5 transcount=2 lastbatchstarted=2008-07-02T10:09:16.187 lastbatchcompleted=2008-07-02T10:09:16.187 clientapp=Microsoft® Windows® Operating System hostname=FTWSTKSQL02 hostpid=13184 loginname=marypoppins isolationlevel=read uncommitted (1) xactid=650440632 currentdb=7 lockTimeout=4294967295 clientoption1=538968096 clientoption2=128056

    06/30/2008 12:25:01,spid23s,Unknown,inputbuf

    06/30/2008 12:25:01,spid23s,Unknown,exec sps_SERVER_ImportProcessing_MidDay 1425 'FTWSTKSQL02'

    06/30/2008 12:25:01,spid23s,Unknown,frame procname=adhoc line=1 sqlhandle=0x0100070063dc2502d0569e49000000000000000000000000

    06/30/2008 12:25:01,spid23s,Unknown,-- PRINT 'Morning Import Has Run Starting Mid-Day Import'

    06/30/2008 12:25:01,spid23s,Unknown,EXEC sps_SERVER_ImportProcessing @LastModifiedBy 'MIDDAY'

    06/30/2008 12:25:01,spid23s,Unknown,frame procname=SERVER.dbo.sps_SERVER_Processing_Day line=41 stmtstart=1778 stmtend=2024 sqlhandle=0x0300070001177b154186bc00a29a00000100000000000000

    06/30/2008 12:25:01,spid23s,Unknown,EXECUTE @Result = sps_SERVER_UpdateExceptions @LastModifiedBy @Location

    06/30/2008 12:25:01,spid23s,Unknown,frame procname=SERVER.dbo.sps_SERVER_ImportProcessing line=776 stmtstart=58128 stmtend=58316 sqlhandle=0x030007009da2bc0bbf433501c49a00000100000000000000

    06/30/2008 12:25:01,spid23s,Unknown,-- 02/03/2006 DUS close exceptions for accounts not on a worklist per SCR 14519. END.

    06/30/2008 12:25:01,spid23s,Unknown,-- 06/06/2008 DUS Performance Improvement per SCR 19090. PART 2 of 2. END.

    06/30/2008 12:25:01,spid23s,Unknown,AND OVM.PKSERVER_VisitModules IS NULL*/

    06/30/2008 12:25:01,spid23s,Unknown,FKSERVER_Worklists IS NULL

    06/30/2008 12:25:01,spid23s,Unknown,WHERE

    06/30/2008 12:25:01,spid23s,Unknown,ON OE.FKSERVER_Visits = OVM.FKSERVER_Visits

    06/30/2008 12:25:01,spid23s,Unknown,LEFT JOIN SERVER_VisitModules OVM

    06/30/2008 12:25:01,spid23s,Unknown,FROM SERVER_Exceptions OE

    06/30/2008 12:25:01,spid23s,Unknown,ThroughDateTime = getdate()

    06/30/2008 12:25:01,spid23s,Unknown,LastModifiedDate = @LastModifiedDate

    06/30/2008 12:25:01,spid23s,Unknown,Location = @Location

    06/30/2008 12:25:01,spid23s,Unknown,LastModifiedBy = @LastModifiedBy

    06/30/2008 12:25:01,spid23s,Unknown,SET

    06/30/2008 12:25:01,spid23s,Unknown,/*UPDATE SERVER_Exceptions

    06/30/2008 12:25:01,spid23s,Unknown,ON OE.PKSERVER_Exceptions = TE.PKSERVER_Exceptions

    06/30/2008 12:25:01,spid23s,Unknown,INNER JOIN #Temp_Exceptions2 TE

    06/30/2008 12:25:01,spid23s,Unknown,FROM SERVER_Exceptions OE

    06/30/2008 12:25:01,spid23s,Unknown,ThroughDateTime = getdate()

    06/30/2008 12:25:01,spid23s,Unknown,LastModifiedDate = @LastModifiedDate

    06/30/2008 12:25:01,spid23s,Unknown,Location = @Location

    06/30/2008 12:25:01,spid23s,Unknown,SET LastModifiedBy = @LastModifiedBy

    06/30/2008 12:25:01,spid23s,Unknown,UPDATE SERVER_Exceptions WITH (ROWLOCK)

    06/30/2008 12:25:01,spid23s,Unknown,frame procname=SERVER.dbo.sps_SERVER_UpdateExceptions line=117 stmtstart=7906 stmtend=9510 sqlhandle=0x03000700e9bfa03b56e42401be9a00000100000000000000

    06/30/2008 12:25:01,spid23s,Unknown,executionStack

    06/30/2008 12:25:01,spid23s,Unknown,process id=processa43a68 taskpriority=5 logused=23987732 waitresource=KEY: 7:72057600365101056 (14002b8f6209) waittime=3031 ownerId=650127885 transactionname=user_transaction lasttranstarted=2008-07-02T10:00:20.317 XDES=0x4c4adc18 lockMode=U schedulerid=2 kpid=5268 status=suspended spid=76 sbid=0 ecid=15 priority=0 transcount=0 lastbatchstarted=2008-07-02T10:00:14.910 lastbatchcompleted=2008-07-02T10:00:14.910 clientapp=DTS Designer hostname=FTWSTKSQL02 hostpid=6660 isolationlevel=read committed (2) xactid=650127885 currentdb=7 lockTimeout=4294967295 clientoption1=538968096 clientoption2=128056

    06/30/2008 12:25:01,spid23s,Unknown,process-list

    06/30/2008 12:25:01,spid23s,Unknown,deadlock victim=process3449c4d8

    06/30/2008 12:25:01,spid23s,Unknown,deadlock-list

    06/30/2008 12:25:01,spid10s,Unknown,ResType:ExchangeId Stype:'AND' SPID:76 BatchID:0 ECID:0 TaskProxy:(0x405C2364) Value:0x2ecf2350 Cost:(5/10007)

    06/30/2008 12:25:01,spid10s,Unknown,Victim Resource Owner:

    06/30/2008 12:25:01,spid10s,Unknown,Log Viewer could not read information for this log entry. Cause: Data is Null. This method or property cannot be called on Null values.. Content:

    06/30/2008 12:25:01,spid10s,Unknown,ResType:LockOwner Stype:'OR'Xdes:0x4C4ADC18 Mode: U SPID:76 BatchID:0 ECID:15 TaskProxy:(0x43FBA700) Value:0x325d8ee0 Cost:(5/23987732)

    06/30/2008 12:25:01,spid10s,Unknown,Requested By:

    06/30/2008 12:25:01,spid10s,Unknown,Owner:0x431ABAE0 Mode: X Flg:0x0 Ref:0 Life:02000000 SPID:51 ECID:0 XactLockInfo: 0x4A3D54A4

    06/30/2008 12:25:01,spid10s,Unknown,Grant List 1:

    06/30/2008 12:25:01,spid10s,Unknown,KEY: 7:72057600365101056 (14002b8f6209) CleanCnt:2 Mode:X Flags: 0x0

    06/30/2008 12:25:01,spid10s,Unknown,Node:7

    06/30/2008 12:25:01,spid10s,Unknown,Log Viewer could not read information for this log entry. Cause: Data is Null. This method or property cannot be called on Null values.. Content:

    06/30/2008 12:25:01,spid10s,Unknown,Node:3

    06/30/2008 12:25:01,spid10s,Unknown,Log Viewer could not read information for this log entry. Cause: Data is Null. This method or property cannot be called on Null values.. Content:

    06/30/2008 12:25:01,spid10s,Unknown,Log Viewer could not read information for this log entry. Cause: Data is Null. This method or property cannot be called on Null values.. Content:

    06/30/2008 12:25:01,spid10s,Unknown,-- next branch --

    06/30/2008 12:25:01,spid10s,Unknown,Log Viewer could not read information for this log entry. Cause: Data is Null. This method or property cannot be called on Null values.. Content:

    06/30/2008 12:25:01,spid10s,Unknown,ResType:LockOwner Stype:'OR'Xdes:0x4A3D5480 Mode: IU SPID:51 BatchID:0 ECID:0 TaskProxy:(0x3AD36378) Value:0x5cf3ef60 Cost:(5/19696)

    06/30/2008 12:25:01,spid10s,Unknown,Requested By:

    06/30/2008 12:25:01,spid10s,Unknown,Owner:0x449251E0 Mode: UIX Flg:0x0 Ref:0 Life:02000000 SPID:76 ECID:0 XactLockInfo: 0x5AE4182C

    06/30/2008 12:25:01,spid10s,Unknown,Grant List 2:

    06/30/2008 12:25:01,spid10s,Unknown,PAGE: 7:1:1594571 CleanCnt:3 Mode:UIX Flags: 0x2

    06/30/2008 12:25:01,spid10s,Unknown,Node:5

    06/30/2008 12:25:01,spid10s,Unknown,Log Viewer could not read information for this log entry. Cause: Data is Null. This method or property cannot be called on Null values.. Content:

    06/30/2008 12:25:01,spid10s,Unknown,ResType:LockOwner Stype:'OR'Xdes:0x4BA513D8 Mode: U SPID:76 BatchID:0 ECID:11 TaskProxy:(0x43FBA640) Value:0x5e658de0 Cost:(5/23987732)

    06/30/2008 12:25:01,spid10s,Unknown,Requested By:

    06/30/2008 12:25:01,spid10s,Unknown,Input Buf: RPC Event: Proc [Database Id = 7 Object Id = 345678234]

    06/30/2008 12:25:01,spid10s,Unknown,SPID: 51 ECID: 0 Statement Type: UPDATE Line #: 734

    06/30/2008 12:25:01,spid10s,Unknown,Owner:0x3E8EB0E0 Mode: X Flg:0x0 Ref:0 Life:02000000 SPID:51 ECID:0 XactLockInfo: 0x4A3D54A4

    06/30/2008 12:25:01,spid10s,Unknown,Grant List 1:

    06/30/2008 12:25:01,spid10s,Unknown,KEY: 7:72057600365101056 (4500f3396951) CleanCnt:2 Mode:X Flags: 0x0

    06/30/2008 12:25:01,spid10s,Unknown,Node:4

    06/30/2008 12:25:01,spid10s,Unknown,Log Viewer could not read information for this log entry. Cause: Data is Null. This method or property cannot be called on Null values.. Content:

    06/30/2008 12:25:01,spid10s,Unknown,Node:3

    06/30/2008 12:25:01,spid10s,Unknown,Log Viewer could not read information for this log entry. Cause: Data is Null. This method or property cannot be called on Null values.. Content:

    06/30/2008 12:25:01,spid10s,Unknown,Node:2

    06/30/2008 12:25:01,spid10s,Unknown,Log Viewer could not read information for this log entry. Cause: Data is Null. This method or property cannot be called on Null values.. Content:

    06/30/2008 12:25:01,spid10s,Unknown,ResType:LockOwner Stype:'OR'Xdes:0x4BE93A50 Mode: IX SPID:81 BatchID:0 ECID:0 TaskProxy:(0x42FE4378) Value:0x1a5eac60 Cost:(5/0)

    06/30/2008 12:25:01,spid10s,Unknown,Requested By:

    06/30/2008 12:25:01,spid10s,Unknown,Input Buf: Language Event: exec sps_SERVER_IProcessing_Day 2456 'FTWSTKSQL02'--servername

    06/30/2008 12:25:01,spid10s,Unknown,SPID: 76 ECID: 0 Statement Type: UPDATE Line #: 347

    06/30/2008 12:25:01,spid10s,Unknown,Owner:0x3EE18440 Mode: SIX Flg:0x0 Ref:0 Life:02000000 SPID:76 ECID:0 XactLockInfo: 0x5AE4182C

    06/30/2008 12:25:01,spid10s,Unknown,Grant List 2:

    06/30/2008 12:25:01,spid10s,Unknown,Grant List 0:

    06/30/2008 12:25:01,spid10s,Unknown,PAGE: 7:1:1930780 CleanCnt:2 Mode:SIX Flags: 0x2

    06/30/2008 12:25:01,spid10s,Unknown,Node:1

    06/30/2008 12:25:01,spid10s,Unknown,Log Viewer could not read information for this log entry. Cause: Data is Null.

    This method or property cannot be called on Null values.. Content:

    06/30/2008 12:25:01,spid10s,Unknown,Wait-for graph

    06/30/2008 12:25:01,spid10s,Unknown,Deadlock encountered .... Printing deadlock

  • Did u happen to check if there are INSERTS/UPDATES/SELECTS happening on the Database at the same time. the SPID are system SPID's, so better be carefull is you are thinking of using the Kill statement.

  • yes Lot of insert\update\deletes are happening at this time and looks like none of them is system SPIDs.The thing is deadlock is getting resolved automatically but its rolling back that process which we dont want to rollback.I set deadlock priority also.

  • Wow, that's an impressive deadlock. Was that a once off, or is it reoccurring?

    I would suggest that you enable either 1204 or 1222, not both. They have the same purpose, just different output formats.

    Now, what can be gleaned from this:

    Node 1:

    procedure sps_SERVER_IProcessing_Day 2456 'FTWSTKSQL02' deadlocked on Line #: 347, doing an update. Resource: Page 7:1:1930780

    To find the table involved, run the following

    DBCC TRACEON (3604) -- output to client

    DBCC PAGE (7,1,1930780) -- dump page headers

    DBCC TRACEFF (3604)

    You will see a lot of info from the page headers. Look for the object ID, then run SELECT OBJECT_NAME(<ObjectID>) in the database that this lot is in.

    Node 4 - executing a procedure with the ID 345678234. Deadlocked on line 734 doing an update. Resource on key 7:72057600365101056

    To find the name of the proc, run SELECT OBJECT_NAME(345678234)

    To find the table it was deadlocking on, run the following

    select o.name

    from sys.partitions p

    inner join sys.objects o on p.object_id = o.object_id

    where p.partition_id = 72057600365101056

    Node:5 - deadlocked on PAGE: 7:1:1594571

    Can't see the input buffer. Use same method as for node 1 to locate the table.

    Node 7, I'm not sure how to interpret. There are references to stored procs that you could check.

    SERVER.dbo.sps_SERVER_Processing_Day line=41

    SERVER.dbo.sps_SERVER_ImportProcessing line=776

    SERVER.dbo.sps_SERVER_UpdateExceptions line=117

    Could be a stack trace.

    The resource it mentions is the same as for node 4 - key 7:72057600365101056

    Does that help at all?

    Also, 700 line long stored procs? :ermm:

    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

    We walk in the dark places no others will enter
    We stand on the bridge and no one may pass
  • Mani Singh (7/7/2008)


    the SPID are system SPID's, so better be carefull is you are thinking of using the Kill statement.

    The system spids are the ones reporting the deadlock, not the ones involved in the deadlock. Also, you don't have to kill processes when you get a deadlock. SQL will detect the deadlock and automatically kill one of the connections.

    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

    We walk in the dark places no others will enter
    We stand on the bridge and no one may pass

Viewing 5 posts - 1 through 4 (of 4 total)

You must be logged in to reply to this topic. Login to reply