Trying to track deadlocking jobs (NOP?)

Please start any new threads on our new site at https://forums.sqlteam.com. We've got lots of great SQL Server experts to answer whatever question you can come up with.

All Forums

SQL Server 2005 Forums

Transact-SQL (2005)

Trying to track deadlocking jobs (NOP?)

Author

Topic

Transact Charlie
Master Smack Fu Yak Hacker

3451 Posts

Posted - 2009-08-11 : 05:18:34

Hi all,

I've got an extremely annoying intermittent problem.

Here's the setup:

There is a database server (running 2005 standard edition).

The server has 35 databases, each of which is schematically identical. (they are different clients so the data is different but the database structure is identical)

Each of the databases has an associated overnight job (a scheduled job that runs at 01:00).

The overnight jobs do a few things but the one that seems to be giving me a problem is the first step. This step is responsible for updating employee information in the database based on an [approvalEvent] table. this table holds pending changes to employees details -- like name changes to be performed at a certain date for example.

The first step is vary simple. It calls a stored proc. The stored proc loops through any changes that should happen (which is usually 0 but depending on time of year can go into hundreds of changes) and then dynamically UPDATES certain tables.

Everything is local to the database in question. Nothing should be referencing any outside objects.

This setup has been working fine (without changes) for a year or two. (of course there are sometimes problems when users have entered crazy data but the jobs still *work*)

Recently though some of them (randomly) have been deadlocking and being chosen as the deadlock victim. This appears to be completely random. Everything will be fine for a week or so and then one day (like today) I come in and find my mailbox has 4 failed jobs. (all on same server, all in step 1, all chosen as the deadlock victim with another process).

==========================================

Steps taken so far:

I didn't want to run profiler on the database server because I can never be sure when a problem is going to happen and I didn't want to add more load to the server.

What I did do was add some debug logic to the failure step (that sends me an email if there has been a problem). I am now dumping the output of a customised sp_who type stored proc into a table on the database in the result of a failure.

I'm getting output like this:


dbname	spid	status	login	blkBy	command	CPUTime	diskIO	lastBatch	programName
master	326	RUNNABLE                      	NT AUTHORITY\SYSTEM	  .	SELECT INTO     	78	176	08/11/2009 01:00	SQLAgent - TSQL JobStep (Job 0x1E68C5747ACA9A4EB756DB8BE23A2C42 : Step 5)
master	327	SUSPENDED                     	NT AUTHORITY\SYSTEM	  .	INSERT          	125	184	08/11/2009 01:00	SQLAgent - TSQL JobStep (Job 0x542AA1FF43E02E438B633535820665CD : Step 5)
A	346	SUSPENDED                     	NT AUTHORITY\SYSTEM	357	NOP             	63	176	08/11/2009 01:00	SQLAgent - TSQL JobStep (Job 0x7483171FE6F2EA4B9122E6A2399AD6ED : Step 1)
master	328	SUSPENDED                     	NT AUTHORITY\SYSTEM	  .	SELECT INTO     	62	143	08/11/2009 01:00	SQLAgent - TSQL JobStep (Job 0xB1B2BE1E7EC42B42B9095AB5802FFF4A : Step 5)
B	329	SUSPENDED                     	NT AUTHORITY\SYSTEM	  .	SELECT          	31	21	08/11/2009 01:00	SQLAgent - TSQL JobStep (Job 0x070AC6308B31304F8A8904186DA0A8A6 : Step 3)
C	330	SUSPENDED                     	NT AUTHORITY\SYSTEM	  .	SELECT          	0	11	08/11/2009 01:00	SQLAgent - TSQL JobStep (Job 0x235B912DAD49F24E93B5E002C2D1611E : Step 3)
D	331	SUSPENDED                     	NT AUTHORITY\SYSTEM	357	NOP             	16	170	08/11/2009 01:00	SQLAgent - TSQL JobStep (Job 0x26EA886C6C55AD42A5D16669CB3E7462 : Step 1)
E	332	SUSPENDED                     	NT AUTHORITY\SYSTEM	  .	EXECUTE         	266	399	08/11/2009 01:00	SQLAgent - TSQL JobStep (Job 0x16885C2BABAD8A41B7F4EB0C1EA4072E : Step 2)
F	333	SUSPENDED                     	NT AUTHORITY\SYSTEM	  .	SELECT          	0	60	08/11/2009 01:00	SQLAgent - TSQL JobStep (Job 0xD53EAA7FE85F9D43823836431E400E49 : Step 3)
G	334	SUSPENDED                     	NT AUTHORITY\SYSTEM	  .	UPDATE          	79	78	08/11/2009 01:00	SQLAgent - TSQL JobStep (Job 0x36F0CACFDAD2624E983B023C42E583D9 : Step 2)
H	335	SUSPENDED                     	NT AUTHORITY\SYSTEM	357	NOP             	0	188	08/11/2009 01:00	SQLAgent - TSQL JobStep (Job 0xBB212EE8232E694F9DFE69F5F41E182E : Step 1)
I	336	SUSPENDED                     	NT AUTHORITY\SYSTEM	357	NOP             	16	149	08/11/2009 01:00	SQLAgent - TSQL JobStep (Job 0x4FD41A5F39A73C4581F0A95655F0B8DB : Step 1)
J	337	SUSPENDED                     	NT AUTHORITY\SYSTEM	357	NOP             	31	162	08/11/2009 01:00	SQLAgent - TSQL JobStep (Job 0x21289C9EE1082B41B9E75693CEBB6E38 : Step 1)
K	338	SUSPENDED                     	NT AUTHORITY\SYSTEM	  .	SELECT          	15	69	08/11/2009 01:00	SQLAgent - TSQL JobStep (Job 0xFEB05139903B6C4DAC9F7B2F0F6A0AD5 : Step 2)
L	339	SUSPENDED                     	NT AUTHORITY\SYSTEM	  .	SELECT          	125	306	08/11/2009 01:00	SQLAgent - TSQL JobStep (Job 0xA8316D72B30CB34586FBA4D7D1492E24 : Step 2)
M	340	SUSPENDED                     	NT AUTHORITY\SYSTEM	357	NOP             	31	223	08/11/2009 01:00	SQLAgent - TSQL JobStep (Job 0x77530367AB7BCE48A2618ADBC65CE8B4 : Step 1)
N	341	SUSPENDED                     	NT AUTHORITY\SYSTEM	  .	SELECT          	15	145	08/11/2009 01:00	SQLAgent - TSQL JobStep (Job 0x6B85738C6795644EB0B8F4D051212FD7 : Step 1)
O	342	SUSPENDED                     	NT AUTHORITY\SYSTEM	357	NOP             	15	171	08/11/2009 01:00	SQLAgent - TSQL JobStep (Job 0xA5A672CE4DA25F4B8C7DE9A4C7F46906 : Step 1)
P	343	SUSPENDED                     	NT AUTHORITY\SYSTEM	357	NOP             	0	103	08/11/2009 01:00	SQLAgent - TSQL JobStep (Job 0x7AAAD25F94434C4AB9C24E219E0D1465 : Step 1)
Q	344	SUSPENDED                     	NT AUTHORITY\SYSTEM	  .	OPEN CURSOR     	516	1388	08/11/2009 01:00	SQLAgent - TSQL JobStep (Job 0x2320CCFF638993458AC5B3986FB848F6 : Step 1)
tempdb	345	RUNNABLE                      	NT AUTHORITY\SYSTEM	  .	SELECT          	110	223	08/11/2009 01:00	SQLAgent - TSQL JobStep (Job 0xF1B30FB973FDE34F8EF2A67D28DCD2B7 : Step 5)
R	353	SUSPENDED                     	NT AUTHORITY\SYSTEM	  .	NOP             	16	119	08/11/2009 01:00	SQLAgent - TSQL JobStep (Job 0x7797EB585EFA8F4F863A0288BB24117E : Step 1)
S	354	SUSPENDED                     	NT AUTHORITY\SYSTEM	  .	EXECUTE         	0	9	08/11/2009 01:00	SQLAgent - TSQL JobStep (Job 0x5A3E4D670FE01743A9E4A9DD226D143C : Step 3)
T	355	SUSPENDED                     	NT AUTHORITY\SYSTEM	357	NOP             	32	153	08/11/2009 01:00	SQLAgent - TSQL JobStep (Job 0x93D7D317F3B96948A1A97CCBC1119AB0 : Step 1)
U	356	SUSPENDED                     	NT AUTHORITY\SYSTEM	357	NOP             	78	197	08/11/2009 01:00	SQLAgent - TSQL JobStep (Job 0x07DDD1A0A90BD8499E27AA4E4ADBFB93 : Step 1)
V	357	SUSPENDED                     	NT AUTHORITY\SYSTEM	353	NOP             	31	136	08/11/2009 01:00	SQLAgent - TSQL JobStep (Job 0x6E3E4E068EFE1B458E75675821A2D165 : Step 1)
W	358	SUSPENDED                     	NT AUTHORITY\SYSTEM	  .	SELECT          	94	4880	08/11/2009 01:00	SQLAgent - TSQL JobStep (Job 0x14D4F6B54D329D499DEBA48D9986E755 : Step 1)
X	359	SUSPENDED                     	NT AUTHORITY\SYSTEM	  .	SELECT          	16	40	08/11/2009 01:00	SQLAgent - TSQL JobStep (Job 0xDE690772EFC7394DA5E4A12163A4592A : Step 2)

(I've changed the dbNames to protect my clients).

As you can see STEP 1 is trying to do a NOP?? command (is that NO-OPERATION)?

And they are all blocked by another STEP 1 process also doing a NOP command (357).

That spid is in turn blocked by 353 which is also doing NOP (nothing?).

The stored proc is very simple (if a little horrible).

In outline what it does is this:

Declares a cursor to loop through event lines

1) Makes up a dyanimc string for each line which is an UPDATE statement which targets one of 5 tables (none of which typically contains more than 10,000 rows of data)

2) Executes the update statement

3) repeat.

Depending on amount of changes this proc can take at max a minute to run.

Does anyone have any more information about this NOP command? If it is really doing nothing then it seems odd that something else also doing nothing can be blocking it.

Any other advice about the jobs?

I did think of staggering them but that would add some more admin overhead.

Thanks for your input.
Charlie.

Charlie
===============================================================
Msg 3903, Level 16, State 1, Line 1736
The ROLLBACK TRANSACTION request has no corresponding BEGIN TRANSACTION

spirit1
Cybernetic Yak Master

11752 Posts

Posted - 2009-08-11 : 05:31:02

try this for immediate deadlock notifications:
http://weblogs.sqlteam.com/mladenp/archive/2008/07/18/Immediate-deadlock-notifications-without-changing-existing-code.aspx

this way you can get the deadlock info immediately when it happens without needing to run profiler.

___________________________________________________________________________
Causing trouble since 1980
Blog: http://weblogs.sqlteam.com/mladenp
Speed up SSMS development: www.ssmstoolspack.com <- version 1.5 out!

Transact Charlie
Master Smack Fu Yak Hacker

3451 Posts

Posted - 2009-08-11 : 05:37:19

hi Spirit1.

Thanks for that.

Do I need to have service broker enabled for this to work?

Regards,

Charlie.

Charlie
===============================================================
Msg 3903, Level 16, State 1, Line 1736
The ROLLBACK TRANSACTION request has no corresponding BEGIN TRANSACTION

spirit1
Cybernetic Yak Master

11752 Posts

Posted - 2009-08-11 : 05:43:45

yes you do. in the db you want to run this in.

___________________________________________________________________________
Causing trouble since 1980
Blog: http://weblogs.sqlteam.com/mladenp
Speed up SSMS development: www.ssmstoolspack.com <- version 1.5 out!

Transact Charlie
Master Smack Fu Yak Hacker

3451 Posts

Posted - 2009-08-11 : 05:45:27

I'm thinking that the previous post from that blog:

http://weblogs.sqlteam.com/mladenp/archive/2008/05/21/SQL-Server-2005-Immediate-Deadlock-notifications.aspx

Might actually be exactly what I need.

I don't think I need service broker for that do I?

The pain was trying to find out exactly which process was causing the deadlock and that seems to be a great way to find out.

Charlie
===============================================================
Msg 3903, Level 16, State 1, Line 1736
The ROLLBACK TRANSACTION request has no corresponding BEGIN TRANSACTION

spirit1
Cybernetic Yak Master

11752 Posts

Posted - 2009-08-11 : 05:55:35

yes that can be useful too

that's why i wrote both of those just in case.

for the first versino you don't need service broker.
for the second you do need it. the second is better since you don't have to change existing code at all.

___________________________________________________________________________
Causing trouble since 1980
Blog: http://weblogs.sqlteam.com/mladenp
Speed up SSMS development: www.ssmstoolspack.com <- version 1.5 out!

Transact Charlie
Master Smack Fu Yak Hacker

3451 Posts

Posted - 2009-08-11 : 06:02:47

Thanks for the expert advice. This looks like a great tool for me.

Thumbs up!

Charlie
===============================================================
Msg 3903, Level 16, State 1, Line 1736
The ROLLBACK TRANSACTION request has no corresponding BEGIN TRANSACTION

Subscribe to SQLTeam.com

SQLTeam.com Articles via RSS

SQLTeam.com Weblog via RSS

- Advertisement -

Resources