Of-late one of our SSRS 2005 report subscriptions started to fail regularly with the error message
Failure sending mail: Timeout expired. The timeout period elapsed prior to completion of the operation or the server is not responding.
That report was pretty simple and if run on demand, it used to take less than 3 seconds to render. I started my troubleshooting from ReportServerDB. Report Server stores the execution information in ExecutionLog table. The status of the subscription is stored in Subscription table. I checked both the tables and they did not contain any other message.
Since the report was timing out, I thought that some other task which runs at the same time as that of the report subscription might be blocking the subscription. So I requested my DBA to check for any task like jobs, SSIS packages & windows scheduling but could not find anything.
Then I went over the Report Server log files. Report Server stores all that happens in it in few log files. These log files are located at
<Installation Directory>\Program files\Microsoft SQL Server\MSSQL.X\Reporting Services\LogFiles
To know more about what are the different type of log files that SSRS creates and what it contains, have a look at this thread. Though written for SSRS 2000, this is still applicable for other versions.
In the log file I could see that Report Server was running some “dbcleanup” job at the same time as that of the subscription and that job was timing out.
ReportingServicesService!dbcleanup!27!1/5/2011-02:02:05:: e ERROR: Expiration of old execution log entries failed: System.Data.SqlClient.SqlException: Timeout expired. The timeout period elapsed prior to completion of the operation or the server is not responding.
From the error message I could figure out that SSRS is trying to purge the old log entries. In SQL SERVER 2005, you can control whether you want to purge the Execution Log file and if so how many days old records to purge from Site Settings.
My DBA figured out that when purging is enabled, SSRS makes use of a stored procedure called “ExpireExecutionLogEntries” in ReportServer. And this procedure is trying to delete the execution log by executing the below query
delete from ExecutionLog where DateDiff(day, TimeStart, getdate()) >= (select CAST(CAST(Value as nvarchar) as integer) from ConfigurationInfo where [Name] = ‘ExecutionLogDaysKept‘)
In my case it was trying to delete more than 10 million record in one go 😦 and hence timing out. This is really poor coding.
We modified the stored procedure to use batching while deleting which fixed the timeout issue which in turn fixed the subscription failure. Though going thru the log file and figuring out what is happening is little bit difficult, it has lot information which can help us to identify the real problem.