Rozwiązywanie problemów z błędami 502 w usłudze ARR

Ten artykuł pomaga rozwiązać problemy związane z błędami 502 w routingu żądań aplikacji (ARR).

Dotyczy: Internetowe usługi informacyjne

HTTP 502 — omówienie

Podczas pracy z wdrożeniami routingu żądań aplikacji usług IIS (ARR) jednym z błędów, które mogą wystąpić, jest "HTTP 502 — zła brama". Błąd 502.3 oznacza, że działając jako serwer proxy, ARR nie może ukończyć żądania do serwera nadrzędnego i wysłać odpowiedzi z powrotem do klienta. Ten problem może wystąpić z wielu powodów. Na przykład nie można nawiązać połączenia z serwerem, brak odpowiedzi z serwera lub odpowiedź serwera trwała zbyt długo (przekroczliśmy limit czasu). Jeśli możesz odtworzyć błąd, przeglądając farmę internetową z kontrolera, a szczegółowe błędy są włączone na serwerze, może zostać wyświetlony błąd podobny do następującego komunikatu o błędzie:

Główna przyczyna błędu określa, co należy zrobić, aby rozwiązać problem.

Błędy przekroczenia limitu czasu 502.3

Usługa ARR używa kodu błędu na powyższym zrzucie ekranu do serwera proxy żądania i określania źródła błędu, ponieważ zawiera on kod zwrotny z witryny WinHTTP.

Kod błędu można dekodować za pomocą narzędzia err.exe. W tym przykładzie kod błędu jest mapowany na ERROR_WINHTTP_TIMEOUT. Te informacje można również znaleźć w dziennikach usług IIS dla skojarzonej witryny internetowej na kontrolerze ARR. Poniżej znajduje się fragment wpisu dziennika usług IIS dla błędu 502.3 z większością pól przyciętych pod kątem czytelności:

sc-status	sc-substatus	sc-win32-status	czas potrzebny
502	3	12002	29889

Stan win32 12002 jest mapowany na ten sam błąd ERROR_WINHTTP_TIMEOUT zgłoszony na stronie błędu.

Co dokładnie upłynął limit czasu?

Ten limit czasu można sprawdzić, włączając śledzenie żądań zakończonych niepowodzeniem na serwerze usług IIS. Pierwszy punkt widoczny w dzienniku śledzenia żądania zakończonej niepowodzeniem i jest to miejsce, do którego wysłano żądanie w zdarzeniu ARR_SERVER_ROUTED. Drugim punktem jest identyfikator X-ARR-LOG-ID, którego można użyć do śledzenia żądania na serwerze docelowym. Ułatwia to śledzenie miejsca docelowego lub miejsca docelowego żądania 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

W poniższym przykładzie pokazano, jak może to wyglądać w dziennikach śledzenia żądań zakończonych niepowodzeniem serwera docelowego. Możesz sprawdzić, czy znaleziono prawidłowe żądanie, dopasowując wartości "X-ARR-LOG-ID" w obu śladach.

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

W poprzednim przykładzie widać, że serwer ARR rozłączył się przed wysłaniem odpowiedzi HTTP. Sygnatura czasowa dla GENERAL_FLUSH_RESPONSE_END może służyć jako przewodnik do znajdowania odpowiedniego wpisu w dziennikach usług IIS na serwerze docelowym.

Data	Czas	s-ip	cs-method	cs-uri-stem	cs-uri-query	s-port	cs-username	sc-status	sc-substatus	sc-win32-status	czas potrzebny
2011-07-18	16:51:06	192.168.0.216	POBIERZ	/Czas/	-	80	-	200	0	64	45208

Usługi IIS na serwerze docelowym zarejestrowały kod stanu HTTP 200 wskazujący, że żądanie zostało pomyślnie zakończone. Ponadto stan win32 zmienił się na 64, który mapuje na ERROR_NETNAME_DELETED. Ten kod stanu zazwyczaj wskazuje, że klient (ARR jest "klientem" w tym przypadku) rozłączył się przed zakończeniem żądania.

Przyczyna

Serwer ARR zgłosił przekroczenie limitu czasu, w którym należy najpierw przyjrzeć się.

Chociaż dziennik serwera członkowskiego wskazuje, że odpowiedź została wysłana w ciągu 45 sekund (45208 ms), wpis dziennika usług IIS z serwera ARR wskazuje, że czas potrzebny jest bardzo blisko 30 sekund. Oznacza to, że ARR przekracza limit czasu żądania i możesz to potwierdzić, sprawdzając limit czasu serwera proxy w ustawieniach serwera proxy farmy serwerów. Domyślnie jest ona ustawiona na 30 sekund.

Dlatego w tym przypadku wyraźnie widać, że limit czasu ARR był krótszy niż wykonanie żądania. W związku z tym warto sprawdzić, czy ten czas wykonywania był typowy, czy też trzeba było sprawdzić, dlaczego żądanie trwa dłużej niż oczekiwano. Jeśli ten czas wykonywania był oczekiwany i normalny, zwiększenie limitu czasu ARR powinno rozwiązać ten błąd.

Inne możliwe przyczyny ERROR_WINHTTP_TIMEOUT to:

• ResolveTimeout: występuje, jeśli rozpoznawanie nazw trwa dłużej niż określony okres limitu czasu.
• ConnectTimeout: występuje, jeśli połączenie z serwerem trwa dłużej niż określony limit czasu po usunięciu nazwy.
• SendTimeout: występuje, jeśli wysłanie żądania trwa dłużej niż ta wartość limitu czasu. Operacja wysyłania jest anulowana.
• ReceiveTimeout: występuje, jeśli odpowiedź trwa dłużej niż ta wartość limitu czasu. Żądanie zostało anulowane.

Jeśli zaobserwujesz dwa pierwsze przyczyny i ResolveTimeoutConnectTimeout, opisana wcześniej metodologia rozwiązywania problemów nie będzie działać. Dzieje się tak dlatego, że nie widzisz żadnego ruchu na serwerze docelowym i w związku z tym nie znasz kodu błędu. Dlatego w tym przypadku ResolveTimeoutConnectTimeout możesz przechwycić ślad WinHTTP, aby uzyskać dodatkowe informacje. Zobacz sekcję śledzenia WinHTTP lub WEBIO i na następujących blogach, aby uzyskać inne przykłady dotyczące rozwiązywania problemów i śledzenia:

• 502.3 Nieprawidłowa brama "Upłynął limit czasu operacji" z routingiem żądań aplikacji usług IIS (ARR)
• Winhttp Tracing Options for Troubleshooting with Application Request Routing

502.3 Błędy zakończenia połączenia

Błędy 502.3 są również zwracane, gdy połączenie między serwerem ARR i serwerem członkowskim jest rozłączone w połowie strumienia. Aby przetestować ten typ problemu, utwórz stronę .aspx, która wywołuje polecenie Response.Close(). W poniższym przykładzie istnieje katalog o nazwie "time", który jest skonfigurowany ze stroną .aspx jako dokumentem domyślnym w tym katalogu. Podczas próby przechodzenia do katalogu usługa ARR wyświetla następujący komunikat o błędzie:

Błąd 0x80072efe odpowiada ERROR_INTERNET_CONNECTION_ABORTED. Żądanie można prześledzić na serwerze, który faktycznie przetworował je przy użyciu tych samych kroków, które zostały użyte wcześniej w tym narzędziu do rozwiązywania problemów, z jednym wyjątkiem. Podczas gdy śledzenie żądań zakończonych niepowodzeniem na serwerze docelowym pokazuje żądanie przetworzone na serwerze, skojarzony wpis dziennika nie jest wyświetlany w dziennikach usług IIS. Zamiast tego to żądanie jest rejestrowane w dzienniku HTTPERR w następujący sposób:

HTTP/1.1 GET /time/ - 1 Connection_Dropped DefaultAppPool

Wbudowane dzienniki na serwerze docelowym nie zawierają żadnych dodatkowych informacji o problemie, więc następnym krokiem będzie zebranie śledzenia sieci z serwera ARR. W poprzednim przykładzie strona .aspx wywoływana Response.Close() bez zwracania żadnych danych. Wyświetlenie tego w śledzeniu sieci pokazuje, że Connection: close nagłówek HTTP pochodził z serwera docelowego. Dzięki tym informacjom można rozpocząć badanie przyczyn wysłania nagłówka Connection: close .

Poniższy błąd to kolejny przykład nieprawidłowej odpowiedzi z serwera członkowskiego:

W tym przykładzie usługa ARR zaczęła odbierać dane od klienta, ale wystąpił problem podczas odczytywania treści jednostki żądania. Spowodowało to zwrócenie kodu błędu 0x80072f78. Aby dokładniej zbadać problem, użyj monitora sieci na serwerze członkowskim, aby uzyskać ślad sieciowy problemu. Ten konkretny przykład błędu został utworzony przez wywołanie na Response.Close() stronie ASP.net po wysłaniu części odpowiedzi, a następnie wywołaniu polecenia Response.Flush(). Jeśli ruch między serwerem ARR i serwerami członkowskimi jest za pośrednictwem protokołu SSL, śledzenie WinHTTP w systemie Windows Server 2008 lub śledzenie webIO w systemie Windows Server 2008 R2 może dostarczyć dodatkowych informacji. Śledzenie operacji WebIO zostało opisane w dalszej części tego narzędzia do rozwiązywania problemów.

502.4 Nie można odnaleźć odpowiedniego serwera do kierowania żądania

Błąd HTTP 502.4 ze skojarzonym kodem błędu 0x00000000 zazwyczaj wskazuje, że wszystkie elementy członkowskie farmy są w trybie offline lub w inny sposób nieosiągalne.

Pierwszym krokiem jest sprawdzenie, czy serwery członkowskie są w trybie online. Aby to sprawdzić, przejdź do węzła Serwery w farmie w Menedżerze usług IIS.

Aby przywrócić serwery w trybie offline, kliknij prawym przyciskiem myszy nazwę serwera i wybierz pozycję Dodaj do równoważenia obciążenia. Jeśli nie możesz przywrócić serwerów do trybu online, sprawdź, czy serwery członkowskie są osiągalne z serwera ARR. Sprawdź okienko Komunikaty śledzenia na stronie Serwery , aby wyszukać wskazówki dotyczące problemu. Jeśli używasz programu Web Farm Framework (WFF) 2.0, ten błąd może wystąpić po ponownym uruchomieniu puli aplikacji. Aby odzyskać, należy ponownie uruchomić usługę farmy sieci Web.

Śledzenie WinHTTP lub WebIO

Zazwyczaj narzędzia do przechwytywania pakietów, takie jak WireShark , dostarczają informacji potrzebnych do dokładnego określenia limitu czasu. Jednak istnieją czasy (na przykład, gdy ruch jest szyfrowany za pomocą protokołu SSL), że należy wypróbować inne podejście. Począwszy od systemów Windows 7 i Windows Server 2008 R2, możesz włączyć śledzenie WinHTTP przy użyciu narzędzia netsh, uruchamiając następujące polecenie z administracyjnego wiersza polecenia:

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

Następnie odtwórz problem. Po odtworzeniu problemu zatrzymaj śledzenie, uruchamiając następujące polecenie:

netsh trace stop

Wykonanie stop polecenia trwa kilka sekund. Po zakończeniu znajdziesz plik net.etl i plik net.cab w C:\temppliku . Przed uruchomieniem powyższych poleceń należy upewnić się, że C:\temp folder istnieje. Plik .cab zawiera dzienniki zdarzeń i inne dane, które mogą okazać się przydatne podczas analizowania pliku etl.

Aby przeanalizować dziennik,

1. Otwórz go w programie Netmon 3.4 lub nowszym.

2. Upewnij się, że skonfigurowano profil analizatora. Aby to osiągnąć, otwórz menuOpcjenarzędzi>, wybierz kartę >Profile analizatora Profil systemu Windows, a następnie wybierz przycisk Ustaw jako aktywny, aby zastosować zmiany.

3. Przewiń ślad, aż znajdziesz wystąpieniew3wp.exe , w którym działa funkcja ARR, skorelując ją z kolumną nazwy procesu UT .

4. Kliknij prawym przyciskiem myszy w3wp i wybierz pozycję Dodaj nazwę procesu UT, aby wyświetlić filtr. Spowoduje to ustawienie filtru wyświetlania podobnego do następującego:

   UTProcessName == "w3wp.exe (1432)"
   

Możesz dodatkowo filtrować wyniki, zmieniając je na następujące:

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

Musisz przewinąć dane wyjściowe do momentu znalezienia błędu przekroczenia limitu czasu. W poniższym przykładzie upłynął limit czasu żądania, ponieważ uruchomienie żądania zajęło ponad 30 sekund (domyślny limit czasu usługi 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) 

W poniższym przykładzie serwer zawartości był całkowicie w trybie 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} 

Inne zasoby

• Narzędzie wyszukiwania błędów
• Kody błędów Winhttp
• Śledzenie żądań zakończonych niepowodzeniem
• Winhttp Tracing
• Monitor sieci

Zastrzeżenie dotyczące innych firm

Produkty innych firm omówione w tym artykule są wytwarzane przez producentów niezależnych od firmy Microsoft. Firma Microsoft nie udziela żadnych gwarancji, dorozumianych ani żadnego innego rodzaju, w odniesieniu do wydajności lub niezawodności tych produktów.