Job duration much longer than step durations

Question

Post reply

Job duration much longer than step durations

Ronzo

Hall of Fame

Points: 3917
More actions
August 13, 2019 at 9:48 pm

#3671181

I have a particular VM instance of SQL that is exhibiting perplexing behavior. The job consists of two steps, the first typically runs in under 2 seconds, while the second runs around a minute. But the duration of the job itself has been ranging up to an hour! For example, the 11:37 run today list step 1 with a duration of 0:03, then shows step 2 with a 0:39 duration (but starting 5 minutes later), then shows a total duration of 7:02. The 11:47 run has durations of 0:00, 1:41 (starting 39 minutes later), and 40:55.
Any ideas what to look for? I'm thinking the VM or SQL Agent is just overloaded, but was looking for input on both what would cause this behavior and how to best address it. Both job steps are simple invocations of stored procedures via TSQL.
Have Fun!
Ronzo

Viewing 8 posts - 1 through 7 (of 7 total)

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

Alejandro Santana SSCommitted Points: 1838 More actions · Answer 1

Hello

Have you tried executing your procedures manually?

Greetings

Grant Fritchey SSC Guru Points: 398908 More actions · Answer 2

Sounds like blocking or resource contention. Take a look at the system_health Extended Event session. Excessive waits and blocks are automatically captured there. It should give you a lot more information to go on. Here's some examples of how to retrieve that data. You can also use the Data Viewer window to search them.

"The credit belongs to the man who is actually in the arena, whose face is marred by dust and sweat and blood"
- Theodore Roosevelt

Author of:
SQL Server Execution Plans
SQL Server Query Performance Tuning

Ronzo Hall of Fame Points: 3917 More actions · Answer 3

Yes. Procedures run in indicated times (roughly 2 seconds and one minute) when run directly from query window. Only when run from job is there additional "delay".

Have Fun!
Ronzo

Ronzo Hall of Fame Points: 3917 More actions · Answer 4

Grant,

Thanks for suggestions. I will reply later with whatever I discover.

Have Fun!
Ronzo

Ronzo Hall of Fame Points: 3917 More actions · Answer 5

Grant,

Great references! I had to do a double take after reading your article and then finding my 4 health logs covered the last two seconds! I am diving deeper now, since it appears they are just full of (mostly) deadlocks writing to job history, which is firing trigger msdb.dbo.ti_Restart_Job.

Have Fun!
Ronzo

Ronzo Hall of Fame Points: 3917 More actions · Answer 6

Yup, all our fault. The trigger ti_Restart_Job was added by the team to handle restarting jobs that are hung, but was not implemented very well. Thanks for help finding the issue.

Have Fun!
Ronzo

Grant Fritchey SSC Guru Points: 398908 More actions · Answer 7

Thanks for coming back with what the problem was. So many people never let us know.

You can modify system_health to keep more data, but, from the sounds of it, I wouldn't recommend that just yet. Best of luck.

"The credit belongs to the man who is actually in the arena, whose face is marred by dust and sweat and blood"
- Theodore Roosevelt

Author of:
SQL Server Execution Plans
SQL Server Query Performance Tuning