次の方法で共有

失敗した要求トレースによる PHP エラーのトラブルシューティング

適用対象: インターネット インフォメーション サービス

PHP を実行しているときに、エラーページを調べてエラー状態を診断できない場合があります。 以下の原因が考えられます。

  • エラーが発生している URL がわからない。
  • エラーは断続的に発生し、手動で再現することはできません (エラーは、ユーザー入力または頻繁に発生しない可能性がある外部の動作条件によって異なる場合があります)。
  • エラーの発生が運用環境に限定される。

このような場合、エラーの内容を定義することは困難であり、診断はさらに困難です。 要求ログまたはエラー ログを調べることで、エラーの原因となっている URL を特定できる場合がありますが、エラーの原因を特定できない場合もあります。

インターネット インフォメーション サービス (IIS) を使用すると、失敗した要求トレースを使用してこれらの困難なエラー状態を追跡および診断しやすくなります。これにより、特定の要求の詳細な実行トレースを自動的にキャプチャするエラー定義を作成できます。 「 IIS でトレースを使用して失敗した要求をトラブルシューティングする と 失敗した要求トレースを使用して書き換えルールをトレースするを参照してください。

PHP 診断に役立つよう、これらのトレースを作成して、PHP からの要求入力データと応答データをキャプチャすることもできます。 これにより、これらのエラー状態を診断するために必要な分析情報を得ることができます。

もう 1 つの非常に一般的なアプリケーションの問題は、コードがハングしたり、リソースの消費が激しいループに陥ったりすることです。 これは、多くの場合、次の理由で発生します。

  • ファイルやネットワークに対するブロック I/O 操作の完了に時間がかかっている。たとえば、リモートの Web サービスやデータベースにアクセスする場合が該当します。
  • コードにバグがあり、無限 (または実行時間の長い) ループに陥っている。CPU を占有したりメモリを割り当てたりする可能性もあります。
  • コードが共有リソースやロックでハングまたはデッドロック状態になっている。

これらの条件により、要求を行うユーザーの待ち時間やタイムアウトが長くなります。また、この条件は、アプリケーションのパフォーマンスやサーバー全体にも悪影響を与える可能性もあります。

IIS では、現在実行中の要求を調べることで、ハングしている要求を簡単に特定できます。

失敗した要求トレースを使用して、不明または再現困難なエラーを診断する

失敗した要求のトレースは、断続的または再現困難なエラーの状態を追跡し、要求や応答、さらには IIS モジュールからの豊富なトレース イベントに関する詳細を調べることでエラー状態を診断する効果的な方法となる場合があります。

失敗した要求のトレースは、特定のエラー定義を満たす要求のみをトレースするように構成でき、成功した要求のトレース オーバーヘッドの大部分を回避できるため、運用環境で使用できます。

サイトの失敗した要求トレースを有効にするには (このサンプルでは、 TroubleshootingPhp を使用します)、次の手順を使用します。

  1. IIS マネージャーに切り替えます。 閉じている場合は、Start を選択し、インターネット インフォメーション サービス (IIS) マネージャーを選択します。

  2. [サーバー] ノードを展開し、[サイト] ノードを展開します。

  3. 左側のツリー ビューで、サイトの名前を見つけて選択します。

  4. [IIS] で、[失敗した要求トレースの規則] をダブルクリックします。
    [失敗した要求トレースルール] アイコンにフォーカスがある [I I S] セクションのスクリーンショット。

  5. [ Actions パネルで、[サイト トレース 編集を選択します。

  6. [ 有効 ] チェック ボックスをオンにします。

  7. [OK] を選択します。

  8. 次に、失敗した要求トレースの規則を作成します。 Actions パネルで、Add を選択します。

  9. [すべてのコンテンツ] オプションはオンのままにします。
    [すべてのコンテンツ] オプションが選択されている [失敗した要求トレースルールの追加] ダイアログ ボックスのスクリーンショット。

  10. [次へ] を選択します。

  11. Status code(s)に「400-999」と入力します。
    状態コードとして 4 0 0 ダッシュ 9 9 9 が入力された [トレース条件の定義] 画面のスクリーンショット。

  12. [次へ] を選択します。

  13. 既定のトレース プロバイダーを有効のままにして、 Finish を選択します。

  14. 要求を行うことができる状態になりました。 これらの手順では、要求がサイトの他のユーザーによって行われ、その要求や応答が認識されていないことを前提としています。 たとえば、Internet Explorer を使用して次の要求を行います。

    • 要求 http://localhost:84/hello.php
    • 要求http://localhost:84/products.php?productid=3。
    • 要求 http://localhost:84/products.php?productid=5 (このページではエラーが発生します)

  15. 失敗した要求のトレースを確認します。

    • [開始]、[] の順に選択し、[コマンド プロンプト] 選択してコマンド プロンプト ウィンドウを開きます。

    • 次のコマンドを実行して、サイトに対して生成されたトレース ログを一覧表示します。

      %windir%\system32\inetsrv\appcmd.exe list traces /site.name:"TroubleshootingPhp"

    • 次のような出力が表示されます。

      TRACE "troubleshootingPhp/fr000001.xml" (url:http://localhost:84/products.php?product=5,statuscode:500,wp:2864)

    • 出力は、 /products.php?product=5要求に対してトレース ログが生成され、HTTP 500 エラーが発生したことを示します。 次のことが示されます。

      • Products.php ページでエラーが発生しました。
      • エラーの原因となった入力は、他のクエリ文字列のエラーが表示されないため、 product=5可能性が高くなります (このページに頻繁にアクセスする場合、この結論はより正確になります。その場合、この特定のクエリ文字列に対してのみ複数のエラーが表示されます)。

  16. では、特定のトレース ログを取得して、要求に関するさらに詳しい情報と、考えられるエラーの原因を収集していきましょう。 これを行うには、コマンド プロンプトから次のコマンドを実行します (前の出力のトレース ログの引用符で囲まれた ID を使用)。

    %windir%\system32\inetsrv\appcmd.exe list traces /site.name:"TroubleshootingPhp" /text:*

    これには、次のような出力が含まれている必要があります。

    TRACELOG
  TRACE.NAME:" troubleshootingPhp/fr000001.xml"
  PATH:"C:\inetpub\logs\FailedReqLogFiles\W3SVC2\fr000001.xml"
URL:"http://localhost:84/products.php?product=5"
  STATUSCODE:"500"
  SITE.ID:"2"
  SITE.NAME:"TroubleshootingPhp"
  WP.NAME:"2864"
  APPPOOL.NAME:"TroubleshootingPhp"
  verb:"GET"
  remoteUserName:""
  userName:""
  tokenUserName:"NT
AUTHORITY\IUSR"
  authenticationType:"anonymous"
  activityId:"{ 00000000-0000-0000-1400-0080000000FA }"
  failureReason:"STATUS_CODE"
  triggerStatusCode:"500"
  timeTaken:"100"
xmlns:freb:"http://schemas.microsoft.com/win/2006/06/iis/freb"

  17. トレース ログを調べます。 前の出力で指定したパスを使用して、ブラウザーでトレース ログ ファイルを開きます (このサンプルでは、 C:\inetpub\logs\FailedReqLogFiles\W3SVC2\fr000001.xml)。 [概要] タブには、要求に関する基本情報が表示されます。 エラーの状態が FastCGIModule によって設定されたことを確認できます。これは、エラーの発生源が PHP であることを示しています。 他の場合は、エラーが他の IIS モジュールから発生している場合があります。その場合は、ログ内の豊富なトレース情報を使用して原因を特定できます。 ただし、この場合は、PHP によって生成された応答を実際に確認して、エラーのより詳しい情報を把握する必要があります。
    要求診断 Web ページの [要求の概要] タブのスクリーンショット。

  18. Compact ビュー タブを選択します。このタブには、要求の処理中に IIS および IIS モジュールによって生成されるトレース イベントの詳細な一覧が表示されます。
    [コンパクト ビュー] タブが強調表示されている [診断の要求] 画面のスクリーンショット。

    注:

    • GENERAL_REQUEST_START イベントには、要求の URL、動詞、サイトに関するランタイム情報、要求のディスパッチ先アプリケーションなど、いくつかの基本情報が表示されます。
    • GENERAL_REQUEST_HEADERS イベントにはヘッダーの完全な一覧が表示されます。エラーを引き起こした可能性のあるユーザー入力を判断するときに重要な手掛かりになる場合があります。
    • GENERAL_RESPONSE_HEADERS イベントと GENERAL_RESPONSE_ENTITY_BUFFER イベントからは、完全な応答ヘッダーと、クライアントに送信された応答本文が得られます。 このケースでは、エラーを診断するために必要な追加情報が応答本文から得られ、製品 ID に誤りがあることがわかります。

その他、トレース ログを調べる際に考慮すべきセクションを次に示します。

  • [要求の概要] パネルには、要求の概要とその結果が表示されるほか、要求の実行中に警告またはエラー イベントが強調表示されます。
  • [要求の詳細] パネルでは、要求の実行を階層表示でき、さまざまなカテゴリ (モジュールの通知、認証/認可など) でイベントをフィルター処理することもできます。また、パフォーマンス ビューもあり、実行のどの部分に最も時間がかかったかを把握するうえで役立ちます。
  • コンパクト ビューには、要求の実行に関する豊富な情報を含め、イベントの完全な一覧が表示されます。 IIS モジュールの多くは、その実行に関する情報を生成します。その情報を利用することで、要求の処理と結果のさまざまな側面を理解することができます。 この情報は、URL の書き換えや認証など、複雑な対話式操作のトラブルシューティングを行うときに非常に役立ちます。

現在の要求の実行状態を調査して、ハングしている要求を特定する

IIS では、現在実行中の要求を調べることで、ハングしている要求を簡単に特定できます。

あるページを要求すると、プログラムのバグが原因で無限ループに陥るとします。 次の手順では、このページは loop.php。 タスク マネージャーでは、Php-cgi.exeがビジー状態であり、CPU の 100% 近くを消費している場合があります (複数の CPU コアがある場合は、合計 CPU の 1/# のコアを消費するプロセスが表示されます)。 どの要求がハングしているかを特定してみましょう。

  1. Start を選択し、インターネット インフォメーション サービス (IIS) マネージャーを選択します。

  2. 左側のツリー ビューで、 Server ノードを選択します。

  3. [IIS] の [ワーカー プロセス] をダブルクリックします。

  4. アプリケーション プール名でアプリケーション プール名をダブルクリックして、Requests ビューを開きます。 (この例では、 TroubleshootingPhp.)
    [アプリケーション プール名] が強調表示されている [ワーカー プロセス] 画面のスクリーンショット。

  5. ページがタイムアウトした場合は、Web ブラウザーに切り替えてページを最新の情報に更新します。これは、これらの手順全体で必要になります。 IIS マネージャーに戻り、[要求] ビューを最新の情報に更新します。

  6. 現在実行中の要求の一覧を確認し、問題のページへの要求を示します。このサンプルでは、 /loop.php。 要求のエントリから次のことがわかります。

    • 要求がしばらく実行されていること (経過時間)。
    • 要求の URL (このサンプルでは、 /loop.php)。
    • モジュール名 (FastCGIModule)。
    • 実行ステージ (ExecuteRequestHandler)。

ビューを何度か更新すると、同じ要求が同じステージで実行され続けていることが確認できます。これは、要求がハングしていることを示します。

  • コマンド プロンプトを使用して、ハングしている要求を特定します。 コマンド プロンプトでは、特定のアプリケーションや特定の URL への要求など、関心のある要求をフィルターで抽出できます。 これを利用して、現在実行中の要求を監視するスクリプトを自動化できます。 コマンド プロンプト ウィンドウを開くには、 Start を選択し、コマンド プロンプト 選択します。

  • Web ブラウザーに切り替えて、http://localhost:84/loop.php ページを最新の情報に更新します ( loop.php はサンプル名であり、ページの名前を使用する必要があることに注意してください)。次の手順では、このページを継続的に更新する必要がある場合があります。 コマンド プロンプトに切り替えます。

  • 次のコマンドを実行して、1 秒以上実行されている要求を一覧表示します。

    %windir%\system32\inetsrv\appcmd.exe list requests /elapsed:1000

    loop.phpではなく、ページ名を使用して、次のような出力が表示されます。

    REQUEST " fa000000080000026" (url:GET /loop.php, time:2840 msec, client:localhost, stage:ExecuteRequestHandler, module:FastCgiModule)

  • 利用できる要求の属性に基づいて任意の数の条件を指定し、返される要求をフィルター処理します。 たとえば、特定の URL への要求のみを表示するには、次のようにします。

    %windir%\system32\inetsrv\appcmd.exe list requests /url:/loop.php /elapsed:1000

  • AppCmd コマンド リンクを使用して、より複雑なクエリを実行することもできます。たとえば、実行時間の長い要求を持つすべてのアプリケーションを特定できます。

    %windir%\system32\inetsrv\appcmd.exe list requests /elapsed:1000 /xml | %windir%\system32\inetsrv\appcmd list apps /in

    次のようなアプリケーションの一覧が表示されます。

    APP "troubleshootingPhp/" (applicationPool:troubleshootingPhp)

  • 現在の要求データに基づいてアクションを実行する例を次に示します。5 秒以上実行されている要求を使用してアプリケーション プールをリサイクルします。

    %windir%\system32\inetsrv\appcmd.exe list requests /elapsed:1000 /xml | %windir%\system32\inetsrv\appcmd list apppools /in /xml | %windir%\system32\inetsrv\appcmd recycle apppools /in

    アプリケーションの名前を含む次の出力が表示されます。

    "TroubleshootingPhp" successfully recycled

詳細