遇到一个有意思的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

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' )

   at System.Data.OracleClient.OracleConnection.CheckError(OciErrorHandle errorHandle, Int32 rc)

w3wp!processing!18!2015/1/30-00:04:31:: i INFO: Merge abort handler called. Aborting data sources ...

   --- End of inner exception stack trace ---

   --- End of inner exception stack trace ---

w3wp!library!d!01/30/2015-00:04:53:: i INFO: Call to RenderFirst( '/JO/EEL/JOReportZH_FTYEMI' )