SQL Server でスレッドが CPU を解放せずに占有し続けた状態となる Non-yielding Scheduler となった場合、SQL Server のプロセスのダンプが出力されます。
出力されたダンプについては、Non-yielding IOCP Listener, Non-yielding Scheduler and non-yielding resource monitor known issues and fixes で解説されている内容を基に解析を行うことになりますが、SQL Server 2022 では解析のための情報が追加されているようです。
SQL Server から出力されるダンプファイルについては、次のような情報で解説が行われています。
SQL Server 2019 以降、動作の変更が行われており、SQL Serverへの影響を軽減するための製品の改善 によると次のような動作になっているようです。
同じ問題に対する繰り返しダンプを排除します。 同じ問題に対して繰り返しメモリ ダンプが削除されます。 スタックシグネチャを使用すると、SQL エンジンは例外が既に発生したかどうかを追跡し、既に例外が存在する場合は新しいメモリ ダンプを生成しません。 これは、アクセス違反、スタック オーバーフロー、アサート、およびインデックス破損の例外に適用されます。 これにより、メモリ ダンプで使用されるディスク領域の量が大幅に削減され、ダンプを生成するためにプロセスが一時的に凍結されることはありません。 これは 2019 年SQL Serverに追加されました。
ダンプの出力には情報量に応じて時間がかかり、ダンプの出力自体が同時実行性の低下の原因となる可能性があります。
同一の問題が連続して発生している場合、問題の発生毎にダンプが出力されると、情報の出力による影響が大きくなるため、繰り返しのダンプの出力を排除される動作が、2019 から含まれたようです。
私が検証していた範囲では、Non-yielding Scheduler の発生も同様の動作となっているように見え、複数回、Non-yielding Scheduler が発生しても、ダンプが出力されるのは、SQL Server のサービスが最後に起動してからの初回発生時のみとなっているようで 2 回目以降はサービスが再起動されるまで、ダンプが出力されませんでした。
Non-yielding Scheduler が発生したスタックの情報については、ダンプ内出力されることもあるのですが、初回しかダンプが出力されないと、最初に発生したタイミングの情報しか確認ができず、直近で発生した Non-Yielding Scheduler がどのようなコールスタックなのかを解析することができません。
Non-yielding Scheduler が発生しているかどうかは「ERRORLOG ファイル」「non_yielding_scheduler_callback_executed 拡張イベント」で確認することができ、拡張イベントで確認した場合にはコールスタックも確認することができます。
ただし、拡張イベントで確認できるコールスタックは次のようになっています。
sqldk!XeSosPkg::non_yielding_scheduler_callback_executed::Publish sqldk!SOS_Scheduler::ExecuteNonYieldSchedulerCallbacks sqldk!SchedulerMonitor::CheckScheduler sqldk!SchedulerMonitor::CheckSchedulers sqldk!SchedulerMonitor::Run sqldk!SchedulerMonitor::EntryPoint sqldk!SOS_Task::Param::Execute sqldk!SOS_Scheduler::RunTask sqldk!SOS_Scheduler::ProcessTasks
Non-yielding Scheduler が発生したスレッドの情報ではなく、「監視をしているスレッドとなる、スケジューラーモニターが Non-yielding Scheduler を検知した」という情報しか確認をすることができません。
どのようなスレッドが CPU を解放していなかったのかについては、従来までは出力されたダンプから確認をするのが一般的な方法だったと思うのですが、SQL Server 2022 では ERRORLOG に、g_copiedStackInfo の情報が出力されるようになったようです。
これにより、Non-yielding Scheduler が発生したスレッドの、コールスタックの情報を ERRORLOG から確認することができるようになりました。こちらの情報については発生毎に出力されているようで、2 回目以降の発生についても情報が出力されています。
実際に出力を行った、ERRORLOG の内容が以下になるのですが、SQL Server 2022 では「Copied stack」という情報が新しく出力されるようになり、この情報は Non-yielding Scheduler が発生するごとに出力がされるようです。
この情報は、g_copiedStackInfo のコンテキスト情報となっているようで、出力されている address の情報を解析することで、コールスタックを確認することができます。
実際の上記の出力を使用してコールスタックを解決すると次のような情報を確認することができます。
sqlmin!GetNonLobColumnDataByRef sqlmin!BTreeRow::SaveCurrentPosition sqlmin!IndexRowScanner::MoveKeyOrderToRowOnNextPage sqlmin!IndexRowScanner::MoveToRowOnNextPage sqlmin!IndexDataSetSession::GetBatchInternal sqlmin!DatasetSession::GetBatch sqlmin!RowsetNewSS::GetBatch sqlmin!CBpQScanRowStoreScan::BpFetchNextBatch sqlmin!CBpQScan::GetNextBatch sqlmin!CBpQScanProject::BpGetNextBatch sqlmin!CBpQScan::GetNextBatch sqlmin!CBpChildIteratorScanner::BpGetNextBatch sqlmin!CBpQScanHashAggNew::ProcessInput sqlmin!CBpQScanHashAggNew::PbsGetForOriginalInputs sqlmin!CBpSpillProcessor::Main sqlmin!CBpQScanHashAggNew::BpGetNextBatch sqlmin!CBpQScan::GetNextBatch sqlmin!CBpQScanProject::BpGetNextBatch sqlmin!CBpQScan::GetNextBatch sqlmin!CBpQScanSort::Accumulate sqlmin!CBpQScanSort::BpOpen sqlmin!CQScanBatchHelper::Open sqlmin!CQScanNew::OpenHelper sqlmin!CQScanXProducerNew::Open sqlmin!FnProducerOpen sqlmin!FnProducerThread sqlmin!SubprocEntrypoint sqldk!SOS_Task::Param::Execute sqldk!SOS_Scheduler::RunTask sqldk!SOS_Scheduler::ProcessTasks sqldk!Worker::EntryPoint sqldk!ThreadScheduler::RunWorker
上記は、検証のため長時間スレッドの切り替えを停止したため、わかりやすい情報が出力されています。
しかし、Non-yielding Scheduler が実際に発生していたタイミングの情報が取得できているかどうか (NtWaitForSingleObject またはそれに類似する処理以外の情報となっているか) については、瞬間的なものであるためタイミング次第ですが、トラブルシューティングをする際に参考となる情報の自動的な取得が行われるようになったのは嬉しいですね。