小物SEのメモ帳

IT関係の試したことや調べたことの備忘録

【SQL Server】CPU使用率、IO負荷の高いクエリレポート

クエリのパフォーマンス状況の確認方法として、DMVを組み合わせた「CPU使用率の高いクエリ」や「IO負荷の高いクエリ」を取得するクエリを事前に準備しているシステム管理者も多いかと思いますが、グラフィカルなレポートという形で取得するのも視覚的に確認できてよいかと思いますので、出力方法の説明です。
※デメリットとして、レポート出力ではSQLハンドルは出力できているものの、実行プランは別途取得する必要があります。

特に次のレポートは比較的利用価値が高いのではないでしょうか。
「パフォーマンス - バッチ実行の統計」
「パフォーマンス - 平均IO数ごとの上位のクエリ」
「パフォーマンス - IOの総数ごとの上位のクエリ」
「パフォーマンス - CPUの平均時間ごとの上位のクエリ」
「パフォーマンス - CPUの総時間ごとの上位のクエリ」

尚、これらのレポートは出力時に裏でSQLを実行し、動的管理ビューからデータ取得をしていますので、キャッシュ上に残存しているデータのみがレポート対象となります。

レポート出力の手順

左ペインの「オブジェクト エクスプローラー」のインスタンス名を選択し右クリック、「レポート(P)」-「標準レポート」を押下して、表示したいグラフをクリックします。
f:id:utiowa:20170314002607p:plain

レポート内容

①「パフォーマンス - バッチ実行の統計」
f:id:utiowa:20170314002619p:plain

これはバッチごとの平均・総CPU、論理読み取り数、論理書き込み数についてのレポートになります。

f:id:utiowa:20170314002630p:plain
平均はすべてデフォルト表示で、それぞれのプラス表示をクリックするとトータルの取得値が確認できます。

キャッシュ上に残存しているデータのうち、バッチ単位で高負荷なものを確認することができます。
またバッチ番号のプラス表示をクリックするとステートメント毎の情報が確認できます。

実際に裏でレポート表示に使われているクエリは次のようなものになります。

exec sp_executesql @stmt=N'begin try 
declare @dbid int; 
set @dbid = db_id(); 
declare @cnt int;  
declare @record_count int; 
declare @sql_handle varbinary(64);  
declare @sql_handle_string varchar(130); 
declare @grand_total_worker_time float ; 
declare @grand_total_IO float ; 
declare @sql_handle_convert_table table(
        row_id int identity 
,       t_sql_handle varbinary(64)
,       t_display_option varchar(140) collate database_default
,       t_display_optionIO varchar(140) collate database_default
,       t_sql_handle_text varchar(140) collate database_default
,       t_SPRank int
,   t_SPRank2 int
,       t_SQLStatement varchar(max) collate database_default
,       t_execution_count int 
,       t_plan_generation_num int
,       t_last_execution_time datetime
,       t_avg_worker_time float
,       t_total_worker_time bigint
,       t_last_worker_time bigint
,       t_min_worker_time bigint
,       t_max_worker_time bigint 
,       t_avg_logical_reads float
,       t_total_logical_reads bigint
,       t_last_logical_reads bigint
,       t_min_logical_reads bigint 
,       t_max_logical_reads bigint
,       t_avg_logical_writes float
,       t_total_logical_writes bigint
,       t_last_logical_writes bigint
,       t_min_logical_writes bigint
,       t_max_logical_writes bigint
,       t_avg_IO float
,       t_total_IO bigint
,       t_last_IO bigint
,       t_min_IO bigint
,       t_max_IO bigint
);
declare @objects table (
        obj_rank int
,       total_cpu bigint 
,       total_reads bigint
,       total_writes bigint
,       total_io bigint
,       avg_cpu bigint 
,       avg_reads bigint
,       avg_writes bigint
,       avg_io bigint
,       cpu_rank int
,       total_cpu_rank int
,       read_rank int
,       write_rank int
,       io_rank int
); 

insert into @sql_handle_convert_table 
Select  sql_handle
,       sql_handle as chart_display_option 
,       sql_handle as chart_display_optionIO 
,       master.dbo.fn_varbintohexstr(sql_handle)
,       dense_rank() over (order by s1.sql_handle) as SPRank 
,       dense_rank() over (partition by s1.sql_handle order by s1.statement_start_offset) as SPRank2
,       (select top 1 substring(text,(s1.statement_start_offset+2)/2, (case when s1.statement_end_offset = -1  then len(convert(nvarchar(max),text))*2 else s1.statement_end_offset end - s1.statement_start_offset) /2  ) from sys.dm_exec_sql_text(s1.sql_handle)) as [SQL Statement]
,       execution_count
,       plan_generation_num
,       last_execution_time
,       ((total_worker_time+0.0)/execution_count)/1000 as [avg_worker_time]
,       total_worker_time/1000
,       last_worker_time/1000
,       min_worker_time/1000
,       max_worker_time/1000
,       ((total_logical_reads+0.0)/execution_count) as [avg_logical_reads]
,       total_logical_reads
,       last_logical_reads
,       min_logical_reads
,       max_logical_reads
,       ((total_logical_writes+0.0)/execution_count) as [avg_logical_writes]
,       total_logical_writes
,       last_logical_writes
,       min_logical_writes
,       max_logical_writes
,       ((total_logical_writes+0.0)/execution_count + (total_logical_reads+0.0)/execution_count) as [avg_IO]
,       total_logical_writes + total_logical_reads
,       last_logical_writes +last_logical_reads
,       min_logical_writes +min_logical_reads
,       max_logical_writes + max_logical_reads  
from    sys.dm_exec_query_stats s1 
cross apply sys.dm_exec_sql_text(sql_handle) as  s2 
where s2.objectid is null
order by  s1.sql_handle; 

select @grand_total_worker_time = sum(t_total_worker_time) 
,       @grand_total_IO = sum(t_total_logical_reads + t_total_logical_writes)  
from @sql_handle_convert_table; 

select @grand_total_worker_time = case when @grand_total_worker_time > 0 then @grand_total_worker_time else 1.0 end  ; 
select @grand_total_IO = case when @grand_total_IO > 0 then @grand_total_IO else 1.0 end  ; 

Insert into @objects  
select t_SPRank
,       sum(t_total_worker_time)
,       sum(t_total_logical_reads)
,       sum(t_total_logical_writes)
,       sum(t_total_IO)
,       sum(t_avg_worker_time) as avg_cpu
,       sum(t_avg_logical_reads)
,       sum(t_avg_logical_writes)
,       sum(t_avg_IO)
,       rank() over(order by sum(t_avg_worker_time) desc)
,       row_number() over(order by sum(t_total_worker_time) desc)
,       row_number() over(order by sum(t_avg_logical_reads) desc)
,       row_number() over(order by sum(t_avg_logical_writes) desc)
,       row_number() over(order by sum(t_total_IO) desc) 
from @sql_handle_convert_table 
group by t_SPRank ; 

update @sql_handle_convert_table set t_display_option = ''show_total'' 
where t_SPRank in (select obj_rank from @objects where (total_cpu+0.0)/@grand_total_worker_time < 0.05) ; 

update @sql_handle_convert_table set t_display_option = t_sql_handle_text 
where t_SPRank in (select obj_rank from @objects where total_cpu_rank <= 5) ; 

update @sql_handle_convert_table set t_display_option = ''show_total'' 
where t_SPRank in (select obj_rank from @objects where (total_cpu+0.0)/@grand_total_worker_time < 0.005); 

update @sql_handle_convert_table set t_display_optionIO = ''show_total'' 
where t_SPRank in (select obj_rank from @objects where (total_io+0.0)/@grand_total_IO < 0.05); 

update @sql_handle_convert_table set t_display_optionIO = t_sql_handle_text 
where t_SPRank in (select obj_rank from @objects where io_rank <= 5) ; 

update @sql_handle_convert_table set t_display_optionIO = ''show_total''  
where t_SPRank in (select obj_rank from @objects where (total_io+0.0)/@grand_total_IO < 0.005); 

select (s.t_SPRank)%2 as l1
,       (dense_rank() over(order by s.t_SPRank,s.row_id))%2 as l2
,       s.*
,       ob.cpu_rank as t_CPURank 
,       ob.read_rank as t_ReadRank 
,       ob.write_rank as t_WriteRank  
from @sql_handle_convert_table  s join @objects ob on (s.t_SPRank = ob.obj_rank)
end try
begin catch
select -100 as l1
,       ERROR_NUMBER() as l2
,       ERROR_SEVERITY() as row_id
,       ERROR_STATE() as t_sql_handle
,       ERROR_MESSAGE() as t_display_option
,       1 as t_display_optionIO ,       1 as t_sql_handle_text ,        1 as t_SPRank ,     1 as t_SPRank2 ,    1 as t_SQLStatement ,           1 as t_execution_count  ,       1 as t_plan_generation_num ,    1 as t_last_execution_time ,            1 as t_avg_worker_time ,        1 as t_total_worker_time ,      1 as t_last_worker_time ,       1 as t_min_worker_time ,        1 as t_max_worker_time ,        1 as 
t_avg_logical_reads ,      1 as t_total_logical_reads ,    1 as t_last_logical_reads ,     1 as t_min_logical_reads ,      1 as t_max_logical_reads ,      1 as t_avg_logical_writes ,     1 as t_total_logical_writes ,   1 as t_last_logical_writes ,    1 as t_min_logical_writes ,     1 as t_max_logical_writes ,     1 as t_avg_IO , 1 as t_total_IO ,       1 as t_last_IO ,        1 as t_min_IO ,    1 as t_max_IO,    1 as t_CPURank,    1 as t_ReadRank,    1 as t_WriteRank
end catch',@params=N''


ちなみにSQLserverでは、複数ステートメントのまとまりをバッチと呼びます。(ステートメントは単一のクエリのことです。)

例えば、以下のようなものがあった場合は、

SELECT ~
UPDATE ~
GO

SELECT、UPDATEはそれぞれ1ステートメントで、SELECTからGOまでのひとかたまりが1バッチとなります。


②「パフォーマンス - 平均IO数ごとの上位のクエリ」
f:id:utiowa:20170314002710p:plain

これはキャッシュ上に残存するクエリのうち、1回あたりのIO数が多い上位クエリについてのレポートになります。
レポート上には同クエリについてそれぞれIOの総数で見た場合の負荷を同時に見ることができ便利です。
平均IO数が多いが、総IO数があまり多くない場合、全体への負荷は高くないが、単一クエリとしては高負荷である場合がありますので、非効率なクエリ(インデックスが不足しているなど)でないか注意が必要かと思います。

実際に裏でレポート表示に使われているクエリは次のようなものになります。

exec sp_executesql @stmt=N'begin try
select top 10 rank() over (order by (total_logical_reads+total_logical_writes)/(execution_count+0.0) desc,sql_handle,statement_start_offset ) as row_no
,       (rank() over (order by (total_logical_reads+total_logical_writes)/(execution_count+0.0) desc,sql_handle,statement_start_offset ))%2 as l1
,       creation_time
,       last_execution_time
,       (total_worker_time+0.0)/1000 as total_worker_time
,       (total_worker_time+0.0)/(execution_count*1000) as [AvgCPUTime]
,       total_logical_reads as [LogicalReads]
,       total_logical_writes as [LogicalWrites]
,       execution_count
,       total_logical_reads+total_logical_writes as [AggIO]
,       (total_logical_reads+total_logical_writes+0.0)/execution_count as [AvgIO]
,       case when sql_handle IS NULL
                then '' ''
                else ( substring(st.text,(qs.statement_start_offset+2)/2,(case when qs.statement_end_offset = -1        then len(convert(nvarchar(MAX),st.text))*2      else qs.statement_end_offset    end - qs.statement_start_offset) /2  ))
        end as query_text 
,       db_name(st.dbid) as database_name
,       st.objectid as object_id
from sys.dm_exec_query_stats  qs
cross apply sys.dm_exec_sql_text(sql_handle) st
where (total_logical_reads+total_logical_writes ) > 0
order by [AvgIO] desc
end try
begin catch
select -100 AS row_no
,       1 AS l1, 1 AS creation_time, 1 AS last_execution_time,  1 AS total_worker_time,  1 AS AvgCPUTime, 1 AS logicalReads,  1 AS LogicalWrites
,       ERROR_NUMBER() AS execution_count
,       ERROR_SEVERITY() AS AggIO
,       ERROR_STATE() AS AvgIO
,       ERROR_MESSAGE() AS query_text 
end catch',@params=N''


レポート形式ではなく、同様の情報と同時に実行プランも取得したい場合は次のとおり。

select top 10 rank() over (order by (total_logical_reads+total_logical_writes)/(execution_count+0.0) desc,sql_handle,statement_start_offset ) as row_no
,       (rank() over (order by (total_logical_reads+total_logical_writes)/(execution_count+0.0) desc,sql_handle,statement_start_offset ))%2 as l1
,       creation_time
,       last_execution_time
,       (total_worker_time+0.0)/1000 as total_worker_time
,       (total_worker_time+0.0)/(execution_count*1000) as [AvgCPUTime]
,       total_logical_reads as [LogicalReads]
,       total_logical_writes as [LogicalWrites]
,       execution_count
,       total_logical_reads+total_logical_writes as [AggIO]
,       (total_logical_reads+total_logical_writes+0.0)/execution_count as [AvgIO]
,       case when sql_handle IS NULL
                then ' '
                else ( substring(st.text,(qs.statement_start_offset+2)/2,(case when qs.statement_end_offset = -1        then len(convert(nvarchar(MAX),st.text))*2      else qs.statement_end_offset    end - qs.statement_start_offset) /2  ))
        end as query_text 
,       db_name(st.dbid) as database_name
,       st.objectid as object_id
,		qs.sql_handle
,		qp.query_plan
from sys.dm_exec_query_stats  qs
CROSS APPLY sys.dm_exec_sql_text(sql_handle) st
CROSS APPLY sys.dm_exec_query_plan(plan_handle) qp
where (total_logical_reads+total_logical_writes ) > 0
order by [AvgIO] desc


③「パフォーマンス - IOの総数ごとの上位のクエリ」
f:id:utiowa:20170314002954p:plain

これはキャッシュ上に残存するクエリのうち、IOの総数が多い上位クエリについてのレポートになります。
上記②と同様にそれぞれ平均IO数がどの程度か確認することができます。総IO数が多く、かつ平均IO数も多い場合は、チューニングすると全体に対し大きな効果が得られますので、ここからチューニング対象を見ていくとよいかと思います。

実際に裏でレポート表示に使われているクエリは次のようなものになります。
見ての通り、②のレポートで実行しているものを総IO数にてソートしたものと同様になります。

exec sp_executesql @stmt=N'begin try
select top 10 rank() over (order by total_logical_reads+total_logical_writes desc,sql_handle,statement_start_offset ) as row_no
,       (rank() over (order by total_logical_reads+total_logical_writes desc,sql_handle,statement_start_offset ))%2 as l1
,       creation_time
,       last_execution_time
,       (total_worker_time+0.0)/1000 as total_worker_time
,       (total_worker_time+0.0)/(execution_count*1000) as [AvgCPUTime]
,       total_logical_reads as [LogicalReads]
,       total_logical_writes as [LogicalWrites]
,       execution_count
,       total_logical_reads+total_logical_writes as [AggIO]
,       (total_logical_reads+total_logical_writes)/(execution_count+0.0) as [AvgIO]
,       case when sql_handle IS NULL
                then '' ''
                else ( substring(st.text,(qs.statement_start_offset+2)/2,(case when qs.statement_end_offset = -1        then len(convert(nvarchar(MAX),st.text))*2      else qs.statement_end_offset    end - qs.statement_start_offset) /2  ) )
        end as query_text 
,       db_name(st.dbid) as database_name
,       st.objectid as object_id
from sys.dm_exec_query_stats  qs
cross apply sys.dm_exec_sql_text(sql_handle) st
where total_logical_reads+total_logical_writes > 0 
order by [AggIO]  desc
end try
begin catch
select -100 AS row_no
,       1 AS l1, 1 AS creation_time, 1 AS last_execution_time,  1 AS total_worker_time,  1 AS Avg_CPU_Time, 1 AS logicalReads,  1 AS LogicalWrites
,       ERROR_NUMBER() AS execution_count
,       ERROR_SEVERITY() AS AggIO
,       ERROR_STATE() AS AvgIO
,       ERROR_MESSAGE() AS query_text 
end catch',@params=N''

よって、レポート形式ではなく、同様の情報と同時に実行プランも取得したい場合は次のとおり。

select top 10 rank() over (order by total_logical_reads+total_logical_writes desc,sql_handle,statement_start_offset ) as row_no
,       (rank() over (order by total_logical_reads+total_logical_writes desc,sql_handle,statement_start_offset ))%2 as l1
,       creation_time
,       last_execution_time
,       (total_worker_time+0.0)/1000 as total_worker_time
,       (total_worker_time+0.0)/(execution_count*1000) as [AvgCPUTime]
,       total_logical_reads as [LogicalReads]
,       total_logical_writes as [LogicalWrites]
,       execution_count
,       total_logical_reads+total_logical_writes as [AggIO]
,       (total_logical_reads+total_logical_writes)/(execution_count+0.0) as [AvgIO]
,       case when sql_handle IS NULL
                then ' '
                else ( substring(st.text,(qs.statement_start_offset+2)/2,(case when qs.statement_end_offset = -1        then len(convert(nvarchar(MAX),st.text))*2      else qs.statement_end_offset    end - qs.statement_start_offset) /2  ) )
        end as query_text 
,       db_name(st.dbid) as database_name
,       st.objectid as object_id
,		qs.sql_handle
,		qp.query_plan
from sys.dm_exec_query_stats  qs
CROSS APPLY sys.dm_exec_sql_text(sql_handle) st
CROSS APPLY sys.dm_exec_query_plan(plan_handle) qp
where total_logical_reads+total_logical_writes > 0 
order by [AggIO]  desc


④「パフォーマンス - CPUの平均時間ごとの上位のクエリ」
f:id:utiowa:20170314002744p:plain

これはキャッシュ上に残存するクエリのうち、1回あたりのCPU使用量が多い上位クエリについてのレポートになります。
レポート上には同クエリについてそれぞれCPU使用量の総時間で見た場合の負荷を同時に見ることができます。
②と同様に、平均使用時間に比べて総時間が多くない場合は、単一クエリとしてはCPUに対し高負荷である場合がありますので、非効率なクエリでないか注意が必要かと思います。

実際に裏でレポート表示に使われているクエリは②のレポートで実行しているものを平均CPU時間にてソートしたものと同様になります。
よって、レポート形式ではなく、同様の情報と同時に実行プランも取得したい場合は次のとおり。

select top 10 rank() over(order by (total_worker_time+0.0)/execution_count desc,sql_handle,statement_start_offset ) as row_no
,       (rank() over(order by (total_worker_time+0.0)/execution_count desc,sql_handle,statement_start_offset ))%2 as l1
,       creation_time
,       last_execution_time 
,       (total_worker_time+0.0)/1000 as total_worker_time
,       (total_worker_time+0.0)/(execution_count*1000) as [AvgCPUTime]
,       total_logical_reads as [LogicalReads]
,       total_logical_writes as [LogicalWrites]
,       execution_count
,       total_logical_reads+total_logical_writes as [AggIO]
,       (total_logical_reads+total_logical_writes)/(execution_count+0.0) as [AvgIO]
,       case when sql_handle IS NULL
                then ' '
                else ( substring(st.text,(qs.statement_start_offset+2)/2,       (case when qs.statement_end_offset = -1         then len(convert(nvarchar(MAX),st.text))*2      else qs.statement_end_offset    end - qs.statement_start_offset) /2  ) )
        end as query_text 
,       db_name(st.dbid) as db_name
,       st.objectid as object_id
,		qs.sql_handle
,		qp.query_plan
from sys.dm_exec_query_stats  qs
CROSS APPLY sys.dm_exec_sql_text(sql_handle) st
CROSS APPLY sys.dm_exec_query_plan(plan_handle) qp
where total_worker_time  > 0 
order by [AvgCPUTime] desc

⑤「パフォーマンス - CPUの総時間ごとの上位のクエリ」
f:id:utiowa:20170314002800p:plain

これはキャッシュ上に残存するクエリのうち、総CPU使用量が多い上位クエリについてのレポートになります。
レポート上には同クエリについてそれぞれ平均CPU使用時間で見た場合の負荷を同時に見ることができます。
③と同様に、総時間が長く、かつ平均使用時間も長い場合、チューニングすると全体のCPU使用効率に対し大きな効果が得られますので、チューニング可否を検討するとよいかと思います。

実際に裏でレポート表示に使われているクエリは②のレポートで実行しているものを総CPU時間にてソートしたものと同様になります。
よって、レポート形式ではなく、同様の情報と同時に実行プランも取得したい場合は次のとおり。

select top 10 rank() over(order by total_worker_time desc,sql_handle,statement_start_offset) as row_no
,       (rank() over(order by total_worker_time desc,sql_handle,statement_start_offset))%2 as l1
,       creation_time
,       last_execution_time
,       (total_worker_time+0.0)/1000 as total_worker_time
,       (total_worker_time+0.0)/(execution_count*1000) as [AvgCPUTime]
,       total_logical_reads as [LogicalReads]
,       total_logical_writes as [logicalWrites]
,       execution_count
,       total_logical_reads+total_logical_writes as [AggIO]
,       (total_logical_reads+total_logical_writes)/(execution_count + 0.0) as [AvgIO]
,   case when sql_handle IS NULL
                then ' '
                else ( substring(st.text,(qs.statement_start_offset+2)/2,(case when qs.statement_end_offset = -1        then len(convert(nvarchar(MAX),st.text))*2      else qs.statement_end_offset    end - qs.statement_start_offset) /2  ) )
        end as query_text 
,       db_name(st.dbid) as database_name
,       st.objectid as object_id
,		qs.sql_handle
,		qp.query_plan
from sys.dm_exec_query_stats  qs
CROSS APPLY sys.dm_exec_sql_text(sql_handle) st
CROSS APPLY sys.dm_exec_query_plan(plan_handle) qp
where total_worker_time > 0 
order by total_worker_time  desc


これらのレポートは表示後に右クリックでPDF出力も可能であるため、他人に見せる際にも活用できますので、一度使ってみるとよいと思います。