SQL Serverの利用中にレスポンス遅延が発生した場合、どのクエリがボトルネックになっているか簡単に確認する方法をご紹介します。レスポンス遅延発生時の切り分けなどにご利用ください。
概要
SQL Serverでは、Oracel DatabaseのStatsPack・AWRのようなパフォーマンス・レポート機能が標準では提供されていません。今回のブログ記事では、SQLトレースもしくは統計情報を利用して遅いクエリを特定する方法をご紹介します。記事の内容は、SQL Server 2012・SQL Server 2014にて検証しております。
1. SQL Server Profilerを利用したSQLトレース
- 手順1. SQL Server Profilerの起動
- 手順2. SQLトレースの実行
2. スクリプトを利用したSQLトレース
- 手順1. SQLトレーススクリプトの作成
- 手順2. SQLトレースの実行
3. 動的管理ビューを利用した統計情報の抽出
- 手順1. Accel Platform上で該当する操作の実行
- 手順2. 動的管理ビュー sys.dm_exec_query_statsから統計情報の抽出
調査方法にはそれぞれメリット・デメリットが存在するため、調査の状況に合わせて適切な方法を選択してください。
| 調査方法 | 各SQLの実行時間に関する情報 | 取得によるシステム負荷の低さ |
|---|---|---|
| SQL Server Profiler | ○ | × |
| SQLトレーススクリプト | ○ | △ |
| 動的管理ビュー | △ | ○ |
1. SQL Server Profilerを利用したSQLトレース
ここでは、SQL Server上で実行されているSQLをトレースして、一定時間以上処理を実行していたクエリをリストアップする方法をご紹介します。SQLトレースを実行するには、SQL Serverに付属しているイベントキャプチャツール SQL Server Profilerを利用します。
SQL Server Profilerの実行はSQL Serverに負荷を与えるため、運用環境では利用しないでください。検証環境のSQL Server上で実行してください。
SQL Server Profilerの詳細については、Microsoft社のドキュメントを参照してください。
手順1. SQL Server Profilerの起動
1. SQL Server Profilerを起動します。
SQL Server Management Studioのツールバー「ツール」から「SQL Server Profiler」を選択し、SQL Server Profilerを起動します。
2. SQL Server Profilerからデータベースへ接続します。
認証情報を入力し、接続ボタンを押下することで、SQL Server Profilerからデータベースへ接続します。
手順2. SQLトレースの実行
1. SQLトレースのプロパティを入力します。
- タブ「全般」にて任意のトレース名を入力します。
-
タブ「全般」にて「使用するテンプレート」を空白に設定します。
-
キャチャするイベントを設定します。
タブ「イベントの選択」にて「Stored Procedures」の「SP:StmtCompleted」にチェックを入れます。
タブ「イベントの選択」にて「TSQL」の「SQL:StmtCompleted」にチェックを入れます。
-
キャプチャするイベントに対するフィルタリングを設定します。
タブ「イベントの選択」にて「列フィルター」を押下し、フィルターの編集画面を表示します。
「Duration」を選択し、「次の値以上」に抽出したい処理時間の下限を入力します。今回のブログ記事では、1000(ミリ秒)を設定しています。
「DatabaseName」を選択し、「次のパターンに一致」にAccel Platformから接続しているデータベースのデータベース名を入力します。
2. SQLトレースを実行します。
実行ボタンを押下し、SQLトレースを実行します。
3. Accel Platform側で該当する操作を実行します。
Accel Platform上でレスポンス遅延が発生する操作を実行し、操作の完了を待ちます。
4. SQLトレースを停止し、トレース結果を確認します。
- Accel Platform側での操作完了後にトレースを停止します。SQL Server Profilerの画面上の停止ボタンを押下します。
-
SQL Server Profilerの画面からリストアップされたSQLを確認します。
2. スクリプトを利用したSQLトレース
ここでは、SQL Server Profilerを経由せず、スクリプトを直接実行することでSQL Server上で実行されているSQLをトレースする方法をご紹介します。SQL Server Profilerを経由する場合に比べて、SQL Serverに対する負荷が大幅に減少します。
スクリプトによるSQLトレースの場合でも、SQL Serverに対する多少の負荷が残るため、運用環境では利用される際はご注意ください。
手順1. SQLトレーススクリプトの作成
以下のひな形を修正し、SQLトレーススクリプトを作成します。
- 「%トレースファイルを出力するパス%」にトレースファイルを出力するWindows上のファイルパスを設定します。
- 設定したファイルパスに既に同名のファイルが存在する場合、スクリプト実行時にエラーが発生します。
- 設定したファイルパスに対してSQL Serverを実行しているWindowsユーザが書き込み権限を有していない場合、スクリプト実行時にエラーが発生します。
- 「%データベース名%」にAccel Platformから接続しているデータベースのデータベース名を入力します。
こちらのひな形ではなく、独自にSQLトレーススクリプトを作成する場合は、SQL トレーススクリプトの作成、実行 (SQL Server 2005 ～ 2014)を参照してください。
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 100 101 102 103 104 105 106 107 108 109 110 |
-- Create a Queue declare @rc int declare @TraceID int declare @maxfilesize bigint set @maxfilesize = 5 -- Please replace the text InsertFileNameHere, with an appropriate -- filename prefixed by a path, e.g., c:\MyFolder\MyTrace. The .trc extension -- will be appended to the filename automatically. If you are writing from -- remote server to local drive, please use UNC path and make sure server has -- write access to your network share exec @rc = sp_trace_create @TraceID output, 2, N'%トレースファイルを出力するパス%', @maxfilesize, NULL if (@rc != 0) goto error -- Client side File and Table cannot be scripted -- Set the events declare @on bit set @on = 1 exec sp_trace_setevent @TraceID, 45, 1, @on exec sp_trace_setevent @TraceID, 45, 9, @on exec sp_trace_setevent @TraceID, 45, 3, @on exec sp_trace_setevent @TraceID, 45, 4, @on exec sp_trace_setevent @TraceID, 45, 5, @on exec sp_trace_setevent @TraceID, 45, 6, @on exec sp_trace_setevent @TraceID, 45, 7, @on exec sp_trace_setevent @TraceID, 45, 8, @on exec sp_trace_setevent @TraceID, 45, 10, @on exec sp_trace_setevent @TraceID, 45, 11, @on exec sp_trace_setevent @TraceID, 45, 12, @on exec sp_trace_setevent @TraceID, 45, 13, @on exec sp_trace_setevent @TraceID, 45, 14, @on exec sp_trace_setevent @TraceID, 45, 15, @on exec sp_trace_setevent @TraceID, 45, 16, @on exec sp_trace_setevent @TraceID, 45, 17, @on exec sp_trace_setevent @TraceID, 45, 18, @on exec sp_trace_setevent @TraceID, 45, 22, @on exec sp_trace_setevent @TraceID, 45, 25, @on exec sp_trace_setevent @TraceID, 45, 26, @on exec sp_trace_setevent @TraceID, 45, 28, @on exec sp_trace_setevent @TraceID, 45, 29, @on exec sp_trace_setevent @TraceID, 45, 34, @on exec sp_trace_setevent @TraceID, 45, 35, @on exec sp_trace_setevent @TraceID, 45, 41, @on exec sp_trace_setevent @TraceID, 45, 48, @on exec sp_trace_setevent @TraceID, 45, 49, @on exec sp_trace_setevent @TraceID, 45, 50, @on exec sp_trace_setevent @TraceID, 45, 51, @on exec sp_trace_setevent @TraceID, 45, 55, @on exec sp_trace_setevent @TraceID, 45, 60, @on exec sp_trace_setevent @TraceID, 45, 61, @on exec sp_trace_setevent @TraceID, 45, 62, @on exec sp_trace_setevent @TraceID, 45, 64, @on exec sp_trace_setevent @TraceID, 45, 66, @on exec sp_trace_setevent @TraceID, 41, 1, @on exec sp_trace_setevent @TraceID, 41, 9, @on exec sp_trace_setevent @TraceID, 41, 3, @on exec sp_trace_setevent @TraceID, 41, 4, @on exec sp_trace_setevent @TraceID, 41, 5, @on exec sp_trace_setevent @TraceID, 41, 6, @on exec sp_trace_setevent @TraceID, 41, 7, @on exec sp_trace_setevent @TraceID, 41, 8, @on exec sp_trace_setevent @TraceID, 41, 10, @on exec sp_trace_setevent @TraceID, 41, 11, @on exec sp_trace_setevent @TraceID, 41, 12, @on exec sp_trace_setevent @TraceID, 41, 13, @on exec sp_trace_setevent @TraceID, 41, 14, @on exec sp_trace_setevent @TraceID, 41, 15, @on exec sp_trace_setevent @TraceID, 41, 16, @on exec sp_trace_setevent @TraceID, 41, 17, @on exec sp_trace_setevent @TraceID, 41, 18, @on exec sp_trace_setevent @TraceID, 41, 25, @on exec sp_trace_setevent @TraceID, 41, 26, @on exec sp_trace_setevent @TraceID, 41, 29, @on exec sp_trace_setevent @TraceID, 41, 35, @on exec sp_trace_setevent @TraceID, 41, 41, @on exec sp_trace_setevent @TraceID, 41, 48, @on exec sp_trace_setevent @TraceID, 41, 49, @on exec sp_trace_setevent @TraceID, 41, 50, @on exec sp_trace_setevent @TraceID, 41, 51, @on exec sp_trace_setevent @TraceID, 41, 55, @on exec sp_trace_setevent @TraceID, 41, 60, @on exec sp_trace_setevent @TraceID, 41, 61, @on exec sp_trace_setevent @TraceID, 41, 64, @on exec sp_trace_setevent @TraceID, 41, 66, @on -- Set the Filters declare @intfilter int declare @bigintfilter bigint set @bigintfilter = 1000000 exec sp_trace_setfilter @TraceID, 13, 0, 4, @bigintfilter exec sp_trace_setfilter @TraceID, 35, 0, 6, N'%データベース名%' -- Set the trace status to start exec sp_trace_setstatus @TraceID, 1 -- display trace id for future references select TraceID=@TraceID goto finish error: select ErrorCode=@rc finish: go |
手順2. SQLトレーススクリプトの実行
1. 作成したSQLトレーススクリプトを実行します。
作成したSQLトレーススクリプトを実行し、戻り値のトレースIDを取得します。
2. Accel Platform側で該当する操作を実行します。
Accel Platform上でレスポンス遅延が発生する操作を実行し、操作の完了を待ちます。
3. SQLトレースを停止し、トレース結果を確認します。
以下のコマンドを実行し、SQLトレースを停止します。
%TRACE_ID%には、「1. 作成したSQLトレーススクリプトを実行します。」で取得した値を設定してください。
|
1 2 3 4 |
exec sp_trace_setstatus %TRACE_ID%, 0 exec sp_trace_setstatus %TRACE_ID%, 2 |
出力されたトレースファイルを開き、トレース結果を確認します。
3. 動的管理ビューを利用した統計情報の抽出
レスポンス遅延が再現する検証環境をすぐに構築できない場合、運用環境で調査を行う必要があります。SQLトレースは運用環境での利用が難しいため、ここでは動的管理ビュー上の統計情報から遅延しているクエリを抽出する方法をご紹介します。
動的管理ビュー sys.dm_exec_query_stats
動的管理ビューは、SQL Serverのパフォーマンスに関する様々な統計情報を格納したビューです。今回は、クエリのパフォーマンス統計が格納されている動的管理ビュー sys.dm_exec_query_statsから遅延しているクエリの情報を抽出します。
動的管理ビューは統計情報であるため、直前に操作した際のクエリに関する情報のみ抽出するということが実現できません。そのため、正確な調査を行うには、SQLトレースにより調査を行うことを推奨します。
検証を行う前に以下のコマンドを実行することで、動的管理ビュー sys.dm_exec_query_statsを初期化した状態で検証を行うことができますが、プロシージャ キャッシュ全体がクリアされ、クエリの実行計画がすべて消えてしまうため、運用環境では実行しないでください。
|
1 2 3 |
DBCC FREEPROCCACHE |
動的管理ビューの詳細については、動的管理ビューおよび関数 (Transact-SQL)を参照してください。動的管理ビュー sys.dm_exec_query_statsの詳細については、sys.dm_exec_query_stats (Transact-SQL)を参照してください。
手順1. Accel Platform上で該当する操作の実行
Accel Platform上でレスポンス遅延が発生する操作を実行し、操作の完了を待ちます。
手順2. 動的管理ビュー sys.dm_exec_query_statsから統計情報の抽出
動的管理ビュー sys.dm_exec_query_statsから統計情報を抽出し、ボトルネックになっているクエリを特定します。sys.dm_exec_query_statsにはクエリに関する様々なパフォーマンス統計が格納されており、CPU・物理IOボトルネックなど様々な観点でクエリをリストアップできますが、ここでは処理時間順にリストアップする方法をご紹介します。
1. 平均処理時間がかかっているクエリを特定します。
以下のSQLを実行し、結果を確認します。
|
1 2 3 4 5 6 7 8 9 10 |
select top 30 total_elapsed_time / execution_count / 1000 as AvgElapsedTime ,text as SQLtext from sys.dm_exec_query_stats cross apply sys.dm_exec_sql_text(sql_handle) order by AvgElapsedTime desc; |
2. 累積の処理時間がかかっているクエリを特定します。
以下のSQLを実行し、結果を確認します。
|
1 2 3 4 5 6 7 8 9 10 |
select top 30 total_elapsed_time / 1000 as ElapsedTime ,text as SQLtext from sys.dm_exec_query_stats cross apply sys.dm_exec_sql_text(sql_handle) order by ElapsedTime desc; |
