ASP.NET

  • [アーティクル]

IIS のログを使ったアプリケーションのトラブルシューティング

Eduardo Sanabria

コードを一切見ないで、アプリケーションのトラブルシューティングやデバッグを行おうとしたことはありますか。あるいは、アプリケーションが機能しなくなり、ブラウザーからもアプリケーションからも役に立つエラー コードが提供されなかったことはありますか。

個人的にはどちらのシナリオにも数多く直面しているため、このような事態に備えておくことが大事だと考えています。今回説明するテクニックは、コードを実行するプラットフォームが何であれ、IIS の管理下で実行するあらゆるアプリケーションやシステムのトラブルシューティングに役立ちます。このテクニックは、個人的にも、さまざまな状況でのアプリケーションや Web サイトのトラブルシューティングに役立ってきました。特に最近標準になってきているシナリオとして PC 以外のデバイスでのトラブルシューティングに有効です。最近のケースとしては、Windows ベースのデバイスで問題なく機能していたビデオが Apple のデバイスでは表示されない理由を解明するのに役立ちました。

考慮事項

IIS の管理下で実行される ASP.NET アプリケーションや他の Web アプリケーションをデバッグするのに有効なテクニックはたくさんあります。多くの場合、ブラウザー自体から具体的なエラーやエラーのセットが生成され、問題を解決するにはそれで十分です。

しかし、情報が十分でなかったとしたらどうでしょう。このような状況では、別のテクニックをいくつか知っていると役に立ちます。最も単純かつ迅速で、最も良く知られているテクニックの 1 つが、サーバーで直接アプリケーションを実行する方法です。このオプションが構成されていないサーバーもありますが、構成されていれば、サーバーは一般に他のコンピューターに比べて有効なデバッグ情報を提供します。このサーバーの動作は、言うまでもなく、マイクロソフトがセキュリティを目的として組み込んでいます。サーバーのブラウザーで詳細データを入手するには、Internet Explorer で [インターネット オプション]、[詳細設定] の順にクリックして [HTTP エラー メッセージを簡易表示する] チェック ボックスをオフにします。

さらに情報が必要な場合はログが重要な情報源になります。マイクロソフトは強力なログ記録機能をサーバーに組み込んでいます。トラブルシューティングを突き詰めていく際にはこのログが大いに役立ちます。ただし、ログを利用する場合は、探している情報がどこにあるかを知っていることが前提になります。

IIS のログ記録を有効にする

まず、サーバーで Windows ログを有効にします。これにはいくつか方法があります。実際の手順は、実行している Windows Server のバージョンによって異なります (場合によっては大きく異なります)。

各バージョンの手順を詳しく説明したり、それぞれのメリットやデメリットを説明することは今回の目的ではないので、ここでは省略します。ここでは、デバッグする場合はログを正しく使用することと、実際にエラーが発生する前にログを有効にしておかなければならないことだけを指摘しておきます。Windows Server 2003 および 2012 を対象にした次の 2 つの MSDN 記事に有効な情報がたくさん記載されています。「Windows Server 2003 で Web サイトのログ記録を構成する方法 (bit.ly/cbS3xZ)」と「IIS でログを構成する (bit.ly/18vvSgT)」を参考にしてください。この 2 つ記事がニーズに合わなくても、さまざまなバージョンの Windows Server で IIS のログを有効にする方法が記載されているオンライン記事は他にもたくさんあります。

正しい ID 番号を特定する

ログを有効にしたら、トラブルシューティングを行う Web サイトの IIS 内での ID 番号を調べる必要があります。通常サーバーは複数の Web サイトをホストするので、ログ フォルダーを手動で見つけようとしても難しくなるため ID 番号が重要になります (45 の Web サイトを運用するサーバーで試してみましたが、見つけるのはほぼ不可能でした)。

IIS マネージャーを開き、ホストされているすべての Web サイトを表示します。今回の例では、WebSite2 が突然機能しなくなったり、断続的に機能する理由を調べます。

図 1 に示すように、WebSite2 の ID は "3" です。次に、この Web サイトに対応するログ フォルダーを開きます。このフォルダーは通常 (常にではありません) Inetpub フォルダー内にあります。Windows の場合、Inetpub フォルダーは通常サーバーのルート (C:) に作成されますが、今回の例では D: ドライブにあります。業界のベスト プラクティスとして、障害時に簡単に交換できるように、コードと OS は別のドライブに配置するようにします。


図 1 Web サイトの ID 番号の検索

Windows の場合、ログ フォルダーにはすべて W3SVC# という名前が付けられ、# に Web サイトの ID が入ります。今回は、デバッグするサイトの ID が 3 なので、ログ ファイルは W3SVC3 というフォルダーに配置されます (図 2 参照)。


図 2 ログ ファイルのフォルダーを開く

ファイルの閲覧

対象のフォルダーを開くと、たくさんのファイルが表示されることがあります。サーバー履歴の構成方法やログを有効にしている期間によりますが、IIS は通常、多種多様なファイルをたくさん保持しています。必要なファイルを見つけるのにほぼ確実なのは、一覧を下にスクロールして一番下のファイルを開く方法です。ただし、エラーが発生した正確な時間がわかっていれば、その日付と時刻を使用してファイルの名前から見つけることができます。どちらの方法でも、Notepad.exe などのファイル エディターを使ってファイルを開きます。

おそらくファイルの中にはたくさんのデータが見つかります。一見、この情報は難解で役に立たないように思えるかもしれませんが、少し理解すれば、データに埋もれている貴重な情報をたくさん見つけることができます。そこで、ログに記録されるデータの中でも最も役立つデータ要素をいくつか見ていくことにします。

IIS と Windows により、HTTP 要求ごとに 1 行がログに記録されます。以下に代表的な行を示します。

2013-08-28 00:01:12 128.128.128.20 GET /default.asp - 443 - 200.200.200.17 Mozilla/4.0+(compatible; +MSIE+8.0; +Windows+NT+6.1; +WOW64;+Trident/4.0;+SLCC2;+.NET+CLR+2.0.50727; +.NET+CLR+3.5.30729;+.NET+CLR+3.0.30729;+InfoPath.3;+MS-RTC+LM+8; +.NET4.0C;+.NET4.0E; +.NET+CLR+1.1.4322) 200 0 0 15

上記は実際の IIS ログの行を示しています。このデータ行は "標準" 形式の 1 つです。ただし、IIS のオプションは細かい構成が可能なので、実際のファイルが完全にこのサンプルのようになっている保証はありません。ここでは、すべてのデータを取り上げるのではなく、アプリケーションのデバッグに最も関連が深い要素に注目します。

このサンプルで初めに注目するのは要求の日付です。この日付はサーバーの日付です。世界中のタイム ゾーンが異なる国に設置された多数のサーバーでたくさんの Web アプリケーションを運用している場合、この日付を誤解してしまう可能性があります。ただし、エラーが発生した実際の日時を正確に表していることは間違いありません。多くのサーバーでは GMT 時間が使用されていますが、その形式を確認してください。

次に、アクセスした IP アドレス、HTTP 操作の種類 (GET)、および要求またはアクセスした実際のファイルが記録されています。以下のサンプル行では、コードから default.asp ファイルを呼び出しています。

128.128.128.20 GET /default.asp

処理のこの段階で既にエラーが発生している可能性もあるので、この情報は有益です。たとえば、この時点は別のファイルへの呼び出しを想定していたかもしれません。

行の以下の部分は、要求の発信元 IP アドレスと受信ポートを示しています。

443 - 200.200.200.17

トラブルシューティングを行っている要求が実際に既知のソースから送信されていることを確認する必要が生じることもあるので、この情報も貴重です。

ご覧のように、実際に使用されたポートも記録されます。一見重要には思えないわずかな情報が、問題を調べる際に役立つこともあります。たとえば、ファイアウォールの構成が適切ではないかもしれません。このデータに続くたくさんの情報はほとんどがバージョン関連の情報です。

+MSIE+8.0; +Windows+NT+6.1;+WOW64;+Trident/4.0;+SLCC2; +.NET+CLR+2.0.50727; +.NET+CLR+3.5.30729;+.NET+CLR+3.0.30729; +InfoPath.3;+MS-RTC+LM+8; +.NET4.0C

たとえば、ブラウザーが 32 ビット版か 64 ビット版か、CLR のバージョン (.NET の概念まで掘り下げる開発者向け)、および実際にサーバーにインストールされている .NET バージョン (このケースでは、.NET 4 C) を確認できます。

真相にたどり着く

ここまでは、ログ ファイル エントリの比較的明確な部分を示しました。最も重要なのは、HTTP 要求に応答しているブラウザーを確認できることです。ブラウザーが異なれば結果が変わることがあるため、これがわかるだけで十分な場合もあります。以下の断片的な文字列は、ファイルに Firefox や Chrome がどのように記録されるかを示しています。

;+rv:17.0)+Gecko/20100101+Firefox/17.0 404 0 2 109
 +AppleWebKit/537.36+(KHTML,+like+Gecko)+Chrome/­28.0.1500.95+Safari/537.36 200 0 0 125

HTTP 要求の表記はよく似ているため、複数の HTTP 要求からデバッグ対象を見つけるのは困難になる可能性があります。このような場合、ブラウザーを変更してみます。Safari や Opera など、別 (また想定外の) ブラウザーのエントリを追加すると、問題のエントリが簡単に見つかり、結果としてトラブルシューティングも容易になる可能性があります。

最後に、行末の 4 つ目の項目を見てみましょう。

200 0 0 15

末尾の数字 15 は、HTTP 要求の応答時間 (ミリ秒) です。これは非常に有益な情報です。要求の処理にかかった時間を知ることは、特定のコード スニペット、Web サービス、またはプロセスにかかっている時間が想定通りであることや "正常" であることを判断するのに役立ちます。

ある処理の比較的単純な手順に想定外の時間がかかっているのを発見して驚くことがあります。最近、アプリケーションのログインに成功したり失敗したりするケースがありました。トラップできるブラウザー エラーはおろか何のエラーも表示されずに、ログインに失敗するだけです。ログに記録された応答時間から、web.config ファイルに以下のプロパティがあるのを見つけました。

<add name="CacheProfile1" duration="30" />

この 30 秒の設定は一見無害に見えますが、このパラメーター値が単純に大きすぎたのです。値を下げると、アプリケーションは想定どおりに機能しました。

ここで、上記で取り上げた中で最も重要なパラメーターの 1 つに注目します (わかりやすくするために下記に行をもう一度示します)。最初の項目 200 は IIS から実際に返された HTTP 応答です。

200 0 0 15

HTTP 応答コード 200 は成功を意味します。エラーが発生すると、多くの場合、404 (見つかりません) や 500 (内部サーバー エラー) など、トラブルシューティングや問題の解決に役立つ情報を提供する既知のエラーの種類が見つかります。HTTP 状態コードの正式なリストについては、bit.ly/17sGpwE(英語) を参照してください。

さて、今回このコラムを執筆するきっかけとなった、実際のケースをもう 1 つ紹介します。PC では問題もなく実行され機能していた Web サイトに iPad デバイスからアクセスすると、ビデオ ストリームが単純に機能しなくなります。問題なのは、エラーコードが表示されず、ビデオが機能しないだけなのです。

このような状況では、ログによるトラブルシューティングが非常に有益であることが実証されます。(問題の要求を切り分けるために) ログを確認して Safari からの HTTP 要求をチェックし、サーバーから 404 エラーが返されていることがわかりました。エラー メッセージは分かりづらく、サイトの PC バージョンでは何の問題もなく機能していたので、エラー自体も信じがたいように思われました。

ログではオブジェクトが見つからなかったと報告されていますが、ファイルが適切な場所にあることはわかっています。この問題によって、iOS と Windows のファイルの制御方法と保存方法の違いがわかりました。ビデオを読み込むソース コードを確認すると、ビデオ ファイルの実際のパスをハード コーディングしていて、そのパスが iOS iPad デバイスに存在しませんでした。これが 404 が返される原因です。

ここで重要なことは、生じたすべての現象が他の原因を示していたことです。たとえば、このような問題は、通常、IIS がサポートしないメディアの種類 (Multipurpose Internet Mail Extensions (MIME)) の存在をチェックすれば解決できます。しかし、MIME の種類が存在しないことに問題があれば、エラー コードは HTTP 415 (サポートされていないメディアの種類) のようなエラーになりますが、ログにはそのコードが記録されていません。IIS のログを使用するデバッグは、この問題を見つけられたことで有益だと証明されました。可能性が高いと考えることから原因を追求していくのではなく、実際のエラー コードをチェックして、それを調べることで多くの時間が節約されます。繰り返しになりますが、ログの読み取り方を知っていれば時間を節約できます。

まとめ

"理解しがたい" 状況に遭遇しても、ログ ファイルが、アプリケーションのデバッグやトラブルシューティングの強力なツールになります。ただし、ログの中で調べる場所と、情報の意味を理解していることが前提です。ログ内のデータの調査は、問題を見つけて解決するのに、最も簡単 (かつ、洗練されていて完璧) な方法の 1 つです。

少しの実践とある程度の訓練が必要になりますが、このテクニックを磨けば、アプリケーションや IIS の問題の大半はデバッグして解決できるようになります。このようなテクニックはだれにでも有効な手段です。

Eduardo Sanabria は、テキサス州エル パソの HP Enterprise Services の Service Delivery Consultant IV です。その立場で彼は、質の高い結果を残し、現在のプロジェクトでは .NET 該当分野の専門家 (SME) としての役割を果たしています。Sanabria はアプリケーション開発のすべてのサイクルでの 25 年以上の経験を生かして Hewlett-Packard で活躍しています。彼の専門は、.NET、データベース アプリケーション、データ処理、および Web 開発です。Sanabria の連絡先は EdSanabria@Yahoo.com(英語のみ) です。

この記事のレビューに協力してくれた技術スタッフの Roger Hawkins (Hewlett-Packard) に心より感謝いたします。
Roger Hawkins は、Hewlett-Packard の全米最高技術責任者であり、著名な技術者であり、同社の HP フェローでもあります。 "