Top (参数)

最近在优化数据库服务器上高消耗语句/过程,发现一个存储过程优化后依旧出现在Profiler跟踪里。将Profiler跟踪文件中过程执行语句取出,打开一个查询窗口(SPID=144),set statistics io on,同时开启Profiler跟踪SPID=144中的语句执行情况。
下面是在查询窗口的执行结果,逻辑读只有17:

我们再看Profiler跟踪窗口的结果:

此处的CPU(1216)、Reads(160206)相比查询窗口中的逻辑读高出很多。查看存储过程相应部分对应的语句,仅仅是两个表关联查询而已:

如果直接执行存储过程中的语句会是怎样的呢?首先,按照过程参数传递的形式,将必要的参数Declare,执行:

其次,将参数用具体数值代替,再次执行:

以上两图中逻辑读没发现什么区别,但我们转到Profiler跟踪窗口,单独执行存储过程中的查询语句,如果top N 是以参数形式传入其cpu、reads与执行存储过程的消耗差不多,但比top 具体值的cpu、reads高很多:

此时我们应该想到它们的执行计划是不同的,从Profiler结果可以看出这块的消耗可以通过具体值,或在语句结尾+option(recompile)来降低。
下面我们将@typeid=2这一段封装到测试存储过程,然后分别查看语句末尾有无+option(recompile),执行此存储过程并查看执行计划。首先,我们对@typeid=2中的语句不做任何修改,模拟原过程执行情况:

然后,我们在查询语句的末尾加上+option(recompile),让其执行到此语句时,重编译:

注意到了没有,两者使用的索引完全一样,但它们在Profiler跟踪里的消耗却相差甚大。重编译在排序操作返回的记录数(228)较原过程的排序操作返回的记录数(47331)少很多,它直接影响对表u上idx_userID的执行次数。推测就是对u的执行次数,导致两个语句在Profiler跟踪里的消耗悬殊。
实际上不管是执行存储过程还是单独执行语句,在查询窗口的消息信息中没有表u的逻辑读取信息:

依据执行计划,肯定有对u表的读取操作,为什么在set statistics io on时,它没有出现?什么情况下会出现这种情况呢?
优化心得
使用RML分析.TRC文件真的很方便,我们可以按照下面的步骤来分析数据库服务器上高消耗的语句:
1、开启服务器端跟踪收集一段时间的数据(例如18:00~次日06:00,cpu>=33,根据情况调整)
2、使用RML工具分析跟踪数据(.TRC),很多存储过程调用或动态语句总体是一样的,只是带的参数会有不同,这个工具会把它们归类
3、根据归类,优先将总消耗大的语句优化
4、RML分析报表以图表展示,支持导出到execl、word、pdf;也可以用语句直接从库下获取符合需求的语句
下面代码提取[按照同一类型的语句,统计最昂贵的语句]:

--使用RML Cmd Prompt导入跟踪数据
ReadTrace -I"F:\TroubleShooting\Trace\HostName_InstanceName_HighCPU33_after.trc" -o"F:\TroubleShooting\Trace\output" -S"127.0.0.1,7777" -d"PerfAnalysis" -E

USE PerfAnalysis
GO
--查询跟踪
select MIN(StartTime),MAX(EndTime),COUNT(*)
from fn_trace_gettable(N'F:\TroubleShooting\Trace\HostName_InstanceName_HighCPU33_after.trc', default)
where cpu is not null

select * from ReadTrace.tblTimeIntervals
select top 10 * from ReadTrace.tblBatchPartialAggs 
select top 10 * from ReadTrace.tblUniqueBatches

--最初是按HashID得到总消耗CPU、Duration、Reads、Writes前N的语句
--后期根据需求添加DBID、LoginNameID,还可以计算平均消耗
select *,
        row_number() over(order by sum_CPU_ms desc) as QueryNumber
    from (
        select     --a.HashID,
            sum(CompletedEvents) as Executes,
            sum(TotalCPU) as sum_CPU_ms,
            sum(TotalCPU)/sum(CompletedEvents) as avg_CPU_ms,--add
            sum(TotalDuration)/1000 as sum_Duration_ms,
            sum(TotalDuration)/(sum(CompletedEvents)*1000) as avg_Duration_ms,--add
            sum(TotalReads) as sum_Reads,
            sum(TotalReads)/sum(CompletedEvents) as avg_Reads,--add
            sum(TotalWrites) as sum_Writes,
            sum(TotalWrites)/sum(CompletedEvents) as avg_Writes,--add
            --sum(AttentionEvents) as sum_Attentions, 
            --(select StartTime from ReadTrace.tblTimeIntervals i where TimeInterval = @StartTimeInterval) as [StartTime],
            --(select EndTime from ReadTrace.tblTimeIntervals i where TimeInterval = @EndTimeInterval) as [EndTime],
            --add DatabaseName、LoginName
            (select distinct DatabaseName from fn_trace_gettable(N'F:\TroubleShooting\Trace\HostName_InstanceName_HighCPU33_after.trc', default) where DatabaseID=a.DBID) as DatabaseName,
            (select LoginName from ReadTrace.tblUniqueLoginNames where iID=a.LoginNameID) as LoginName,
            (select cast(NormText as nvarchar(4000)) from ReadTrace.tblUniqueBatches b where b.HashID = a.HashID) as [NormText],
                   row_number() over(order by sum(TotalCPU) desc) as CPUDesc,
                   row_number() over(order by sum(TotalCPU) asc) as CPUAsc,
                   row_number() over(order by sum(TotalDuration) desc) as DurationDesc,
                   row_number() over(order by sum(TotalDuration) asc) as DurationAsc,
                   row_number() over(order by sum(TotalReads) desc) as ReadsDesc,
                   row_number() over(order by sum(TotalReads) asc) as ReadsAsc,
                   row_number() over(order by sum(TotalWrites) desc) as WritesDesc,
                   row_number() over(order by sum(TotalWrites) asc) as WritesAsc
            from ReadTrace.tblBatchPartialAggs a
                --where TimeInterval @StartTimeInterval and @EndTimeInterval
                    --and a.AppNameID = isnull(@iAppNameID, a.AppNameID)
                    --and a.LoginNameID = isnull(@iLoginNameID, a.LoginNameID)
                    --and a.DBID = isnull(@iDBID, a.DBID)
            group by a.HashID,a.DBID,a.LoginNameID
               ) as Outcome
        where     (CPUDesc <= 20 
            --or CPUAsc <= @TopN
            or DurationDesc <= 20 
            --or DurationAsc <= @TopN
            or ReadsDesc <= 20 
            --or ReadsAsc <= @TopN
            or WritesDesc <= 20 
            --or WritesAsc <= @TopN
        )
        order by sum_CPU_ms desc
        option (recompile)

select top 100 EventClass,TextData,DatabaseName,DatabaseID,Duration/1000 Duration_ms,CPU CPU_ms,Reads,Writes,StartTime,EndTime,HostName,LoginName,ApplicationName
from fn_trace_gettable(N'F:\TroubleShooting\Trace\HostName_InstanceName_HighCPU33_after.trc', default)
where TextData like '%GAMEWEB_ADMIN_GAMESCORE_LOG%'
View Code

代码对应的是RML报表的Top Unique Batches页面,同时增加对数据库、应用程序分组,以及平均消耗值信息。部分组件导出到execl、word、pdf时报错,可以使用语句直接从数据库下提取消耗列表。

posted @ 2016-01-26 21:23  Uest  阅读(713)  评论(0编辑  收藏  举报