2

We have several SQL Servers running SQL Agent jobs, recording history in their own sysjobhistory tables. I am attempting to set up one centralized server with a job that collects the history from all the other servers, formats it a bit, and puts it into a table called AllJobHistory. As part of this process, I would like one column to indicate that multiple steps of a job were part of the same job run. They are already marked as being part of the same job through the job_id column, but I want to know that specific rows came from the 3:00 run of the job versus the 4:00 run. Being able to filter based on this column would make troubleshooting jobs that much easier for us, but I don’t see anything that links those steps together in any existing system table or DMV, is there?

My first attempt at rolling my own was to use the run_date, run_time, and run_duration columns. For each step, if I subtract the total run_duration up to this point from the run_time, it should bring me back to a time that is unique compared to all other runs of this job. This looked like it was working until I found a case where it wasn’t (likely because SQL Server is rounding run_time and run_duration at the precision of seconds). Here is my attempt at the query (with extra columns removed).

WITH JobDetails AS 
(
    SELECT 
        QUOTENAME(UPPER('ServerName')) AS [Server],
        j.job_id AS [JobID],
        j.name AS [JobName],
        s.step_id AS [Step],
        msdb.dbo.agent_datetime(run_date, run_time) AS [RunDate],
        (run_duration/10000*3600 + (run_duration/100)%100*60 + run_duration%100) AS [RunDurationSeconds]
    FROM msdb.dbo.sysjobhistory h
    INNER JOIN msdb.dbo.sysjobs j ON j.job_id = h.job_id
    LEFT OUTER JOIN msdb.dbo.sysjobsteps s ON s.job_id = h.job_id AND s.step_id = h.step_id 
    WHERE h.step_id != 0
), GroupedDetails AS (
    SELECT 
        jd.[Server],
        jd.[JobID],
        jd.JobName,
        jd.Step,
        jd.RunDate,
        jd.RunDurationSeconds,
        DATEADD(SECOND, 
            -ISNULL(SUM(jd.RunDurationSeconds) OVER
                (PARTITION BY jd.JobName ORDER BY jd.JobName, jd.RunDate, jd.Step 
                ROWS BETWEEN UNBOUNDED PRECEDING AND 1 PRECEDING), 0), 
            jd.RunDate) AS grp
    FROM JobDetails AS  jd
)
SELECT 
    gd.[Server],
    gd.JobName,
    gd.Step,
    gd.RunDate,
    gd.RunDurationSeconds,
    CONVERT(VARCHAR(36), gd.JobID) + '_' + FORMAT(gd.grp, 'yyyyMMdd_HHmmss') AS JobRunString
FROM GroupedDetails AS gd;

Here is an example where it worked as I wanted it to, for a job that has three steps. Note that the JobRunString matches for the first run and again for the second run. WorkingExample

And here is an example where it did not work as I wanted it to. Note that Step1RunDate + Step1RunDurationSeconds != Step2RunDate, causing a mismatch of JobRunString. NotWorkingExample

So, is there any reliable way of linking the steps of a job run together in sysjobhistory?

  • Are you actually running the same job multiple times in a 2-second span? Just making sure, because that seems a little odd. – Brent Ozar Oct 4 '17 at 16:56
  • No, those are step 1 and step 2 of a job. None of our jobs run more often than every 10 seconds. – SQLDoug Oct 4 '17 at 17:21
2

Note that sysjobhistory has an ID column (instance_id). at least one entry should hit the table for each step of a job that was completed, followed by an entry with step_id = 0, recording the outcome of the job. Each step also records the time (run_date and run_time) the step was started, which will be equal to or greater than the time the job was started. So, the step_id = 0 row for a given run has a higher instance_id than the related steps, but a lower (or equal) run time.

So, try doing an initial pull of the data from the rows where step_id = 0 into a temp table (or equivalent). Then, all rows from sysjobhistory with the same job_id, a lower instance_id, and a higher or equal start time (from run_date and run_time) should belong to the job run you're looking for.

I used something much like this for a failed job report I used to run, at a former employer.

Here's a stripped down, modified version of that code. It ran for me in a quick test on a SQL Server 2016 box, just now. However, I don't have any jobs that run frequently enough that multiple runs would have the same run times.

USE msdb;

DECLARE @start_date varchar(8) = '20171001';

IF(OBJECT_ID('tempdb..#failhist') IS NOT NULL) DROP TABLE #failhist;

CREATE TABLE #failhist
(
    [job_name] [sysname] NOT NULL,
    [run_datetime] [datetime] NULL,
    [run_ended] [datetime] NULL,
    [instance_id] [int] NOT NULL,
    [job_id] [uniqueidentifier] NOT NULL,
    [run_date] [int] NOT NULL,
    [run_time] [int] NOT NULL
);


INSERT INTO #failhist
select *
  FROM
(SELECT j.name as job_name
       ,CONVERT(DATETIME, RTRIM(run_date)) + (run_time * 9 + run_time % 10000 * 6 + run_time % 100 * 10) / 216e4
        as run_datetime
       ,CONVERT(DATETIME, RTRIM(run_date)) + (run_time * 9 + run_time % 10000 * 6 + run_time % 100 * 10) / 216e4 + (run_duration * 9 + run_duration % 10000 * 6 + run_duration % 100 * 10) / 216e4
        as run_ended
       ,h.instance_id
       ,h.job_id
       ,h.run_date
       ,h.run_time
   from msdb..sysjobhistory h INNER JOIN msdb..sysjobs j ON h.job_id = j.job_id
  WHERE h.step_id = 0
    and h.run_date >= @start_date
) x
;

SELECT
       t.job_name AS [Job/Step]
      ,' ' + CONVERT(varchar(19), t.run_datetime, 121) + ' to ' + CONVERT(varchar(19), t.run_ended, 121) AS Run_Msg
      ,0 as HdrDetail
      ,t.job_name
      ,t.run_datetime
      ,t.instance_id
      ,-1 as step_id
      ,jh.instance_id as actual_instance_id
  FROM #failhist t
         INNER JOIN msdb..sysjobhistory jh ON (    t.job_id = jh.job_id
                                               AND t.instance_id >= jh.instance_id
                                               AND (   t.run_date < jh.run_date
                                                    OR (    t.run_date = jh.run_date
                                                        AND t.run_time <= jh.run_time
                                                       )
                                                   )
                                              )
 WHERE jh.step_id = 0
UNION ALL
SELECT
       '        '
      +CASE
         WHEN jh.step_id = 0
           THEN 'Job Summary'
         WHEN jh.run_status BETWEEN 0 AND 1  -- summary
           THEN RIGHT(CAST(100 + jh.step_id as varchar),2) + ' - ' + jh.step_name
         ELSE   '  ' + RIGHT(CAST(100 + jh.step_id as varchar),2) + ' (add''l info)'
       END
      ,'        ' + CAST(jh.message as varchar(max))
      ,1
      ,t.job_name
      ,t.run_datetime
      ,t.instance_id
      ,jh.step_id
      ,jh.instance_id
  FROM #failhist t
         INNER JOIN msdb..sysjobhistory jh ON (    t.job_id = jh.job_id
                                               AND t.instance_id >= jh.instance_id
                                               AND (   t.run_date < jh.run_date
                                                    OR (    t.run_date = jh.run_date
                                                        AND t.run_time <= jh.run_time
                                                       )
                                                   )
                                              )
 ORDER BY run_datetime, instance_id, step_id

If you actually have a job that runs more that once a second, you might have to use a windowing function, to ensure that you don't pick up job steps from an earlier run of the job with the same run_time value.

Caveat: If the limit on the number of rows each job can have in sysjobhistory is hit, you may get odd/incomplete results. Also, I occasionally saw jobs that failed without generating a job outcome (usually a temporary failure to authenticate the Windows user running the job).

  • 1
    Interesting! I had not made the connection that the Job Outcome has a higher instance_id and lower run_time. Thank you for your code sample, I'll check it out and maybe take some useful bits :-) – SQLDoug Oct 4 '17 at 17:53
2

Thanks to the info given by @RDFozz, I was able to come up with a query that gets all the data I was looking for. I did not want to include the step 0, "Job Outcome" lines, and I also removed the nice formatting that was in the @RDFozz query. That was great for a report, but I wanted it to be more like a relational table.

IF OBJECT_ID('tempdb..#JobHist') IS NOT NULL DROP TABLE #JobHist;

CREATE TABLE #JobHist
(
    [job_name] [sysname] NOT NULL,
    [run_datetime] [datetime] NULL,
    [instance_id] [int] NOT NULL,
    [job_id] [uniqueidentifier] NOT NULL,
    [run_date] [int] NOT NULL,
    [run_time] [int] NOT NULL,
);

--Datetime calculation explanation: https://www.sqlservercentral.com/Forums/Topic542581-145-1.aspx
INSERT INTO #JobHist
SELECT
    j.name as job_name
    ,DATEADD(SECOND, (run_time * 9 + run_time % 10000 * 6 + run_time % 100 * 10) / 25.0, CONVERT(DATETIME2(0),RTRIM(run_date))) AS run_datetime
    ,h.instance_id
    ,h.job_id
    ,h.run_date
    ,h.run_time
FROM msdb.dbo.sysjobhistory h 
INNER JOIN msdb.dbo.sysjobs j ON h.job_id = j.job_id
WHERE h.step_id = 0;

SELECT
    QUOTENAME(UPPER('ServerName')) AS [Server],
    t.job_name AS JobName,
    jh.step_id AS StepID,
    jh.step_name AS StepName,
    CASE jh.run_status 
        WHEN 0 THEN 'Failed'
        WHEN 1 THEN 'Successful'
        WHEN 2 THEN 'Retry - step only'
        WHEN 3 THEN 'Cancelled'
        WHEN 4 THEN 'In Progress'
        ELSE 'Unknown'
    END AS RunStatus,
    CONVERT(VARCHAR(MAX), jh.[message]) AS [Message],
    js.[database_name] AS [Database],
    js.Command,
    DATEADD(SECOND, (jh.run_time * 9 + jh.run_time % 10000 * 6 + jh.run_time % 100 * 10) / 25.0, CONVERT(DATETIME2(0), RTRIM(jh.run_date))) AS RunDate,
    (jh.run_duration/10000*3600 + (jh.run_duration/100)%100*60 + jh.run_duration%100) AS [RunDurationSeconds],
    jh.job_id AS JobID,
    t.instance_id AS LocalRunID
INTO #JobRunDetails
FROM #JobHist t
INNER JOIN msdb.dbo.sysjobhistory jh 
    ON t.job_id = jh.job_id
        AND t.instance_id >= jh.instance_id
        AND t.run_date <= jh.run_date
        AND t.run_time <= jh.run_time
INNER JOIN msdb.dbo.sysjobsteps js ON js.job_id = jh.job_id AND js.step_id = jh.step_id
WHERE jh.step_id != 0;

In order to compile results from many servers onto one, I then do the following to get a number per job run that is unique across servers (dbo.DBA_AllJobHistory_JobRun is a Sequence):

SELECT DISTINCT 
    LocalRunID,
    CAST(NULL AS BIGINT) AS RunID
INTO #JobRunSequence
FROM #JobRunDetails;

UPDATE #JobRunSequence SET RunID = NEXT VALUE FOR dbo.DBA_AllJobHistory_JobRun;

And then this inserts the history from this server into the AllJobHistory table where multiple servers are combined.

    MERGE dbo.DBA_AllJobHistory as Target
    USING (
        SELECT
            d.Server,
            d.JobID,
            d.StepID,
            s.RunID,
            d.JobName,
            d.StepName,
            d.RunStatus,
            d.Message,
            d.[Database],
            d.Command,
            d.RunDate,
            d.RunDurationSeconds
        FROM #JobRunDetails d
        INNER JOIN #JobRunSequence s ON s.LocalRunID = d.LocalRunID
    ) AS Source
    ON (Target.Server   = Source.Server AND
        Target.JobID    = Source.JobID  AND
        Target.StepID   = Source.StepID AND
        Target.RunDate  = Source.RunDate)
    WHEN MATCHED THEN 
        UPDATE SET  Target.RunStatus            = Source.RunStatus,     
                    Target.Message              = Source.Message,           
                    Target.RunDurationSeconds   = Source.RunDurationSeconds
    WHEN NOT MATCHED THEN 
        INSERT (Server,
                JobID,
                StepID,
                RunID,
                JobName,
                StepName,
                RunStatus,
                Message,
                [Database],
                Command,
                RunDate,
                RunDurationSeconds
                )
        VALUES (Source.Server,
                Source.JobID,
                Source.StepID,
                Source.RunID,
                Source.JobName,
                Source.StepName,
                Source.RunStatus,
                Source.Message,
                Source.[Database],
                Source.Command,
                Source.RunDate,
                Source.RunDurationSeconds
                );
1

Here is my solution: (My solution also pulls the execution_id: for SSIS executed from the SQL Server Job as well. I got part of the query for that somewhere else, I forget where).

SELECT  sjhP.job_id, job.[name] JobName, 
        sjhP.instance_id parent_instance_id, 

        sjhC.instance_id, sjhC.step_id, sjhC.step_name, sjhC.run_status, 
        msdb.dbo.agent_datetime(sjhC.run_date, sjhC.run_time) 
        DATEADD(SECOND, 
                    ( ( sjhC.run_duration / 1000000 ) * 86400 )
                    + ( ( ( sjhC.run_duration - ( ( sjhC.run_duration / 1000000 ) * 1000000 ) ) / 10000 ) * 3600 )
                    + ( ( ( sjhC.run_duration - ( ( sjhC.run_duration / 10000 ) * 10000 ) ) / 100 ) * 60 ) + 
                          ( sjhC.run_duration - ( sjhC.run_duration / 100 ) * 100 ),
                    msdb.dbo.agent_datetime(sjhC.run_date, sjhC.run_time)) run_enddatetime, 
        --activity.run_requested_date, activity.start_execution_date, activity.stop_execution_date, activity.last_executed_step_date, activity.last_executed_step_id, 
        (sjhC.run_duration/10000 /*HRS*/)*3600 + ((sjhC.run_duration%10000)/100 /*Mins*/)*60 + ((sjhC.run_duration%10000)%100 /*Secs*/) run_duration_seconds, 
        SUBSTRING(sjhC.[message], NULLIF(CHARINDEX('Execution ID: ', sjhC.[message]),0)+14 ,PATINDEX('%[^0-9]%',SUBSTRING(sjhC.[message], NULLIF(CHARINDEX('Execution ID: ', sjhC.[message]),0)+14 ,20))-1) execution_id,                     
        sjhC.sql_message_id, sjhC.sql_severity, sjhC.[message] JobMessage, sjhC.run_date, sjhC.run_time, sjhC.run_duration, 
        sjhC.operator_id_emailed, sjhC.operator_id_netsent, sjhC.operator_id_paged, sjhC.retries_attempted, sjhC.[server] 
        --SELECT *
FROM (  SELECT  msdb.dbo.agent_datetime(sjh0.run_date, sjh0.run_time) run_datetime,
                (sjh0.run_duration/10000 /*HRS*/)*3600 + ((sjh0.run_duration%10000)/100 /*Mins*/)*60 + ((sjh0.run_duration%10000)%100 /*Secs*/) run_duration_seconds, 
                DATEADD(SECOND, 
                        ( ( sjh0.run_duration / 1000000 ) * 86400 )
                        + ( ( ( sjh0.run_duration - ( ( sjh0.run_duration / 1000000 ) * 1000000 ) ) / 10000 ) * 3600 )
                        + ( ( ( sjh0.run_duration - ( ( sjh0.run_duration / 10000 ) * 10000 ) ) / 100 ) * 60 ) + 
                              ( sjh0.run_duration - ( sjh0.run_duration / 100 ) * 100 ),
                        msdb.dbo.agent_datetime(sjh0.run_date, sjh0.run_time)) run_enddatetime, --from: http://sqldbpros.com/2013/08/sql-job-steps-and-run_duration-the-query-that-formats-run_duration-correctly-and-doesnt-make-you-want-to-shoot-your-eye-out/
                ( SELECT MAX(sjh0b.instance_id) prev_instance_id 
                  FROM MSDB.dbo.SysJobHistory sjh0b
                  WHERE sjh0b.job_id = sjh0.job_id AND
                        sjh0b.step_id = 0 AND 
                        msdb.dbo.agent_datetime(sjh0b.run_date, sjh0b.run_time) < msdb.dbo.agent_datetime(sjh0.run_date, sjh0.run_time) 
                ) prev_instance_id, 
                * 
        FROM MSDB.dbo.SysJobHistory sjh0 
        WHERE sjh0.step_id = 0   
     ) sjhP LEFT JOIN
     MSDB.dbo.SysJobHistory sjhC
  ON sjhC.job_id = sjhP.job_id AND
     sjhC.instance_id > ISNULL(sjhP.prev_instance_id,0) AND
     sjhC.instance_id <= sjhP.instance_id LEFT JOIN
     MSDB.DBO.SysJobs job
  ON job.job_id = sjhP.job_id /*LEFT JOIN
     msdb.dbo.SysJobActivity activity
  ON activity.job_id = sjhP.job_id*/
WHERE sjhP.step_id = 0

I spent a lot of time thinking about how I could get what I needed to work, and tried different things, like using the SysJobActivity table to help me pick the steps that were related, but it was not a reliable way of doing it. I wanted every run, not just the most recent run.

I eventually noted that for every run there is always a step_id = 0, even if it failed before running step_id = 1, and that step_id is written last. So when searching for a given job_id with step_order = 0, you can figure out all of the jobs steps that ran between the previous run for step_order = 0 same job and the when the step_order = 0 for the current job is run.

I have gotten some ideas here from others they are not all my own. But now I see that there are some similarities between what I have and others in this stack exchange post. But mine is also different. It works well for me now.

My work here is the main inner and outer joins and scheme of joining the prev_instance_id with the outer query and then in the outermost query figuring out which child rows go with which parent rows (step_id = 0).

I had some code before I rewrote my query and finished it probably yesterday. That code I used to have was a hack, that wasn't reliable and had issues with it. I wish Microsoft had made the SQL Server Job Agent job tables more comprehensible. They should have provided a parent_instance_id or something like that to link them or some other easy mechanism. But I have created this in my query above. You can very easily turn this into a view or a function or stored procedure to make it flexible and reusable! I have mine in a view, that gets later called by a stored procedure!

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.