How to Display Report Execution Time in SSRS (milliseconds)

SQL Server Reporting Services
Hits: 35060
How to Display Report Execution Time in SQL Server Reporting Services 2008 R2
So there are other articles out there but I was looking to display in milliseconds the execution time it took for a particular report (which searches for results matching the submitted parameter) to run.

Lifted from Dattatray Sindol's blog
Other sites have this solution as well so who copied off who is not my concern as this is not the solution to our problem. This is the solution that I initially used but my end-users were asking why is it always 0 seconds. This was because we were using the following MDX statement which had seconds as its smallest denominator:
copyraw 
="Execution Time: " +
CStr(System.DateTime.Now.Subtract(Globals!ExecutionTime).Hours) + " hour(s)" + " , " +
CStr(System.DateTime.Now.Subtract(Globals!ExecutionTime).Minutes) + " minute(s)" + ", " +
CStr(System.DateTime.Now.Subtract(Globals!ExecutionTime).Seconds) + " second(s)"

// yields
// 0 hour(s), 1 minute(s), 2 second(s)
  1.  ="Execution Time: " + 
  2.  CStr(System.DateTime.Now.Subtract(Globals!ExecutionTime).Hours) + " hour(s)" + " , " + 
  3.  CStr(System.DateTime.Now.Subtract(Globals!ExecutionTime).Minutes) + " minute(s)" + ", " + 
  4.  CStr(System.DateTime.Now.Subtract(Globals!ExecutionTime).Seconds) + " second(s)" 
  5.   
  6.  // yields 
  7.  // 0 hour(s), 1 minute(s), 2 second(s) 
This isn't what I want... It wasn't accurate enough and always saying 0 seconds was just confusing the end-user...

Workaround #1
Although I'm convinced of a solution considering the ReportServer database will be able to tell you how many milliseconds it took for a report to execute... I decided to do a database level calculation using two datasets:
copyraw 
-- Oracle 10g: DataSet1 -- your normal dataset query with an added field (ReportStartTime)
SELECT
	field1,
	field2,
	TO_CHAR(systimestamp, 'HH24:MI:SS.FF6') AS ReportStartTime
FROM
	...
  1.  -- Oracle 10g: DataSet1 -- your normal dataset query with an added field (ReportStartTime) 
  2.  SELECT 
  3.      field1, 
  4.      field2, 
  5.      TO_CHAR(systimestamp, 'HH24:MI:SS.FF6') AS ReportStartTime 
  6.  FROM 
  7.      ... 
Then add another dataset (using the same data source if you like):
copyraw 
-- Oracle 10g: DataSet2 -- a quick dataset following the first (started before the first ends? hope not)
SELECT
	TO_CHAR(systimestamp, 'HH24:MI:SS.FF6') AS ReportEndTime
FROM
	DUAL
  1.  -- Oracle 10g: DataSet2 -- a quick dataset following the first (started before the first ends? hope not) 
  2.  SELECT 
  3.      TO_CHAR(systimestamp, 'HH24:MI:SS.FF6') AS ReportEndTime 
  4.  FROM 
  5.      DUAL 
This may be just the time recorded that it took for the query which is somewhat the same thing for us as SSRS performance is always rubbish anyway. Here's a breakdown of the MDX expressions and how I tweaked each one to return the final result:
copyraw 
-- to get just the time value
=(
	CDate(Last(Fields!REPORTENDTIME.Value, "Dataset2"))
	-
	CDate(First(Fields!REPORTSTARTTIME.Value, "Dataset1"))
)
// yields 
// 00:00:02.1543570


-- problems with adding a string to it? CStr will not work, use .ToString
="Time Taken: " 
& (
	CDate(Last(Fields!REPORTENDTIME.Value, "Dataset2"))
	-
	CDate(First(Fields!REPORTSTARTTIME.Value, "Dataset1"))
).ToString & " second(s)"
// yields 
// Time Taken: 00:00:02.15443570 second(s)


-- What if the report actually took more than a minute... more than an hour
="Time Taken: " & (
(Mid(
	CStr(
		(
		CDate(Last(Fields!REPORTENDTIME.Value, "Dataset2"))
		-
		CDate(First(Fields!REPORTSTARTTIME.Value, "Dataset1"))
		).ToString
	), 1, 2
)*3600) + 
(Mid(
	CStr(
		(
		CDate(Last(Fields!REPORTENDTIME.Value, "Dataset2"))
		-
		CDate(First(Fields!REPORTSTARTTIME.Value, "Dataset1"))
		).ToString
	), 4, 2
)*60)
+ Mid(
	CStr(
		(
		CDate(Last(Fields!REPORTENDTIME.Value, "Dataset2"))
		-
		CDate(First(Fields!REPORTSTARTTIME.Value, "Dataset1"))
		).ToString
	), 7, Len(
		CStr(
			(
			CDate(Last(Fields!REPORTENDTIME.Value, "Dataset2"))
			-
			CDate(First(Fields!REPORTSTARTTIME.Value, "Dataset1"))
			).ToString
		)
	)
)) & " second(s)"

// yields 
// Time Taken: 2.15443570 second(s) 
// I don't have a report that takes over an hour to process but in theory this should accommodate it.
  1.  -- to get just the time value 
  2.  =( 
  3.      CDate(Last(Fields!REPORTENDTIME.Value, "Dataset2")) 
  4.      - 
  5.      CDate(First(Fields!REPORTSTARTTIME.Value, "Dataset1")) 
  6.  ) 
  7.  // yields 
  8.  // 00:00:02.1543570 
  9.   
  10.   
  11.  -- problems with adding a string to it? CStr will not work, use .ToString 
  12.  ="Time Taken: " 
  13.  & ( 
  14.      CDate(Last(Fields!REPORTENDTIME.Value, "Dataset2")) 
  15.      - 
  16.      CDate(First(Fields!REPORTSTARTTIME.Value, "Dataset1")) 
  17.  ).ToString & " second(s)" 
  18.  // yields 
  19.  // Time Taken: 00:00:02.15443570 second(s) 
  20.   
  21.   
  22.  -- What if the report actually took more than a minute... more than an hour 
  23.  ="Time Taken: " & ( 
  24.  (Mid( 
  25.      CStr( 
  26.          ( 
  27.          CDate(Last(Fields!REPORTENDTIME.Value, "Dataset2")) 
  28.          - 
  29.          CDate(First(Fields!REPORTSTARTTIME.Value, "Dataset1")) 
  30.          ).ToString 
  31.      ), 1, 2 
  32.  )*3600) + 
  33.  (Mid( 
  34.      CStr( 
  35.          ( 
  36.          CDate(Last(Fields!REPORTENDTIME.Value, "Dataset2")) 
  37.          - 
  38.          CDate(First(Fields!REPORTSTARTTIME.Value, "Dataset1")) 
  39.          ).ToString 
  40.      ), 4, 2 
  41.  )*60) 
  42.  + Mid( 
  43.      CStr( 
  44.          ( 
  45.          CDate(Last(Fields!REPORTENDTIME.Value, "Dataset2")) 
  46.          - 
  47.          CDate(First(Fields!REPORTSTARTTIME.Value, "Dataset1")) 
  48.          ).ToString 
  49.      ), 7, Len( 
  50.          CStr( 
  51.              ( 
  52.              CDate(Last(Fields!REPORTENDTIME.Value, "Dataset2")) 
  53.              - 
  54.              CDate(First(Fields!REPORTSTARTTIME.Value, "Dataset1")) 
  55.              ).ToString 
  56.          ) 
  57.      ) 
  58.  )) & " second(s)" 
  59.   
  60.  // yields 
  61.  // Time Taken: 2.15443570 second(s) 
  62.  // I don't have a report that takes over an hour to process but in theory this should accommodate it. 

Problem #1
If zero rows are returned from the search, then there is no REPORTSTARTTIME. There are two options here:
  1. Create another dataset (would have to be the first dataset to load so you would need delete your current datasets then add them in the order you want them to load) to get the timestamp of when the queries started.
  2. IIF your result row count, if it's zero, just display blank, else, do the rest of the query. Blank out the textbox basically (execution time is kinda irrelevant when you get 0 matches)
We went with option 2.

Check this result - Possibly from the Reporting Server ExecutionLog?
Using the ReportServer Execution Logs, we can determine if this is correct
copyraw 
SELECT TOP 1
	c.Name, 
	e.TimeStart, 
	e.TimeDataRetrieval + e.TimeProcessing + e.TimeRendering AS TotalTime 
FROM
	[ExecutionLog] e
	INNER JOIN [Catalog] c ON c.ItemID=e.ReportID
WHERE c.Name='My Amazing Report'  -- just change the value here to the name of your report
ORDER BY e.TimeStart DESC
  1.  SELECT TOP 1 
  2.      c.Name, 
  3.      e.TimeStart, 
  4.      e.TimeDataRetrieval + e.TimeProcessing + e.TimeRendering AS TotalTime 
  5.  FROM 
  6.      [ExecutionLog] e 
  7.      INNER JOIN [Catalog] c ON c.ItemID=e.ReportID 
  8.  WHERE c.Name='My Amazing Report'  -- just change the value here to the name of your report 
  9.  ORDER BY e.TimeStart DESC 
  1. Deploy the report to the SSRS
  2. Run the report from MS Internet Explorer
  3. Check results using Microsoft SQL Server Management Studio (SSMS)

My test results showed that in fact my time was closer to the "TimeProcessing" field of the ReportServer database, but good enough for us.
Category: SQL Server Reporting Services :: Article: 401
© 2024 Joel Lipman .com. All Rights Reserved.