Felsöka 502-fel i ARR

Den här artikeln hjälper dig att lösa problem som rör 502-fel i routning av programbegäran (ARR).

Gäller för: Internet Information Services

HTTP 502 – Översikt

När du arbetar med IIS-distributioner för programbegäransroutning (ARR) är ett av felen som du kan se "HTTP 502 – Felaktig gateway". Felet 502.3 innebär att ARR inte kunde slutföra begäran till den överordnade servern och skicka ett svar tillbaka till klienten när den fungerade som proxy. Det här problemet kan inträffa av flera orsaker. Det gick till exempel inte att ansluta till servern, inget svar från servern eller så tog det för lång tid för servern att svara (tidsgränsen tog slut). Om du kan återskapa felet genom att bläddra i webbgruppen från kontrollanten och detaljerade fel är aktiverade på servern, kan du se ett fel som liknar följande felmeddelande:

Rotorsaken till felet avgör vad du bör göra för att lösa problemet.

Tidsgränsfel för 502.3

ARR använder felkoden i föregående skärmbild för att skicka begäran via proxy och fastställa orsaken till felet eftersom den innehåller returkoden från WinHTTP.

Du kan avkoda felkoden med verktyget err.exe. I det här exemplet mappas felkoden till ERROR_WINHTTP_TIMEOUT. Du kan också hitta den här informationen i IIS-loggarna för den associerade webbplatsen på ARR-kontrollanten. Följande är ett utdrag från IIS-loggposten för 502.3-felet, där de flesta av fälten har trimmats för läsbarhet:

sc-status	sc-substatus	sc-win32-status	tidsåtgång
502	3	12002	29889

Win32-statusen 12002 mappas till samma ERROR_WINHTTP_TIMEOUT fel som rapporterats på felsidan.

Vad exakt timeout?

Du kan kontrollera den här tidsgränsen genom att aktivera spårning av misslyckade förfrågningar på IIS-servern. Den första punkten som du kan se i spårningsloggen för misslyckade förfrågningar och det är här begäran skickades till i ARR_SERVER_ROUTED händelsen. Den andra punkten är X-ARR-LOG-ID, som du kan använda för att spåra begäran på målservern. Detta hjälper till att spåra målet eller målet för HTTP-begäran:

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

I följande exempel visas hur detta kan se ut på målserverns spårningsloggar för misslyckade förfrågningar. Du kan kontrollera att du har hittat rätt begäran genom att matcha värdena för "X-ARR-LOG-ID" i båda spårningarna.

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

I föregående exempel kan du se att ARR-servern kopplades från innan HTTP-svaret skickades. Tidsstämpeln för GENERAL_FLUSH_RESPONSE_END kan användas som en grov guide för att hitta motsvarande post i IIS-loggarna på målservern.

Datum	Tid	s-ip	cs-method	cs-uri-stem	cs-uri-query	s-port	cs-username	sc-status	sc-substatus	sc-win32-status	tidsåtgång
2011-07-18	16:51:06	192.168.0.216	FÅ	/Tid/	-	80	-	200	0	64	45208

IIS på målservern loggade en HTTP 200-statuskod som anger att begäran har slutförts. Dessutom har win32-statusen ändrats till 64, vilket mappar till ERROR_NETNAME_DELETED. Den här statuskoden anger vanligtvis att klienten (ARR är "klienten" i det här fallet) frånkopplad innan begäran slutfördes.

Orsak

ARR-servern rapporterade en timeout, där du bör titta först.

Även om medlemsserverloggen anger att svaret skickades på 45 sekunder (4 5208 ms), anger IIS-loggposten från ARR-servern att den tidsåtgången är mycket nära 30 sekunder. Detta indikerar att ARR överskrider tidsgränsen för begäran, och du kan bekräfta detta genom att titta på proxy-timeouten i servergruppens proxyinställningar. Som standard är den inställd på 30 sekunder.

I det här fallet kan du alltså tydligt se att ARR-tidsgränsen var kortare än körningen av begäran. Därför kanske du vill kontrollera om den här körningstiden var typisk eller om du behövde undersöka varför begäran tog längre tid än förväntat. Om den här körningstiden var förväntad och normal bör du lösa felet genom att öka ARR-tidsgränsen.

Andra möjliga orsaker till ERROR_WINHTTP_TIMEOUT är:

• ResolveTimeout: Inträffar om namnmatchningen tar längre tid än den angivna tidsgränsen.
• ConnectTimeout: Inträffar om det tar längre tid än den angivna tidsgränsen att ansluta till servern efter att namnet har lösts.
• SendTimeout: Inträffar om det tar längre tid att skicka en begäran än det här tidsgränsvärdet. Sändningsåtgärden avbryts.
• ReceiveTimeout: Inträffar om ett svar tar längre tid än det här tidsgränsvärdet. Begäran avbryts.

När du observerar de två första orsakerna, ResolveTimeout och ConnectTimeout, fungerar inte felsökningsmetoden som beskrevs tidigare. Det beror på att du inte skulle se någon trafik på målservern och därför inte känner till felkoden. I det här fallet eller ResolveTimeoutConnectTimeout kanske du vill samla in en WinHTTP-spårning för ytterligare insikter. Se avsnittet WinHTTP- eller WEBIO-spårning och på följande bloggar finns andra exempel på felsökning och spårning:

• 502.3 Felaktig gateway "Åtgärden överskrids" med IIS-programbegäransroutning (ARR)
• Winhttp Spårningsalternativ för felsökning med routning av programbegäran

502.3 Anslutningsavslutsfel

502.3-fel returneras också när anslutningen mellan ARR och medlemsservern är frånkopplad mitt i strömmen. Om du vill testa den här typen av problem skapar du en .aspx sida som anropar Response.Close(). I följande exempel finns det en katalog med namnet "time", som konfigureras med en .aspx sida som standarddokument i katalogen. När du försöker bläddra till katalogen visar ARR följande felmeddelande:

Felet 0x80072efe motsvarar ERROR_INTERNET_CONNECTION_ABORTED. Begäran kan spåras till den server som faktiskt har bearbetat den med samma steg som användes tidigare i den här felsökaren, med ett undantag. Spårning av misslyckade förfrågningar på målservern visar begäran som bearbetats på servern, men den associerade loggposten visas inte i IIS-loggarna. I stället loggas den här begäran i HTTPERR-loggen på följande sätt:

HTTP/1.1 GET /time/ - 1 Connection_Dropped DefaultAppPool

De inbyggda loggarna på målservern ger ingen ytterligare information om problemet, så nästa steg är att samla in en nätverksspårning från ARR-servern. I föregående exempel anropade Response.Close() .aspx sidan utan att returnera några data. Om du visar detta i en nätverksspårning visas att ett Connection: close HTTP-huvud kom från målservern. Med den här informationen kan du starta en undersökning av varför Connection: close rubriken skickades.

Följande fel är ett annat exempel på ett ogiltigt svar från medlemsservern:

I det här exemplet började ARR ta emot data från klienten, men något gick fel när begärandeentitetstexten lästes. Detta resulterade i att 0x80072f78 felkod returnerades. Om du vill undersöka vidare använder du Nätverksövervakaren på medlemsservern för att hämta en nätverksspårning av problemet. Det här specifika felexemplet skapades genom att anropa Response.Close() på sidan ASP.net efter att en del av svaret skickats och sedan anropats Response.Flush(). Om trafiken mellan ARR-servern och medlemsservrarna är över SSL kan WinHTTP-spårning på Windows Server 2008 eller WebIO-spårning på Windows Server 2008 R2 ge ytterligare information. WebIO-spårning beskrivs senare i den här felsökaren.

502.4 Det gick inte att hitta någon lämplig server för att dirigera begäran

HTTP 502.4-felet med en associerad felkod för 0x00000000 anger vanligtvis att alla medlemmar i servergruppen antingen är offline eller på annat sätt oåtkomliga.

Det första steget är att kontrollera att medlemsservrarna är online. Kontrollera detta genom att gå till noden Servrar under servergruppen i IIS-hanteraren.

Om du vill ta tillbaka offlineservrarna högerklickar du på servernamnet och väljer Lägg till i belastningsutjämning. Om du inte kan ta servrarna online igen kontrollerar du om medlemsservrarna kan nås från ARR-servern. Kontrollera fönstret spårningsmeddelanden på sidan Servrar för att leta efter ledtrådar om problemet. Om du använder Web Farm Framework (WFF) 2.0 kan du få det här felet när programpoolen startas om. Du måste starta om webbgruppstjänsten för att återställa.

WinHTTP- eller WebIO-spårning

Vanligtvis ger paketinsamlingsverktyg som WireShark dig den information du behöver för att identifiera exakt vad som överskrider tidsgränsen. Det finns dock tillfällen (till exempel när trafiken är SSL-krypterad) som du måste prova en annan metod. Från och med Windows 7 och Windows Server 2008 R2 kan du aktivera WinHTTP-spårning med hjälp av netsh-verktyget genom att köra följande kommando från en administrativ kommandotolk:

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

Återskapa sedan problemet. När problemet har återskapats stoppar du spårningen genom att köra följande kommando:

netsh trace stop

Kommandot stop tar några sekunder att slutföra. När det är klart hittar du en net.etl-fil och en net.cab fil i C:\temp. Du måste se till att C:\temp mappen finns innan du kör kommandona ovan. Den .cab filen innehåller händelseloggar och andra data som kan vara användbara vid analys av .etl-filen.

Analysera loggen genom att

1. Öppna den i Netmon 3.4 eller senare.

2. Kontrollera att du har konfigurerat parserprofilen. För att uppnå detta öppnar du menyn Verktygsalternativ>, väljer fliken Parserprofiler i >Windows-profilen och väljer sedan knappen Ange som aktiv för att tillämpa ändringarna.

3. Bläddra igenom spårningen tills du hittar den w3wp.exe instans där ARR körs genom att korrelera med kolumnen UT-processnamn .

4. Högerklicka på w3wp och välj Lägg till UT-processnamn för att visa filtret. Detta anger visningsfiltret som liknar:

   UTProcessName == "w3wp.exe (1432)"
   

Du kan filtrera resultatet ytterligare genom att ändra det till följande:

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

Du måste bläddra igenom utdata tills du hittar timeout-felet. I följande exempel uppnåddes tidsgränsen för en begäran eftersom det tog mer än 30 sekunder (ARR:s standardtidsgräns) att köras.

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) 

I följande exempel var innehållsservern helt 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} 

Andra resurser

• Uppslagsverktyget för fel
• Winhttp-felkoder
• Spårning av misslyckade förfrågningar
• Winhttp Tracing
• Nätverksövervakare

Ansvarsfriskrivning för information från tredje part

De produkter från andra tillverkare som diskuteras i denna artikel tillverkas oberoende av Microsoft. Produkternas funktion eller tillförlitlighet kan därför inte garanteras.