SHOEISHA iD

※旧SEメンバーシップ会員の方は、同じ登録情報(メールアドレス&パスワード)でログインいただけます

EnterpriseZine(エンタープライズジン)編集部では、情報システム担当、セキュリティ担当の方々向けに、EnterpriseZine Day、Security Online Day、DataTechという、3つのイベントを開催しております。それぞれ編集部独自の切り口で、業界トレンドや最新事例を網羅。最新の動向を知ることができる場として、好評を得ています。

直近開催のイベントはこちら!

Security Online Day 2023 春の陣

2023年3月14日(火)10:00~16:00

EnterpriseZine(エンタープライズジン)編集部では、情報システム担当、セキュリティ担当の方々向けの講座「EnterpriseZine Academy」や、すべてのITパーソンに向けた「新エバンジェリスト養成講座」などの講座を企画しています。EnterpriseZine編集部ならではの切り口・企画・講師セレクトで、明日を担うIT人材の育成をミッションに展開しております。

お申し込み受付中!

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

CPU使用率が高い?―謎のスパイクを追え!

006


 過去に担当した案件を漁っていて、「そういえば、こんなことあったなぁ」というものを見つけました。SQL Serverが稼働しているサーバーのCPU使用率が、なぜか定期的にスパイクするというものです。

案件の概要

 お客様はSQL Serverの稼働状況を監視するため、SQL Server AgentのジョブからDMVへのクエリを定期的に発行し、その結果をテキストファイルに保存していました。お客様曰く、「アプリケーションが稼働していないにもかかわらず、CPU使用率が定期的にスパイクしているので、犯人となりそうなのはこのSQL Server Agentのジョブぐらいしかいないと思う。」とのことでした。

犯人のプロセスは特定、しかし…

 SQL Server Agentジョブの定義を頂いたので、早速自分の環境でも同じ現象が発生するかどうか環境を構築してみました。採取するDMVごとにジョブが定義されており、その実行間隔はまちまちです。それぞれのジョブが実行を開始されるのを待って、パフォーマンスカウンターを観察してみました。

 すると、しばらくしてからCPU使用率を表すパフォーマンスカウンターの値が跳ね上がりました。なんとも、あっさりと現象が再現したのです。この時に観察していたパフォーマンスカウンターはサーバーのCPU使用率を表すものでしたので、今度はどのプロセスがこのスパイクを引き起こしているのかを、プロセス単位のパフォーマンスカウンターで観察してみることにしました。スパイクする時はユーザーモードのCPU使用率が高いことを確認していたからです。今の時点で怪しいのは、SQL Serverのプロセスか、SQL Server Agentのプロセスのどちらかですから、観察するのはこの2つのプロセスに絞りました。

 パフォーマンスカウンターをセットして、スパイクを引き起こす何らかのジョブが実行されるのを待ちます。どれほどの間隔だったかは記憶が定かではありませんが、しばらくしてから、やっぱりまたスパイクしました。跳ね上がったカウンターは、SQL Serve Agentのプロセスです。

 これで犯人のプロセスは特定できました。しかし、SQL Server Agentの何の処理がスパイクを引き起こしているのか、また、どのジョブが実行されたときに発生するのかがわかっていませんでしたので、これらのいずれかを調査しようと考えました。

 まぁ、どちらから手を付けてもよかったとは思うのですが、どのジョブが引き起こしているのかを特定してしまえば、SQL Server Agentを調査する時にいちいちジョブのスケジュール実行を待たずに済むだろうと思い、まずは犯人のジョブを特定することにしました。

 お客様は、結構な数のDMVデータを採取していたので、ジョブは数十個あったと思います。これまでの状況から、なんとなくサイズの大きいデータを返すようなクエリが実行されていると問題になりそうだなぁと思っていたので、ジョブの定義をざっと眺めてから怪しそうなものを順に手動で実行していきました。

図1 「ステップでジョブを開始」を怪しそうなものから順番に実行していく
▲図1 「ステップでジョブを開始」を怪しそうなものから順番に実行していく

 すると、以下のクエリを発行するジョブが実行されるタイミングでスパイクが発生することがわかりました。実行時間の長いSQLを抽出するためのクエリです。



SET TEXTSIZE 327680

SELECT TOP 50
	r.session_id, 
	status,
	qt.dbid, 
	qt.objectid, 
	blocking_session_id,
	r.wait_type,
	r.wait_time,
	r.last_wait_type,
	r.wait_resource,
	r.total_elapsed_time,
	r.cpu_time,
	r.reads, 
	r.writes,
	r.logical_reads,
	r.scheduler_id,
	r.plan_handle,
	convert(text, SUBSTRING (qt.text,r.statement_start_offset/2, (case when r.statement_end_offset = -1 then len(convert(nvarchar(max), qt.text)) * 2 else r.statement_end_offset end - r.statement_start_offset)/2)) AS query_text
FROM sys.dm_exec_requests r
CROSS APPLY sys.dm_exec_sql_text(sql_handle) AS qt
WHERE r.session_id > 50
ORDER BY r.total_elapsed_time DESC

 これで、手軽に現象を再現させることができるようになりました。後はSQL Server Agentのどういった処理がCPU使用率をスパイクさせているのかを特定するだけです。

次のページ
CPU使用率が高くなってしまったら?

この記事は参考になりましたか?

  • Facebook
  • Twitter
  • Pocket
  • note
マイクロソフト古賀啓一郎の「今月のケースファイル」連載記事一覧

もっと読む

この記事の著者

古賀 啓一郎(コガ ケイイチロウ)

日本マイクロソフト株式会社勤務。きままなエンジニア。
謎があると解決せずにはいられない性格。
週末は家事に従事。 

※プロフィールは、執筆時点、または直近の記事の寄稿時点での内容です

この記事は参考になりましたか?

この記事をシェア

EnterpriseZine(エンタープライズジン)
https://enterprisezine.jp/article/detail/5748 2014/05/12 16:33

Job Board

PR

おすすめ

アクセスランキング

アクセスランキング

イベント

EnterpriseZine(エンタープライズジン)編集部では、情報システム担当、セキュリティ担当の方々向けに、EnterpriseZine Day、Security Online Day、DataTechという、3つのイベントを開催しております。それぞれ編集部独自の切り口で、業界トレンドや最新事例を網羅。最新の動向を知ることができる場として、好評を得ています。

2023年3月14日(火)10:00~16:00

新規会員登録無料のご案内

  • ・全ての過去記事が閲覧できます
  • ・会員限定メルマガを受信できます

メールバックナンバー

アクセスランキング

アクセスランキング