SE の雑記

SQL Server の情報をメインに Microsoft 製品の勉強内容を日々投稿

SQL Server / SQL Database に対してのクエリのベンチマークをどのような情報で比較するか

leave a comment

設定を変更しながら、設定変更の効果がクエリにどのような影響を与えるかを調査するための、簡単なベンチマークを行うためのスクリプトを最近作成していました。

クエリのベンチマークを行う際には、「どのように設定前後の処理効率の変化を比較するか？」という点を考慮しなくてはいけません。
今回はスクリプトを作成する中でどのような方法で、設定前後のクエリの実行効率の変化を確認していったかをまとめてみたいと思います。
ちなみにスクリプトは PowerShell 7.0 RC2 で作成しています。
(ForEach-Object -Parallel を使用したかったため、PowerShell 7.0 を使用しています)

■実行統計の取得

最初に、処理の実行が完了するのにどの程度の時間がかかったかの「実行統計」を取得する方法を考えました。
SSMS からクエリを実行して、処理効率を比較する際には、次の SET 文を使用することが多いのではないでしょうか。

SET STATISTICS IO, TIME ON
SELECT * FROM sys.objects

これらの SET 文でオプションを有効にすると、テーブルに対しての I/O や CPU の使用時間等の情報をメッセージとして出力することができるようになります。
image
SSMS から実行した際には、メッセージに出力されるので、すぐに情報を取得することができます。

アプリケーションから、これらのメッセージを取得したい場合は、「FireInfoMessageEventOnUserErrors」を True にして、InfoMessage イベントの使用 のように、イベントハンドラーを追加することで出力されているメッセージをアプリケーションからも取得することができます。
今回はシンプルなクエリでの確認であり、このメッセージをパースするのも少し面倒だったので、SET 文のメッセージは使用しない方向で。

(このメッセージを確認するなら SSMS で実行すればよいかと思ったということもあります)
今回は ADO.NET 経由で、DB にアクセスしているので、SQL Server のプロバイダー統計情報 を使用することもできます。

$con = New-Object System.Data.SqlClient.SqlConnection($conStr)
$con.Open()
$cmd = $con.CreateCommand()
$cmd.CommandText = "SELECT COUNT(*) FROM sys.objects"
$con.StatisticsEnabled = $true
$cmd.ExecuteNonQuery()
$con.RetrieveStatistics()
$con.Close()
$con.Dispose()

image
実行時間やネットワークの受信状況の情報はこれで取得することができます。

しかし、CPU や IO といった項目は取得することができませんので、これだけではクエリの実行統計としては不足しているので、今回はこれも見送りで。
最終的に採用した方法が、次の 2 つの情報を組み合わせるというものでした。

実行時間については Stopwatch で取得してもよかったのですが、クエリ実行時の 1 行だけ、実行時間が取得できるようになっていればよかったので、Measure-Command で取得しておきました。

$batchResult = Measure-Command { $cmd.ExecuteNonQuery() }

これでクエリ実行時の実行時間が取得できましたので、次にクエリの実行統計を取得するようにします。
クエリの実行統計については sysdm_exec_sessions から取得をしています。
SQL Server では、この DMV を使用することで「該当のセッションの CPU 使用状況や、I/O の情報」を取得することができます。
計測対象のクエリの実行完了後、コネクションを解放する前に、同一の接続で次のクエリを実行して実行結果を取得するようにしておきます。

SELECT cpu_time, memory_usage, reads, writes, logical_reads, row_count, total_elapsed_time, total_scheduled_time
FROM sys.dm_exec_sessions
WHERE session_id = @@SPID

 
この情報を加工して、次のような結果が取得できるように PowerShell のスクリプトを作成しています。
image
実際のクエリ実行は、PowerShell 7.0 の Foreach-Object -Parallel で次のような実行方法にして、並列度が調整できるようにしています。

1..$thread | ForEach-Object  -ThrottleLimit $thread -Parallel {
    $thread_number = $_
    1..$using:loop | ForEach-Object {
        $loop_number = $_
～クエリ実行～
    }
}

 

■実行するクエリがアクセスするデータ (ワークロードの決定)

どのような情報により、クエリの実行結果を取得するかということは実装できましたので、次は「実行されたクエリがどのようなデータアクセスを発生させるか」を決める必要があります。
シンプルな DML で実行するとしても

  • SELECT
  • INSERT
  • UPDATE
  • DELETE

が必要となりますし、一部のワークロードでは一括挿入 (Bulk Insert) も計測を行う必要があるかもしれません。
アクセスされるデータ量についても意識しておく必要があります。

「少量データアクセス」と「大量データアクセス」では、データアクセス時の負荷も異なりますし、設定によっては大量データへのアクセスの場合に顕著に影響が出てくる可能性が考えられます。
今回のベンチマークスクリプトでは次のアクセスパターンが複数スレッドで試せるようにしてみました。

(スレッド数は、スクリプトを実行する環境の CPU やネットワーク性能を考慮して調整する必要があります。大量のデータを取得するようなワークロードですと、複数スレッドでクエリを実行すると 1Gbps の NW は簡単に上限に達してしまうことがありますので、ネットワークの使用状況も気を付けておく必要があります)

  • SELECT
    • 少量データの SELECT (1 スレッド辺り、行程度のアクセス)
    • 大量データの SELECT (1 スレッド辺り、数千行程度のアクセス)
  • INSERT
    • 1 行ずつの単純 INSERT
  • UPDATE
    • 少量データの UPDATE (1 スレッド辺り、行程度のアクセス)
    • 大量データの UPDATE (1 スレッド辺り、数千行程度のアクセス)
  • DELETE
    • 少量データの DELETE (1 スレッド辺り、行程度のアクセス)
    • 大量データの DELETE (1 スレッド辺り、数千行程度のアクセス)
  • Bulk Insert
    • 1 万件の一括 INSERT

実ワークロードでは、それぞれをミックスしてワークロードを生成させることや、実データに対してこれらのワークロードを発生させる必要がありますが、今回はテスト用なので単純なデータ構造 (複数のループカウンターをもつテーブル構造で各スレッドが異なるループカウンターのデータにアクセスする) で試しており、データ構造はとてもシンプルです。
image
UPDATE については当たり前のことかもしれませんが「更新後のデータは現在のデータから変更され値ている必要がある」ということは必ず意識しておきます。

データの更新状況にもよりますが、SQL Server のトランザクションログには「変更前後のデータが書き込まれる」ため、データに変更がない場合は、トランザクションログのデータの書き込み量が減ってしまい、実際に欲しい情報とならない可能性がありますので。
 

■テスト実施前のデータ/クエリの状態

テストを実施する際には「データがどのような状態になっているか？」も意識しておく必要があります。

最低限、次の 2 つの事象はどのような状態が正しいかはきめておきます。

  • クエリのコンパイルの発生有無
  • データがメモリ上に保持されているか

クエリは初回実行時にはコンパイルが発生しますので、「テスト実行時にクエリのコンパイルが発生してもよいか？」は、CPU 負荷やクエリ実行時間に影響を与える一因となりますので、どのように考えればよいかは検討しておきます。
もう一つ大事な要素が「データはメモリ上にキャッシュされているか？」についてです。

ディスク I/O を含めて挙動を確認するのであれば、データキャッシュをクリアする必要がありますし、普段からデータキャッシュのヒット率が高いのであれば、最初にメモリ上にデータをキャッシュさせておく必要があります。

(分析計のワークロードをテストする場合に、データキャッシュをクリアした状態からテストを開始すると、「普段では発生することにないディスクアクセスの状態でテストが行われた」という可能性もありますので)
クエリのコンパイルやデータキャッシュのヒット率が高い状態でテストを実行するのであれば、同一のテストを 2 回実行することで実現できることもあるかと。
今回は、シンプルなクエリのためコンパイル負荷は低く、ディスクアクセスがポイントとなるワークロードが存在しているため、次の DBCC コマンドを実行しています。

DBCC DROPCLEANBUFFERS;
DBCC FREEPROCCACHE

 
SQL Server であれば、これらの DBCC コマンドを使用できますが、SQL Database では使用できないため、

  • データキャッシュをクリアするための DBCC DROPCLEANBUFFERS の代替として、サービスレベルを変更し、新規環境が利用されることでデータキャッシュをクリアする
  • プランキャッシュをクリアするための DBCC FREEPROCCACHE の代替として、ALTER DATABASE SCOPED CONFIGURATION の CLEAR PROCEDURE_CACHE を実行する

というような手法をとる必要があります。
環境によって「どのようにキャッシュをクリアすることができるか (または、クエリ可能なキャッシュとしてどのようなものがあるか)」を把握しておくことは、一貫性のある結果を求めるためには重要です。
 

■クエリ実行結果の比較と分析

それでは実際にクエリの実行結果を比較していきましょう。

今回、いくつかの設定変更で影響を試しているのですが、その中でも SQL Server 2019 で実装された、「高速データベース復旧 (Accelerated Database Recovery : ADR)」の有効化が、あまり設計を考えずに有効化してしまうとどのように性能に影響を与えるかを結果から分析してみたいと思います。
※ワークロードやデータの構造によって実行結果は大きく変わります。本結果はあくまでも「一例」であり、すべてのワークロードで同様の結果となることを保証したものではありません。
ADR は回復を高速化させるための機能ですので「何らかのデータ変更が行われた際の性能影響が考えられる」ものとなります。
まずは、「少量データの UPDATE」により、性能への影響を確認してみます。
上 : ADR 無効 (デフォルト) / 下 : ADR 有効 (設定変更後) の実行結果となります。
image

「rows」がどちらも「1,000」となっているため、同一行数が変更されていることが確認できますね。

CPU 使用時間や I/O については、多少 ADR が有効の場合の方が高くなっていますが、複数回の UPDATE の実行結果として数 10ms 程度の差ですので、この程度したら OLTP におけるワークロードでは誤差の範囲ととられることもできるかと思います。
各結果に大きな差はありませんので、この情報から、ADR による少量のデータ更新については、処理性能に影響を与えることは少ないのではという検討ができます。
それでは大量のデータ更新をしてみるとどうでしょうか？
実行結果がこちらになります。

複数スレッドをループさせながらクエリを実行させることにより、200 万件のデータが更新されています。

1 クエリ当たりで同時に更新されるデータ数もかなり大き目になるようにデータを調整していますので、同時更新データも先ほどとは全く異なる傾向になるようにしています。
image
少量データ更新と異なり、今回のワークロードでは設定の有効 / 無効によって大きく差が出ていることが確認できますね。
CPU の使用時間や、データ書き込み (writes) は顕著に差が出ている項目と言えるのではないでしょうか。
 

■結果に差が出た理由を考える

ベンチマークスクリプトから、設定変更をすることで、CPU 使用時間や書き込みに差が出ていたことがわかりました。

それでは「どのような事象によって、リソースの使用時間に差が出たのか？」を見ることができるかを考えてみましょう。
私は仕事の中で、「SQL Server の現状診断」をすることがあるのですが、その時に心がけていることが「複数の情報を活用して事象に対しての説明をすることができるか？」というものがあります。

今回のベンチマークするクリプトの実行結果の確認も同様で「リソース使用状況や処理時間に差が出たことの説明を他の情報を使用しても行うことができるか？」を考えます。
今回はいくつかのパターンで情報を取得してみたいと思います。
クエリの実行中の情報取得
SQL Server ではクエリ実行中の情報を取得するための方法がいくつかあります。

今回は、sys.dm_os_waiting_tasks を使用してみます。
この DMV は実行中のクエリの待機情報を取得することができます。

今回のベンチマークスクリプトでは接続文字列の「Application Name」に「MSSQLBenchmark」を指定していますので次のようなクエリで、この DMV の情報を取得することができます。

SELECT * FROM sys.dm_os_waiting_tasks
WHERE session_id in(
	SELECT session_id FROM sys.dm_exec_sessions
	WHERE program_name = 'MSSQLBenchmark'
)

 
ベンチマークスクリプトの実行中に次のような待機事象を取得できることができました。

(この DMV は待ち事象が発生しているタイミングで情報が取得できるものですので、情報の取得タイミングには気を付ける必要があります)
image
今回のワークロードでは「PVS_ADD_RECORD」というラッチの待機事象が発生しているタイミングが存在していることが確認できました。
今回、設定の検証対象としている高速データベース復旧 (ADR) は、高速にデータベースの復旧を完了させるため、データの更新時には「Persistent Version Store : PVS」という領域に変更時のデータを書き込みます。

この変更時のデータを書き込む処理のオーバーヘッドにより、設定を有効化した際に各種ハードウェアリソースの増加につながったと考えられます。
今回はラッチによる待機事象なので、詳細な情報を確認することはできないのですが、sys.dm_exec_session_wait_stats を活用することも考えられます。
この DMV はセッション単位の待ち事象を確認することができるものです。

今回はコネクションを解放する前に、sys.dm_exec_sessions から、自セッションのリソース使用状況を取得するようにしていますが、この際に sys.dm_exec_session_wait_stats の情報も取得するようにしておくことで、「セッション単位の待ち事象」を取得することもできます。

この情報から「どの待機事象が増加したか？」を比較することで処理時間が増加した要因を調査することもできます。
今回は sys.dm_os_waiting_tasks だけで、リソース消費の原因が分かったので、ベンチマークスクリプトには実装しませんでしたが、この情報も分析をするにあたって重要な情報となります。
実行プランの取得
今回は使用しなかったのですが、最新の SQL Server / SQL Database では「実行中のクエリの情報」の取得容易性が向上しています。

SQL Serer は 2016 SP1 以降で実装されているのですが、明示的に設定を変更する必要があったのですが、SQL Server 2019 / SQL Database ではこの機能はデフォルトで有効化されています。
この手法は クエリ プロファイリング インフラストラクチャ として公開されているものとなります。
シンプルな例としては次のようなクエリで情報を取得できます。

SELECT * FROM sys.dm_exec_query_profiles AS qp
OUTER APPLY sys.dm_exec_query_statistics_xml(qp.session_id)
WHERE qp.session_id in (
	SELECT session_id FROM sys.dm_exec_sessions
	WHERE program_name = 'MSSQLBenchmark'
)

 
実行中のクエリの情報では次のような情報を取得することができます。

  • 実行中のクエリの実行プラン
  • 現在の処理状況

これらを分析することで、結果の差の理由を追うということもできます。
 
今回は

  • 実行統計の取得
  • 実行するクエリがアクセスするデータ (ワークロードの決定)
  • テスト実施前のデータ/クエリの状態
  • クエリ実行結果の比較と分析
  • 結果に差が出た理由を考える

というステップで、クエリのベンチマークを実施してみました。
これ以外の情報を比較したり、様々な思考を巡らせて効果を測定することも、もちろんありますが、「何をもって効果を測定するか」ということを検討する際の一例としては、本投稿のような内容もあるのではないでしょうか。

Share

Written by Masayuki.Ozawa

2月 9th, 2020 at 4:57 pm

Posted in SQL Server

Tagged with ,

«
»

Leave a Reply