Partager via

SSRS Performance Troubleshooting: Where did we spend the time before the report even started executing?

  • Article

I recently dealt with couple of scenarios, where, we struggled to understand, at first, why the report was taking so long to finally render, yet, the TimeDataRetrieval, TimeProcessing, TimeRendering in ExecutionLog2 View did not explain the total report processing time.

 

For simplicity, in my observation, the total report processing time is divided into the following:

  1. Step 1) The time between when you click on a report to render and when report with parameters page and "View Report" button shows up and
  2. Step 2) The time between when you choose parameters and click on the "View Report" button and the report is rendered based on your selection. This is typically the report execution time, for which the ExeuctionLog2 view would show all the information.

 

If you have the default values for all parameters, then your report will be directly rendered first time, so, the time for 1) and 2) will be combined to give you impression that report is running for a long time.

 

If you need to choose the parameter values, then, it is easy to see the 2 separate times slices for 1) and 2) above, you can see the Report Viewer Control first, to choose the parameter and click "View Report", this is strictly the time related to step 1. In some cases, the time slice in this step can be significant, which may not be well understood, if we do not pay attention, during your report design. This is what we have discovered in one case and related the same for other, as the behavior was the same.

 

In our scenario, we had report with multiple parameters and they were bound to separate datasets (embedded) which would populate drop down lists with multi-select options. There was a known issue prior to SSRS 2008 R2 SP2, related to number of items in a dropdown parameter list, which was addressed already so we know that was not the problem in our scenario.

 

Without giving the details about the datasets, I just want to point out the Technet article, Report Embedded Datasets and Shared Datasets (Report Builder and SSRS), which discusses the datasets and parameters in details, the same design (embedded datasets for parameters) was used in our scenario. The concentration of this blog is how I found out where the time is spent in scenario step 1 (time slice 1) above.

 

Basically, I used the following tools to track down where the time is spent:

Fiddler Trace

  1. SSRS HTTP Trace
  2. SSRS Verbose Logging.
  3. ExecutionLog2 View
  4. Profiler Trace against the data source, especially observe the time before the actual report execution takes place.

 

ExecutionLog2 View would only explain the time in step 2 above.

 

So I used the Fiddler Trace, which showed that, for scenario, which includes, time for 1) and 2) above (no default parameter values set), it was significant time on step 1) and time in step 2 would be expected. It would seem, from the Fildder trace, that the GET request is taking all the time.

 

With further research, I then had SSRS HTTP Tracing and SSRS Verbose logging turned on and finally I was able to track down the time.

 

HTTP Trace would nicely show the GET request for step 1, when the request started and when it finished, which would be equal to the GET request in the Fiddler trace.

 

Researching on the SSRS Verbose Log, I would see that we would have request for each parameter list population, as a form of establishing a connection and then populating the dataset associated the parameter. If you have multiple parameters, you would see one connection and dataset pair for each one, if the parameter is bound to the embedded dataset.

 

Profiler trace helped to understand the time for step 2 first (matches the report execution time, especially TimeDataRetrieval matching the time with ExecutionLog2 View) but then with the information available from SSRS Verbose Log, this time profiler would clearly show all the connections, for each parameter population.

 

Please note, again, this is the time that was spent, before you can click on "View Report" choosing the parameters. If you have default values set, for parameters, you would have to carefully look at each possible connections to the data source (s), to put these two (step 1 and 2 above) together.

 

It was easy to see then why it was taking time before I could see the report page with parameters and "View Reports" and select the parameter and click the button to view the report.

 

In the scenario, where the default parameter values are set, the report will render combining the time in step 1) and 2) above, so you would have to definitely look for the first step carefully and should not only rely on the ExecutionLog2 View.

 

I hope, if you follow these steps, for your next report performance issue, where, it matches the above scenario, you will find the missing time and take appropriate steps (i.e. query tuning, report redesign etc.) to address the performance issue. In this regard, the following blog post will be helpful further performance tuning:

 

SSRS and SSAS-Sourced Parameter Dataset Performance Issues

 

Happy SSRS Performance Troubleshooting…..