遇到一個有意思的Reporting Services報表的案例，在2015-01-30號的凌晨20分左右的時候，有人發現Reporting Services的速度非常慢，而且最后有拋出異常，當時不知道什么情況。只是記錄了其中一張報表的名字，以及出錯信息截圖。如下所示：
第二天，我首先通過下面SQL查看這張報表在2015-01-30 00:00到2015-01-30 02:00這段時間的執行記錄，如下所示，正常情況下，3~5秒報表出來，不正常情況下整個報表耗費了接近60多秒，很奇怪的是TimeDataRetrieval的時間居然為0，大家都知道TimeDataRetrieval、TimeProcessing、TimeRendering分別表示檢索數據、處理報表以及呈現報表所用的毫秒數（SQL里面，我將單位轉化為秒）。但是TimeStart, TimeEnd的時間差（報表進程的持續時段的開始時間和結束時間）居然耗費了60多秒，讓我很是納悶，不太明白，照理來說，TimeDataRetrieval、TimeProcessing、TimeRendering三者的和應該接近於TimeEnd減去TimeStart的差，但是這里的情況明顯不對頭，那么究竟發生了什么事情呢，這張報表不是發生了異常嗎，於是我找到了日志文件C:\Program Files\Microsoft SQL Server\MSSQL.3\Reporting Services\LogFiles\ReportServer__01_30_2015_00_00_46.log
![clipboard[1]](/image/aHR0cHM6Ly9pbWFnZXMwLmNuYmxvZ3MuY29tL2Jsb2cvNzM1NDIvMjAxNTAyLzAzMDAyNTIwMzQzNTEwOC5wbmc=.png "clipboard[1]")
USE [ReportServer];
GO
SELECT C.Name AS ReportName
,E.ReportID AS ReportID
,E.UserName AS UserName
,E.Format AS Format
,E.Parameters AS Parameters
,E.TimeStart AS TimeStart
,E.TimeEnd AS TimeEnd
,E.TimeDataRetrieval*1.0/1000 AS TimeDataRetrieval
,E.TimeProcessing*1.0/1000 AS TimeProcessing
,E.TimeRendering*1.0/1000 AS TimeRendering
,DATEDIFF(SECOND, TimeStart, TimeEnd)
AS CostTime
FROM ReportServer.dbo.ExecutionLog E WITH(NOLOCK)
INNER JOIN ReportServer.dbo.Catalog C WITH(NOLOCK)ON E.ReportID = C.ItemID
WHERE C.Name ='JOReportZH_FTYEMI'
AND E.TimeStart > CAST('2015-01-30 00:00' AS DATETIME)
AND E.TimeStart <= CAST('2015-01-30 02:00' AS DATETIME)
ORDER BY TimeStart DESC
如下所示，因為當時Oracle數據有異常，導致連接數據庫時出現”ORA-12602: TNS: 達到連接共享限制“的錯誤。然后分析日志發現，Reporting Service進程在獲取數據出現異常的情況下，有個錯誤處理機制讓它繼續嘗試訪問數據庫，進行了多次嘗試后才最終將異常拋出，這也是為什么TimeDataRetrieval的時間居然為0。TimeStart, TimeEnd的時間差（指示報表進程的持續時段的開始時間和結束時間）耗費了60多秒的緣故。到此謎底終於揭開！困擾我的疑問豁然開朗！
ReportServer__01_30_2015_00_00_46.log文件里面的部分內容如下所示：
w3wp!library!18!01/30/2015-00:03:28:: i INFO: Call to RenderFirst( '/JO/EEL/JOReportZH_FTYEMI' )
w3wp!runningjobs!d!30/01/2015-00:04:07:: i INFO: Adding: 1 running jobs to the database
w3wp!library!8!01/30/2015-00:04:09:: i INFO: Call to RenderFirst( '/JO/EEL/JOReportZH_FTYEMI' )
w3wp!processing!18!2015/1/30-00:04:31:: e ERROR: Throwing Microsoft.ReportingServices.ReportProcessing.ReportProcessingException: 對數據集“SELECT_MATRIX_OPT”執行查詢失敗。, ;
Info: Microsoft.ReportingServices.ReportProcessing.ReportProcessingException: 對數據集“SELECT_MATRIX_OPT”執行查詢失敗。 ---> System.Data.OracleClient.OracleException: ORA-12602: TNS: 達到連接共享限制
at System.Data.OracleClient.OracleConnection.CheckError(OciErrorHandle errorHandle, Int32 rc)
at System.Data.OracleClient.OracleCommand.Execute(OciStatementHandle statementHandle, CommandBehavior behavior, Boolean needRowid, OciRowidDescriptor& rowidDescriptor, ArrayList& resultParameterOrdinals)
at System.Data.OracleClient.OracleCommand.Execute(OciStatementHandle statementHandle, CommandBehavior behavior, ArrayList& resultParameterOrdinals)
at System.Data.OracleClient.OracleCommand.ExecuteReader(CommandBehavior behavior)
at System.Data.OracleClient.OracleCommand.ExecuteDbDataReader(CommandBehavior behavior)
at System.Data.Common.DbCommand.System.Data.IDbCommand.ExecuteReader(CommandBehavior behavior)
at Microsoft.ReportingServices.DataExtensions.OracleCommandWrapperExtension.ExecuteReader(CommandBehavior behavior)
at Microsoft.ReportingServices.ReportProcessing.ReportProcessing.RuntimeDataSetNode.RunDataSetQuery()
--- End of inner exception stack trace ---
w3wp!processing!18!2015/1/30-00:04:31:: e ERROR: An exception has occurred in data source 'SELECT_MATRIX_OPT'. Details: Microsoft.ReportingServices.ReportProcessing.ReportProcessingException: 對數據集“SELECT_MATRIX_OPT”執行查詢失敗。 ---> System.Data.OracleClient.OracleException: ORA-12602: TNS: 達到連接共享限制
w3wp!processing!18!2015/1/30-00:04:31:: i INFO: Merge abort handler called. Aborting data sources ...
w3wp!dataextension!18!2015/1/30-00:04:31:: w WARN: CommandWrapper.Cancel not called, connection is not valid
w3wp!processing!18!2015/1/30-00:04:31:: e ERROR: Throwing Microsoft.ReportingServices.ReportProcessing.ProcessingAbortedException: 處理報表時出錯。, ;
Info: Microsoft.ReportingServices.ReportProcessing.ProcessingAbortedException: 處理報表時出錯。 ---> Microsoft.ReportingServices.ReportProcessing.ReportProcessingException: 對數據集“SELECT_MATRIX_OPT”執行查詢失敗。 ---> System.Data.OracleClient.OracleException: ORA-12602: TNS: 達到連接共享限制
--- End of inner exception stack trace ---
w3wp!processing!18!2015/1/30-00:04:31:: w WARN: Data source '1.90': Report processing has been aborted.
w3wp!processing!18!2015/1/30-00:04:31:: e ERROR: Throwing Microsoft.ReportingServices.ReportProcessing.ProcessingAbortedException: 處理報表時出錯。, ;
Info: Microsoft.ReportingServices.ReportProcessing.ProcessingAbortedException: 處理報表時出錯。 ---> Microsoft.ReportingServices.ReportProcessing.ReportProcessingException: 對數據集“SELECT_MATRIX_OPT”執行查詢失敗。 ---> System.Data.OracleClient.OracleException: ORA-12602: TNS: 達到連接共享限制
--- End of inner exception stack trace ---
w3wp!webserver!18!01/30/2015-00:04:31:: e ERROR: Reporting Services error Microsoft.ReportingServices.Diagnostics.Utilities.RSException: 處理報表時出錯。 ---> Microsoft.ReportingServices.ReportProcessing.ProcessingAbortedException: 處理報表時出錯。 ---> Microsoft.ReportingServices.ReportProcessing.ReportProcessingException: 對數據集“SELECT_MATRIX_OPT”執行查詢失敗。 ---> System.Data.OracleClient.OracleException: ORA-12602: TNS: 達到連接共享限制
w3wp!library!d!01/30/2015-00:04:53:: i INFO: Call to RenderFirst( '/JO/EEL/JOReportZH_FTYEMI' )
w3wp!runningjobs!1!30/01/2015-00:05:07:: i INFO: RunningJobContext.IsClientConnected; found orphaned request
w3wp!runningjobs!18!30/01/2015-00:05:07:: i INFO: Adding: 1 running jobs to the database
w3wp!runningjobs!1!30/01/2015-00:05:07:: i INFO: RunningJobContext.IsClientConnected; found orphaned request
w3wp!processing!8!2015/1/30-00:05:13:: e ERROR: Throwing Microsoft.ReportingServices.ReportProcessing.ReportProcessingException: 對數據集“SELECT_MATRIX_OPT”執行查詢失敗。, ;
Info: Microsoft.ReportingServices.ReportProcessing.ReportProcessingException: 對數據集“SELECT_MATRIX_OPT”執行查詢失敗。 ---> System.Data.OracleClient.OracleException: ORA-12602: TNS: 達到連接共享限制