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 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%') 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 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%') 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 #rawdata1

The 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,

case

whenConvert(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 ,

Calculating the Average Run Time in Hours Minutes and Seconds and the end of the query.

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 rd1

on rd1.keyy = rd2.keyy

groupby run_date,rd1.run_time ,rd1.run_time_in_Seconds

orderby run_date desc

The complete code example

use msdb

go

/*

drop table #rawdata1

drop table #rawdata2

go

*/

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,

case

whenlen(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)

endas tt

from 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 ) b

select 1 as Keyy, run_time_in_Seconds into #rawdata2 from #rawdata1

select rd1.run_date, rd1.run_time, rd1.run_time_in_Seconds ,Avg(rd2.run_time_in_Seconds) as Average_run_time_in_seconds,

case

whenConvert(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 ,

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 rd1

on rd1.keyy = rd2.keyy

groupby run_date,rd1.run_time ,rd1.run_time_in_Seconds

orderby run_date desc