Solução de problemas de 502 erros no ARR

Este artigo ajuda você a resolve os problemas relacionados a 502 erros no ARR (Roteamento de Solicitação de Aplicativo).

Aplica-se a: Serviços de Informações da Internet

HTTP 502 – Visão geral

Quando você trabalha com implantações do ARR (Roteamento de Solicitação de Aplicativo) do IIS, um dos erros que você pode ver é "HTTP 502 – Gateway Ruim". O erro 502.3 significa que, enquanto atuava como proxy, o ARR não pôde concluir a solicitação para o servidor upstream e enviar uma resposta de volta ao cliente. Esse problema pode acontecer por vários motivos. Por exemplo, a falha na conexão com o servidor, nenhuma resposta do servidor ou o servidor demorou muito para responder (tempo limite). Se você conseguir reproduzir o erro navegando no web farm do controlador e os erros detalhados estiverem habilitados no servidor, você poderá ver um erro semelhante à seguinte mensagem de erro:

A causa raiz do erro determina o que você deve fazer para resolve o problema.

502.3 erros de tempo limite

O ARR usa o código de erro na captura de tela anterior para proxy da solicitação e determinar a origem da falha porque ela contém o código de retorno do WinHTTP.

Você pode decodificar o código de erro com a ferramenta err.exe. Neste exemplo, o código de erro é mapeado para ERROR_WINHTTP_TIMEOUT. Você também pode encontrar essas informações nos logs do IIS para o site associado no controlador ARR. Veja a seguir um trecho da entrada de log do IIS para o erro 502.3, com a maioria dos campos cortados para legibilidade:

sc-status	sc-substatus	sc-win32-status	tempo gasto
502	3	12002	29889

O win32 status 12002 mapeia para o mesmo ERROR_WINHTTP_TIMEOUT erro relatado na página de erro.

O que exatamente tempo limite?

Você pode marcar esse tempo limite habilitando o rastreamento de solicitação com falha no servidor IIS. O primeiro ponto que você pode ver, no log de rastreamento de solicitação com falha e é para o qual a solicitação foi enviada no evento ARR_SERVER_ROUTED. O segundo ponto é o X-ARR-LOG-ID, que você pode usar para acompanhar a solicitação no servidor de destino. Isso ajuda a rastrear o destino ou o destino da solicitação 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

O exemplo a seguir mostra como isso pode ser exibido nos logs de rastreamento de solicitação com falha do servidor de destino. Você pode validar que encontrou a solicitação correta correspondendo aos valores "X-ARR-LOG-ID" em ambos os rastreamentos.

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

No exemplo anterior, você pode ver que o servidor ARR foi desconectado antes da resposta HTTP ser enviada. O carimbo de data/hora para GENERAL_FLUSH_RESPONSE_END pode ser usado como um guia bruto para localizar a entrada correspondente nos logs do IIS no servidor de destino.

data	hora	s-ip	método cs	cs-uri-stem	cs-uri-query	s-port	cs-username	sc-status	sc-substatus	sc-win32-status	tempo gasto
2011-07-18	16:51:06	192.168.0.216	OBTER	/Tempo/	-	80	-	200	0	64	45208

O IIS no servidor de destino registrou um código HTTP 200 status, indicando que a solicitação foi concluída com êxito. Além disso, o status win32 mudou para 64, que mapeia para ERROR_NETNAME_DELETED. Esse código status geralmente indica que o cliente (ARR sendo o 'cliente' nesse caso) desconectado antes da solicitação ser concluída.

Motivo

O servidor ARR relatou um tempo limite, que é onde você deve procurar primeiro.

Embora o log do servidor membro indique que a resposta foi enviada em 45 segundos (45208 ms), a entrada de log do IIS do servidor ARR indica que o tempo gasto é muito próximo de 30 segundos. Isso indica que o ARR está cronometrando a solicitação e você pode confirmar isso examinando o tempo limite de proxy nas configurações de proxy do farm do servidor. Por padrão, ele é definido como 30 segundos.

Portanto, nesse caso, você pode ver claramente que o tempo limite do ARR foi menor do que a execução da solicitação. Portanto, talvez você queira marcar para ver se esse tempo de execução era típico ou se você precisava examinar por que a solicitação estava demorando mais do que o esperado. Se esse tempo de execução fosse esperado e normal, o aumento do tempo limite do ARR deverá resolve o erro.

Outros possíveis motivos para ERROR_WINHTTP_TIMEOUT incluem:

• ResolveTimeout: ocorre se a resolução de nomes demorar mais do que o período de tempo limite especificado.
• ConnectTimeout: ocorre se demorar mais do que o período de tempo limite especificado para se conectar ao servidor após a resolução do nome.
• SendTimeout: ocorre se o envio de uma solicitação demorar mais do que esse valor de tempo limite. A operação de envio foi cancelada.
• ReceiveTimeout: ocorre se uma resposta demorar mais do que esse valor de tempo limite. A solicitação foi cancelada.

Quando você observa os dois primeiros motivos ResolveTimeout e ConnectTimeout, a metodologia de solução de problemas descrita anteriormente não funcionaria. Isso ocorre porque você não veria nenhum tráfego no servidor de destino e, portanto, não saberia o código de erro. Portanto, neste caso de ResolveTimeout ou ConnectTimeout talvez você queira capturar um rastreamento WinHTTP para obter informações adicionais. Consulte a seção rastreamento WinHTTP ou WEBIO e nos seguintes blogs para obter outros exemplos sobre solução de problemas e rastreamento:

• Gateway inválido 502.3 "A operação tempo limite" com o Roteamento de Solicitação de Aplicativo do IIS (ARR)
• Opções de rastreamento winhttp para solução de problemas com roteamento de solicitação de aplicativo

502.3 Erros de término de conexão

Erros 502.3 também são retornados quando a conexão entre a ARR e o servidor membro é desconectada no meio do fluxo. Para testar esse tipo de problema, crie uma página .aspx que chama Response.Close(). No exemplo a seguir, há um diretório chamado "time", que é configurado com uma página .aspx como o documento padrão nesse diretório. Quando você tenta navegar até o diretório, o ARR mostra a seguinte mensagem de erro:

O erro 0x80072efe corresponde a ERROR_INTERNET_CONNECTION_ABORTED. A solicitação pode ser rastreada até o servidor que realmente o processou usando as mesmas etapas usadas anteriormente nesta solução de problemas, com uma exceção. Embora o Rastreamento de Solicitação com Falha no servidor de destino mostre a solicitação processada no servidor, a entrada de log associada não aparece nos logs do IIS. Em vez disso, essa solicitação é registrada no log HTTPERR da seguinte maneira:

HTTP/1.1 GET /time/ - 1 Connection_Dropped DefaultAppPool

Os logs internos no servidor de destino não fornecem nenhuma informação adicional sobre o problema, portanto, a próxima etapa seria coletar um rastreamento de rede do servidor ARR. No exemplo anterior, a página .aspx chamada Response.Close() sem retornar nenhum dado. Exibir isso em um rastreamento de rede mostraria que um Connection: close cabeçalho HTTP vinha do servidor de destino. Com essas informações, você pode iniciar uma investigação sobre por que o Connection: close cabeçalho foi enviado.

O seguinte erro é outro exemplo de uma resposta inválida do servidor membro:

Neste exemplo, o ARR começou a receber dados do cliente, mas algo deu errado ao ler o corpo da entidade de solicitação. Isso resultou no retorno do código de erro 0x80072f78. Para investigar mais, use o Monitor de Rede no servidor membro para obter um rastreamento de rede do problema. Este exemplo de erro em particular foi criado chamando Response.Close() na página ASP.net depois de enviar parte da resposta e, em seguida, chamando Response.Flush(). Se o tráfego entre o servidor ARR e os servidores membros estiver acima do SSL, o rastreamento do WinHTTP no Windows Server 2008 ou no rastreamento WebIO no Windows Server 2008 R2 poderá fornecer informações adicionais. O rastreamento webIO é descrito posteriormente nesta solução de problemas.

502.4 Nenhum servidor apropriado pôde ser encontrado para rotear a solicitação

O erro HTTP 502.4 com um código de erro associado de 0x00000000 geralmente indica que todos os membros do farm estão offline ou inacessíveis.

A primeira etapa é verificar se os servidores membros estão online. Para marcar isso, acesse o nó Servidores no farm no Gerenciador do IIS.

Para trazer de volta os servidores offline, clique com o botão direito do mouse no nome do servidor e selecione Adicionar ao Balanceamento de Carga. Se você não puder colocar os servidores novamente online, verifique se os servidores membros podem ser acessados no servidor ARR. Verifique o painel Rastrear Mensagens na página Servidores para procurar algumas pistas sobre o problema. Se você estiver usando o WFF (Web Farm Framework) 2.0, poderá receber esse erro quando o pool de aplicativos for reiniciado. Você precisa reiniciar o Serviço de Farm Web para se recuperar.

Rastreamento WinHTTP ou WebIO

Normalmente, ferramentas de captura de pacotes como o WireShark fornecem as informações necessárias para identificar exatamente o que está em tempo limite. No entanto, há momentos (como quando o tráfego é criptografado por SSL) que você precisará tentar uma abordagem diferente. Começando com o Windows 7 e o Windows Server 2008 R2, você pode habilitar o rastreamento do WinHTTP usando a ferramenta netsh executando o seguinte comando de um prompt de comando administrativo:

netsh trace start scenario=internetclient capture=yes persistent=no level=verbose tracefile=c:\temp\net.etl

Em seguida, reproduza o problema. Depois que o problema for reproduzido, pare o rastreamento executando o seguinte comando:

netsh trace stop

O stop comando leva alguns segundos para ser concluído. Quando terminar, você encontrará um arquivo net.etl e um arquivonet.cab no C:\temp. Você precisará garantir que a C:\temp pasta exista antes de executar os comandos acima. O arquivo .cab contém logs de eventos e outros dados que podem ser úteis na análise do arquivo .etl.

Para analisar o log,

1. Abra-o no Netmon 3.4 ou posterior.

2. Verifique se você configurou seu perfil de analisador. Para isso, abra o menuOpções de Ferramentas>, selecione a guia >Perfis do Analisador Perfil doWindows e selecione o botão Definir como Ativo para aplicar as alterações.

3. Role o rastreamento até encontrar a instânciaw3wp.exe em que o ARR está em execução correlacionando-se com a coluna nome do processo UT .

4. Clique com o botão direito do mouse no w3wp e selecione Adicionar nome do processo UT para exibir o filtro. Isso define o filtro de exibição semelhante a:

   UTProcessName == "w3wp.exe (1432)"
   

Você pode filtrar ainda mais os resultados alterando-os para o seguinte:

UTProcessName == "w3wp.exe (<pid>)" AND ProtocolName == "WINHTTP_MicrosoftWindowsWinHttp"

Você precisará percorrer a saída até encontrar o erro de tempo limite. No exemplo a seguir, uma solicitação foi demorada porque levou mais de 30 segundos (tempo limite padrão da ARR) para ser executada.

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) 

No exemplo a seguir, o servidor de conteúdo estava completamente offline:

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} 

Outros recursos

• Ferramenta de Pesquisa de Erro
• Códigos de erro winhttp
• Rastreamento de solicitação com falha
• Rastreamento winhttp
• Monitor de Rede

Aviso de isenção de responsabilidade para informações de terceiros

Os produtos de terceiros mencionados neste artigo são produzidos por empresas independentes da Microsoft. A Microsoft não oferece nenhuma garantia, implícita ou não, do desempenho ou da confiabilidade desses produtos.