原因不明の処理遅延が「不定期」に発生する（パフォーマンストラブル）：SQL Serverトラブルシューティング（49）（1/2 ページ）

連載バックナンバー

　本連載では、「Microsoft SQL Server（以下、SQL Server）」で発生するトラブルについて、「なぜ起こったか」の理由とともに具体的な対処方法を紹介していきます。

トラブル 36（カテゴリー：処理遅延）：処理遅延が「不定期」に発生する

　「Windows Server 2012 R2」上に「SQL Server 2016 RTM」をインストールした環境を想定して解説します。

トラブルの原因を探る

　前回は「特定のタイミングで」の条件だったために、原因追及の目星をある程度付けやすい事例でした。しかし今回は「不定期」に発生するトラブル事例のようです。

　まず、アプリケーションチームにトラブル発生時の状況をヒアリングします。すると、以下のことが分かりました。

• 発生時間帯に、（処理遅延を招く）バッチ処理は実行されていなかった（○）
• 発生時間帯には、「ほぼ全ての処理」で遅延が発生していた（×）
• 発生直前までのレスポンスタイムに問題はなかった（○）

　この回答を踏まえて、インフラ側でリソースの調査を行います。以下のことが分かりました。

• CPU利用率や待ち行列の長さに問題はなかった（○）
• メモリの使用量は規定値以内で、Page Life Expectancyなどの指標でもメモリ不足を示していなかった（○）
• ディスクI/Oは多少の増減があるものの、正常時と比べて特に大きな変化はなかった（○）

　なお、ユーザーは「これまで正常だったのに、いきなり遅くなった」と感じたそうですが、リソースに大きな問題はありませんでした。そこで「SQL Server Profilerによるトレースの取得」を検討しましたが、本番環境ではトレースを取得することそのもののリスク、つまり本例とは別の遅延要因によって思わぬトラブルを招くリスクがあったために、アプリケーションチームからこの対処は許容されませんでした。

　そこで、エラーログとエラーログ取得フォルダと同じ場所にある「デフォルトトレース」を確認することにしました（図1）（図2）。

図1　デフォルトトレースの出力先

図2　デフォルトトレースの出力内容

　デフォルトトレースとは、SQL Serverが規定動作として取得しているトレースと同じフォーマットのログのことです。SQL Server Profilerから内容を確認できます。トレースの採取はシステムにある程度の負荷を掛けるので、処理遅延を招く可能性があります。採取するデータが多いことから、I/O負荷とそれに伴ってSQL Server内部で待機が発生するためです。一方のデフォルトトレースは採取対象のイベントを極限まで絞り込んであることから、パフォーマンスへの影響はほとんどありません。

　このデフォルトトレースを確認したところ、処理遅延が発生した時間とデフォルトトレースに記録されていた時間がほぼ一致していました。このことから、「トランザクションログファイルの拡張」が原因で遅延が起きていることを推定できました。

　このようにトラブルシューティングでは、さまざまなログを見比べながら問題を総合的に判断する内容を探し出します。なお、今回の例ではパフォーマンスログをあらかじめ取得するようにしていたことから、アプリケーションチームとリソースの議論ができました。