排查 ARR 中的 502 错误
本文可帮助你解决与应用程序请求路由 (ARR) 中的 502 错误相关的问题。
适用于： Internet 信息服务
HTTP 502 - 概述
使用 IIS 应用程序请求路由 (ARR) 部署时，可能会看到的错误之一是“HTTP 502 - 错误的网关”。 502.3 错误意味着，在充当代理时，ARR 无法完成对上游服务器的请求并将响应发送回客户端。 出现此问题的原因有多种。 例如，无法连接到服务器、没有来自服务器的响应，或者服务器花费了太长时间才做出响应， () 超时。 如果能够通过从控制器浏览 Web 场来重现错误，并且服务器上启用了 详细错误 ，则可能会看到类似于以下错误消息的错误：
错误的根本原因决定了应执行哪些操作来解决此问题。
502.3 超时错误
ARR 使用上述屏幕截图中的错误代码来代理请求并确定失败的根源，因为它包含来自 WinHTTP 的返回代码。
可以使用工具 err.exe解码错误代码。 在此示例中，错误代码映射到 ERROR_WINHTTP_TIMEOUT。 还可以在 ARR 控制器上关联网站的 IIS 日志中找到此信息。 以下是 502.3 错误的 IIS 日志条目的摘录，其中大部分字段都进行了剪裁，以便提高可读性：
| sc-status | sc-substatus | sc-win32-status | 所花费的时间 |
|---|---|---|---|
| 502 | 3 | 12002 | 29889 |
win32 状态 12002 映射到错误页中报告的相同ERROR_WINHTTP_TIMEOUT错误。
究竟是什么超时？
可以通过在 IIS 服务器上启用失败请求跟踪来检查此超时。 可以在失败的请求跟踪日志中看到的第一个点，这是在 ARR_SERVER_ROUTED 事件中将请求发送到的位置。 第二点是 X-ARR-LOG-ID，可用于跟踪目标服务器上的请求。 这有助于跟踪 HTTP 请求的目标或目标：
77. ARR_SERVER_ROUTED RoutingReason="LoadBalancing", Server="192.168.0.216", State="Active", TotalRequests="3", FailedRequests="2", CurrentRequests="1", BytesSent="648", BytesReceived="0", ResponseTime="15225" 16:50:21.033
78. GENERAL_SET_REQUEST_HEADER HeaderName="Max-Forwards", HeaderValue="10", Replace="true" 16:50:21.033
79. GENERAL_SET_REQUEST_HEADER HeaderName="X-Forwarded-For", HeaderValue="192.168.0.204:49247", Replace="true" 16:50:21.033
80. GENERAL_SET_REQUEST_HEADER HeaderName="X-ARR-SSL", HeaderValue="", Replace="true" 16:50:21.033
81. GENERAL_SET_REQUEST_HEADER HeaderName="X-ARR-ClientCert", HeaderValue="", Replace="true" 16:50:21.033
82. GENERAL_SET_REQUEST_HEADER HeaderName="X-ARR-LOG-ID", HeaderValue="dbf06c50-adb0-4141-8c04-20bc2f193a61", Replace="true" 16:50:21.033
83. GENERAL_SET_REQUEST_HEADER HeaderName="Connection", HeaderValue="", Replace="true" 16:50:21.033
以下示例演示目标服务器的“失败请求跟踪”日志上的显示方式。 可以通过匹配两个跟踪中的“X-ARR-LOG-ID”值来验证是否已找到正确的请求。
185. GENERAL_REQUEST_HEADERS Headers="Connection: Keep-Alive Content-Length: 0 Accept: */* Accept-Encoding: gzip, deflate Accept-Language: en-US Host: test Max-Forwards: 10 User-Agent: Mozilla/4.0 (compatible; MSIE 8.0; Windows NT 6.1; WOW64; Trident/4.0) X-Original-URL: /time/ X-Forwarded-For: 192.168.0.204:49247 X-ARR-LOG-ID: dbf06c50-adb0-4141-8c04-20bc2f193a61
<multiple entries skipped for brevity>
345. GENERAL_FLUSH_RESPONSE_END BytesSent="0", ErrorCode="An operation was attempted on a nonexistent network connection. (0x800704cd)" 16:51:06.240
在前面的示例中，可以看到 ARR 服务器在发送 HTTP 响应之前已断开连接。 GENERAL_FLUSH_RESPONSE_END时间戳可用作大致指南，以便在目标服务器上的 IIS 日志中查找相应的条目。
| date | time | s-ip | cs-method | cs-uri-stem | cs-uri-query | s-port | cs-username | sc-status | sc-substatus | sc-win32-status | 所花费的时间 |
|---|---|---|---|---|---|---|---|---|---|---|---|
| 2011-07-18 | 16:51:06 | 192.168.0.216 | GET | /时间/ | - | 80 | - | 200 | 0 | 64 | 45208 |
目标服务器上的 IIS 记录了 HTTP 200 状态代码，指示请求已成功完成。 此外，win32 状态已更改为 64，映射到ERROR_NETNAME_DELETED。 此状态代码通常指示客户端 (ARR 是“客户端”，在这种情况下) 请求完成之前断开连接。
原因
ARR 服务器报告了超时，这是你应该先查看的位置。
尽管成员服务器日志指示响应在 45 秒 (45208 毫秒) 发送，但 ARR 服务器的 IIS 日志条目指示所花费的时间非常接近 30 秒。 这表示 ARR 正在超时请求，可以通过查看服务器场的代理设置中的代理超时来确认这一点。 默认情况下，它设置为 30 秒。
因此，在这种情况下，可以清楚地看到 ARR 超时比请求的执行时间短。 因此，你可能想要检查，以查看此执行时间是否是典型的，或者是否需要调查请求花费的时间超过预期的原因。 如果此执行时间是预期且正常的，则增加 ARR 超时应可解决错误。
ERROR_WINHTTP_TIMEOUT的其他可能原因包括：
-
ResolveTimeout：如果名称解析花费的时间超过指定的超时期限，则发生。 -
ConnectTimeout：如果解析名称后连接到服务器所花费的时间超过指定的超时期限，则发生。 -
SendTimeout：如果发送请求所花费的时间超过此超时值，则发生。 已取消发送操作。 -
ReceiveTimeout：如果响应花费的时间超过此超时值，则发生。 请求已取消。
观察前两个原因和 ConnectTimeout时，ResolveTimeout前面概述的故障排除方法不起作用。 这是因为在目标服务器上看不到任何流量，因此不会知道错误代码。 因此，在这种情况下，ResolveTimeoutConnectTimeout你可能想要捕获 WinHTTP 跟踪以获取其他见解。 有关故障排除和跟踪的其他示例，请参阅 WinHTTP 或 WEBIO 跟踪 部分和以下博客：
502.3 连接终止错误
当 ARR 与成员服务器之间的连接在流中断开连接时，也会返回 502.3 错误。 若要测试此类问题，请创建调用 Response.Close()的.aspx页。 在以下示例中，有一个名为“time”的目录，该目录配置了.aspx页作为该目录中的默认文档。 尝试浏览到目录时，ARR 会显示以下错误消息：
错误0x80072efe对应于ERROR_INTERNET_CONNECTION_ABORTED。 可以将请求跟踪到使用此疑难解答前面所用的相同步骤实际处理请求的服务器，但有一个例外。 虽然目标服务器上的“失败请求跟踪”显示服务器上处理的请求，但关联的日志条目不会出现在 IIS 日志中。 相反，此请求记录在 HTTPERR 日志中，如下所示：
HTTP/1.1 GET /time/ - 1 Connection_Dropped DefaultAppPool
目标服务器上的内置日志不提供有关该问题的任何其他信息，因此下一步是从 ARR 服务器收集网络跟踪。 在前面的示例中，.aspx页调用 Response.Close() ，但不返回任何数据。 在网络跟踪中查看此内容会发现 Connection: close HTTP 标头来自目标服务器。 利用此信息，可以开始调查发送标头的原因 Connection: close 。
以下错误是成员服务器响应无效的另一个示例：
在此示例中，ARR 开始从客户端接收数据，但在读取请求实体正文时出错。 这导致返回0x80072f78错误代码。 若要进一步调查，请在成员服务器上使用 网络监视器 来获取问题的网络跟踪。 此特定错误示例是在发送部分响应然后调用 Response.Close() 后在 ASP.net 页中调用 Response.Flush()创建的。 如果 ARR 服务器与成员服务器之间的流量通过 SSL，则 Windows Server 2008 上的 WinHTTP 跟踪或 Windows Server 2008 R2 上的 WebIO 跟踪可能会提供其他信息。 WebIO 跟踪稍后将在此疑难解答中介绍。
502.4 找不到合适的服务器来路由请求
HTTP 502.4 错误以及关联的错误代码0x00000000通常表示服务器场的所有成员都处于脱机状态或无法访问。
第一步是验证成员服务器是否处于联机状态。 若要检查此问题，请转到 IIS 管理器中场下的“服务器”节点。
若要恢复脱机服务器，请右键单击服务器名称，然后选择“ 添加到负载均衡”。 如果无法使服务器重新联机，请验证成员服务器是否可以从 ARR 服务器访问。 查看“服务器”页中的“跟踪消息”窗格，查找有关问题的一些线索。 如果使用 Web 场框架 (WFF) 2.0，则可能会在应用程序池重启时收到此错误。 需要重启 Web 场服务才能恢复。
WinHTTP 或 WebIO 跟踪
通常， 像 WireShark 这样的数据包捕获工具会为你提供所需的信息，以准确识别超时的内容。但是，有时 (，例如，当流量是 SSL 加密) ，你将需要尝试其他方法。 从 Windows 7 和 Windows Server 2008 R2 开始，可以通过从管理命令提示符运行以下命令，使用 netsh 工具启用 WinHTTP 跟踪：
netsh trace start scenario=internetclient capture=yes persistent=no level=verbose tracefile=c:\temp\net.etl
然后，重现问题。 重现问题后，通过运行以下命令停止跟踪：
netsh trace stop
该 stop 命令需要几秒钟才能完成。 完成后，可以在 中找到 net.etl 文件和 net.cab 文件 C:\temp。 在运行上述命令之前， C:\temp 需要确保文件夹存在。 .cab 文件包含事件日志和其他数据，这些日志和其他数据可能有助于分析 .etl 文件。
若要分析日志，
在 Netmon 3.4 或更高版本中打开它。
请确保已设置分析程序配置文件。 为此，请打开“ 工具>选项” 菜单，选择“ 分析程序配置文件” 选项卡 >“Windows 配置文件”，然后选择“ 设置为活动 ”按钮以应用更改。
滚动跟踪，直到找到运行 ARR 的w3wp.exe 实例，方法是与 UT 进程名称 列相关联。
右键单击 w3wp，然后选择“ 添加 UT 进程名称”以显示筛选器。 这会设置类似于以下内容的显示筛选器：
UTProcessName == "w3wp.exe (1432)"
可以通过将结果更改为以下内容来进一步筛选结果：
UTProcessName == "w3wp.exe (<pid>)" AND ProtocolName == "WINHTTP_MicrosoftWindowsWinHttp"
需要滚动浏览输出，直到找到超时错误。 在以下示例中，请求超时，因为运行时间超过 30 秒 (ARR 的默认超时) 。
336 2:32:22 PM 7/22/2011 32.6380453 w3wp.exe (1432) WINHTTP_MicrosoftWindowsWinHttp WINHTTP_MicrosoftWindowsWinHttp:12:32:23.123 ::sys-recver starts in _INIT state
337 2:32:22 PM 7/22/2011 32.6380489 w3wp.exe (1432) WINHTTP_MicrosoftWindowsWinHttp WINHTTP_MicrosoftWindowsWinHttp:12:32:23.123 ::current thread is not impersonating
340 2:32:22 PM 7/22/2011 32.6380584 w3wp.exe (1432) WINHTTP_MicrosoftWindowsWinHttp WINHTTP_MicrosoftWindowsWinHttp:12:32:23.123 ::sys-recver processing WebReceiveHttpResponse completion (error-cdoe = ? (0x5b4), overlapped = 003728F0)
341 2:32:22 PM 7/22/2011 32.6380606 w3wp.exe (1432) WINHTTP_MicrosoftWindowsWinHttp WINHTTP_MicrosoftWindowsWinHttp:12:32:23.123 ::sys-recver failed to receive headers; error = ? (1460)
342 2:32:22 PM 7/22/2011 32.6380800 w3wp.exe (1432) WINHTTP_MicrosoftWindowsWinHttp WINHTTP_MicrosoftWindowsWinHttp:12:32:23.123 ::ERROR_WINHTTP_FROM_WIN32 mapped (?) 1460 to (ERROR_WINHTTP_TIMEOUT) 12002
343 2:32:22 PM 7/22/2011 32.6380829 w3wp.exe (1432) WINHTTP_MicrosoftWindowsWinHttp WINHTTP_MicrosoftWindowsWinHttp:12:32:23.123 ::sys-recver returning ERROR_WINHTTP_TIMEOUT (12002) from RecvResponse()
344 2:32:22 PM 7/22/2011 32.6380862 w3wp.exe (1432) WINHTTP_MicrosoftWindowsWinHttp WINHTTP_MicrosoftWindowsWinHttp:12:32:23.123 ::sys-req completes recv-headers inline (sync); error = ERROR_WINHTTP_TIMEOUT (12002)
在以下示例中，内容服务器已完全脱机：
42 2:26:39 PM 7/22/2011 18.9279133 WINHTTP_MicrosoftWindowsWinHttp WINHTTP_MicrosoftWindowsWinHttp:12:26:39.704 ::WinHttpReceiveResponse(0x11d23d0, 0x0) {WINHTTP_MicrosoftWindowsWinHttp:4, NetEvent:3}
43 2:26:39 PM 7/22/2011 18.9279633 WINHTTP_MicrosoftWindowsWinHttp WINHTTP_MicrosoftWindowsWinHttp:12:26:39.704 ::sys-recver starts in _INIT state {WINHTTP_MicrosoftWindowsWinHttp:4, NetEvent:3}
44 2:26:39 PM 7/22/2011 18.9280469 WINHTTP_MicrosoftWindowsWinHttp WINHTTP_MicrosoftWindowsWinHttp:12:26:39.704 ::current thread is not impersonating {WINHTTP_MicrosoftWindowsWinHttp:4, NetEvent:3}
45 2:26:39 PM 7/22/2011 18.9280776 WINHTTP_MicrosoftWindowsWinHttp WINHTTP_MicrosoftWindowsWinHttp:12:26:39.704 ::sys-recver processing WebReceiveHttpResponse completion (error-cdoe = WSAETIMEDOUT (0x274c), overlapped = 003728F0) {WINHTTP_MicrosoftWindowsWinHttp:4, NetEvent:3}
46 2:26:39 PM 7/22/2011 18.9280802 WINHTTP_MicrosoftWindowsWinHttp WINHTTP_MicrosoftWindowsWinHttp:12:26:39.704 ::sys-recver failed to receive headers; error = WSAETIMEDOUT (10060) {WINHTTP_MicrosoftWindowsWinHttp:4, NetEvent:3}
47 2:26:39 PM 7/22/2011 18.9280926 WINHTTP_MicrosoftWindowsWinHttp WINHTTP_MicrosoftWindowsWinHttp:12:26:39.704 ::ERROR_WINHTTP_FROM_WIN32 mapped (WSAETIMEDOUT) 10060 to (ERROR_WINHTTP_TIMEOUT) 12002 {WINHTTP_MicrosoftWindowsWinHttp:4, NetEvent:3}
48 2:26:39 PM 7/22/2011 18.9280955 WINHTTP_MicrosoftWindowsWinHttp WINHTTP_MicrosoftWindowsWinHttp:12:26:39.704 ::sys-recver returning ERROR_WINHTTP_TIMEOUT (12002) from RecvResponse() {WINHTTP_MicrosoftWindowsWinHttp:4, NetEvent:3}
其他资源
第三方信息免责声明
本文中提到的第三方产品由 Microsoft 以外的其他公司提供。 Microsoft 不对这些产品的性能或可靠性提供任何明示或暗示性担保。