アプリから動かすと遅いが SSMS から動かすと速いのは ARITHABORT の違いという情報の動作を理解する

アプリケーションから実行すると遅いクエリを SSMS から実行した場合、SSMS はデフォルトの SET オプションが ARITHABORT ON になっており、この差によって実行時間に差が出ているという情報を見たことがあるのではないでしょうか。
参考の情報として Slow in the Application, Fast in SSMS? が紹介されることもあるかと。

このドキュメントの中では、次のように記載されています。

There are a few more possibilities that we will look into in the next chapter, but by far the most common reason for slow in the application, fast in SSMS is parameter sniffing and the different defaults for ARITHABORT. (If that was all you wanted to know, you can stop reading. If you want to fix your performance problem – hang on! And, no, putting SET ARITHABORT ON in the procedure is not the solution.)

SET ARITHABORTをONにすることは解決策ではないと記載されているように、この部分が重要となります。

SET オプションの現在の内容

現在の SET オプションについては、いくつかの方法で取得することができます。
一つ目の方法が @@OPTIONS を使用するものです

SELECT 
    CASE WHEN (@@OPTIONS & 16384) >0    THEN '1' ELSE '0' END +
    CASE WHEN (@@OPTIONS & 8192) > 0    THEN '1' ELSE '0' END +
    CASE WHEN (@@OPTIONS & 4096) > 0    THEN '1' ELSE '0' END +
    CASE WHEN (@@OPTIONS & 2048) > 0    THEN '1' ELSE '0' END +
    CASE WHEN (@@OPTIONS & 1024) > 0    THEN '1' ELSE '0' END +
    CASE WHEN (@@OPTIONS & 512) > 0     THEN '1' ELSE '0' END +
    CASE WHEN (@@OPTIONS & 256) > 0     THEN '1' ELSE '0' END +
    CASE WHEN (@@OPTIONS & 128) > 0     THEN '1' ELSE '0' END +
    CASE WHEN (@@OPTIONS & 64) > 0      THEN '1' ELSE '0' END +
    CASE WHEN (@@OPTIONS & 32) > 0      THEN '1' ELSE '0' END +
    CASE WHEN (@@OPTIONS & 16) > 0      THEN '1' ELSE '0' END +
    CASE WHEN (@@OPTIONS & 8) > 0       THEN '1' ELSE '0' END +
    CASE WHEN (@@OPTIONS & 4) > 0       THEN '1' ELSE '0' END +
    CASE WHEN (@@OPTIONS & 2) > 0       THEN '1' ELSE '0' END +
    CASE WHEN (@@OPTIONS & 1) > 0       THEN '1' ELSE '0' END
    AS set_option,
    CASE WHEN (@@OPTIONS & 16384) >0    THEN 'XACT_ABORT;' ELSE '' END +
    CASE WHEN (@@OPTIONS & 8192) > 0    THEN 'NUMERIC_ROUNDABORT;' ELSE '' END +
    CASE WHEN (@@OPTIONS & 4096) > 0    THEN 'CONCAT_NULL_YIELDS_NULL;' ELSE '' END +
    CASE WHEN (@@OPTIONS & 2048) > 0    THEN 'ANSI_NULL_DFLT_OFF;' ELSE '' END +
    CASE WHEN (@@OPTIONS & 1024) > 0    THEN 'ANSI_NULL_DFLT_ON;' ELSE '' END +
    CASE WHEN (@@OPTIONS & 512) > 0     THEN 'NOCOUNT;' ELSE '' END +
    CASE WHEN (@@OPTIONS & 256) > 0     THEN 'QUOTED_IDENTIFIER;' ELSE '' END +
    CASE WHEN (@@OPTIONS & 128) > 0     THEN 'ARITHIGNORE;' ELSE '' END +
    CASE WHEN (@@OPTIONS & 64) > 0      THEN 'ARITHABORT;' ELSE '' END +
    CASE WHEN (@@OPTIONS & 32) > 0      THEN 'ANSI_NULLS;' ELSE '' END +
    CASE WHEN (@@OPTIONS & 16) > 0      THEN 'ANSI_PADDING;' ELSE '' END +
    CASE WHEN (@@OPTIONS & 8) > 0       THEN 'ANSI_WARNINGS;' ELSE '' END +
    CASE WHEN (@@OPTIONS & 4) > 0       THEN 'CURSOR_CLOSE_ON_COMMIT;' ELSE '' END +
    CASE WHEN (@@OPTIONS & 2) > 0       THEN 'IMPLICIT_TRANSACTIONS;' ELSE '' END +
    CASE WHEN (@@OPTIONS & 1) > 0       THEN 'DISABLE_DEF_CNST_CHK;' ELSE '' END
    AS set_option_desc

現在のセッションの SET オプションの内容を出力するものとなり、SSMS の設定がデフォルトの状態から実行すると、次のような値が設定されていることが確認できます。
ARITHABORT が有効になっていますね。

CONCAT_NULL_YIELDS_NULL;ANSI_NULL_DFLT_ON;QUOTED_IDENTIFIER;ARITHABORT;ANSI_NULLS;ANSI_PADDING;ANSI_WARNINGS;

今回、アプリケーションとしては、Microsoft.Data.SqlClient を使用しており、この場合は次のようなオプションとなり、ARITHABORT が有効でないことが確認できますね。

CONCAT_NULL_YIELDS_NULL;ANSI_NULL_DFLT_ON;QUOTED_IDENTIFIER;ANSI_NULLS;ANSI_PADDING;ANSI_WARNINGS;

もう一つの方法としてはsys.dm_exec_sessionsを使用するものです。
次のようなクエリを実行すると、DMV 経由でセッションのオプションの状態を確認することができます。

select 
    session_id, client_interface_name, quoted_identifier, arithabort, ansi_null_dflt_on, ansi_defaults, ansi_warnings, ansi_padding, ansi_nulls 
from 
    sys.dm_exec_sessions 
where 
    session_id = @@SPID

次の画像は実際の取得結果です。
一つ目が SSMS / 二つ目の画像が LINQPad で実行したものですが、ARITHABORT の状態に差があることが確認できますね。

このように、クエリの実行方法によっては SET オプションの内容に差が発生します。

SET オプションの差がどのようにクエリ実行に影響を与えるか

SQL Server のクエリのキャッシュについて SET オプションの状態も考慮されます。
そのため、異なるオプションが設定されているセッションで実行されたクエリは、異なるクエリとしてキャッシュされます。

次のようなクエリを SSMS とアプリから実行したとします。

EXEC sp_executesql N'SELECT COUNT(*) FROM LINEITEM WHERE L_SHIPDATE >= @shipdate', N'@shipdate date', @shipdate = '1998/12/01'

このクエリを実行した場合に、どのようにキャッシュが行われるかというと、次のようにキャッシュされます。

select 
    t.text, 
    cp.objtype,
    qs.execution_count ,
    p.query_plan,
    qs.sql_handle,
    qs.plan_handle
from 
    sys.dm_exec_query_stats AS qs
    outer apply sys.dm_exec_sql_text(sql_handle) AS t
    outer apply sys.dm_exec_query_plan(plan_handle) as p
    left join sys.dm_exec_cached_plans AS cp
        ON cp.plan_handle = qs.plan_handle
where 
    t.text LIKE'%LINEITEM%'
option (recompile)

アプリから実行した際も Prepared ステートメントとして実行していますので、アプリ / SSMS のどちらも objtype=Prepared としてキャッシュされています。
sql_handle も同様ですので、同じテキストが使用されていることが確認できますが、plan_handle については一部異なっていることが確認できますね。

実際のクエリプランを確認してみます。
クエリプランの中には、次のように SET オプションの状態も記録されています。

そのため、同一のクエリを実行していても SET オプションが異なれば違う実行プランとしてキャッシュされます。

SSMS で次のように実行すると、アプリケーションから実行されているクエリとオプションが同じになります。

SET ARITHABORT OFF
GO
EXEC sp_executesql N'SELECT COUNT(*) FROM LINEITEM WHERE L_SHIPDATE >= @shipdate', N'@shipdate date', @shipdate = '1998/12/01'

先ほどと異なり、execution_count が 2 となっており、同一の実行プランがキャッシュされていることが確認できますね。

「異なるプランとしてキャッシュされている = コンパイルが発生し、新しい実行プランが作成されている」ということになります。

そのため、アプリケーションから実行が遅く、SSMS で実行が早いという場合の調査については「同一の実行プランで実行されているか」を意識することが重要となります。

どのような情報に着目すればよいか

実際に、アプリケーションからの実行は遅いが、SSMS から実行した場合は速いという状況を作ってみます。
今回、アプリケーションからは次のように実行しています。

検索時のパラメーターとしては「1992/02/28」を指定しており、実行に 18 秒かかっています。
このような状況となったとき、SSMS では、次のようなクエリを実行して確認を行うのではないでしょうか。

EXEC sp_executesql N'SELECT COUNT(*) FROM LINEITEM WHERE L_SHIPDATE >= @shipdate', N'@shipdate date', @shipdate = '1992/02/28'

SSMS から実行した場合は、7 秒で終わっていますので、アプリケーションから実行している場合と比較して倍以上速くなっています。

このような状態となった場合ですが次のような方法が考えられます。

1. 同一の SET オプションで実行する

異なる SET オプションで実行すると新しい実行プランが生成されますので、問題が発生しているアプリケーションと同様のオプションを設定して、SSMS から動作を確認します。(この際、アプリケーションからは、Prepared を使用しているのであれば、SSMS からの実行方法も同様のものに合わせます)

SET ARITHABORT OFF
GO
EXEC sp_executesql N'SELECT COUNT(*) FROM LINEITEM WHERE L_SHIPDATE >= @shipdate', N'@shipdate date', @shipdate = '1998/12/01'

調査を行う時点で、アプリケーションから実行されているクエリが遅いのであれば、キャッシュされている同一のプランを SSMS から使用すれば SSMS からの実行も遅いです。

調査を実施している時点でもアプリケーションからの実行が遅くて、SSMS からの実行が早い場合は、「キャッシュされている同一の実行プランが使用されているか？」を意識することが重要です。

2. クエリのキャッシュを調査する

同一の実行プランが使用されているかを、キャッシュから調べる際の起点となる情報の取得にはいくつかの方法があります。
今回は SSMS から実際の実行プランを取得して調査を行いたいと思います。

SSMS から実際の実行プランを取得すると「StatementSqlHandle」を確認することができます。

この値を使用して、次のようなクエリを実行します。

select 
    t.text, 
    cp.objtype,
    qs.execution_count ,
    p.query_plan,
    qs.sql_handle,
    qs.plan_handle
from 
    sys.dm_exec_query_stats AS qs
    outer apply sys.dm_exec_sql_text(sql_handle) AS t
    outer apply sys.dm_exec_query_plan(plan_handle) as p
    left join sys.dm_exec_cached_plans AS cp
        ON cp.plan_handle = qs.plan_handle
where 
   qs.statement_sql_handle = 0x0900F3C9DF803578A8EF4350055F1BFA7D3E0000000000000000000000000000000000000000000000000000
option (recompile)

実行すると次のような情報が取得できますので、「SSMS から実行しているクエリが、アプリケーションから実行されているクエリと同一の実行プランが使用されているか？」を確認します。
(今回は、StatementSqlHandle で検索していますが、query_hash / query_plan_hash 等を使用する方法もあります)

アプリケーションと同一のプランが使用されているかの確認の方法はいくつかあると思いますが、単純なものですと SSMS から何回かクエリを実行して、「想定している実行プランの execution_count が増加しているか」で確認することもできるかと。

キャッシュされている実行プランの中には、SET オプションの状態だけでなく、どのような (どのタイミングで更新された) 統計情報が使用されてコンパイルが行われたか？

コンパイルされたタイミングでは、どのようなパラメーターが指定されたのか？

という情報が保持されています。

SET オプションの状態のほかに、このような情報も活用することで、問題が発生しているクエリの実行プランとの違い (使用された統計情報が異なる / コンパイル時に指定されたパラメーターが異なる) を把握することは、クエリの調査で重要ではないでしょうか。

「SSMS では、アプリケーションから実行した場合と ARITHABORT のデフォルト値が異なるため、SSMS で実行すると速度に差が出る」ではなく、「SSMS ではアプリケーションと SET オプションの値が異なるため、アプリケーションで実行されたものとは異なる実行プランが生成され、利用されたために速度に差がある」(ARITHABORT の設定が本質ではない) ということを意識しておくことは重要ではないでしょうか。