[SQL Troubleshooting] 第4回 サーバートレースの解析方法 – (1)


山崎 実久
SQL Engine Support Engineer

以前に、「DO’s&DONT’s #1: やらない方がいいこと – 運用環境で、Profiler GUI を使用してトレースする」、「SQL トレーススクリプトの作成、実行 (SQL Server 2000)」、「SQL トレーススクリプトの作成、実行 (SQL Server 2005, 2008, 2008 R2)」 というタイトルで、Profiler を利用したサーバートレースの採取方法について本 blog でご案内しました。

SQL Server 上で実行されたクエリが遅いなどの問題がある際、サーバートレースを採取し解析することで、問題のあるクエリを特定し、クエリの実行状況を確認することができます。問題のあるクエリを特定するため長期間サーバートレースを採取する場合、サーバートレースの出力ファイルサイズが数 GB と大きくなる場合があります。 採取したファイルを Profiler で開き確認することも可能ですが、非常に手間がかかります。そこで役立つのが、システム関数 fn_trace_gettable です。 システム関数 fn_trace_gettable を利用することで、サーバートレースの出力ファイルをテーブルに格納することができます。 格納したテーブルに対しクエリを実行し、ある程度調査対象のクエリを絞った上で、Profiler 上でトレースファイルを開き、該当のクエリの実行プランなどを確認することができます。

以下、サーバートレースで採取すべきトレースイベントの紹介も含め、fn_trace_gettable の利用方法をご案内します。

———————————-
a. クエリの実行状況を確認するために必要なトレースイベント

b. システム関数 fn_trace_gettable を利用しサーバートレースの出力ファイルをテーブルに格納
c. CPU Time の値が大きいクエリを検索
d. reads や writes の値が大きいクエリを検索
e. まとめ

———————————-

a. クエリの実行状況を確認するために必要なトレースイベント

SQL Server 上で実行されたクエリの開始と停止の状況を確認するために、以下のイベントを選択し、サーバートレースを採取します。
サーバートレースの採取方法については、「SQL トレーススクリプトの作成、実行 (SQL Server 2000)」、「SQL トレーススクリプトの作成、実行 (SQL Server 2005, 2008, 2008 R2)」 をご参照ください。

– エラーと警告
Attention
– パフォーマンス
ShowPlan Statistics Profile
ShowPlan XML Statistics Profile
– ストアド プロシージャ
RPC:Starting
RPC:Completed
SP:Starting
SP:Completed
SP:StmStarting
SP:StmtCompleted
– TSQL
SQL:BatchStarting
SQL:BatchCompleted
SQL:StmtStarting
SQL:StmtCompleted

+ 参考情報
SQL Server 2008 R2
SQL Server イベント クラスの参照

本blog
クエリタイムアウト – その仕組み

b. システム関数 fn_trace_gettable を利用しサーバートレースの出力ファイルをテーブルに格納

サーバートレースの出力ファイル (xxxx.trc) をテーブル (下記の例では、tracet) にインポートする場合、以下の例のようにクエリを実行します。
fn_trace_gettable の引数に指定している number_files の値が以下のクエリの例のように default の場合、連番の名前で出力された trc ファイル(例 xxx_1trc, xxx_2.trc, xxx_3.trc など)全てをテーブルに取り込む設定となります。
途中、連番が途切れている場合、途切れたところまでしか取り込まれませんので、注意が必要です。

(例)
————————————–
use データベース名
go
select * into tracet from fn_trace_gettable (‘C:\xxx.trc’,default)
go

————————————–

※SQL Server 2005、2008 , 2008 R2 では fn_trace_gettable を利用いただき、SQL Server 2000 では ::fn_trace_gettable を指定する必要があります。

+ 参考情報
SQL Server 2000
fn_trace_gettable

SQL Server 2008 R2
fn_trace_gettable (Transact-SQL)

(実行例)

 fn_trace_gettablwe

c. CPU Time の値が大きいクエリを検索

b で作成したトレースのデータを含むテーブルに対し、以下の例のようにクエリを実行し、CPU Time の値が大きいクエリを特定します。

(例)
————————————–
use データベース名
go

select ste.name,t.spid,t.TextData,t.duration,t.StartTime,t.EndTime,t.cpu,t.reads,t.writes from tracet t inner join sys.trace_events ste
on t.EventClass = ste.trace_event_id
where t.cpu >=0 order by t.cpu desc
————————————–

(実行例)
以下の例では、CPU Time の値が大きい順に並べています。採取したトレースの中では、ストアドプロシージャ  proc01 実行時の CPU Time が 32 ミリ秒と一番大きいことがわかります。
下記の cpu の単位はミリ秒、 duration
の単位はマイクロ秒です。

cpu02

– 参考情報
データ列を使用したイベントの説明

d. reads や writes の値が大きいクエリを検索

b で作成したトレースのデータを含むテーブルに対し、以下のようなクエリを実行し、Reads や Writes の値が大きいクエリを特定します。
Reads や Writes は、メモリ上の 8 KB からなるページの論理読み取りページ数、論理書き込みページ数を示しています。これらの値が大きいクエリは、ディスク I/O の負荷に関わるクエリの可能性があります。実際の物理読み取り数や、物理書き込み数は、パフォーマンスログや動的管理ビューから確認することができます。
該当のクエリについて、現象が発生していない状態で採取したログから、現象が発生していない場合の状態(reads や writes、クエリプラン)を確認後、現象発生時と比較し、クエリチューニングを行います。

(例)
————————————–
use データベース名
go
select ste.name,t.spid,t.TextData,t.duration,t.StartTime,t.EndTime,t.cpu,t.reads,t.writes from tracet t inner join sys.trace_events ste
on t.EventClass = ste.trace_event_id
where t.Reads >=0 order by t.Reads desc, t.Writes desc
————————————–

(実行例)
下記例では、Reads および Writes の値が大きい順に並べています。採取したトレースの中では、ストアドプロシージャ proc01 実行時の Reads および Writes の値が一番大きいことがわかります。
Reads および Writes の値の単位はページ となります(1 ページ は 8KB です)。

ReadsWrites01

まとめ

上記を利用し、サーバーの CPU 負荷が高い時や、Disk I/O の負荷が高い時、SQL Server の処理に起因している問題か否か確認することができます。パフォーマンスログとサーバートレースの結果を照らし合わせて確認する方法は、第5回 サーバートレースの解析方法 2 でご紹介します。

サーバー負荷がある時の、CPU Time の値が大きいクエリや、Reads および Writes の値が大きいクエリを特定し、クエリの実行プランをサーバーの負荷のない場合と比較することで、問題のあるクエリのチューニングを行うこともできます。

 

SQL Server トラブルシューティング 6 回シリーズのご案内

本記事は、第 4 回目となります。他の記事は以下をご参照ください。
http://blogs.msdn.com/b/jpsql/archive/2012/03/30/sql-server-6.aspx

第1回 SQL Server のログ、イベントログの確認方法 (03/30 UP)
第2回 パフォーマンスログの採取方法 (04/20 UP)
第3回 パフォーマンスログの確認方法 (05/07 UP)
第4回 サーバートレースの解析方法 1 (★ 05/18 UP 本記事)
第5回 サーバートレースの解析方法 2 (02/18 UP)
第6回 ブロッキング情報の確認方法 (07/24 UP)

 


Comments (0)

Skip to main content