排查失败请求跟踪的 PHP 错误

适用于： Internet Information Services

运行 PHP 时，有时无法检查错误页来诊断错误条件。 在以下情况下可能发生这种问题：

• 你不知道哪个 URL 遇到错误。
• 此错误间歇性地发生，并且无法手动重现错误（此错误可能取决于用户输入或外部操作条件，这些条件可能很少发生）。
• 此错误仅发生在生产环境中。

在这些情况下，很难定义错误是什么，甚至更难诊断错误。 你可以通过检查请求日志或错误日志来确定导致错误的 URL，但在确定导致错误的原因方面可能仍存在问题。

借助 Internet Information Services（IIS），可以使用请求失败跟踪，更轻松地查找和诊断这些复杂的错误情况，从而创建自动捕获特定请求详细执行跟踪的失败定义。 请参阅 使用 IIS 中的跟踪对失败的请求进行故障排除，并使用 失败的请求跟踪来跟踪重写规则。

为了帮助 PHP 诊断，还可执行这些跟踪来捕获请求输入数据和来自 PHP 的响应数据。 这可以提供诊断这些错误状态所需的见解。

另一个相当常见的应用程序问题是代码挂起或陷入资源密集型循环。 发生这种情况的原因通常是：

• 文件或网络上的阻止 I/O 操作需要很长时间才能完成，例如在访问远程 Web 服务或数据库时。
• 代码有一个漏洞，导致它进入无限循环或长时间运行，可能还会导致 CPU 资源大量消耗或造成多余的内存分配。
• 代码在共享资源或锁上挂起或产生死锁。

这些情况导致发出请求的用户等待时间长或超时，也可能对应用程序的性能（甚至整个服务器）产生负面影响。

IIS 提供了一种快速识别挂起请求的方法：通过检查当前正在执行的请求。

使用失败请求追踪诊断未知或难以复现的错误

失败请求跟踪可能是一种有效的方法，用于找到间歇性或难以重现的错误状态，并通过检查有关 IIS 模块中的请求、响应和大量跟踪事件的详细信息来诊断错误状态。

失败请求跟踪可用于生产环境中，因为它可以配置为仅跟踪满足特定故障定义的跟踪请求，并且可以避免成功的请求的大部分跟踪开销。

若要为站点启用失败请求跟踪（在本示例中，我们使用 TroubleshootingPhp），请使用以下步骤：

1. 切换到“IIS 管理器”。 如果已关闭，请选择“开始”，然后选择“Internet Information Services”（IIS）管理器。

2. 展开服务器节点，然后展开站点节点。

3. 在左侧的树视图中，找到并选择网站的名称。

4. 在IIS下，双击失败请求跟踪规则。
   

5. 在 “操作 ”面板中，选择“ 编辑网站跟踪”。

6. 选中“启用”复选框。

7. 选择“确定”。

8. 现在，创建一个失败请求跟踪规则。 在 “操作 ”面板中，选择“ 添加”。

9. 保持“所有内容”选项处于选中状态。
   

10. 选择下一步。

11. 在状态代码中输入 400-999。
    

12. 选择下一步。

13. 使默认跟踪提供程序保持启用状态，然后选择“ 完成”。

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 生成的响应，以便更深入地了解错误。
    

18. 选择“压缩视图”选项卡。此选项卡显示 IIS 和 IIS 模块在处理请求期间生成的跟踪事件的详细列表。
    

    注意:

    • GENERAL_REQUEST_START 事件显示一些基本信息，包括请求 URL、谓词、有关站点的运行时信息以及请求被调度到的应用程序。
    • GENERAL_REQUEST_HEADERS 事件提供标头的完整列表，在某些情况下，确定哪些用户输入可能导致了错误时可能很重要。
    • GENERAL_RESPONSE_HEADERS 和 GENERAL_RESPONSE_ENTITY_BUFFER 事件提供完整的响应头和发送到客户端的响应正文。 在这种情况下，响应正文提供诊断错误所需的额外信息，指示不正确的产品 ID。

下面是检查跟踪日志时应考虑的其他部分：

• “请求摘要”面板提供请求摘要及其结果，并突出显示请求执行期间出现的任何警告或错误事件。
• “请求详细信息”面板提供请求执行的分层视图，还允许按各种类别（例如模块通知、身份验证/授权等）筛选事件。它还提供性能视图，可帮助你了解执行哪些部分所花费的时间最长。
• “紧凑视图”提供事件的完整列表，包括有关执行请求的大量信息。 许多 IIS 模块都生成有关其执行的信息，可用于了解请求的处理和结果的各个方面。 排查复杂的交互问题（例如 URL 重写或身份验证）时，此信息非常有用。

通过检查当前请求的执行情况来查找挂起的请求

有一种快速的方法，可以通过检查 IIS 中正在执行的请求来确定哪些请求处于挂起状态。

假设你请求的页面由于编程 bug 而进入无限循环。 在后续步骤中，此页面 loop.php。 在任务管理器中，你可能会发现Php-cgi.exe繁忙，占用 CPU 的近 100%（如果有多个 CPU 核心，则会看到进程消耗了总 CPU 的 1/# 核心数）。 您可以确定哪个请求处于挂起状态：

1. 选择“开始”，然后选择“Internet Information Services”（IIS）管理器。

2. 在左侧的树视图中，选择“ 服务器 ”节点。

3. 在 IIS 下，双击“工作进程”。

4. 在“应用程序池名称”下，双击应用程序池名称以打开“请求”视图。 （在此示例中，它是 TroubleshootingPhp.）
   

5. 切换到 Web 浏览器，如果页面已超时，则刷新该页面。可能需要不断在这些步骤中执行此操作。 切换回“IIS 管理器”，然后刷新“请求”视图。

6. 观察当前正在执行的请求的列表，其中显示了对问题页的请求（在本示例中为 /loop.php）。 请求条目显示：

   • 请求已执行一段时间（已用时间）。
   • 请求的 URL（在本示例中为 /loop.php）。
   • 模块名 (FastCGIModule)。
   • 执行阶段 (ExecuteRequestHandler)。

可以多次刷新视图，观察同一请求继续在同一阶段的执行情况，指出挂起的请求。

• 使用命令提示符确定挂起的请求。 使用命令提示符，可以筛选掉相关请求，例如对特定应用程序或特定 URL 的请求。 它可用于自动执行监视当前正在执行的请求的脚本。 通过依次选择“开始”和“命令提示符”打开命令提示符窗口。

• 切换到 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)
  

• 以下是一个基于当前请求数据采取措施的示例：将已运行超过五秒的请求所在的应用程序池进行回收。

  %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
  

详细信息

• 错误处理和日志记录