How to trace Deadlock in SQL Server 2000
-
Hi All,
While we are executing a procedure for differenct parameters at the same time, we are encountering 'Deadlock' problem..
For Ex.
If we are executing the following procedure for different parameters, we are facing this problem. (of course, it is calling more than 20 procedures)
proc_create_fsa_export '20070630','755','Y','html'
proc_create_fsa_export '20070630','284,'Y','html'
---------
We enabled following traces
DBCC TRACEON (3604)
DBCC TRACEON (1204)
---------------------
This is log file we got
-------------
2007-07-16 13:34:56.59 logon Login failed for user 'JUnitCustomer'.
2007-07-16 13:34:56.67 logon Login failed for user 'JUnitCustomer'.
2007-07-16 13:34:56.71 logon Login failed for user 'JUnitCustomer'.
2007-07-16 13:34:56.84 logon Login failed for user 'JUnitCustomer'.
2007-07-16 13:35:12.43 spid4 ResType:LockOwner Stype:'OR' Mode: IX SPID:78 ECID:0 Ec
0x6B133538) Value:0x292007-07-16 13:35:12.43 spid4 Victim Resource Owner:
2007-07-16 13:35:12.43 spid4 ResType:LockOwner Stype:'OR' Mode: IX SPID:78 ECID:0 Ec
0x6B133538) Value:0x292007-07-16 13:35:12.43 spid4 Requested By:
2007-07-16 13:35:12.43 spid4 Grant List 2::
2007-07-16 13:35:12.43 spid4 Input Buf: Language Event: proc_create_fsa_export '20070630','755','Y','html'
2007-07-16 13:35:12.43 spid4 SPID: 74 ECID: 0 Statement Type: UPDATE Line #: 240
2007-07-16 13:35:12.43 spid4 Owner:0x6965bc00 Mode: S Flg:0x0 Ref:0 Life:00000001 SPID:74 ECID:0
2007-07-16 13:35:12.43 spid4 Grant List 0::
2007-07-16 13:35:12.43 spid4 PAG: 10:1:77490 CleanCnt:2 Mode: SIU Flags: 0x2
2007-07-16 13:35:12.43 spid4 Node:2
2007-07-16 13:35:12.43 spid4
2007-07-16 13:35:12.43 spid4 ResType:LockOwner Stype:'OR' Mode: IX SPID:74 ECID:0 Ec
0x7BB75538) Value:0x292007-07-16 13:35:12.43 spid4 Requested By:
2007-07-16 13:35:12.43 spid4 Input Buf: Language Event: proc_create_fsa_export '20070630','284','Y','html'
2007-07-16 13:35:12.43 spid4 SPID: 78 ECID: 0 Statement Type: UPDATE Line #: 351
2007-07-16 13:35:12.43 spid4 Owner:0x2f9157c0 Mode: S Flg:0x0 Ref:0 Life:00000001 SPID:78 ECID:0
2007-07-16 13:35:12.43 spid4 Grant List 2::
2007-07-16 13:35:12.43 spid4 Grant List 0::
2007-07-16 13:35:12.43 spid4 PAG: 10:1:77489 CleanCnt:2 Mode: SIU Flags: 0x2
2007-07-16 13:35:12.43 spid4 Node:1
2007-07-16 13:35:12.43 spid4
2007-07-16 13:35:12.43 spid4 Wait-for graph
2007-07-16 13:35:12.43 spid4
2007-07-16 13:35:12.43 spid4 ...
2007-07-16 13:35:34.57 logon Login failed for user 'JUnitCustomer'.
2007-07-16 13:35:34.73 logon Login failed for user 'JUnitCustomer'.
2007-07-16 13:35:34.76 logon Login failed for user 'JUnitCustomer'.
2007-07-16 13:35:34.89 logon Login failed for user 'JUnitCustomer'.
2007-07-16 13:35:38.56 logon Login failed for user 'JUnitCustomer'.
----------
We could not see KEY in this trace file.
Kindly help us to fix this issue.
Regards,
Ezhilan
-
Check setting isolation levels appropriate so that deadlocks and locks can be avoided.
Cheers,
Sugeshkumar Rajendran
SQL Server MVP
http://sugeshkr.blogspot.com -
Hi Sugesh,
How about using this at the beginning of the procedure...
SET TRANSACTION ISOLATION LEVEL
{ READ COMMITTED
| READ UNCOMMITTED
| REPEATABLE READ
| SERIALIZABLE
}
By the way, which Transaction level is recommended to use..
Regards,
Ezhilan
-
You can use read committed isolation level so that you don't get uncommitted data as a result.
Cheers,
Sugeshkumar Rajendran
SQL Server MVP
http://sugeshkr.blogspot.com -
Isolation levels may help, but the real problem is going to be in the code. If you have explicit transactions that look like the following, you may want to consider making the code so that it doesn't need to both read and write to the same tables within the transaction...
BEGIN TRAN
UPDATE sametable
...yadda, yadda...
SELECT whatever
FROM sametable
COMMIT
or vice-versa. And, it may not be quite that simple... there may be multiple tables involved because of all the procs (sounds like you wrote it to do one row at a time... lemme guess... I'll bet cursors or While loops are involved) and you may have very long running explicit transactions across multiple tables depending on if you started a transaction in the outer proc.
The key is to make transactions as short, sweet, fast as possible, and to affect as few tables as possible. And, setting the transaction isolation level to even READ UNCOMMITTED may not help because WRITEs place locks no matter what.
If you're main program does something like this, you're gonna need to consider some major rework in not only the code, but how you think, as well...
--Start of Main Proc
WHILE rows remain to be processed (or not... might be just one row)
BEGIN
BEGIN TRAN
... do something to start working on one row...
CALL PROCA (which does updates and selects)
PROCA CALLS PROCB (which does updates and selects)
PROCB CALLS PROCC (maybe even in a loop) (which does upates and selects)
CALL PROCD (which does updates and selects)
PROCD CALLS PROCE (which does updates and selects)
PROCE CALLS PROCC (maybe even in a loop) (which does upates and selects)
...etc, etc..
COMMIT
END -- of loop... loop until all rows complete
...absolutely worst scenario in the world for deadlocks especially if more than one instance of the proc runs at a time. You're gonna need to find a way to make the amount of code that runs between the outer-most BEGIN TRAN/COMMIT pair a heck of a lot shorter.
And, PLEASE, THIS IS IMPORTANT!!!! I hope you're not using a sequence table or a NextID table in all of this... if you are, then I guarantee THAT is the main source of the deadlocks in this proc... most folks just don't know how to write a correct GetNextID proc for those and they end up with hundreds and even thousands of deadlocks a day. How do I know? I work for a company that used to have that problem and I fixed it... they had an AVERAGE of 640 deadlocks per day with spikes to 4000 deadlocks in a single day. After I fixed the GetNextID proc and built a couple of staging tables for the intensly hit tables, their deadlocks dropped to only 12 a day. A lot more rework (move all calls to GetNextID out of transactions) was necessary to get it down to 0 to 5 a day... I'm still working on the others.
The main source of our problem was a really poorly written 3rd party application... in other words, really bad code. That's the key... code that wasn't written correctly... if you have code that calls 20 procs individually for each row, you've got some potentially serious bad code that you're going to have to scope out for long running transactions and shorten them up, big time.
--Jeff Moden
RBAR is pronounced "ree-bar" and is a "Modenism" for Row-By-Agonizing-Row.
First step towards the paradigm shift of writing Set Based code:
________Stop thinking about what you want to do to a ROW... think, instead, of what you want to do to a COLUMN.Change is inevitable... Change for the better is not.
Helpful Links:
How to post code problems
How to Post Performance Problems
Create a Tally Function (fnTally) -
P.S. And, you don't need to see the KEY in this case... the report not only tells you which proc is doing it... it also tells you the line numbers in the proc that are causing the problem
--Jeff Moden
RBAR is pronounced "ree-bar" and is a "Modenism" for Row-By-Agonizing-Row.
First step towards the paradigm shift of writing Set Based code:
________Stop thinking about what you want to do to a ROW... think, instead, of what you want to do to a COLUMN.Change is inevitable... Change for the better is not.
Helpful Links:
How to post code problems
How to Post Performance Problems
Create a Tally Function (fnTally) -
Hi Jelf Moden,
Thankyou very much for your inputs. It was really useful.
BTW...can you please tell me, how can I find out which procedure is doing it and line numbers which cause the problem.
Sorry, I am novice in SQL Server.
Regards,
Ezhilan
-
2007-07-16 13:35:12.43 spid4 Input Buf: Language Event: proc_create_fsa_export '20070630','755','Y','html'
2007-07-16 13:35:12.43 spid4 SPID: 74 ECID: 0 Statement Type: UPDATE Line #: 240
2007-07-16 13:35:12.43 spid4 Owner:0x6965bc00 Mode: S Flg:0x0 Ref:0 Life:00000001 SPID:74 ECID:0
2007-07-16 13:35:12.43 spid4 Grant List 0::
2007-07-16 13:35:12.43 spid4 PAG: 10:1:77490 CleanCnt:2 Mode: SIU Flags: 0x2
2007-07-16 13:35:12.43 spid4 Node:2
2007-07-16 13:35:12.43 spid4
2007-07-16 13:35:12.43 spid4 ResType:LockOwner Stype:'OR' Mode: IX SPID:74 ECID:0 Ec
0x7BB75538) Value:0x292007-07-16 13:35:12.43 spid4 Requested By:
2007-07-16 13:35:12.43 spid4 Input Buf: Language Event: proc_create_fsa_export '20070630','284','Y','html'
2007-07-16 13:35:12.43 spid4 SPID: 78 ECID: 0 Statement Type: UPDATE Line #: 351
2007-07-16 13:35:12.43 spid4 Owner:0x2f9157c0 Mode: S Flg:0x0 Ref:0 Life:00000001 SPID:78 ECID:0
Line numbers are marked. This should help you now.
Cheers,
Sugeshkumar Rajendran
SQL Server MVP
http://sugeshkr.blogspot.com -
2007-07-16 13:34:56.59 logon Login failed for user 'JUnitCustomer'.
2007-07-16 13:34:56.67 logon Login failed for user 'JUnitCustomer'.
2007-07-16 13:34:56.71 logon Login failed for user 'JUnitCustomer'.
2007-07-16 13:34:56.84 logon Login failed for user 'JUnitCustomer'.
2007-07-16 13:35:12.43 spid4 ResType:LockOwner Stype:'OR' Mode: IX SPID:78 ECID:0 Ec
0x6B133538) Value:0x292007-07-16 13:35:12.43 spid4 Victim Resource Owner:
2007-07-16 13:35:12.43 spid4 ResType:LockOwner Stype:'OR' Mode: IX SPID:78 ECID:0 Ec
0x6B133538) Value:0x292007-07-16 13:35:12.43 spid4 Requested By:
2007-07-16 13:35:12.43 spid4 Grant List 2::
2007-07-16 13:35:12.43 spid4 Input Buf: Language Event: proc_create_fsa_export '20070630','755','Y','html'
2007-07-16 13:35:12.43 spid4 SPID: 74 ECID: 0 Statement Type: UPDATE Line #: 240
2007-07-16 13:35:12.43 spid4 Owner:0x6965bc00 Mode: S Flg:0x0 Ref:0 Life:00000001 SPID:74 ECID:0
2007-07-16 13:35:12.43 spid4 Grant List 0::
2007-07-16 13:35:12.43 spid4 PAG: 10:1:77490 CleanCnt:2 Mode: SIU Flags: 0x2
2007-07-16 13:35:12.43 spid4 Node:2
2007-07-16 13:35:12.43 spid4
2007-07-16 13:35:12.43 spid4 ResType:LockOwner Stype:'OR' Mode: IX SPID:74 ECID:0 Ec
0x7BB75538) Value:0x292007-07-16 13:35:12.43 spid4 Requested By:
2007-07-16 13:35:12.43 spid4 Input Buf: Language Event: proc_create_fsa_export '20070630','284','Y','html'
2007-07-16 13:35:12.43 spid4 SPID: 78 ECID: 0 Statement Type: UPDATE Line #: 351
2007-07-16 13:35:12.43 spid4 Owner:0x2f9157c0 Mode: S Flg:0x0 Ref:0 Life:00000001 SPID:78 ECID:0
2007-07-16 13:35:12.43 spid4 Grant List 2::
2007-07-16 13:35:12.43 spid4 Grant List 0::
2007-07-16 13:35:12.43 spid4 PAG: 10:1:77489 CleanCnt:2 Mode: SIU Flags: 0x2
--Jeff Moden
RBAR is pronounced "ree-bar" and is a "Modenism" for Row-By-Agonizing-Row.
First step towards the paradigm shift of writing Set Based code:
________Stop thinking about what you want to do to a ROW... think, instead, of what you want to do to a COLUMN.Change is inevitable... Change for the better is not.
Helpful Links:
How to post code problems
How to Post Performance Problems
Create a Tally Function (fnTally) -
Hope you are using these trace flags in the SQL server startup parameter
1204 and 3605
These trace flags will show you the deadlock information in the errorlog..
hope this helps !
-
Heh... look at the original post... no need to put these in startup (although that's a good idea!).
--Jeff Moden
RBAR is pronounced "ree-bar" and is a "Modenism" for Row-By-Agonizing-Row.
First step towards the paradigm shift of writing Set Based code:
________Stop thinking about what you want to do to a ROW... think, instead, of what you want to do to a COLUMN.Change is inevitable... Change for the better is not.
Helpful Links:
How to post code problems
How to Post Performance Problems
Create a Tally Function (fnTally) -
Hehe ... GetNextID again
Yes it does require careful programing practices.
In other set of things you should also try to keep access to the tables in the "same" sequence and only touch each destination table "ONCE" per transaction.
Just my $0.02
* Noel -
initial problem statement shows trace parameters 1204 and 3604. What's the difference between 3604 and 3605?
-
3604 is to log everytime that deadlock monitor start running DONOT use that 3605 is the guy!
* Noel -
3604 directs output to the client, 3605 directs it into the error log.
I don't think 3605 is necessary. 1204 on its own writes deadlock info into the error log. We used just that one for over a year and all deadlock graphs showed up in the error log.
3604 and 3605 are usually used with things like DBCC page
Gail Shaw
Microsoft Certified Master: SQL Server, MVP, M.Sc (Comp Sci)
SQL In The Wild: Discussions on DB performance with occasional diversions into recoverabilityWe walk in the dark places no others will enter
We stand on the bridge and no one may pass
Viewing 15 posts - 1 through 14 (of 14 total)
You must be logged in to reply to this topic. Login to reply