案件の概要
あるお客様から「昨日、SQL Serverが予期しない動きをしていて、その時のSQLトレースを採取してあるからちょっと見てほしい。」という依頼を受けました。ざっとトレースデータ眺めて、その後、ひと通りお客様へヒアリングしたのですが、どうもお客様のアプリケーションの問題ではなさそうですし、SQL Serverの設定なども特に問題はなさそうでした。
今あるデータからは問題の原因を特定できそうになかったので、調査に必要なデータを別途採取させてほしい旨を伝えました。しかし、お客様のほうで今すぐに現象の再現を行えないことや、テスト環境でしか発生しておらず緊急性を要していないということもあり、その日は情報採取を行わずに、後日、私からあらためて採取してほしい情報を整理してお伝えすることになりました。
悪い予感
SQL Serverには、トラブルを調査するためのツールがたくさん用意されています。パフォーマンスカウンター、SQLトレース、拡張イベント、トレースフラグ、DMVなど、その種類はさまざまで調査したい現象や環境によって使い分けることができます。今回、私がその場で採取したいと思った情報は、これらSQL Serverが提供するツールで採取できる情報ではなく、Time Travel Tracer(*) (以降、TTT)というツールで採取する情報でした。TTTは、アタッチしたプロセス内のスレッド`が実行したインストラクションを記録するため、TTTで採取したトレース情報をデバッガで開くと、あたかもその場でデバッグをしているかのように、アタッチしたプロセス内で起きた現象の再生や巻き戻しができるのです。
(*) TTTは一般には提供されていないツールです。トラブルシューティングの為に、サポートがTTTによる情報採取をお願いすることがあります。(http://support.microsoft.com/kb/2716889)
しかし、TTTでの情報採取は負荷が高く、アプリケーションの動作状況によっては情報量も多くなるため、SQL Serverのようなサーバーアプリケーションに対してはあまり手軽に採取できるものではありません。そこで、TTT以外にもう少しライトウェイトな方法で調査に有効そうな情報を採取できないか調べてみることにしてみました。前述のとおり、この問題に対しては緊急性を要していなかったので時間には余裕があったのです。
SQL Serverでトレース情報といえば、やはり、拡張イベントです。ひょっとしたら、今回の問題に有効なイベントがあるかもしれません。ただ、拡張イベントはイベント数が多いため、私もどんなイベントが用意されているかをすべて把握していないのです。そこで、下記のクエリを発行して、イベントの一覧を取得し、イベント名からそれらしいイベントが存在しないか調査してみることにしました。
発行したクエリがすぐに結果を返さなかったので、結果を待つ時間がもったいないと思い並行して違う案件の作業をはじめました。私のデスクトップマシンには、デバッグビルドのSQL Serverをインストールしているので、通常すぐ終わるようなクエリでも時間がかかることが多々あるのです。
別案件の作業が一段落して、クエリを発行したSQL Server Management Studio (SSMS)の画面をみると、先ほどのクエリがまだ終了していません。かれこれ10分か15分は経っているはずです。「これはおかしい、ひょっとしたらどこかでエラーになっているんじゃないかな。」と思い、SQL Serverのログフォルダを開きました。
悪い予感は的中しました。ログフォルダにメモリダンプファイルが大量に出力されていたのです。
