Monitoring SQL Server Agent job run times
- by okeofs
Introduction
A few months back, I was
asked how long a particular nightly process took to run. It was a super
question and the one thing that struck me was that there were a plethora of
factors affecting the processing time. This said, I developed a query to
ascertain process run times, the average nightly run times and applied some
KPI’s to the end query. The end goal being to enable me to quickly detect
anomalies and processes that are running beyond their normal times.
As many of you are aware, most of the necessary data for this type of query,
lies within the MSDB database.
The core portion of the query is shown below.select
sj.name,sh.run_date, sh.run_duration,
case
when len(sh.run_duration) = 6 then convert(varchar(8),sh.run_duration)
when len(sh.run_duration) = 5 then '0' + convert(varchar(8),sh.run_duration)
when len(sh.run_duration) = 4 then '00' + convert(varchar(8),sh.run_duration)
when len(sh.run_duration) = 3 then '000' + convert(varchar(8),sh.run_duration)
when len(sh.run_duration) = 2 then '0000' + convert(varchar(8),sh.run_duration)
when len(sh.run_duration) = 1 then '00000' +
convert(varchar(8),sh.run_duration)
end as tt
from dbo.sysjobs sj with (nolock)
inner join dbo.sysjobHistory sh with (nolock)
on sj.job_id = sh.job_id
where sj.name = 'My Agent Job'
and [sh.Message] like '%The job%')
Run_date
and run_duration are obvious fields. The field ‘Name’ is the name of the job
that we wish to follow. The only major challenge was that the format of the run
duration which was not as ‘user friendly’ as I would have liked. As an example,
the run duration 1 hour 10 minutes and 3 seconds would be displayed as 11003;
whereas I wanted it to display this in a more user friendly manner as 01:10:03.
In
order to achieve this effect, we need to add leading zeros to the run_duration
based upon the case logic shown above.
At
this point what we need to do add colons between the hours and minutes and one
between the minutes and seconds. To achieve this I nested the query shown above
(in purple) within a ‘super’ query. Thus the run time ([Run Time]) is
constructed concatenating a series of substrings (See below in Blue). select
run_date,substring(convert(varchar(20),tt),1,2) + ':' +substring(convert(varchar(20),tt),3,2) +
':' +substring(convert(varchar(20),tt),5,2) as [run_time]
from (select
sj.name,sh.run_date, sh.run_duration,case
when
len(sh.run_duration) = 6 then convert(varchar(8),sh.run_duration)when
len(sh.run_duration) = 5 then '0' + convert(varchar(8),sh.run_duration)when
len(sh.run_duration) = 4 then '00' + convert(varchar(8),sh.run_duration)when
len(sh.run_duration) = 3 then '000' + convert(varchar(8),sh.run_duration)when
len(sh.run_duration) = 2 then '0000' + convert(varchar(8),sh.run_duration)when
len(sh.run_duration) = 1 then '00000' + convert(varchar(8),sh.run_duration)end
as ttfrom
dbo.sysjobs sj with (nolock)inner
join dbo.sysjobHistory sh with (nolock) on
sj.job_id = sh.job_id where
sj.name = 'My Agent Job'and
[sh.Message] like '%The job%') a
Now
that I had each nightly run time in hours, minutes and seconds (01:10:03), I
decided that it would very productive to calculate a rolling run time average.
To do this, I decided to do the calculations in base units of seconds.
This
said, I encapsulated the query shown above into a further ‘super’ query (see
the code in RED below). This encapsulation is shown below. The astute reader
will note that I used implied casting from integer to string, which is not the
best method to use however it works. This said and if I were constructing the
query again I would definitely do an explicit
convert. To Recap: I now have a key field of ‘1’, each and every applicable run
date and the total number of SECONDS that the process ran for each run date,
all of this data within the #rawdata1 temporary table.
Select
1 as keyy,run_date,(substring(b.run_time,1,2)*3600) +
(substring(b.run_time,4,2)*60) + (substring(b.run_time,7,2)) as
run_time_in_Seconds,run_time into #rawdata1 from ( select run_date,substring(convert(varchar(20),tt),1,2)
+ ':' + substring(convert(varchar(20),tt),3,2) +
':' +substring(convert(varchar(20),tt),5,2) as
[run_time] from (select
sj.name,sh.run_date, sh.run_duration, case
when
len(sh.run_duration) = 6 then convert(varchar(8),sh.run_duration)when
len(sh.run_duration) = 5 then '0' + convert(varchar(8),sh.run_duration)when
len(sh.run_duration) = 4 then '00' + convert(varchar(8),sh.run_duration)when
len(sh.run_duration) = 3 then '000' + convert(varchar(8),sh.run_duration)when
len(sh.run_duration) = 2 then '0000' + convert(varchar(8),sh.run_duration)when
len(sh.run_duration) = 1 then '00000' + convert(varchar(8),sh.run_duration)end
as ttfrom
dbo.sysjobs sj with (nolock)inner
join dbo.sysjobHistory sh with (nolock)on
sj.job_id = sh.job_id where
sj.name = 'My Agent Job'and
[sh.Message] like '%The job%') a )b
Calculating
the average run time
We now select each run time in seconds from
#rawdata1 and place the values into another temporary table called #rawdata2.
Once again we create a ‘key’, a hardwired ‘1’. select 1 as Keyy, run_time_in_Seconds into
#rawdata2 from #rawdata1The purpose of doing so is to make the
average time AVG() available to the query immediately without having to do
adverse grouping.
Applying KPI Logic
At this point, we shall apply some logic to
determine whether processing times are within the norms. We do this by applying
colour names. Obviously, this example is a super one for SSRS and traffic light
icons.select rd1.run_date,
rd1.run_time, rd1.run_time_in_Seconds ,Avg(rd2.run_time_in_Seconds) as
Average_run_time_in_seconds,casewhenConvert(decimal(10,1),rd1.run_time_in_Seconds)/Avg(rd2.run_time_in_Seconds)<=
1.2 then 'Green' when
Convert(decimal(10,1),rd1.run_time_in_Seconds)/Avg(rd2.run_time_in_Seconds)<
1.4 then 'Yellow' else 'Red'end as [color],
Calculating
the Average Run Time in Hours Minutes and Seconds and the end of the query.
casewhen len(convert(varchar(2),Avg(rd2.run_time_in_Seconds)/(3600))) = 1 then '0' + convert(varchar(2),Avg(rd2.run_time_in_Seconds)/(3600))else convert(varchar(2),Avg(rd2.run_time_in_Seconds)/(3600))end + ':' + case when len(convert(varchar(2),Avg(rd2.run_time_in_Seconds)%(3600)/60)) = 1 then '0' + convert(varchar(2),Avg(rd2.run_time_in_Seconds)%(3600)/60)else convert(varchar(2),Avg(rd2.run_time_in_Seconds)%(3600)/60)end + ':' + case when len(convert(varchar(2),Avg(rd2.run_time_in_Seconds)%60)) = 1 then '0' + convert(varchar(2),Avg(rd2.run_time_in_Seconds)%60)else convert(varchar(2),Avg(rd2.run_time_in_Seconds)%60)end as [Average Run Time HH:MM:SS] from #rawdata2 rd2 innerjoin #rawdata1 rd1on rd1.keyy = rd2.keyygroup by run_date,rd1.run_time ,rd1.run_time_in_Seconds order by run_date descThe complete code example
use msdbgo/*drop table #rawdata1drop table #rawdata2go*/select 1 as keyy,run_date,(substring(b.run_time,1,2)*3600) + (substring(b.run_time,4,2)*60) + (substring(b.run_time,7,2)) as run_time_in_Seconds,run_time into #rawdata1 from (select run_date,substring(convert(varchar(20),tt),1,2) + ':' +substring(convert(varchar(20),tt),3,2) + ':' +substring(convert(varchar(20),tt),5,2) as [run_time] from (select name,run_date, run_duration, casewhenlen(run_duration) = 6 then convert(varchar(8),run_duration)whenlen(run_duration) = 5 then '0' + convert(varchar(8),run_duration)whenlen(run_duration) = 4 then '00' + convert(varchar(8),run_duration)whenlen(run_duration) = 3 then '000' + convert(varchar(8),run_duration)whenlen(run_duration) = 2 then '0000' + convert(varchar(8),run_duration)whenlen(run_duration) = 1 then '00000' + convert(varchar(8),run_duration)end as ttfrom dbo.sysjobs sj with (nolock)innerjoin dbo.sysjobHistory sh with (nolock) on sj.job_id = sh.job_id where name = 'My Agent Job'and [Message] like '%The job%') a ) bselect 1 as Keyy, run_time_in_Seconds into #rawdata2 from #rawdata1select rd1.run_date, rd1.run_time, rd1.run_time_in_Seconds ,Avg(rd2.run_time_in_Seconds) as Average_run_time_in_seconds,casewhenConvert(decimal(10,1),rd1.run_time_in_Seconds)/Avg(rd2.run_time_in_Seconds)<= 1.2 then 'Green' when Convert(decimal(10,1),rd1.run_time_in_Seconds)/Avg(rd2.run_time_in_Seconds)< 1.4 then 'Yellow' else 'Red'end as [color],Case when len(convert(varchar(2),Avg(rd2.run_time_in_Seconds)/(3600))) = 1 then '0' + convert(varchar(2),Avg(rd2.run_time_in_Seconds)/(3600))else convert(varchar(2),Avg(rd2.run_time_in_Seconds)/(3600))end + ':' + case when len(convert(varchar(2),Avg(rd2.run_time_in_Seconds)%(3600)/60)) = 1 then '0' + convert(varchar(2),Avg(rd2.run_time_in_Seconds)%(3600)/60)else convert(varchar(2),Avg(rd2.run_time_in_Seconds)%(3600)/60)end + ':' + case when len(convert(varchar(2),Avg(rd2.run_time_in_Seconds)%60)) = 1 then '0' + convert(varchar(2),Avg(rd2.run_time_in_Seconds)%60)else convert(varchar(2),Avg(rd2.run_time_in_Seconds)%60)end as [Average Run Time HH:MM:SS] from #rawdata2 rd2 innerjoin #rawdata1 rd1on rd1.keyy = rd2.keyygroup by run_date,rd1.run_time ,rd1.run_time_in_Seconds order by run_date desc
