IIS のパフォーマンスの問題やアプリケーションエラーを LogParser でトラブルシューティングする

2022-09-24

このトラブルシューティングツールで使用されるツールと知識

Microsoft LogParser (https://www.microsoft.com/download/details.aspx?id=24659)
コマンドプロンプト
IIS HTTP 状態コードの基本的な知識が役立ちます (https://support.microsoft.com/kb/943891)
SQL クエリの基本的な知識が役立ちます

概要

このトラブルシューティングツールは、IIS でホストされているアプリケーションが失敗した場合やパフォーマンスの問題が発生した場合の原因を特定するために IIS ログファイルを分析するのに役立ちます。開始する前に、IIS がログに記録できるすべてのフィールドが既定では有効になっていないことに注意してください。たとえば、[ 送信バイト数 ] と [ 受信バイト数 ] は選択されませんが、パフォーマンスの問題のトラブルシューティングに非常に役立ちます。したがって、これらの追加フィールドを含めるのに最適なタイミングは、システムの問題が発生する前です。そのため、まだ選択していない場合は、これらの追加フィールドを選択すると、問題が発生したときに解決策を見つけるのに役立ちます。

IIS 7 以降でこれを実行する方法について説明する次のブログ:

Windows 2008 での IIS 7 ログデータの変更

シナリオ

システム管理者は、IIS でホストされているシステムのユーザーから応答が遅いとの報告を聞き始めます。 Web ブラウザーが Web サイトにアクセスしているときに、単にタイムアウトするか、完全に応答を停止するという言及があります。

あなたは行動に移り、ワーカープロセスをリサイクルします。通常どおり、すべてが再び動作しているように見えます。

しかし、ソリューションとして受け入れることはできません。なぜこれが起こったのかを知る必要がありますが、どこから始めればいいのかわかりません。エラーコード、スクリーンショットなど、ユーザーからの詳細はなく、通常のパフォーマンスと比較するパフォーマンスデータはありません。多くの場合、他の新しい問題では、重大な根本原因分析から離れています。

Microsoft の LogParser は、すばやく使いやすい優れたツールです。多くの場合、このツールを使用すると、サーバーで発生した内容をより深く理解し、問題を特定するのに役立ちます。 LogParser で収集した情報を取得し、データベースチーム、ネットワークチーム、または開発者に渡して、より詳細な分析を行うことができます。

データ収集

既定では、IIS ログファイルは次のディレクトリにあります。

IIS 7 以降: %SystemDrive%\inetpub\logs\LogFiles
IIS 6 以前: %WinDir%\System32\LogFiles

このトラブルシューティングツールでは、IIS 8 を使用します。 IIS マネージャーを開き、図 1 に示すように [サイト] を選択します。これにより、サーバーでホストされている各 Web サイトの ID が表示されます。分析する W3SVC* ディレクトリを決定するには、この ID が必要です。

メインウィンドウに [サイト] が表示されている [I I S Manager] ウィンドウのスクリーンショット。
図 1: Web サイトの ID の取得

Windows エクスプローラーを開き、パフォーマンスの問題が発生した Web サイトの IIS ログファイルを含むディレクトリに移動します。 図 2 は、その様子を示しています。

ファイルの場所を示す Windows エクスプローラーのスクリーンショット。
図 2: IIS ログファイルの場所

IIS ログファイルは非常に大きい場合があります。たとえば、 図 2 では、 ログファイル u_ex12101858.log のサイズは約 100 MB です。これらのログファイルは巨大で、数十万もの個々のログファイルエントリが含まれている可能性があるため、これらの各ファイルを手動で調べることでエラーが発生することは適切な方法ではなく、投資する時間に対して結果はほとんど返されません。

これは、LogParserがトラブルシューティングに不可欠なツールになったときです。

データ分析

最初の手順では、エラーが含まれている可能性があるログファイルを特定します。たとえば、お客様が 2012 年 6 月 3 日のパフォーマンスについて不平を言っていた場合、ログファイルは u_ex120603.log で、次のようになります。

"12" は 2012 年の短縮年です
"06" は 6 か月目 (6 月) を指します。
"03" は月の 3 日目です

注: 上記の例では、IIS ログ記録が毎日ログファイルをローテーションするように構成されていることを前提としています。これは既定です。 IIS の設定を変更して、週単位や時間単位などの異なる時間間隔でログファイルをローテーションする場合、ログファイル名は異なります。 IIS ログファイル名の構文の詳細については、IIS ログファイルの名前付け構文 (https://support.microsoft.com/kb/242898) に関する記事を参照してください。

注意

既定では、IIS ログの日付と時刻は GMT を使用して格納されます。エラーを含むログを決定するときは、これを考慮する必要があります。つまり、次の例に示すように、LogParser の TO_LOCALTIME() 関数を使用して日付/時刻を調整できます。

注意

logparser.exe "SELECT TO_STRING(TO_LOCALTIME(TO_TIMESTAMP(date,time)),'yyyy-MM-dd hh:mm:ss') AS LocalTime,
COUNT(*) AS Hits FROM *.log WHERE date='2012-10-18'
GROUP BY LocalTime ORDER BY LocalTime" -i:w3c

エラーを含む IIS ログファイルを特定したら、それらを分析できる場所にコピーする必要があります。この手順は省略可能ですが、LogParser クエリの実行に時間がかかる場合があり、ログファイルが大きい場合は、Log Parser がシステムリソースと競合する可能性があるため、IIS サーバー上のログを分析することはお勧めしません。

たとえば、IIS ログを、LogParser ファイルを既にコピーしたパーソナルコンピューター上のフォルダーにコピーします。これは、通常、ログファイルを分析する方法です。 図 3 は、この記事を作成するために格納した場所の例を示しています。

ログパーサー実行可能ファイルの場所を示す Windows エクスプローラーのスクリーンショット。 図 3: LogParser を使用して分析のためにローカルにホストされている IIS ログファイル

LogParser をダウンロードしたら、分析を開始する準備が整います。最初に実行したクエリを 図 4 に示します。結果により、IIS が要求にどのように応答したかの概要が示されます。

logparser.exe "SELECT sc-status, sc-substatus, COUNT(*) FROM *.log GROUP BY sc-status, sc-substatus ORDER BY sc-status" -i:w3c
    
    sc-status sc-substatus COUNT(ALL *)
    --------- ------------ ------------
    200       0            3920658
    206       0            2096
    301       0            1031
    302       0            65386
    304       0            178705
    400       0            35
    401       2            692096
    404       0            2935
    404       11           7
    405       0            1
    406       0            36
    500       0            11418
    
    Statistics:
    -----------
    Elements processed: 4189228
    Elements output:    12
    Execution time:     7.70 seconds

図 4: LogParser クエリ (sc-status と sc-substatus)

結果内の関心のあるポイントは次のとおりです。

200 から 304 の HTTP 状態コード (成功した要求) の比率
500 個の HTTP 状態コード (失敗した要求) の数

これらの各状態コードの重要性については、以下で説明します。

HTTP 200 と 304 状態コードの比率 (成功した要求の分析)

200 と 304 の HTTP 状態コードの比率は、サーバーから直接ではなく、クライアントのキャッシュから取得されている要求の数を示しているため、重要です。 図 4 の結果は、HTTP 状態コードが 200 になった要求が 3,920,658 件あることを示しています。これは、要求されたファイルが毎回サーバーから提供されたことを意味します。これに対し、178,705 件の要求があり、その結果、304 の HTTP 状態コードが生成されました。これは、要求されたファイルがローカルキャッシュから取得されたことを意味します。言い換えると、要求の 95.5% がサーバーから処理されます。

キャッシュは、システムのパフォーマンスに非常に良い影響を与える可能性があります。静的圧縮と動的圧縮の両方の詳細については、 IIS 7 での HTTP 圧縮の構成に関する記事を参照してください。

HTTP 500 状態コード (失敗した要求の分析)

HTTP 500 ステータスコードは、システムの重大な問題を示している可能性があります。 HTTP 500 エラーの根本原因がシステムに与える影響のレベルは、ワーカープロセスのクラッシュまで多岐に及ぶことがあります。したがって、これらが表示されたら、 図 5 に示すクエリを実行して、500 HTTP 状態コードが発生した要求を見つける必要があります。

logparser.exe "SELECT cs-uri-stem, COUNT(*) FROM *.log WHERE sc-status=500 GROUP BY cs-uri-stem ORDER BY COUNT(*) DESC" -i:w3c
    
    cs-uri-stem                 COUNT(ALL *)
    --------------------------- ------------
    /ShoppingCart/ViewCart.aspx 1378
    /DataService.asmx           1377  
    /Start/default.aspx         949
    /GetDetailsView.aspx        753
    /Details/ImageUrls.asmx     722
    
    Statistics:
    -----------
    Elements processed: 4189228
    Elements output:    5
    Execution time:     24.89 seconds

図 5: LogParser クエリ (cs-uri-stem with a 500 sc-status)

これらの結果は、要求されたときに HTTP 500 状態コードで応答したファイルのパスと名前を示します。この種の情報は、開発チームにとって重要です。たとえば、開発チームは、その特定のコードをさらに調べて、コードブロックに含まれずに try {...} catch {...} 実行されるコードを検索したり、最適化する必要がある大規模なデータクエリを実行したりすることができます。

この例をさらに詳しく見て、HTTP 500 状態コードの上位共同作成者に注目してみましょう。これらのエラーがいつ発生したかは、この情報を使用して依存関係に問題があるかどうかを同時に確認できるため、興味深い情報です。

logparser.exe "SELECT TO_STRING(TO_TIMESTAMP(date,time),'yyyy-MM-dd hh') AS Hour,
COUNT(*) FROM *.log WHERE sc-status=500 AND cs-uri-stem='/Start/default.aspx' AND date='2012-10-18' GROUP BY Hour ORDER BY Hour" -i:w3c
    
    Hour          COUNT(ALL *)
    ------------- ------------
    2012-10-18 08 191
    2012-10-18 09 163
    2012-10-18 14 150
    
    Statistics:
    -----------
    Elements processed: 4189228
    Elements output:    3
    Execution time:     6.36 seconds

図 6: LogParser クエリ (cs-uri-stem with a 500 sc-status)

図 6 の結果のサブセットでは、問題の日付範囲が制限されています。この情報は、ネットワーク、データベース、オペレーティングシステム管理者、開発チームに渡して、他に何かが同時に発生しているかどうかを確認できます。例: 08:00 から 09:59:59 GMT と 14:00:00 から 14:59:59 GMT の間で、追加の問題がありましたか?

LogParser クエリの次のセットでは、次のフィールドを使用します。これは、パフォーマンスの問題に関するより良い分析情報を提供する可能性があります。

フィールド	説明	既定で有効
time-taken	アクションが実行された時間の長さ (ミリ秒単位)	はい
sc-bytes	サーバーによって送信されたバイト数	いいえ
cs-bytes	サーバーが受信したバイト数	いいえ

前述のように、sc バイトと cs バイトのフィールドを有効にするか、可能な場合は自分で有効にするように要求してください。システムとその動作に関する貴重な分析情報が提供されます。 たとえば、図 7 を見てみましょう。平均時間は数百ミリ秒でかなり良いことがわかります。ただし、最大時間を見てください。それはあまりにも多くの時間です。

logparser.exe "SELECT  cs-method, COUNT(*) AS TotalCount, MAX(time-taken) AS MaximumTime, AVG(time-taken) AS AverageTime FROM *.log GROUP BY cs-method ORDER BY TotalCount DESC" -i:w3c
    
    cs-method TotalCount MaximumTime AverageTime
    --------- ---------- ----------- -----------
    GET       3172034    1366976     153
    POST      1011765    256539      359  
    HEAD      5363       26750       209  
    
    Statistics:
    -----------
    Elements processed: 4189228
    Elements output:    3
    Execution time:     6.36 seconds

図 7: LogParser クエリ (MAX および AVG 時間)

私はあなたがすでに答える必要がある次の質問を自分自身に尋ねているのを知っています。どの要求にそれほど時間がかかっていますか? 図 8 は、その質問に対する回答を示しています。ご注意のように、私は先に進み、LogParserクエリにscバイトフィールドを含めます。 sc バイトは、サーバーからクライアントに送り返されるファイルのサイズを表します。

logparser.exe "SELECT cs-uri-stem, time-taken, sc-bytes FROM *.log WHERE time-taken > 250000 ORDER BY time-taken DESC" -i:w3c
    
    cs-uri-stem                 time-taken sc-bytes
    --------------------------- ---------- --------
    /ShoppingCart/ViewCart.aspx 1366976    256328
    /DataService.asmx           1265383    53860
    /Start/default.aspx         262796     8077
    /GetDetailsView.aspx        261305     5038
    /Details/ImageUrls.asmx     256539     2351
    
    Statistics:
    -----------
    Elements processed: 4189228
    Elements output:    5
    Execution time:     8.98 seconds

図 8: LogParser クエリ (MAX および AVG 時間)

要求の所要時間が "通常" の応答時間を超えていると、全員が同意する可能性があります。ただし、ファイルのサイズは、管理者または開発者が分析して、サイズが許容範囲内にあるかどうかを判断する必要があるものです。

結論として、GetDetailsView.aspx ファイルは 500 個の HTTP 状態コードをスローしており、比較的小さなファイルであったとしても、完了に時間がかかっているということです。このファイルで発生する問題が発生した日時を確認し、発生した問題をファイル内のコードで調べることができます。 (たとえば、IIS ログには、クエリ文字列に渡された変数の一覧が含まれています。これらの値で不適切なデータを確認できます)。

図 4 から図 8 に示す例は、問題の根本原因がどこに存在するのかを理解するのに役立ちます。ただし、この分析は、より多くの質問とより深い分析につながる状況のより良いビューを提供しているだけである可能性があります。その場合は、このデータの表現をより提示しやすい方法で作成できます。次のセクションでは、これについて詳しく説明します。

レポート

LogParser クエリとその結果を含むコマンドウィンドウのスクリーンショットは、パフォーマンスの問題の分析フェーズで問題が発生する可能性があります。しかし、何が起こったかを説明するためにマネージャーや取締役の前に行く必要がある場合は、マークを満たしていない可能性があります。

注意

LogParser を使用してグラフを動作させるには、Office Web コンポーネントをインストールする必要があります。次の記事では、これを行う方法について説明します。

図 9 は、要求の数とそれに関連付けられている HTTP 状態コードを含む 3D 円グラフを作成する LogParser クエリを示しています。これらは成功したので、私はステータス200を削除しました。ここで私が後にしているのは、OK以外の要求です。

logparser.exe "SELECT sc-status AS Status, COUNT(*) AS Count INTO status.gif FROM *.log WHERE sc-status > 200 GROUP BY Status ORDER BY Status" -i:w3c -o:CHART -chartType:PieExploded3D -ChartTitle:"Request Status"
    
    Statistics:
    -----------
    Elements processed: 4189228
    Elements output:    10
    Execution time:     6.20 seconds

図 9: LogParser クエリ (3D 円グラフを作成する)

クエリの結果を 図 10 に示します。イメージに影響を与える LogParser に渡すことができる追加のパラメーターがいくつかあります。たとえば、凡例、groupSize、config などです。完全なリストを取得するには、「 LogParser -h -o:CHART 」と入力して、すべてのパラメーターのリストを指定します。このコマンドでは、さまざまなグラフの種類の一覧も提供されます。

要求の状態の割り当てを示す 3 次元円グラフの図。
図 10: LogParser 3D 円グラフ

もう 1 つの便利なグラフは、キャッシュされた要求と実際の要求の比率です。 200 の HTTP 状態コードは、要求されたファイルがサーバーから取得されることを意味しますが、クライアントから 304 が取得されることを説明したデータ分析セクションを思い出してください。 図 11 は 、このグラフを作成するための LogParser クエリを示しています。値パラメーターを使用していることに注意してください。

logparser.exe "SELECT sc-status AS Status, COUNT(*) AS Count INTO cache.gif FROM *.log WHERE sc-status=200 OR sc-status=304 GROUP BY Status ORDER BY Status" -i:w3c -o:CHART -chartType:PieExploded3D -ChartTitle:"Cache" -values:ON
    
    Statistics:
    -----------
    Elements processed: 4189228
    Elements output:    2
    Execution time:     6.35 seconds

図 11: LogParser クエリ (3D 円グラフを作成する)

HTTPステータスコード200と304の違いは明確に見えますが、それぞれにヒット数を含めるためにいくつかの値を追加するかもしれないと思いました。 図 12 は 、前の LogParser クエリの出力を示しています。

キャッシュの割り当てを示す 3 次元円グラフの図。
図 12: LogParser 3D 円グラフ

LogParserを使用してIISログをグラフ化することで、データテーブルよりもはるかに良い結果を伝えるのに役立つ方法について、今すぐ画像が得られていると思います。しかし、停止する前に、縦棒グラフの種類を使用するもう 1 つの例を示したいと思います。 図 13 に示す LogParser クエリでは、1 時間あたり 500 個の HTTPS 状態コードの数を示す 3D 縦棒グラフが生成されます。

logparser.exe "SELECT to_string(to_timestamp(date, time), 'yyyy-MM-dd hh') AS Hour, COUNT(*) AS Count INTO 500.gif FROM *.log WHERE sc-status=500 GROUP BY Hour ORDER BY Hour" -i:w3c -o:CHART -chartType:Column3D -ChartTitle:"500 Errors by Hour"
    
    Statistics:
    -----------
    Elements processed: 4189228
    Elements output:    13
    Execution time:     6.32 seconds

図 13: LogParser クエリ (3D 縦棒グラフの作成)

結果のグラフを 図 14 に示します。

日付ごとの 1 時間あたり 500 エラーの数を示す 3 次元縦棒グラフの図。
図 14: LogParser 3D 縦棒グラフ

Excel と CSV を使用したグラフの作成

このセクションの冒頭で、LogParser のグラフ機能を使用する場合は、Office Web コンポーネント (OWC) のインストールが要件であることを説明しました。組織では、これを禁止する制限がある場合や、単にインストールしたくない場合があります。どちらの場合も、LogParser クエリ結果を CSV ファイルにエクスポートし、Excel にインポートすることを検討してください。

図 15 は、CSV ファイルに 200 ではないすべての要求の HTTP 状態コードを抽出する LogParser クエリを示しています。

logparser.exe "SELECT sc-status AS Status, COUNT(*) AS Count INTO status.csv FROM *.log WHERE sc-status > 200 GROUP BY Status ORDER BY Status" -i:w3c -o:csv
    
    Statistics:
    -----------
    Elements processed: 4189228
    Elements output:    10
    Execution time:     6.20 seconds

図 15: LogParser クエリ (Excel にインポートするための CSV ファイルを作成する)

図 15 では、LogParser が CSV 形式で出力を作成するために -o パラメーターを使用していることに注意してください。

グラフを作成できるように CSV ファイルを Excel にインポートするには、Excel を開き、[データ] タブに移動し、[テキストから] を選択します。 図 16 は 、この外観を示しています。

[Excel データ] タブメニューオプションを示すスクリーンショット。 図 16: LogParser によって作成された CSV ファイルを Excel にインポートする

LogParser クエリによって作成されたstatus.csv ファイルを選択し、インポートウィザードに移動します。 "コンマ" 区切り CSV ファイルをインポートすると、列 A の状態と、列 B の各状態の出現回数が表示されます。これは、 図 15 に示す LogParser クエリを実行したことを前提としています。最後に、ヘッダーを含む列 A と B からすべてのデータを選択し、作成する円グラフの種類を選択します。 図 17 は、これがどのように表示されるかを示しています。

Excel の [挿入] タブのオプションを示すスクリーンショット。列 A と列 B のデータが選択されます。 図 17: CSV ファイルを使用して円グラフを作成する

最終的な結果は、 図 10 で前に示したのと同様の円グラフ ( 図 18) です。色、グラフの種類、ラベルなどに関して多くのオプションがあります。ボタンをクリックすると、グラフの種類を円グラフから横棒グラフまたは折れ線に変更できます。 Excel 内でプロフェッショナルな見た目のグラフを作成するには、多くのオプションがあります。

要求の状態を示す 3 次元円グラフのスクリーンショット。
図 18: 図 10 のような CSV ファイルを使用した円グラフ

LogParser を使用して、その分析の結果を分析して表示するためのさまざまなオプションと可能性があります。その他のヒントと例については、Robert McMurray によって書かれたこれらの記事を参照してください。 LogParser のインストールパッケージ内には、非常に便利なヘルプファイルと多くの事前書き込みスクリプトも用意されています。次のセクションでは、これと他のトピックについて詳しく説明します。

Help

LogParser 2.2 をコンピューターにインストールすると、既定でディレクトリに C:\Program Files (x86)\Log Parser 2.2 インストールされます。その場所に移動し、Samples\Queries and Samples\Scripts ディレクトリを確認して、事前に書き込まれたコードを豊富に用意して、すばやく移動できるようにします。

また、LogParser.chm ファイル内の内容を読み取ることで、大きな利点を実現できます。

IIS ログファイルのサイズの縮小または分割

IIS ログファイルが大きすぎて LogParser がクエリを実行できないことがあります。これは 32 ビットコンピューターで最も可能性が高いですが、64 ビットコンピューターでも発生する可能性があります。ただし、LogParser クエリの実行時に "メモリ不足" エラーが発生した場合は、 図 19 に示すコマンドの実行を検討してください。このクエリでは、大きな IIS ログファイルからいくつかの重要なフィールドを抽出し、別のフィールドに配置します。その結果、ログファイルが小さくなります。

logparser.exe "SELECT date, time, c-ip, cs-uri-stem, cs-uri-query, sc-status, sc-substatus, sc-win32-status, sc-bytes, cs-bytes, time-taken INTO u_exJUSTRIGHT.log FROM u_exTOOBIG.log" -i:w3c -o:w3c
    
    Statistics:
    -----------
    Elements processed: 19712301
    Elements output:    19712301
    Execution time:     3.07 seconds

図 19: IIS ログファイルのサイズを小さくする (フィールドを削除する)

この例では、ファイルサイズを約 45% 削減しました。多くの場合、これは十分かもしれません。他の人ではそうではないかもしれません。元のログファイルのサイズによって異なります。 IIS ログファイルのサイズを小さくする必要がある場合は、 図 20 に示すように、LogParser クエリに日時制約を追加することを検討してください。

logparser.exe "SELECT date, time, c-ip, cs-uri-stem, cs-uri-query, sc-status, sc-substatus, sc-win32-status, sc-bytes, cs-bytes, time-taken INTO u_exJUSTRIGHT.log FROM u_exTOOBIG.log WHERE to_timestamp(date, time) >= timestamp('2012-11-09 00:00:00', 'yyyy-MM-dd hh:mm:ss')" -i:w3c -o:w3c
    
    Statistics:
    -----------
    Elements processed: 240123
    Elements output:    240123
    Execution time:     0.45 seconds

図 20: WHERE 句を追加して IIS ログファイルのサイズをさらに小さくする

これはファイルサイズを小さくするための貴重な手法ですが、IIS ログから不要なエントリを削除する場合にも役立ちます。たとえば、問題のトラブルシューティングを開始すると、時間、sc バイト、cs バイトがログに記録されていないことが認識されます。 IIS で有効にし、最近有効にしたフィールドを含むエントリのみをクエリで分析するようにします。 where ステートメントを使用して、これらのフィールドが有効になっている時点から IIS ログファイルからデータを抽出します。これは、AVG、MIN、MAX の集計を使用する場合に重要です。

まとめ

LogParser は、さまざまなシステムログの種類を分析するための小さいが強力なツールです。この記事では、IIS ログに適用できるクエリについて説明しました。 IIS 環境でパフォーマンスの問題やエラーが発生した場合、どこから開始するかを知りにくい場合があります。

いくつかの SQL スキルを持つシステム管理者は非常に高度な LogParser クエリをすばやく構築できるため、LogParser を出発点として使用できます。これらのクエリを使用して、問題の根本原因分析をさらに進めることができます。

役に立つリンク

この記事で参照されているリンクと、追加情報を含むいくつかのリンクを次に示します。