Shoeisha Technology Media

EnterpriseZine(エンタープライズジン)

EnterpriseZine(エンタープライズジン)

テーマ別に探す

CPU使用率が高い - Again -

edited by DB Online   2014/05/19 12:00

 前回にひきつづき、またもや!CPU使用率が高いとの知らせを受けました。

案件の概要

SQL ServerプロセスのCPU使用率が高いので、何か負荷の高いクエリが実行されているのだろうと思いました。お客様は本番を数か月後に控えていましたが、自由にサーバーを触ることが出来る期間だったので、その場でクエリを書いてCPU使用率の高いクエリを特定することにしました。

怪しいクエリを特定する

select top 10 * 
from sys.dm_exec_query_stats qs
cross apply sys.dm_exec_sql_text(qs.sql_handle)
cross apply  sys.dm_exec_query_plan(qs.plan_handle)
order by last_worker_time desc
 ↑こんなクエリで確認したような気がします。


 問題のクエリはすぐに特定できました。以下のようなクエリです。これは、ワーカーの状態を監視するクエリです。定期的にスパイクすることから、お客様も私も何か監視系のクエリが悪さをしているのだろうというのは予測していました。

  select
	  top 50
	  getdate() as snap_time
	, start_quantum - wait_resumed_ms_ticks as signal_wait_ms
	, start_quantum, wait_resumed_ms_ticks
	, t.session_id
	, t.task_address
	, t.scheduler_id
	, wk.worker_address
	, wk.state
	, wk.status
	, wk.is_sick
	, wk.is_in_cc_exception
	, wk.is_fatal_exception
	, wk.is_inside_catch
	, wk.is_in_polling_io_completion_routine
	, wk.exception_num
	from sys.dm_os_workers wk
	left join sys.dm_os_waiting_tasks wt
	    on wk.task_address = wt.waiting_task_address
	left join sys.dm_os_tasks t
	    on wk.task_address = t.task_address
	where 
	        wk.is_preemptive <> 1
		and wk.task_address is not null
		and wt.waiting_task_address is null 
		and t.session_id is not null
		and start_quantum - wait_resumed_ms_ticks > @signal_wait_limit
	order by
	    signal_wait_ms desc
 ↑ 「変なクエリだな。」と思われるかもしれないですが、昔このお客様の環境で特殊な問題が起きて、それが再発した時にひょっとしたら調査のヒントになるかもしれないという情報をとっているのです。

 
 このクエリは、定常的に採取してほしい情報のひとつとして私が提供したクエリだったのですが、これまでCPU時間を消費するようなことはなかったのです。なんだか、最近になってCPU使用率が高くなってきているようなのです。

  「どうやって調査しようかな。」と問題のクエリを眺めていた時にピンときました。とあるKBのことを思い出したのです。TOP句を使用している時に、オプティマイザがうまく最適化できない場合があるというものです。詳細は割愛しますが、かなりこのKBに合致している可能性が高いなと思いました。

 KBの内容を詳しく確認したくなったので、現場での作業を終了しました。会社に戻ってから、KBの内容とソースコード確認して、「今回の問題はやっぱりこれだなぁ、なんでクエリを書いている時に気が付かなかったんだろう。」と思っていたのですが、ふと肝心なことを確認し忘れていたことに気が付きました。

  CPU使用率が高いのは、Nested Loops結合プランが選択されていたからです。これは現場で確認しました。Nested Loops結合は、その名の通りネストしたループ処理で行を見つける処理ですから、大量のデータがあるとクルクルとループしてCPU時間を消費します。つまり、本来は少ないデータを処理する場合に向いている処理なのです。

 現場でクエリを見ていた時、私はなんでオプティマイザが正しい結合操作を選択しないんだろうとばかり考えていました。Nested Loops結合は最適な選択ではなかったからです。その結果、先のKBを思い出したのですが、重要なことを見過ごしていました。

 よくよく考えてみると、問題のクエリが参照しているDMVが返すデータ件数というのはたかが知れているはずです。Table ScanしようがNested Loops結合だろうが、そもそもサーバーに対してそんなに負荷を与えることはないはずです。

 つまり、オプティマイザの問題はあるにせよ、根本的な問題として考えられるのは、先のクエリが結合しているDMV、sys.dm_os_workersとsys.dm_os_tasksのどちらかの件数が、異常に増加しているということだったのです。私はこれを確認し忘れていました。

 Sys.dm_os_workersやsys.dm_os_tasksは、SQL Serverの内部オブジェクトのインスタンスをほぼそのまま返しているだけです。つまり、ワーカーかタスクのインスタンスが大量に生成されて解放されない状態だと考えられるのです。また、「最近になって発生しだした。」という事象からも、起きている現象は一つしかないと思いました。これはオブジェクトの解放漏れ・メモリリークです。

※この続きは、会員の方のみお読みいただけます(登録無料)。


※この続きは、会員の方のみお読みいただけます(登録無料)。


著者プロフィール

バックナンバー

連載:マイクロソフト古賀啓一郎の「今月のケースファイル」

もっと読む

All contents copyright © 2007-2019 Shoeisha Co., Ltd. All rights reserved. ver.1.5