5

I wrote a report that is executed by a few hundred users each day and the underlying stored procedure for the data set only takes milliseconds to execute. According to the ReportServer.dbo.ExecutionLog3 table I noticed the TimeDataRetrieval was regularly showing 5-10 seconds. The AdditionalInfo column shows the ExecuteReaderTime is a few milliseconds as expected and the TotalTimeDataRetrieval shows 5-10 seconds. What can I do to reduce the TotalTimeDataRetrieval for each report execution?

A few more useful facts. The server itself has 128 GB of RAM devoted to SSRS and the OS, so it isn't a memory constraint. The number of rows retrieved is 1-20 rows and estimated memory usage is well under 1,000KB.

My best guess is that it is taking about 5-10 seconds to open a connection to the database. I believe this can be substantiated by the ConnectionOpenTime attribute in the AdditionalInfo column. It shows 5-10 seconds and the sum of the ConnectionOpenTime and ExecuteReaderTime equals the TotalTimeDataRetrieval. Perhaps there is a way to force SQL Server to keep connections open longer? Maybe the worker threads are being killed after being idle for more than a few seconds?

5
  • are your statistics up to date? Commented Jan 14, 2013 at 23:39
  • Yes. SQL Profile Traces show the stored procedures are taking milliseconds. Internal logging in the stored procedures show they are taking milliseconds. Commented Jan 14, 2013 at 23:41
  • Yes, statistics are updated multiple times a day on the underlying table that powers the report. This is not a query performance issue. This is something else. Commented Jan 14, 2013 at 23:43
  • Which code? The stored procedure is SELECT Column1, Column2, Column3 FROM SomeDatabase.dbo.SomeTable (NOLOCK) WHERE FilterId = @SomeIntParameter; The report RDL file itself is a simple tablix, a single dataset, and a single parameter. I've noticed the report execution is fine after the first execution completes for a user so long as the ExecutionId doesn't change even if they pick completely different parameter values. When digging through the AdditionalInfo column in ExecutionLog3, it shows the ConnectionOpenTime goes to almost nothing in the subsequent executions. Commented Jan 14, 2013 at 23:48
  • Did you ever solve this? I'm in the exact same situation. Commented Apr 25, 2017 at 15:09

1 Answer 1

0

Wow this is a really old question. I believe I have found an answer to the problem, but you'll have to see if it helps you.

Using the trace should at least let you know if the connection time is slow, or the query time is slow...

I followed the instructions found here.

I will include the details here in case the link ever breaks:

First, configure Report Server to turn on tracing

Configuration Settings for a Native Mode Report Server You can turn report execution logging on or off from the Server Properties page in SQL Server Management Studio. The EnableExecutionLogging is and Advanced property.

By default, log entries are kept 60 days. Entries that exceed this date are removed at 2:00 A.M. every day. On a mature installation, only 60 days of information will be available at any given time.

You cannot set limits on the number of rows or on the type of entries that are logged.

To enable execution logging:

Start SQL Server Management Studio with administrative privileges. For example right-click the Management Studio icon and click 'Run as administrator'.

Connect to the desired report server.

Right-click the server name and click Properties. If the Properties option is disabled, verify you ran SQL Server Management Studio with administrative privileges.

Click the Logging page.

Select Enable report execution Logging.

To enable verbose logging:

You need to enable logging as described in the previous steps and then complete the following:

From the Server Properties dialog, click the Advanced page.

In the User-defined section, change the ExecutionLogLevel to verbose. This field is a text entry field and the two possible values are verbose and normal.

Next run some reports.

Query the ReportServer database, which will have this view:

    Use ReportServer  
    select * from ExecutionLog3 order by TimeStart DESC

The last column is an XML column called AdditionalInfo

For each dataset it will say how long it took to connect, and how long to get the data. Here is an example:

...
 <Connections>
    <Connection>
      <ConnectionOpenTime>4540</ConnectionOpenTime>
      <DataSets>
        <DataSet>
          <Name>CourseAreas</Name>
          <RowsRead>18</RowsRead>
          <TotalTimeDataRetrieval>4554</TotalTimeDataRetrieval>
          <ExecuteReaderTime>11</ExecuteReaderTime>
        </DataSet>
      </DataSets>
    </Connection>
...

See here it took a whopping 4540ms to connect to the database! Which is actually the local database server. And only 11ms to run the query. Something is wrong...

So now I went to the machine running Report server to configure it: http://localhost/reports

I navigated Home -> relevant Folder -> relevant Datasource. The ConnectionString had an IP address of the local machine (not even its primary address...) I changed it to "localhost", and tested the connection. It was instantaneous. Probably using a memory connection rather than TCP/IP, I'm not sure.

Before I made the change, pressing Test Connection took about 5s to return, just like reported in the trace. I applied the change, and the Test Connection returned immediately. After I clicked Apply, I verified that now my reports are returning in under a second. Some reports that made three dataset connections had been taking 15s or longer, and now are sub second as they should be.

Problem solved!

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge you have read our privacy policy.

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