8
2

Delete article

Deleted articles cannot be recovered.

Draft of this article would be also deleted.

Are you sure you want to delete this article?

More than 5 years have passed since last update.

ZOZOテクノロジーズ #3Advent Calendar 2019

Day 19

SQL Server: DMVを使ってCPUボトルネックなクエリをできる限り正確に特定する方法について考えてみた

Last updated at Posted at 2019-12-18

背景

ドキュメントには、DMV(動的管理ビュー)の一種であるsys.dm_exec_query_statsを使った、CPUボトルネックなクエリを特定するクエリサンプルとして、以下のSQLが紹介されています。

image.png
出典:こちら

sys.dm_exec_query_statsには、以下の性質があります。

リコンパイルされると
1.plan_generation_numがカウントアップ
2.creation_timeがコンパイル時間にアップデート
3.execution_count / total_worker_time / total_elapsed_time 等が0にリセットされる

正確には、古いplan_generation_numの値をもったレコードが削除され、新しいplan_generationi_numの値をもったレコードがINSERTされるような気もしますが。。

また、ドキュメントには以下の記載があります。

つまり、プランがキャッシュから削除されると、対応する行もこのビューから削除されます。

上記性質を踏まえると、MSのドキュメントに記載されているクエリは、「クエリがリコンパイルされることなく、かつ一切キャッシュアウトしない」という前提のもとで正確な値がとれる、ということになります。

しかし、多くのクエリが実行されているプロダクション環境においては、クエリの再コンパイルが頻繁に起き、キャッシュアウトされることも想定されます。

また、ドキュメントで紹介されているクエリは「平均のCPU使用時間が高いクエリ」を抽出することはできますが、サーバーにCPU負荷をかけているクエリを特定する、という目的であれば、「CPU負荷が高い時間帯における、総CPU使用時間が高いクエリ」を特定したいところです。

こうした背景を踏まえて、DMVを使ってできる限り正確にCPU高負荷なクエリを見つける方法を考えてみました。

プロダクション環境でのリコンパイル発生状況を確認する

パフォーマンスモニターでもリコンパイル発生状況は確認できますが、本記事で主役となるsys.dm_exec_query_statsを使ってリコンパイル発生状況を確認してみます。

select *
  ,SUBSTRING(qt.TEXT, qs.statement_start_offset / 2, (
      CASE 
        WHEN qs.statement_end_offset = - 1
          THEN LEN(CONVERT(NVARCHAR(MAX), qt.TEXT)) * 2
        ELSE qs.statement_end_offset
      END - qs.statement_start_offset
   ) / 2) as statement
   from sys.dm_exec_query_stats qs
OUTER APPLY sys.dm_exec_sql_text(qs.sql_handle) AS qt -- クエリテキスト用
OUTER apply sys.dm_exec_query_plan(plan_handle) as qp -- プランプラン用
where creation_time > dateadd(SECOND, -60, getdate())
and execution_count >= 10

このクエリは、「過去60秒以内にリコンパイルされ、リコンパイル後の実行回数が10回以上」なクエリを抽出します。
このクエリを実行してレコードがとれる場合は、「本当はCPUを沢山使っているけど、頻繁にリコンパイルされてtotal_worker_timeがリセットされているためにtotal_worker_timeが小さな値になっている」ような状況が発生してる可能性があります。

アイデア

特定の2点におけるsys.dm_exec_query_statsの情報を全てダンプして保存した場合、各レコードはクエリAまたはクエリBのいずれかに該当します。
image.png

クエリA:creation_time <= Time ①
クエリB:creation_time > Time ①
※last_execution_time ≒ Time ② であると仮定します。プロダクション環境で常に実行され続けているようなクエリばかりの場合はこの仮定で問題ありません。

このとき、Time ①とTime ②の間の時間帯におけるCPU使用時間が高いクエリを見つけるために、クエリAとクエリBにおいて以下の計算を実施します。
クエリA:Time ②のtotal_worker_time - Time ①のtotal_worker_time
クエリB:Time ②のtotal_worker_time * (Time ② - Time ①) / (Time ②-creation_time)

これにより、コンパイル時間(=total_worker_timeの算出開始時間)が異なるクエリ達であっても、同一の時間間隔における使用CPU時間を推定し、その値が大きい順に並び替えることでCPUボトルネックなクエリを推定できると考えました。

作成したクエリと、クエリを使った解析手順

1.このクエリを実行してまずダンプ用のテーブルを作成します。
2.このクエリを(1分に1回など)定期的に実行します。最低2回取得できればOKです。
3.このクエリの、@snapshot_time_earlier@snapshot_time_laterの2か所に、実在するcollect_dateの値を入れて実行します。

下図のように、CPU使用時間の寄与率が高い順に結果が表示されるので、それらのクエリがチューニングできないかを検討すればOKです。
image.png

まとめ

結果にノイズが混ざったりしますが、何も工夫しないよりは正確な情報が取得できると思います。

8
2
0

Register as a new user and use Qiita more conveniently

  1. You get articles that match your needs
  2. You can efficiently read back useful information
  3. You can use dark theme
What you can do with signing up
8
2

Delete article

Deleted articles cannot be recovered.

Draft of this article would be also deleted.

Are you sure you want to delete this article?