Job Step delayed execution problem

• Pedro Lima

  SSC Enthusiast

  Points: 126

  More actions

  December 5, 2016 at 9:16 am

  #315575

  Hi all!

  I have a weird behaviour that I'm having some trouble to identify...

  We have a process that creates jobs based on a queue of processes. Each job has 3 steps:

  -- The first executes a simple select statement:

  EXEC msdb..sp_add_jobstep @job_name = @nome_Job

  ,@step_name = 'INIT'

  ,@subsystem = 'TSQL'

  ,@command = 'SET NOCOUNT ON SELECT ''##START_TIME##'' + rtrim(cast(getdate() as char(40)))+''##START_TIME##'''

  ,@retry_attempts = 0

  ,@on_success_action = 3

  ,@retry_interval = 1

  ,@output_file_name = @log_file

  ,@flags = 4

  -- The Second, the code of the task

  EXEC msdb..sp_add_jobstep @job_name = @nome_Job

  ,@step_name = 'EXECUTION'

  ,@subsystem = 'TSQL'

  ,@command = @Step_Completo

  ,@retry_attempts = 0

  ,@retry_interval = 1

  ,@on_success_action = 1

  ,@on_fail_action = 3

  ,@output_file_name = @log_file

  ,@flags = 6

  -- The third and last, it's only run if one of the above fails:

  EXEC msdb..sp_add_jobstep @job_name = @nome_Job

  ,@step_name = 'ERROR'

  ,@subsystem = 'TSQL'

  ,@command = 'SET NOCOUNT ON SELECT ''Process End with ERROR'' SELECT ''##END_TIME##'' + rtrim(cast(getdate() as char(40)))+''##END_TIME##'''

  ,@retry_attempts = 0

  ,@on_success_action = 2

  ,@on_fail_action = 2

  ,@retry_interval = 1

  ,@output_file_name = @log_file

  ,@flags = 6

  IMPORTANT: All the steps are logged to local file.

  And now the issue!

  We identified this random behaviour:

  Job 'TASK ACME' : Step 1, 'INIT' : Began Executing 2016-12-03 20:18:23

  --------------------------------------------------------------------

  ##START_TIME##Dec 4 2016 12:16AM##START_TIME##

  Job 'TASK ACME' : Step 2, 'EXECUTION' : Began Executing 2016-12-04 00:16:02

  Does anyone has some clue how can we find why there are almost 4 hours of delay between the 'INIT' step starting and writing the string?!

  Thanks

  pmartinslima