Non-yielding scheduler エラーの調査を実施する際の参考情報 の続きの投稿となるのですが、SQL Server で Non-yielding scheduler となる状態を作り出すため、スレッドと強制的に中断状態にして
- リングバッファーに RING_BUFFER_NONYIELD_COPIEDSTACK を出力
- 拡張イベントに scheduler_monitor_non_yielding_ring_buffer_recorded を出力
させるための方法のメモです。
本来は、スケジューラーモニターで次の状態を検知させ、ダンプを出力させるところまで再現したかったのですが、私の理解度が低く、そこまでは再現できていません。
# Child-SP RetAddr Call Site 00 00000006`b2ddbc28 00007ffd`db9185c3 ntdll!NtWaitForSingleObject+0x14 01 00000006`b2ddbc30 00007ff6`cb98bb2e KERNELBASE!WaitForSingleObjectEx+0x93 02 00000006`b2ddbcd0 00007ff6`cb98b8a3 sqlservr!CDmpDump::InvokeSqlDumper+0x1ee 03 00000006`b2ddbdd0 00007ff6`cb98b5a4 sqlservr!CDmpDump::DumpInternal+0x1b3 04 00000006`b2ddbe80 00007ffd`c356e743 sqlservr!CDmpDump::Dump+0x24 05 00000006`b2ddbec0 00007ffd`c420d1b5 sqllang!SQLDumperLibraryInvoke+0x1f3 06 00000006`b2ddbf00 00007ffd`c420e046 sqllang!SQLLangDumperLibraryInvoke+0x185 07 00000006`b2ddbfc0 00007ffd`c41d8c42 sqllang!CImageHelper::DoMiniDump+0x6f6 08 00000006`b2ddc1e0 00007ff6`cb963eb5 sqllang!stackTrace+0xa42 09 00000006`b2dddc00 00007ffd`c5956840 sqlservr!SQL_SOSNonYieldSchedulerCallback+0x465 0a 00000006`b2dfdea0 00007ffd`c592e59b sqldk!SOS_OS::ExecuteNonYieldSchedulerCallbacks+0xe0 0b 00000006`b2dfe150 00007ffd`c58c54ef sqldk!SOS_Scheduler::ExecuteNonYieldSchedulerCallbacks+0x1ab 0c 00000006`b2dfe330 00007ffd`c58c47b2 sqldk!SchedulerMonitor::CheckScheduler+0x25e 0d 00000006`b2dfe4d0 00007ffd`c58c3d72 sqldk!SchedulerMonitor::CheckSchedulers+0x1ea 0e 00000006`b2dfee40 00007ffd`c59c47c9 sqldk!SchedulerMonitor::Run+0xc2 0f 00000006`b2dfef40 00007ffd`c58b9e53 sqldk!SchedulerMonitor::EntryPoint+0x9 10 00000006`b2dfef70 00007ffd`c58ba28f sqldk!SOS_Task::Param::Execute+0x232 11 00000006`b2dff570 00007ffd`c58ba05e sqldk!SOS_Scheduler::RunTask+0xbf 12 00000006`b2dff5e0 00007ffd`c58d79a2 sqldk!SOS_Scheduler::ProcessTasks+0x39d 13 00000006`b2dff700 00007ffd`c58d7b9f sqldk!SchedulerManager::WorkerEntryPoint+0x2a1 14 00000006`b2dff7d0 00007ffd`c58d83fa sqldk!SystemThreadDispatcher::ProcessWorker+0x42a 15 00000006`b2dffad0 00007ffd`df0c7974 sqldk!SchedulerManager::ThreadEntryPoint+0x406 16 00000006`b2dffbc0 00007ffd`df7ea2f1 kernel32!BaseThreadInitThunk+0x14 17 00000006`b2dffbf0 00000000`00000000 ntdll!RtlUserThreadStart+0x21
リングバッファー / 拡張イベントで Non-yieding scheduler についての情報を出力する際の動作仕様については、Resource Monitor が、SQL Serverを実行しているサーバーで非生成条件を入力する から確認することができます。
ポイントとなるのが、次の記載です。
Scheduler Monitor タスクは 5 秒ごとに実行されます。 スケジュール モニターは、リソース モニターが過去 60 秒間にコンシューマー間で移動したかどうかを確認します。 スケジューラ モニターは、リソース モニターがコンシューマーを 60 秒間経過していないと検出した場合、スケジュール モニターはこのシナリオをリソース モニターが非利回り状態になると解釈します。 この解釈により、スケジュール モニターは、「現象」セクションで説明されているエラー メッセージをログに記録します。
SQL Server では Scheduler Monitor (スケジューラーモニター) というバックグランドタスクが動作しており、このタスクが 5 秒間隔で Non-yielding 状態になっているタスクの存在を確認しているということになります。
SQL Server の通常のタスクで完了しているクエリについては、次のようなコールスタックとなります。
# Child-SP RetAddr Call Site 00 00000006`bd1fecc8 00007ffd`db9185c3 ntdll!NtWaitForSingleObject+0x14 01 00000006`bd1fecd0 00007ffd`c58b1f98 KERNELBASE!WaitForSingleObjectEx+0x93 02 00000006`bd1fed70 00007ffd`c58b1d8a sqldk!SOS_Scheduler::SwitchContext+0x4c3 03 00000006`bd1ff080 00007ffd`c58b3f16 sqldk!SOS_Scheduler::SuspendNonPreemptive+0xe3 04 00000006`bd1ff0f0 00007ffd`c58ba6b8 sqldk!WaitableBase::Wait+0x16a 05 00000006`bd1ff170 00007ffd`c58ba017 sqldk!WorkDispatcher::DequeueTask+0x502 06 00000006`bd1ff290 00007ffd`c58d79a2 sqldk!SOS_Scheduler::ProcessTasks+0x233 07 00000006`bd1ff3b0 00007ffd`c58d7b9f sqldk!SchedulerManager::WorkerEntryPoint+0x2a1 08 00000006`bd1ff480 00007ffd`c58d83fa sqldk!SystemThreadDispatcher::ProcessWorker+0x42a 09 00000006`bd1ff780 00007ffd`df0c7974 sqldk!SchedulerManager::ThreadEntryPoint+0x406 0a 00000006`bd1ff870 00007ffd`df7ea2f1 KERNEL32!BaseThreadInitThunk+0x14 0b 00000006`bd1ff8a0 00000000`00000000 ntdll!RtlUserThreadStart+0x21
クエリ実行時にタスクを完了させず、スレッドを中断状態にすることで Non-yielding 状態を発生させようと思います。
自分が実行したクエリで意図的に発生させたいので、windbg で次の関数の呼び出し時にブレークポイントを設定します。
bp sqlmin!CXte::ExecCompile
コンパイル時にブレークポイントを発生するようにします。
自分が実行したクエリ以外が設定したブレークポイントにヒットする可能性もありますが、ある程度稼働した状態の環境であれば、自分が実行した以外のクエリがコンパイルされる頻度は低いので、
SELECT TOP 100 * FROM LINEITEM option(recompile)
というような明示的にリコンパイルしたクエリを実行した場合にブレークポイントにヒットする可能性が高いかと思います。
上手く実行ができると、コンパイルを発生させるクエリを実行したと同時にブレークポイントを発生させることができますので、うまくデバッガーで動作をキャッチさせることができたら、スレッドを中断状態にします。
~.n;g
中断させたスレッドについては、windbg でも確認できますが、私は windbg を使いこなせていないため、Process Explorer で中断されているスレッドを確認しています。
Process Explorer で SQL Server のプロセスの情報から、スレッドの情報を確認することで、先ほど中断したスレッドの状態を確認することができます。
停止したスレッドについても Process Explorer から再開 (Resume) することもできるため、手軽にスレッドを操作するのは便利かと思います。
これでリングバッファーと拡張イベントへの情報の出力を確認することができます。
SQL Server ではバックグラウンドタスクとして次のようなモニターが動作しています。
- sqldk!SchedulerMonitor
- sqllang!SystemHealthMonitor
- sqldk!ResourceMonitor
- sqlmin!lockMonitor
- sqlmin!DeadlockMonitor
今回は Scheduler Monitor の動作を中心に確認をしていたのですが、リングバッファーとの連携については、リソースモニターの メモリ不足の検出 の動作についても記載されており、メモリ不足の検知についても同様の確認を行うことができます。(リソースモニターについては sqldk!ResourceMonitor::WriteNotificationToRingBuffer がリングバッファーへの書き込みになっていると思います)
Non-yielding は OS へのプリエンティブタスクへの切り替えでも発生できるはずなので、メモリ割り当てやデータファイル拡張をうまく活用することでも再現できるかもしれませんが、もう少し内部動作を理解して意図的に再現テストができるようになりたいものですね。