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

项目
07/03/2023

适用于： Internet 信息服务

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

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

在这些情况下，很难定义错误是什么，更难诊断错误。可以通过检查请求日志或错误日志来确定导致错误的 URL，但确定导致错误发生的原因可能仍很困难。

Internet Information Services (IIS) ，通过失败请求跟踪可以更轻松地跟踪和诊断这些困难的错误条件，这使你可以创建可自动捕获特定请求的详细执行跟踪的失败定义。请参阅使用 IIS 中的跟踪对失败的请求进行故障排除和使用失败的请求跟踪来跟踪重写规则。

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

另一个相当常见的应用程序问题是挂起或进入资源密集型循环的代码。这通常可能是因为：

文件或网络上的阻止 I/O 操作需要很长时间才能完成，例如访问远程 Web 服务或数据库时。
代码具有一个 bug，导致它进入无休止的 (或长时间运行的) 循环，也可能旋转 CPU 或分配内存。
代码在共享资源或锁上挂起或死锁。

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

IIS 提供一种快速方法，通过检查当前正在执行的请求来确定哪些请求挂起。

使用失败的请求跟踪来诊断未知或难以重现的错误

失败请求跟踪是跟踪间歇性或难以重现错误条件和诊断错误条件的有效方法，方法是检查有关来自 IIS 模块的请求、响应和大量跟踪事件的详细信息。

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

若要在此示例中为站点 (启用失败请求跟踪，请使用 TroubleshootingPhp) ，使用以下步骤：

切换到 IIS 管理器。如果已关闭，请选择“ 启动”，然后选择“ Internet Information Services (IIS) 管理器”。
展开“ 服务器 ”节点，然后展开“ 站点” 节点。
在左侧的树视图中，找到并选择站点的名称。
在 “IIS”下，双击“ 失败的请求跟踪规则”。
在 “操作” 面板中，选择“ 编辑站点跟踪”。
选中 “启用” 复选框。
选择“确定”。
现在，创建失败的请求跟踪规则。在 “操作” 面板中，选择“ 添加”。
使“ 所有内容 ”选项保持选中状态。
选择“下一步”。
在状态代码中输入 400-999 () 。
选择“下一步”。
使默认跟踪提供程序保持启用状态，然后选择“ 完成”。
现在，可以发出请求。对于这些步骤，假设请求是由网站的其他用户发出的，而你不知道他们的请求或响应。例如，使用 Internet Explorer 发出以下请求：
- 请求 http://localhost:84/hello.php
- 请求 http://localhost:84/products.php?productid=3
- 请求 http://localhost:84/products.php?productid=5 (此页面生成错误)
查找失败的请求跟踪：
- 选择 “开始”， 然后选择“ 命令提示符” 以打开“命令提示符”窗口。
- 运行以下命令，列出为站点生成的跟踪日志：
```
%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，因为不会看到其他查询字符串的失败， (如果经常访问此页面，则此结论会更准确;在这种情况下，仅看到此特定查询字符串) 的多个错误。

现在可以获取特定的跟踪日志，以收集有关请求的详细信息以及失败的可能原因。为此，请使用上一个输出) 中带引号的跟踪日志 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"

检查跟踪日志。使用此示例中上一个输出 (中指定的路径在浏览器中打开跟踪日志文件，C:\inetpub\logs\FailedReqLogFiles\W3SVC2\fr000001.xml) 。 “摘要”选项卡提供有关请求的基本信息。可以看到错误状态是由 FastCGIModule 设置的，这表明错误来自 PHP。在其他情况下，你可能会看到错误来自其他 IIS 模块，在这种情况下，可以使用日志中的大量跟踪信息来确定原因。但是，在这种情况下，需要实际查看 PHP 生成的响应，以便深入了解错误。
选择“ 压缩视图 ”选项卡。此选项卡显示 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 核心，则消耗 CPU (近 100%（如果有多个 CPU 核心），则进程消耗了总 CPU) 的 1/# 内核。可以确定哪个请求挂起：

选择 “开始”，然后选择“ Internet Information Services (IIS) 管理器”。
在左侧的树视图中，选择“ 服务器 ”节点。
在 “IIS”下，双击“ 工作进程”。
在 “应用程序池名称”下，双击应用程序池名称以打开 “请求” 视图。 (在此示例中，它是 疑难解答Php.)
切换到 Web 浏览器，并在页面超时时刷新页面。可能需要在整个这些步骤中完成此操作。切换回 IIS 管理器，然后刷新 “请求” 视图。
观察当前正在执行的请求的列表，其中显示了对问题页的请求，在此示例中为 /loop.php。请求条目显示：
- 请求已执行一段时间 (已用时间) 。
- 此示例中请求 (的 URL /loop.php) 。
- 模块名称 (FastCGIModule) 。
- 执行阶段 (ExecuteRequestHandler) 。

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

使用命令提示符确定哪个请求正在挂起。使用命令提示符，可以筛选出感兴趣的请求，例如对特定应用程序或特定 URL 的请求。它可用于自动执行监视当前正在执行的请求的脚本。选择“ 开始”，然后选择“命令提示符”，打开“ 命令提示符”窗口。
切换到 Web 浏览器，然后刷新页面 http://localhost:84/loop.php 。 (请注意， loop.php 是示例名称;应使用页面名称。) 可能需要持续刷新此页面以执行以下步骤。切换到 命令提示符。

运行以下命令，列出已执行超过一秒的请求：

%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

通过

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

使用失败的请求跟踪来诊断未知或难以重现的错误

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

更多信息

反馈

反馈

其他资源