排查 ARR 中的 502 错误
本文可帮助你解决与应用程序请求路由(ARR)中的 502 个错误相关的问题。
适用于: Internet Information Services
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 | time-taken |
---|---|---|---|
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 | time-taken |
---|---|---|---|---|---|---|---|---|---|---|---|
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 服务器报告了一个超时,这是你应该首先查看的位置。
尽管成员服务器日志指示响应是在 45 秒(45208 毫秒)中发送的,但 ARR 服务器的 IIS 日志条目表示花费的时间非常接近 30 秒。 这表示 ARR 超时请求,可以通过查看服务器场的代理设置中的代理超时来确认这一点。 默认情况下,它设置为 30 秒。
因此,在这种情况下,可以清楚地看到 ARR 超时时间比请求的执行时间短。 因此,可能需要检查此执行时间是否是典型的,或者是否需要调查请求花费的时间是否超过预期。 如果该执行时间是正常的预期时间,则增加 ARR 超时应可解决该错误。
ERROR_WINHTTP_TIMEOUT 的其他可能原因包括:
ResolveTimeout
:如果名称解析花费的时间超过指定的超时期限,则会发生此错误。ConnectTimeout
:如果在解析名称后连接到服务器的超时时间超过指定的超时期限,则会发生此情况。SendTimeout
:发送请求的时间超过此超时值时发生。 发送操作已取消。ReceiveTimeout
:如果响应花费的时间超过此超时值,则会发生此情况。 请求已取消。
当你观察前两个原因时, ResolveTimeout
前面 ConnectTimeout
概述的故障排除方法将不起作用。 这是因为不会在目标服务器上看到任何流量,因此不知道错误代码。 因此,在这种情况下ResolveTimeout
ConnectTimeout
,或者你可能想要捕获 WinHTTP 跟踪以获取其他见解。 有关故障排除和跟踪的其他示例,请参阅 WinHTTP 或 WEBIO 跟踪部分和以下博客:
502.3 连接终止错误
当 ARR 与成员服务器之间的连接中途断开时,也会返回 502.3 错误。 若要测试此类问题,请创建调用的.aspx页 Response.Close()
。 在以下示例中,有一个名为“time”的目录,该目录配置为.aspx页作为该目录中的默认文档。 尝试浏览到目录时,ARR 会显示以下错误消息:
错误 0x80072efe 对应于 ERROR_INTERNET_CONNECTION_ABORTED。 请求可以跟踪到实际使用此故障排除程序前面所用的相同步骤处理该请求的服务器,但有一个例外。 虽然目标服务器上的失败请求跟踪显示服务器上处理的请求,但关联的日志条目不会显示在 IIS 日志中。 此请求记录在 HTTPERR 日志中,如下所示:
HTTP/1.1 GET /time/ - 1 Connection_Dropped DefaultAppPool
目标服务器上的内置日志不提供有关该问题的任何其他信息,因此下一步是从 ARR 服务器收集网络跟踪。 在上一示例中,调用 Response.Close()
的.aspx页不返回任何数据。 在网络跟踪中查看此项会显示 Connection: close
HTTP 标头来自目标服务器。 利用此信息,可以开始调查发送标头的原因 Connection: close
。
以下错误是来自成员服务器的无效响应的另一个示例:
在此示例中,ARR 开始从客户端接收数据,但在读取请求实体正文时出了问题。 这导致返回0x80072f78错误代码。 若要进一步调查,请使用 成员服务器上的网络监视器 来获取问题的网络跟踪。 此特定错误示例是在发送响应的一部分后,在 ASP.net 页中调用Response.Close()
,然后调用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 等数据包捕获工具为你提供了准确识别超时所需的信息。但是,有时(例如流量已加密时),需要尝试其他方法。 从 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.cabC:\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 不对这些产品的性能或可靠性提供任何明示或暗示性担保。