SQL Server讀懂語句運行的統計信息 SET STATISTICS TIME IO PROFILE ON

對於語句的運行，除了執行計划本身，還有一些其他因素要考慮，例如語句的編譯時間、執行時間、做了多少次磁盤讀等。

如果DBA能夠把問題語句單獨測試運行，可以在運行前打開下面這三個開關，收集語句運行的統計信息。

這些信息對分析問題很有價值。

SET STATISTICS TIME ON
SET STATISTICS IO ON
SET STATISTICS PROFILE ON

 

SET STATISTICS TIME ON

---

請先來看看SET STATISTICS TIME ON會返回什么信息。先運行語句：

DBCC DROPCLEANBUFFERS
--清除buffer pool里的所有緩存數據
DBCC freeproccache
GO

--清除buffer pool里的所有緩存的執行計划
SET STATISTICS TIME ON
GO
USE [AdventureWorks]
GO
SELECT DISTINCT([ProductID]),[UnitPrice] FROM [dbo].[SalesOrderDetail_test]
WHERE [ProductID]=777
GO
SET STATISTICS TIME OFF
GO

 

除了結果集之外，SQLSERVER還會返回下面這兩段信息

SQL Server 分析和編譯時間: 
   CPU 時間 = 15 毫秒，占用時間 = 104 毫秒。
SQL Server 分析和編譯時間: 
   CPU 時間 = 0 毫秒，占用時間 = 0 毫秒。

(4 行受影響)

SQL Server 執行時間:
   CPU 時間 = 171 毫秒，占用時間 = 1903 毫秒。
SQL Server 分析和編譯時間: 
   CPU 時間 = 0 毫秒，占用時間 = 0 毫秒。

大家知道SQLSERVER執行語句是分以下階段：分析-》編譯-》執行

根據表格的統計信息分析出比較合適的執行計划，然后編譯語句，最后執行語句

 

下面說一下上面的輸出是什么意思：

---

1、CPU時間 ：這個值的含義指的是在這一步，SQLSERVER所花的純CPU時間是多少。也就是說，語句花了多少CPU資源

2、占用時間 ：此值指這一步一共用了多少時間。也就是說，這是語句運行的時間長短，有些動作會發生I/O操作，產生了I/O等待，

或者是遇到阻塞、產生了阻塞等待。總之時間用掉了，但是沒有用CPU資源。所以占用時間比CPU時間長是很正常的 ，但是CPU時間是

語句在所有CPU上的時間總和。如果語句使用了多顆CPU，而其他等待幾乎沒有，那么CPU時間大於占用時間也是正常的

3、分析和編譯時間：這一步，就是語句的編譯時間。由於語句運行之前清空了所有執行計划，SQLSERVER必須要對他編譯。

這里的編譯時間就不為0了。由於編譯主要是CPU的運算，所以一般CPU時間和占用時間是差不多的。如果這里相差比較大，

就有必要看看SQLSERVER在系統資源上有沒有瓶頸了。

這里他們是一個15毫秒，一個是104毫秒

4、SQLSERVER執行時間： 語句真正運行的時間。由於語句是第一次運行，SQLSERVER需要把數據從磁盤讀到內存里，這里語句的

運行發生了比較長的I/O等待。所以這里的CPU時間和占用時間差別就很大了，一個是171毫秒，而另一個是1903毫秒

總的來講，這條語句花了104+1903+186=2193毫秒，其中CPU時間為15+171=186毫秒。語句的主要時間應該是都花在了I/O等待上

 

現在再做一遍語句，但是不清除任何緩存

SET STATISTICS TIME ON
GO

SELECT DISTINCT([ProductID]),[UnitPrice] FROM [dbo].[SalesOrderDetail_test]
WHERE [ProductID]=777

GO
SET STATISTICS TIME OFF
GO

這次比上次快很多。輸出時間統計信息是：

SQL Server 分析和編譯時間: 
   CPU 時間 = 0 毫秒，占用時間 = 0 毫秒。
SQL Server 分析和編譯時間: 
   CPU 時間 = 0 毫秒，占用時間 = 0 毫秒。

(4 行受影響)

SQL Server 執行時間:
   CPU 時間 = 156 毫秒，占用時間 = 169 毫秒。
SQL Server 分析和編譯時間: 
   CPU 時間 = 0 毫秒，占用時間 = 0 毫秒。

由於執行計划被重用，“SQL分析和編譯時間” CPU時間是0，占用時間是0

由於數據已經緩存在內存里，不需要從磁盤上讀取，SQL執行時間 CPU時間是156，占用時間這次和CPU時間非常接近，是169。

這里省下運行時間1903-169=1734毫秒，從這里可以再次看出，緩存對語句執行性能起着至關重要的作用

為了不影響其他測試，請運行下面的語句關閉SET STATISTICS TIME ON

SET STATISTICS TIME OFF
GO

 

 

 

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 行受影響)
表 'SalesOrderDetail_test'。掃描計數 5，邏輯讀取 15064 次，物理讀取 0 次，預讀 15064 次，lob 邏輯讀取 0 次，lob 物理讀取 0 次，lob 預讀 0 次。

各個輸出的含義是：

---

表：表的名稱。這里的表就是SalesOrderDetail_test

 

掃描計數：執行的掃描次數。按照執行計划，表格被掃描了幾次。一般來講大表掃描的次數越多越不好。唯一的例外是如果執行計划選擇了並發運行，

由多個thread線程同時做一個表的讀取，每個thread讀其中的一部分，但是這里會顯示所有thread的數目。也就是有幾個thread在並發做，

就會有幾個掃描。這時數目大一點沒問題的。

 

邏輯讀取：從數據緩存讀取的頁數。頁數越多，說明查詢要訪問的數據量就越大，內存消耗量越大，查詢也就越昂貴。

可以檢查是否應該調整索引，減少掃描的次數，縮小掃描范圍

順便說一下這個邏輯讀取的統計原理：為什麽顯示出來的結果的單位不是Page，也不是K或KB。SQLSERVER

里在做讀和寫的時候，會運行到某一段特定的代碼。每調用一次這個代碼，Reads/Write就會加1。所以這個值比較大

那語句一定做了比較多的I/O，但是不能通過這個值計算出I/O的絕對數量，這個值反映的是邏輯讀寫量不是物理讀寫量

邏輯讀取 15064 次

 

 

物理讀取：從磁盤讀取的頁數

 

預讀：為進行查詢而預讀入緩存的頁數

 

物理讀取+預讀：就是SQLSERVER為了完成這句查詢而從磁盤上讀取的頁數。如果不為0，說明數據沒有緩存在內存里。運行速度一定會受到影響

 

LOB邏輯讀取：從數據緩存讀取的text、ntext、image、大值類型（varchar(max)、nvarchar(max)、varbinary(max)）頁的數目

 

LOB物理讀取：從磁盤讀取的text、ntext、image、大值類型頁的數目

 

LOB預讀：為進行查詢而放入緩存的text、ntext、image、大值類型頁的數目

 

然后再來運行一遍，不清空緩存

SET STATISTICS IO ON
GO

SELECT DISTINCT([ProductID]),[UnitPrice] FROM [dbo].[SalesOrderDetail_test]
WHERE [ProductID]=777
GO

結果集返回：

表 'SalesOrderDetail_test'。掃描計數 5，邏輯讀取 15064 次，物理讀取 0 次，預讀 0 次，lob 邏輯讀取 0 次，
lob 物理讀取 0 次，lob 預讀 0 次。

這次邏輯讀取不變，還是15064頁。但是物理讀取和預讀都是0了。說明數據已經緩存在內存里
第二次運行不需要再從磁盤上讀一遍，節省了時間

 

為了不影響其他測試，請運行下面語句關閉SET STATISTICS IO ON

SET STATISTICS IO OFF
GO

 

 

SET STATISTICS PROFILE ON

---

這是三個設置中返回最復雜的一個，他返回語句的執行計划，以及語句運行在每一步的實際返回行數統計。

通過這個結果，不僅可以得到執行計划，理解語句執行過程，分析語句調優方向，也可以判斷SQLSERVER是否

選擇了一個正確的執行計划。

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

返回的結果集很長，下面說一下重要字段

---

注意：這里是從最下面開始向上看的，也就是說從最下面開始一直執行直到得到結果集所以（行1）里的rows字段顯示的值就是這個查詢返回的結果集。

而且有多少行表明SQLSERVER執行了多少個步驟,這里有6行，表明SQLSRVER執行了6個步驟！！

 

Rows:執行計划的每一步返回的實際行數

Executes:執行計划的每一步被運行了多少次

StmtText:執行計划的具體內容。執行計划以一棵樹的形式顯示。每一行都是運行的一步，都會有結果集返回，也都會有自己的cost

EstimateRows:SQLSERVER根據表格上的統計信息，預估的每一步的返回行數。在分析執行計划時，

我們會經常將Rows和EstimateRows這兩列做對比，先確認SQLSERVER預估得是否正確，以判斷統計信息是否有更新

EstimateIO:SQLSERVER根據EstimateRows和統計信息里記錄的字段長度，預估的每一步會產生的I/O cost

EstimateCPU:SQLSERVR根據EstimateRows和統計信息里記錄的字段長度，以及要做的事情的復雜度，預估每一步會產生的CPU cost

TotalSubtreeCost:SQLSERVER根據EstimateIO和EstimateCPU通過某種計算公式，計算出每一步執行計划子樹的cost

（包括這一步自己的cost和他的所有下層步驟的cost總和），下面介紹的cost說的都是這個字段值

Warnings:SQLSERVER在運行每一步時遇到的警告，例如，某一步沒有統計信息支持cost預估等。

Parallel:執行計划的這一步是不是使用了並行的執行計划

 

從上面結果可以看出執行計划分成4步，其中第一步又分成並列的兩個子步驟

步驟a1（第5行）：從[SalesOrderHeader_test]表里找出所有a.[SalesOrderID]>43659 AND a.[SalesOrderID]<53660的值

因為表在這個字段上有一個聚集索引，所以SQL可以直接使用這個索引的seek

SQL預測返回10000條記錄，實際也就返回了10000條記錄.。這個預測是准確的。這一步的cost是0.202(totalsubtreecost)

步驟a2（第6行）：從[SalesOrderDetail_test]表里找出所有 a.[SalesOrderID]>43659 AND a.[SalesOrderID]<53660的值

因為表在這個字段上有一個非聚集索引，所以SQL可以直接使用這個索引的seek

這里能夠看出SQL聰明的地方。雖然查詢語句只定義了[SalesOrderHeader_test]表上有a.[SalesOrderID]>43659 AND a.[SalesOrderID]<53660過濾條件，

但是根據語義分析，SQL知道這個條件在[SalesOrderDetail_test]上也為真。所以SQL選擇先把這個條件過濾然后再做join。這樣能夠大大降低join的cost

在這一步SQL預估返回50561條記錄，實際返回50577條。cost是0.127，也不高

步驟b（第4行）：將a1和a2兩步得到的結果集做一個join。因為SQL通過預估知道這兩個結果集比較大，所以他直接選擇了Hash Match的join方法。

SQL預估這個join能返回50313行，實際返回50577行。因為SQL在兩張表的[SalesOrderID]上都有統計信息，所以這里的預估非常准確

這一步的cost等於totalsubtreecost減去他的子步驟，0.715-0.202-0.127=0.386。由於預估值非常准確，可以相信這里的cost就是實際每一步的cost

步驟c（第3行）：在join返回的結果集基礎上算count(*)的值這一步比較簡單，count(*)的結果總是1，所以預測值是正確的。

其實這一步的cost是根據上一步（b）join返回的結果集大小預估出來的。我們知道步驟b的預估返回值非常准確，所以這一步的預估cost也不會有什么大問題

這棵子樹的cost是0.745，減去他的子節點cost，他自己的cost是0.745-0.715=0.03。是花費很小的一步

步驟b（第2行）：將步驟c返回的值轉換為int類型，作為結果返回

這一步是上一步的繼續，更為簡單。convert一個值的數據類型所要的cost幾乎可以忽略不計。所以這棵子樹的cost和他的子節點相等，都是0.745。

也就是說，他自己的cost是0

 

通過這樣的方法，用戶可以了解到語句的執行計划、SQL Server預估的准確性、cost的分布

 

最后說一下：不同SQL Server版本，不同機器cost可能會不一樣，例如SQL Server 2005 、SQL Server 2008

 

---

2020-4-8補充

SET STATISTICS IO ON中物理讀和邏輯讀的誤區

SET STATISTICS IO ON實際上指的是SQL Server從文件系統讀取一個數據庫8K頁面 計算為一個 物理IO/物理讀，而不是對物理磁盤的一次讀寫IO

要說清楚這個問題，需要知道， 默認一般情況下

Windows的內存分頁大小單位是  4KB，Linux的內存分頁大小單位是  4KB

數據庫的最小讀寫單位是 8K頁面

Windows操作系統的NTFS文件系統最小讀寫單位（分配單元/簇）是 4KB，Linux的操作系統的ext4文件系統的最小讀寫單位（block文件塊）是4KB，x86系統的文件系統一般文件塊都是4KB

機械硬盤的的最小讀寫單位（邏輯扇區和物理扇區）是512字節

固態硬盤因為沒有扇區的概念，用的是分塊，一個分塊一般是4KB，固態硬盤暫且不討論

如下圖

那么，先說結論，實際上STATISTICS IO 中物理讀和邏輯讀的統計對象自始至終都是數據庫8K頁面，比如，邏輯讀1次， 物理讀1次，實際上都是按8KB頁為單位的，是SQL Server的統計方式

這樣就會造成誤解

有人會問，如果物理讀為1次，那么數據庫對磁盤只是做了一次讀寫操作一次IO，對嗎

有人會問，如果邏輯讀為1次，那么數據庫在內存中只是讀寫了一個內存頁一次IO，對嗎

這樣理解會有點問題

對於物理讀情況，SQL Server是運行在Windows上的一個軟件，那么這個軟件在文件系統上存儲數據依然按照NTFS文件系統的規則，一個8K的頁面數據需要占用2個分配單元

大家可以用winhex這個軟件，按8K頁面查看數據庫的mdf文件可以查看到完整的一個數據庫頁面數據

那么，這個8KB頁面讀或寫到硬盤，就需要16*512次IO，也就是實際寫入一個數據庫頁面需要16個硬盤IO，正因為這樣，所以有可能出現頁面寫入不完整情況，才會有各種數據庫的頁面完整性檢測機制，例如mysql的double write，mssql的頁面校驗機制

注意，即使是固態硬盤，也不要關閉這些頁面完整性檢測機制的參數

所以說，SET STATISTICS IO ON中你看到的1次物理讀，實際上對應硬盤的16次IO

對於邏輯讀情況，Windows的一個內存頁是4KB，一個數據庫頁面8KB，讀寫一個內存中的數據庫頁面實際上是讀寫了兩個內存頁，但是STATISTICS IO 只顯示 邏輯讀1次

然后內存中8KB數據庫頁跟文件系統中的8KB數據庫頁是一一對應的，不然的話，B+樹索引結構和二分查找法就會失效，查找數據也無從談起

 

總結

SET STATISTICS IO ON只是SQL Server的統計方式，實際上對硬盤、文件系統、內存產生的IO並不是那么回事，不要被它帶偏了

參考文章
https://post.smzdm.com/p/ag89zv97/