One fine day, one of our data driven subscription which was running fine, failed with timeout error.
library!WindowsService_118!eb4!12/20/2011-07:30:01:: i INFO: Handling data-driven subscription 1b850434-fe69-47e5-a227-219d1b2e040c to report /External Reports/Report1, owner: domain\user, delivery extension: Report Server Email.
library!WindowsService_118!1288!12/20/2011-07:30:01:: i INFO: Initializing EnableExecutionLogging to ‘True’ as specified in Server system properties.
library!WindowsService_118!1288!12/20/2011-07:30:01:: i INFO: Initializing EnableExecutionLogging to ‘True’ as specified in Server system properties.
library!WindowsService_118!eb4!12/20/2011-07:30:37:: e ERROR: Error processing data driven subscription 1b850434-fe69-47e5-a227-219d1b2e040c: System.Data.SqlClient.SqlException: Timeout expired. The timeout period elapsed prior to completion of the operation or the server is not responding.
at System.Data.SqlClient.SqlInternalConnection.OnError(SqlException exception, Boolean breakConnection)
at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj)
at System.Data.SqlClient.TdsParserStateObject.ReadSniError(TdsParserStateObject stateObj, UInt32 error)
at System.Data.SqlClient.TdsParserStateObject.ReadSni(DbAsyncResult asyncResult, TdsParserStateObject stateObj)
at System.Data.SqlClient.TdsParserStateObject.ReadNetworkPacket()
at System.Data.SqlClient.TdsParserStateObject.ReadBuffer()
at System.Data.SqlClient.TdsParserStateObject.ReadByte()
at System.Data.SqlClient.TdsParser.Run(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj)
at System.Data.SqlClient.SqlDataReader.ConsumeMetaData()
The report was scheduled to run at 1:00 am GMT. The error log does not say which one timed out, whether the data driven subscription query or the actual report query or the report server itself. When we returned to office (around 4:00 am GMT), we ran the data driven subscription query and it completed within few seconds. We ran the report on-demand and it worked it fine.
Also noted that the Execution Log table did not even have an entry. Normally the execution log should have an entry whether the report completed successfully or not. This made me to think that the report failed even before execution… probably at the initiation itself. But was not sure whether execution of data driven query is part of execution or initiation.
Went through the error log line by line but still could not get any clue. Finally I decided to involve my DBA to troubleshoot using profiler. And the culprit was data driven query, it was timing out during that specific time. We adjusted the run time little bit and it worked fine.