加入收藏 | 设为首页 | 会员中心 | 我要投稿 李大同 (https://www.lidatong.com.cn/)- 科技、建站、经验、云计算、5G、大数据,站长网!
当前位置: 首页 > 站长学院 > MsSql教程 > 正文

SQLServer语句运行统计信息

发布时间:2020-12-12 16:05:43 所属栏目:MsSql教程 来源:网络整理
导读:对于SQL语句,其编译时间、执行时间、做了多少磁盘读等非常重要,它直接关系到SQL语句的执行效率。在SQLServer中,有下面三个开关,用于收集语句运行的统计信息。这些信息对分析问题很有价值。 Set statistics time on Set statistics io on Set statistics

对于SQL语句,其编译时间、执行时间、做了多少磁盘读等非常重要,它直接关系到SQL语句的执行效率。在SQLServer中,有下面三个开关,用于收集语句运行的统计信息。这些信息对分析问题很有价值。
Set statistics time on
Set statistics io on
Set statistics profile on

下面分别对这三条语句进行实例说明。


?? 1、Set statistics time on

请先来看看Set statistics time on会返回什么信息。先运行语句:
dbcc dropcleanbuffers
-- 清除buffer pool里的所有缓存的数据
dbcc freeproccache
go
-- 清除buffer pool里的所有缓存的执行计划
go
Set statistics time on
go
select distinct ProductID,UnitPrice
from dbo.SalesOrderDetail_test
where ProductID = 777
union
select ProductID,UnitPrice
from dbo.SalesOrderDetail_test
where ProductID = 777
go
Set statistics time off
go

除了结果集以外,SQL Server还会返回下面这两段信息。
SQL Server parse and compile time:
?? CPU time = 15 ms,elapsed time = 36 ms.

(4 row(s) affected)

SQL Server Execution Times:
?? CPU time = 32 ms,? elapsed time = 767 ms.

1.CPU Time

这个值的含义指的是在这一步,SQL Server所花的纯CPU时间是多少,也就是说,语句花了多少CPU资源。

2.elapsed Time

此值指这一步一共用了多少时间,也就是说,这是语句运行的时间长短。(add by zhj: 从进程的角度来看,很容易理解,elapsed Time = CPU Time + 非运行时间,这里的非运行时间主要包括阻塞态时间、就绪态时间等,具体的,要看操作系统中进程有哪几种非运行状态。从内存读取数据到CPU的时间貌似也是非运行时间吧)

有些动作会发生I/O操作、产生了I/O等待,或者是遇到阻塞、产生阻塞的等待,总之时间用掉了,但是没有用CPU资源,所以Elapsed Time比CPU Time长是很正常的。但是CPU Time是语句在所有CPU上的时间总和,如果语句使用了多颗CPU,而其他等待几乎没有,那么CPU Time大于Elapsed Time也是正常的。

3.SQL Server parse and compile time

这一步,就是语句的编译时间。由于语句运行之前清空了所有执行计划,SQL Server必须要对它编译。这里的编译时间就不为0了。由于编译主要是CPU的运算,所以一般CPU Time和Elapsed Time是差不多的。如果这里相差比较大,就有必要看看SQL Server在系统资源上有没有瓶颈。

这里它们一个是15毫秒,另一个是36毫秒。

4.SQL Server Execution Times

语句真正运行的时间。由于语句是第一次运行,SQL Server需要把数据从磁盘读到内存里,这里语句的运行发生了比较长的I/O等待。所以这里的CPU Time和Elapsed Time差别就很大了,一个是32毫秒,而另一个是767毫秒。

总的来讲,这条语句花了36 + 767= 803毫秒,其中CPU时间为15 + 32 = 47毫秒。语句的主要时间应该是都花在了I/O的等待上了。

现在再做一遍语句,但是不清除任何缓存。
Set statistics time on
go
select distinct ProductID,UnitPrice
from dbo.SalesOrderDetail_test
where ProductID = 776
union
select ProductID,UnitPrice
from dbo.SalesOrderDetail_test
where ProductID = 776
go

这次应该比上次快很多,输出时间统计信息是:
SQL Server parse and compile time:
?? CPU time = 0 ms,elapsed time = 1 ms.

(4 row(s) affected)

SQL Server Execution Times:
?? CPU time = 32 ms,? elapsed time = 41 ms.

由于执行计划被重用,“SQL Server parse and compile time”CPU Time是0,Elapsed Time也仅是1,这里省下编译时间36– 1 = 15毫秒。

由于数据已经缓存在内存里,不需要从磁盘上读取,“SQL Server Execution Times”CPU Time是32,Elapsed Time这次和CPU Time非常接近,是41,这里省下运行时间767– 41= 726毫秒。

从这里可以再次看出,缓存对语句执行性能起着至关重要的作用。

为了不影响其他测试,请运行下面的语句关闭Set Statistics Time On。
Set statistics time off
Go


?? 2、Set statistics io on

?????? 这个开关能够输出语句做的物理读和逻辑读的数目,对分析语句的复杂度有很重要的作用。

?????? 还是以刚才那个查询为例。
?????? dbcc dropcleanbuffers
?????? go
?????? Set statistics io on
?????? go
?????? select distinct ProductID,UnitPrice
?????? from dbo.SalesOrderDetail_test
?????? where ProductID = 777
?????? go

它的返回是:
(4 row(s) affected)

Table 'SalesOrderDetail_test'. Scan count 1,logical reads 3024,physical reads 1,read-ahead reads 3038,lob logical reads 0,lob physical reads 0,lob read-ahead reads 0.

各个输出的含义是:

Table:表的名称。这里的表就是SalesOrderDetail_test。

scan count:执行的扫描次数。按照执行计划,表格被Scan了几次。一般来讲大表Scan的次数越多越不好,唯一的例外是如果执行计划选择了并发运行,由多个Thread同时做一个表的读取,每个Thread读其中的一部分,但是这里会显示所有Thread的数目。也就是有几个Thread在并发做,就会有几个Scan。这时数目大一点没问题。

logical reads:从数据缓存读取的页数。页数越多,说明查询要访问的数据量就越大,内存消耗量越大,查询也就越昂贵。可以检查是否应该调整索引,减少扫描的次数,缩小扫描范围。

physical reads:从磁盘读取的页数。

read-ahead reads:为进行查询而预读入缓存的页数。

physical reads 和read-ahead reads就是SQL Server为了完成这句查询而从磁盘上读取的页数。如果不为0,说明数据没有缓存在内存里,运行速度一定会受到影响。

lob logical reads:从数据缓存读取的Text、Ntext、Image或大值类型(Varchar(max)、Nvarchar(max)、Varbinary(max))页的数目。

lob physical reads:从磁盘读取的Text、Ntext、Image或大值类型页的数目。

lob read-ahead reads:为进行查询而放入缓存的Text、Ntext、Image或大值类型页的数目。

然后再来运行一遍,不清空缓存。
Set statistics io on
go
select distinct ProductID,UnitPrice
from dbo.SalesOrderDetail_test
where ProductID = 777
go

结果集返回:
Table 'SalesOrderDetail_test'. Scan count 1,physical reads 0,read-ahead reads 0,lob read-ahead reads 0.

这次Logical Reads不变,还是3 024页,但是physical reads 和read-ahead reads都是0了。说明数据已经缓存在内存里,第二次运行不需要再从磁盘上读一遍,节省了时间。

为了不影响其他测试,请运行下面的语句关闭Set statistics io on。
Set statistics io off
Go


? 3、Set statistics profile on

??????? 这是三个设置中返回最复杂的一个,它返回语句的执行计划,以及语句运行在每一步的实际返回行数统计。

? ? ??? 通过这个结果,不仅可以得到执行计划、理解语句执行的过程、分析语句调优的方向,也可以判断SQL

??????? Server是否选择了一个正确的执行计划,如果不正确,原因又大概是什么。

本章前面已经使用过了这个设置的返回结果来分析执行计划。现在再来完整地介绍一下,先从一个最简单的查询谈起。
Set statistics profile on
go
select distinct ProductID,UnitPrice
from dbo.SalesOrderDetail_test
where ProductID = 777
go

返回的结果集很长,笔者先把它们都贴出来,比较重要的字段打上了方框记号,后面加以解释(见图17-44)。


?

Rows:执行计划的每一步返回的实际行数。

Executes:执行计划的每一步被运行了多少次。

StmtText:执行计划的具体内容。执行计划以一棵树的形式显示。每一行,都是运行的一步,都会有结果集返回,也都会有自己的cost。

EstimateRows:SQL Server根据表格上的统计信息,预估的每一步的返回行数。在分析执行计划时,我们会经常将Rows和EstimateRows这两列做对比,先确认SQL Server预估得是否准确。
EstimateIO:SQL Server根据EstimateRows和统计信息里记录的字段长度,预估的每一步会产生的I/O cost。

EstimateCPU:SQL Server根据EstimateRows和统计信息里记录的字段长度,以及要做的事情的复杂度,预估的每一步会产生的CPU cost。

TotalSubtreeCost:SQL Server根据EstimateIO和EstimateCPU通过某种计算公式,计算出的每一步执行计划子树cost(包括这一步自己的cost和它的所有下层步骤的cost总和)。

Warnings:SQL Server在运行每一步时遇到的警告,例如,某一步没有统计信息支持cost预估等。

Parallel:执行计划的这一步是不是使用了并行的执行计划。

所以上面这个简单的执行计划意思是:

(1)执行计划分成两步。

步骤a(行3)

使用Clustered Index Scan(全表扫描)的方式找出所有ProductID = 777的记录。

?????? |--Clustered Index Scan(OBJECT:([AdventureWorks].[dbo].[SalesOrderDetail_test]. [SalesOrderDetail_test_CL]),WHERE:([AdventureWorks].[dbo].[SalesOrderDetail_test]. [ProductID]=(777)))

这一步SQL Server预测会返回522.8行,实际返回484行,所以这一步预估得还算准确。预估cost是2.502。

步骤b(行2)

使用Sort的方式把步骤a返回的484行做一个排序,从中选出Distinct的值。

? |--Sort(DISTINCT ORDER BY:([AdventureWorks].[dbo].[SalesOrderDetail_test].[UnitPrice] ASC))

这一步SQL Server预测会返回146.1行,实际只返回了4行。所以这一步的预估有些不准确。这和SQL Server在ProductID+UnitPrice上没有直接的统计信息有关系。好在这个结果集没有用来做其他事情,直接就是查询的结果。所以预估不太准也没什么影响。

这一步的预估cost是2.637。除掉它的子步骤a的cost 2.502,这一步自己的cost是2.637 – 2.502 =0.135。

(2)执行计划是单线程运行的,也没有报出什么Warning。应该讲,是一个正常的语句。

(3)比较Rows和EstimateRows这两列,SQL Server没有少估计某一步的返回。而多估计的那一步(Step B)在多估的情况下,Cost依然比较小,自己cost只有0.135。实际的cost因为返回结果集小,应该更低。所以可以讲,整个Cost估计得还是比较准确的。主要的cost都花在了全表扫描上了(Step A)。如果要对这个语句进行调优,就要引导SQL Server不要使用Clustered Index Scan这样cost大的动作。在ProductID上加一个索引是一个比较自然的想法。

让我们再运行一句稍微复杂一点的语句,看看结果会怎么样,如图17-45所示。


?

set statistics profile on
go
select count(b.SalesOrderID)
from dbo.SalesOrderHeader_test a
inner join dbo.SalesOrderDetail_test b
on a.SalesOrderID = b.SalesOrderID
where a.SalesOrderID >43659 and a.SalesOrderID< 53660
go

从这个结果能看出来的是执行计划分成4步,其中第一步又分成并列的两个子步骤。

步骤a1(第5行): 从SalesOrderHeader_test表里找出所有SalesOrderID >43 659 and SalesOrderID< 53 660的值。

因为表在这个字段上有一个聚集索引,所以SQL Server可以直接使用这个索引的Seek。

?? |--Clustered Index Seek(OBJECT:([AdventureWorks].[dbo].[SalesOrderHeader_test]. [SalesOrderHeader_test_CL] AS [a]),SEEK:([a].[SalesOrderID] > (43659) AND [a].[SalesOrderID] < (53660)) ORDERED FORWARD)

SQL预测返回10 000条记录,实际也就返回了10 000条,这个预测是准的。这一步的cost是0.202,果然比前面的Clustered Index Scan要低很多。

步骤a2(第6行):从SalesOrderDetail _test表里找出所有SalesOrderID >43 659 and SalesOrderID< 53 660的值。

因为表在这个字段上有一个非聚集索引,所以SQL Server可以直接使用这个索引的Seek。

?? |--Index Seek(OBJECT:([AdventureWorks].[dbo].[SalesOrderDetail_test].[SalesOrderDetail_test_NCL] AS [b]),SEEK:([b].[SalesOrderID] > (43659) AND [b].[SalesOrderID] < (53660)) ORDERED FORWARD)

这里能够看出SQL Server聪明的地方。虽然查询语句只定义了SalesOrderHeader_test表上有SalesOrderID >43 659 and SalesOrderID< 53 660过滤条件,但是根据语义分析,SQL Server知道这个条件在SalesOrderDetail_test上也为真。所以SQL Server选择先把这个条件过滤,然后再做Join,这样能够大大降低Join的cost。

在这一步SQL Server预估返回50 561条记录,实际返回50 577条,Cost是0.109,也不高。

步骤b(第4行):将a1和a2两步得到的结果集做一个Join。

?? |--Hash Match(Inner Join,HASH:([a].[SalesOrderID])=([b].[SalesOrderID]))

因为SQL Server通过预估知道这两个结果集比较大,所以它直接选择了Hash Match的Join方法。SQL预估这个Join能返回50 444行,实际返回50 577行。因为SQL在两张表的SalesOrderID上都有统计信息,所以这里的预估非常准确。

这一步的cost等于TotalSubtreeCost减去它的子步骤,0.697 – 0.202 – 0.109 = 0.386,由于预估值非常准确,可以相信这里的cost就是实际每一步的cost。

步骤c(第3行):在Join返回的结果集基础上算count(*)的值。

?? |--Stream Aggregate(DEFINE:([Expr1009]=Count(*)))

这一步比较简单,count(*)的结果总是1,所以预测值是正确的。其实这一步的cost是根据上一步(b)Join返回的结果集大小预估出来的。我们知道步骤b的预估返回值非常准确,所以这一步的预估cost也不会有什么大问题。

这棵子树的cost是0.727,减去它的子结点cost,它自己的cost是0.727 ? 0.697 = 0.03。是花费很小的一步。

步骤d(第2行):将步骤c返回的值转换成int类型,作为结果返回。

? |--Compute Scalar(DEFINE:([Expr1006]=CONVERT_IMPLICIT(int,[Expr1009],0)))

这一步是上一步的继续,更为简单。Convert一个值的数据类型所要的cost几乎可以忽略不计,所以这棵子树的cost和它的子结点相等,都是0.727,也就是说,它自己的cost是0。

通过这样的方法,用户可以了解到语句的执行计划、SQL Server预估的准确性,以及cost的分布。下一章里,还会继续使用这些方法,来解决语句执行的性能问题。

这里顺便还要提一下执行计划里cost的值绝对大小问题。经常有人会问,两句查询的cost,是不是一句比另一句高,就一定是高的那一句比较耗时?SQL Server是跟据预测结果集(EstimateRows)大小和结果集里的数据类型推算出EstimateIO和EstimateCPU,然后再根据EstimateIO和EstimateCPU推算出TotalSubtreeCost。计算方法是所有SQL Server都一样的(只要SQL版本一样),所以在同一个SQL Server里,可以说,cost高的那一句语句一定会比较复杂。当然,前提是SQL Server要Estimate得准确。

对SQL Server来讲,它也是选择cost最低的执行计划。在“17.3.1连接(Join)”这一节例子里的那三条查询,cost最低的是使用Hash Match的连接方式,所以如果让SQL Server自己选择而不用Join Hint,它会选择Hash Match。

但是对于不同的SQL Server,由于硬件差异,SQL Server能够调动的内存、CPU、磁盘资源也会有所差异。同样Cost的语句,执行的速度会有很大的不同,所以一般不会去对比从不同SQL Server服务器上取得的执行计划里的cost。

????? 注:以上节选自《SQL Server 2012实施与管理实战指南



?????? 实战:在某软件系统中,本人发现其中的一些SQL查询语句很耗时。

??????? 先执行

dbcc dropcleanbuffers
dbcc freeproccache

SET STATISTICS IO ON
SET STATISTICS TIME ON
select id
from local_test1.dbo.T_TASK_DETAIL
where delete_flag =0
SET STATISTICS IO OFF
SET STATISTICS TIME OFF

得到结果如下:

DBCC 执行完毕。如果 DBCC 输出了错误信息,请与系统管理员联系。
DBCC 执行完毕。如果 DBCC 输出了错误信息,请与系统管理员联系。
SQL Server 分析和编译时间:
?? CPU 时间 = 0 毫秒,占用时间 = 0 毫秒。

(135712 row(s) affected)
表 'T_TASK_DETAIL'。扫描计数 1,逻辑读取 1259 次,物理读取 12 次,预读 1256 次,lob 逻辑读取 0 次,lob 物理读取 0 次,lob 预读 0 次。

?SQL Server 执行时间:
?? CPU 时间 = 125 毫秒,占用时间 = 22440 毫秒。

?SQL Server 执行时间:
?? CPU 时间 = 0 毫秒,占用时间 = 0 毫秒。


分析:

13万条数据,查询语句很简单,CPU耗时为125ms,有点多。根据公式 ,总耗时=CPU耗时 + 阻塞态时间 + 就绪态时间。由于从硬盘读取文件(physical reads 12read-ahead reads1256),所以在I/O上有一定的阻塞,那它是不是耗时的主要原因呢?如果是,再次执行下面的语句,elapsed time应该显著减小。


验证:

SET STATISTICS IO ON
SET STATISTICS TIME ON
select id
from local_test1.dbo.T_TASK_DETAIL
where delete_flag =0
SET STATISTICS IO OFF
SET STATISTICS TIME OFF

结果为:

SQL Server 分析和编译时间:
?? CPU 时间 = 0 毫秒,占用时间 = 0 毫秒。

(135712 row(s) affected)
表 'T_TASK_DETAIL'。扫描计数 1,逻辑读取 1259 次,物理读取 0 次,预读 0 次,lob 逻辑读取 0 次,lob 物理读取 0 次,lob 预读 0 次。

?SQL Server 执行时间:
?? CPU 时间 = 78 毫秒,占用时间 = 21705 毫秒。

?SQL Server 执行时间:
?? CPU 时间 = 0 毫秒,占用时间 = 0 毫秒。

对验证结果的分析:占用时间竟然没什么变化,可见,从硬盘物理读取文件导致的I/O阻塞并不是耗时的主要因素。那非运行时间就还有:从内存读取数据到CPU的时间、就绪态时间,先分析到这里吧。

(编辑:李大同)

【声明】本站内容均来自网络,其相关言论仅代表作者个人观点,不代表本站立场。若无意侵犯到您的权利,请及时与联系站长删除相关内容!

    推荐文章
      热点阅读