SQL Server で終了しないように見えるクエリのトラブルシューティング

[アーティクル]
07/30/2024

この記事では、クエリが完了しないと思われる問題のトラブルシューティング手順について説明します。または、クエリを完了するには数時間または数日かかる場合があります。

終わりのないクエリとは

このドキュメントでは、実行またはコンパイルを続けるクエリ、つまり CPU の増加を続けるクエリに焦点を当てています。一部のリソースでブロックまたは待機しているクエリには適用されません (CPU は一定に保たれているか、ほとんど変更されません)。

重要

クエリの実行を完了するために残っている場合は、最終的に完了します。数秒しかかからなかったり、数日かかる場合があります。

"終了しない" という用語は、クエリが実際に完了したときに完了しないという認識を表すために使用されます。

終わりのないクエリを識別する

クエリが継続的に実行されているか、ボトルネックでスタックしているかを特定するには、次の手順に従います。

次のクエリを実行します。

DECLARE @cntr int = 0

WHILE (@cntr < 3)
BEGIN
    SELECT TOP 10 s.session_id,
                    r.status,
                    r.wait_time,
                    r.wait_type,
                    r.wait_resource,
                    r.cpu_time,
                    r.logical_reads,
                    r.reads,
                    r.writes,
                    r.total_elapsed_time / (1000 * 60) 'Elaps M',
                    SUBSTRING(st.TEXT, (r.statement_start_offset / 2) + 1,
                    ((CASE r.statement_end_offset
                        WHEN -1 THEN DATALENGTH(st.TEXT)
                        ELSE r.statement_end_offset
                    END - r.statement_start_offset) / 2) + 1) AS statement_text,
                    COALESCE(QUOTENAME(DB_NAME(st.dbid)) + N'.' + QUOTENAME(OBJECT_SCHEMA_NAME(st.objectid, st.dbid)) 
                    + N'.' + QUOTENAME(OBJECT_NAME(st.objectid, st.dbid)), '') AS command_text,
                    r.command,
                    s.login_name,
                    s.host_name,
                    s.program_name,
                    s.last_request_end_time,
                    s.login_time,
                    r.open_transaction_count,
                    atrn.name as transaction_name,
                    atrn.transaction_id,
                    atrn.transaction_state
        FROM sys.dm_exec_sessions AS s
        JOIN sys.dm_exec_requests AS r ON r.session_id = s.session_id 
                CROSS APPLY sys.Dm_exec_sql_text(r.sql_handle) AS st
        LEFT JOIN (sys.dm_tran_session_transactions AS stran 
             JOIN sys.dm_tran_active_transactions AS atrn
                ON stran.transaction_id = atrn.transaction_id)
        ON stran.session_id =s.session_id
        WHERE r.session_id != @@SPID
        ORDER BY r.cpu_time DESC

    SET @cntr = @cntr + 1
WAITFOR DELAY '00:00:05'
END

サンプル出力を確認します。
- この記事のトラブルシューティング手順は、CPU が経過時間に比例して増加している次のような出力が、大幅な待機時間なしで発生する場合に特に適用されます。一部の CPU バインド T-SQL 要求では論理読み取りがまったく行われない場合があるため(計算の実行やWHILEループなど)、この場合、logical_readsの変更は関係しないことに注意してください。
  
  session_id status cpu_time logical_reads wait_time wait_type
  
  56 実行中 7038 101000 0 NULL
  
  56 実行可能 12040 301000 0 NULL
  
  56 実行中 17020 523000 0 NULL
- この記事は、CPU がわずかに変化したり変更されたりせず、セッションがリソースで待機している次のような待機シナリオを観察する場合は適用されません。
  
  session_id status cpu_time logical_reads wait_time wait_type
  
  56 一時停止中 0 3 8312 LCK_M_U
  
  56 一時停止中 0 3 13318 LCK_M_U
  
  56 一時停止中 0 5 18331 LCK_M_U
詳細については、 Diagnose の待機またはボトルネックを参照してください。

session_id	status	cpu_time	logical_reads	wait_type
56	実行中	7038	101000	NULL
56	実行可能	12040	301000	NULL
56	実行中	17020	523000	NULL

session_id	status	logical_reads	wait_time	wait_type
56	一時停止中	3	8312	LCK_M_U
56	一時停止中	3	13318	LCK_M_U
56	一時停止中	5	18331	LCK_M_U

長いコンパイル時間

まれに、CPU が時間の経過と同時に継続的に増加しているが、クエリの実行によって決まるわけではないことがわかります。代わりに、過度に長いコンパイル (クエリの解析とコンパイル) によって駆動される可能性があります。そのような場合は、 transaction_name 出力列を確認し、 sqlsource_transformの値を探します。このトランザクション名はコンパイルを示します。

診断データの収集

SQL Server Management Studio (SSMS) を使用して診断データを収集するには、次の手順に従います。

最新のクエリ実行プラン XML をキャプチャします。
クエリプランを確認して、遅さがどこから来る可能性があるかを明らかに示しているかどうかを確認します。代表的な例は次のとおりです。
- テーブルまたはインデックスのスキャン (推定行を参照)。
- 巨大な外部テーブルデータセットによって駆動される入れ子になったループ。
- ループの内側に大きな分岐がある入れ子になったループ。
- テーブルスプール。
- 各行の処理に長い時間がかかる SELECT リスト内の関数。
クエリがいつでも高速に実行される場合は、比較する "高速" 実行 Actual XML 実行プランをキャプチャできます。

軽量クエリプロファイルインフラストラクチャは、これらのバージョンの SQL Server で導入されました。これにより、低速クエリの実行中に実際の統計をキャプチャできます。このトラブルシューティング機能を使用すると、実行時にクエリプランのクエリ演算子を調べ、ほとんどの時間がクエリに費やされている場所を把握できます。

Lightweight クエリ実行統計プロファイルインフラストラクチャ v1 を使用してクエリの低速な手順を特定するには次の手順に従います。

次のコマンドを実行して、 query_thread_profile XEvent を有効にします。

CREATE EVENT SESSION [NodePerfStats] ON SERVER
ADD EVENT sqlserver.query_thread_profile(
  ACTION(sqlos.scheduler_id,sqlserver.database_id,sqlserver.is_system,
    sqlserver.plan_handle,sqlserver.query_hash_signed,sqlserver.query_plan_hash_signed,
    sqlserver.server_instance_name,sqlserver.session_id,sqlserver.session_nt_username,
    sqlserver.sql_text))
ADD TARGET package0.ring_buffer(SET max_memory=(25600))
WITH (MAX_MEMORY=4096 KB,
  EVENT_RETENTION_MODE=ALLOW_SINGLE_EVENT_LOSS,
  MAX_DISPATCH_LATENCY=30 SECONDS,
  MAX_EVENT_SIZE=0 KB,
  MEMORY_PARTITION_MODE=NONE,
  TRACK_CAUSALITY=OFF,
  STARTUP_STATE=OFF);

ALTER EVENT SESSION [NodePerfStats] ON SERVER STATE = START

影響を受ける終わりのないクエリをアプリケーションから開始します。

次のコマンドを 1 分ほど離して複数回実行して、クエリプラン演算子の実行時実行統計を確認します。

SELECT CONVERT (varchar(30), getdate(), 126) as runtime,
            qp.session_id,
            convert(nvarchar(48), qp.physical_operator_name) as physical_operator_name,
            qp.row_count,
            qp.estimate_row_count,
            qp.node_id,
            req.cpu_time,
            req.total_elapsed_time,
            substring
            (REPLACE
            (REPLACE
                (SUBSTRING
                (SQLText.text
                , (req.statement_start_offset/2) + 1
                , (
                    (CASE statement_END_offset
                        WHEN -1
                        THEN DATALENGTH(SQLText.text)  
                        ELSE req.statement_END_offset
                        END
                        - req.statement_start_offset)/2) + 1)
            , CHAR(10), ' '), CHAR(13), ' '), 1, 512)  AS active_statement_text
FROM sys.dm_exec_query_profiles qp 
RIGHT OUTER JOIN sys.dm_exec_requests req
    ON qp.session_id = req.session_id
LEFT OUTER JOIN sys.dm_exec_sessions sess
    on req.session_id = sess.session_id
LEFT OUTER JOIN sys.dm_exec_connections conn on conn.session_id = req.session_id
OUTER APPLY sys.dm_exec_sql_text (ISNULL (req.sql_handle, conn.most_recent_sql_handle)) as SQLText
WHERE req.session_id <> @@SPID 
    AND sess.is_user_process = 1 
ORDER BY qp.session_id asc, row_count desc 
--this is to prevent massive grants
OPTION (max_grant_percent = 3, MAXDOP 1)

分析に十分なデータを得るために、1 分間隔で 3 つまたは 4 つのスナップショットをキャプチャします。具体的には、時間の経過に伴う各演算子の row_count 数を比較し、行数の大幅な増加 (100 万以上) を示す値を確認できます。
SSMS の新しいクエリウィンドウで、次のコマンドを実行して、問題のあるクエリの推定クエリプランをキャプチャします。
```
SET SHOWPLAN_XML ON
GO
<problem query here>
GO
SET SHOWPLAN_XML OFF
```
手順 3 でクエリによって識別された行数が最も多いノード ID を使用して、推定クエリプランで同じノードを見つけます。この手順は、プランのどの演算子が実行時間の長さの主な原因であるかを理解するのに役立ちます。
次のコマンドを実行して XEvent を停止します。
```
ALTER EVENT SESSION [NodePerfStats] ON SERVER STATE = STOP
```

Lightweight クエリ実行統計プロファイルインフラストラクチャ v2 を使用して、行数の実際の値を使用してライブクエリプランをキャプチャできます。このプロファイリングインフラストラクチャを使用すると、実行時にクエリプラン内のクエリ演算子を調べ、ほとんどの時間がクエリに費やされる場所を把握できます。

クエリの低速な手順を特定するには、次の手順に従います。

これらのバージョンの SQL Server で軽量インフラストラクチャを有効にするには、次のいずれかの方法を使用します。

次のコマンド実行して、trace フラグ 7412 を有効にします。
```
DBCC TRACEON (7412, -1)
```

または、次のコマンドを実行して、 query_thread_profile XEvent を有効にします。

CREATE EVENT SESSION [PerfStats_LWP_Plan_v2] ON SERVER
ADD EVENT sqlserver.query_plan_profile(
 ACTION(sqlos.scheduler_id,sqlserver.database_id,sqlserver.is_system,
   sqlserver.plan_handle,sqlserver.query_hash_signed,sqlserver.query_plan_hash_signed,
   sqlserver.server_instance_name,sqlserver.session_id,sqlserver.session_nt_username,
   sqlserver.sql_text))
ADD TARGET package0.ring_buffer(SET max_memory=(25600))
WITH (MAX_MEMORY=4096 KB,
 EVENT_RETENTION_MODE=ALLOW_SINGLE_EVENT_LOSS,
 MAX_DISPATCH_LATENCY=30 SECONDS,
 MAX_EVENT_SIZE=0 KB,
 MEMORY_PARTITION_MODE=NONE,
 TRACK_CAUSALITY=OFF,
 STARTUP_STATE=OFF);

ALTER EVENT SESSION [PerfStats_LWP_Plan_v2] ON SERVER STATE = START

影響を受ける終わりのないクエリをアプリケーションから開始します。
次のようなコマンドを使用して、実行中の終わりのないクエリの Session_id を特定します。
```
SELECT t.text, session_id 
FROM sys.dm_exec_requests req
CROSS APPLY sys.dm_exec_sql_text (req.sql_handle) as t
```
次のコマンドを 1 分間隔で 3 回または 4 回実行して、プラン内のクエリプランと実際の統計を調べます。クエリプランを毎回保存して、それらを比較し、CPU 時間の大半を消費しているクエリ演算子を確立できるようにします。具体的には、時間の経過に伴う各演算子の行数 (実際の行数) を比較し、行数の大幅な増加 (100 万以上) を示している演算子を確認できます。 <session_id>を前の手順 3 で見つけた整数値に置き換えます。
```
SELECT * FROM sys.dm_exec_query_statistics_xml (<session_id>)
```

XEvent を開始した場合は停止するか、トレースフラグを無効にします。

ALTER EVENT SESSION [PerfStats_LWP_Plan_v2] ON SERVER STATE = STOP
-- or
DBCC TRACEOFF (7412, -1)

Lightweight クエリ実行統計プロファイルインフラストラクチャ v3 を使用して、行数の実際の値を使用してライブクエリプランをキャプチャできます。このプロファイリングインフラストラクチャを使用すると、実行時にクエリプラン内のクエリ演算子を調べ、ほとんどの時間がクエリに費やされる場所を把握できます。軽量プロファイリングは、SQL Server 2019 で既定で有効になっています。

クエリの低速な手順を特定するには、次の手順に従います。

影響を受ける終わりのないクエリをアプリケーションから開始します。
次のようなコマンドを使用して、実行中の終わりのないクエリの Session_id を特定します。
```
SELECT t.text, session_id 
FROM sys.dm_exec_requests req
CROSS APPLY sys.dm_exec_sql_text (req.sql_handle) as t
```
次のコマンドを 3 回または 4 回実行して、プラン内のクエリプランと実際の統計を調べます。クエリプランを毎回保存して、それらを比較し、CPU 時間の大半を消費しているクエリ演算子を確立できるようにします。 <session_id>を前の手順 3 で見つけた整数値に置き換えます。
```
SELECT * FROM sys.dm_exec_query_statistics_xml (<session_id>)
```
具体的には、 query_plan 列の下にある XML リンクを選択します。グラフィカルクエリプランが新しいウィンドウで開いたら、それを右クリックし、[実行プランを名前を付けて保存 選択します。..。この手順を繰り返して、1 分間隔で 3 つまたは 4 つのスナップショットをキャプチャし、分析に十分なデータを提供します。具体的には、時間の経過に伴う各演算子の行数 (実際の行数) を比較し、行数の大幅な増加 (100 万以上) を示している演算子を確認できます。
Note

sys.dm_exec_query_statistics_xmlから出力が得られない場合は、次のコマンドを実行して、データベースオプションLAST_QUERY_PLAN_STATSが無効になっているかどうかを確認できます。
```
SELECT name, value, value_for_secondary, is_value_default 
FROM sys.database_scoped_configurations
WHERE name = 'LAST_QUERY_PLAN_STATS'
```
データベースレベルで最後のクエリプラン統計を有効にするには、 ALTER DATABASE SCOPED CONFIGURATION SET LAST_QUERY_PLAN_STATS = ONを実行します。

収集されたプランを確認する方法

このセクションでは、収集されたデータを確認する方法について説明します。 SQL Server 2016 SP1 以降のビルドとバージョンで収集された複数の XML クエリプラン (拡張機能 *.sqlplan を使用します。

実行プランをするには、次の手順に従います。

以前に保存したクエリ実行プランファイル (.sqlplan) を開きます。
実行プランの空白領域を右クリックし、 Compare Showplan を選択します。
比較する 2 番目のクエリプランファイルを選択します。
演算子間を流れる多数の行を示す太い矢印を探します。次に、矢印の前または後の演算子を選択し、2 つのプランの actual 行の数を比較します。
2 番目と 3 番目のプランを比較して、同じ演算子で最大の行フローが発生するかどうかを確認します。

次に例を示します。

解決方法

クエリで使用されるテーブルの統計が更新されていることを確認します。
クエリプランで不足しているインデックスの推奨事項を探し、いずれかを適用します。
クエリを簡略化する目的で書き直します。
- より選択的な WHERE 述語を使用して、事前に処理されるデータを減らします。
- 分割します。
- 一時テーブルにいくつかの部分を選択し、後で結合します。
- 行の目標を最適化するために非常に長い時間実行されるクエリの TOP、 EXISTS、および FAST (T-SQL) 削除します。または、 DISABLE_OPTIMIZER_ROWGOAL hint を使用することもできます。詳細については、「 Row Goals Gone Rogue」を参照してください。
- ステートメントを 1 つの大きなクエリに結合する場合は、共通テーブル式 (CTE) を使用しないでください。
クエリヒントを使用して、より適切なプランを作成してみてください。
- HASH JOINまたはヒントMERGE JOIN
- FORCE ORDER ヒント
- FORCESEEK ヒント
- RECOMPILE
- 強制的に実行できる高速クエリプランがある場合は、 PLAN N'<xml_plan>' を使用します
クエリストア (QDS) を使用して、適切な既知のプランが存在する場合、および SQL Server のバージョンでクエリストアがサポートされている場合に、適切な既知のプランを強制します。

待機またはボトルネックを診断する

このセクションは、問題が実行時間の長い CPU 駆動クエリでない場合のリファレンスとしてここに含まれています。これを使用して、待機が原因で長いクエリのトラブルシューティングを行うことができます。

ボトルネックを待機しているクエリを最適化するには、待機の長さとボトルネックの場所 (待機の種類) を特定します。待機の種類が確認されたら待機時間を短縮するか、完全に待機を排除します。

おおよその待機時間を計算するには、クエリの経過時間から CPU 時間 (ワーカー時間) を減算します。通常、CPU 時間は実際の実行時間であり、クエリの有効期間の残りの部分は待機しています。

おおよその待機時間を計算する方法の例:

経過時間 (ミリ秒)	CPU 時間 (ms)	待機時間 (ミリ秒)
3200	3000	200
7080	1000	6080

ボトルネックまたは待機を特定する

待機時間の長い履歴クエリ (全体の経過時間の >20% が待機時間など) を特定するには、次のクエリを実行します。このクエリでは、SQL Server の開始以降にキャッシュされたクエリプランのパフォーマンス統計が使用されます。

SELECT t.text,
         qs.total_elapsed_time / qs.execution_count
         AS avg_elapsed_time,
         qs.total_worker_time / qs.execution_count
         AS avg_cpu_time,
         (qs.total_elapsed_time - qs.total_worker_time) / qs.execution_count
         AS avg_wait_time,
         qs.total_logical_reads / qs.execution_count
         AS avg_logical_reads,
         qs.total_logical_writes / qs.execution_count
         AS avg_writes,
         qs.total_elapsed_time
         AS cumulative_elapsed_time
FROM sys.dm_exec_query_stats qs
         CROSS apply sys.Dm_exec_sql_text (sql_handle) t
WHERE (qs.total_elapsed_time - qs.total_worker_time) / qs.total_elapsed_time
         > 0.2
ORDER BY qs.total_elapsed_time / qs.execution_count DESC

待機時間が 500 ミリ秒を超える現在実行中のクエリを特定するには、次のクエリを実行します。

SELECT r.session_id, r.wait_type, r.wait_time AS wait_time_ms
FROM sys.dm_exec_requests r 
   JOIN sys.dm_exec_sessions s ON r.session_id = s.session_id 
WHERE wait_time > 500
AND is_user_process = 1

クエリプランを収集できる場合は、SSMS の実行プランのプロパティからWaitStats を確認します。
1. Include Actual Execution Plan on を使用してクエリを実行します。
2. [実行プラン]タブで、左端の演算子右クリックします。
3. Propertiesを選択しWaitStatsプロパティを選択します。
4. WaitTimeMs と WaitType を確認します。
PSSDiag/SQLdiag または SQL LogScout LightPerf/GeneralPerf シナリオに慣れている場合は、いずれかのシナリオを使用してパフォーマンス統計を収集し、SQL Server インスタンスで待機中のクエリを特定することを検討してください。収集したデータファイルをインポートし、 SQL Nexus を使用してパフォーマンスデータを分析できます。

待機の排除または削減に役立つ参照

各待機の種類の原因と解決策は異なります。すべての待機の種類を解決する一般的な方法は 1 つもありません。待機の種類に関する一般的な問題のトラブルシューティングと解決に関する記事を次に示します。

多くの待機の種類とそれらが示す内容の説明については、「待機の種類の表を参照してください。

次の方法で共有