Diagnostyka opóźnień HTTP: od Nginx do jądra

# Diagnostyka opóźnień żądań HTTP: od równoważyciela obciążenia do jądra Linux

Wzrost czasu odpowiedzi lub nagłe błędy 5xx w produkcji wymagają natychmiastowej i precyzyjnej lokalizacji problemu. Zamiast chaotycznego sprawdzania serwisów efektywniejsze jest stosowanie podejścia systemowego, które dzieli cały pipeline przetwarzania żądania na segmenty sieciowy i aplikacyjny. Omawiamy metodę szybkiego wyszukiwania wąskich gardeł za pomocą standardowych logów Nginx, nagłówków Server-Timing i niskopoziomowych metryk TCP_INFO.

Punkt startowy: analiza logów równoważyciela

Architektura typowej aplikacji webowej obejmuje kilka warstw: użytkownik, CDN, równoważyciel obciążenia (SLB), aplikacja, pula połączeń i baza danych. Każda z nich może wprowadzać opóźnienia, ale punktem wyjścia dla diagnostyki zawsze powinien być równoważyciel. To on znajduje się w centrum pipeline'u i pozwala natychmiast określić kierunek poszukiwań.

Dla Nginx kluczowe są dwie zmienne: $request_time i $upstream_response_time. Pierwsza rejestruje pełne time przetwarzania żądania od otrzymania pierwszego bajtu od klienta do wysłania ostatniego bajtu odpowiedzi. Druga mierzy wyłącznie czas oczekiwania na odpowiedź od serwera upstream. Jeśli te metryki jeszcze nie są zbierane, należy rozszerzyć format logowania:

log_format timing '$remote_addr - $request_uri '
                  'status=$status '
                  'rt=$request_time '
                  'uct=$upstream_connect_time '
                  'urt=$upstream_response_time';

access_log /var/log/nginx/access.log timing;

Interpretacja danych opiera się na prostym porównaniu. Jeśli $upstream_response_time jest zbliżone do $request_time, wąskie gardło znajduje się po prawej stronie równoważyciela: w kodzie aplikacji, puli połączeń lub bazie danych. Jeśli natomiast $upstream_response_time jest w normie, a $request_time anomalnie wysoki, problem jest zlokalizowany po lewej: w infrastrukturze sieciowej, routingu CDN lub po stronie klienta. Ważne jest, aby nie wstrzykiwać $request_time do nagłówków odpowiedzi za pomocą add_header w celu precyzyjnych pomiarów, ponieważ Nginx formuje nagłówki przed zakończeniem transmisji ciała odpowiedzi. Wiarygodne dane są dostępne tylko w access log po zamknięciu połączenia.

Lokalizacja problemów po stronie aplikacji

Gdy równoważyciel wskazuje na opóźnienia w upstream, należy szczegółowo przeanalizować wewnętrzne operacje aplikacji. Standard W3C Server-Timing pozwala przekazywać klientowi lub systemowi monitoringu precyzyjne pomiary czasu wykonania poszczególnych etapów przetwarzania żądania. Nagłówek ma postać: Server-Timing: app;dur=120, db;dur=95, pool-wait;dur=18. Zapewnia to przejrzystość bez wdrażania ciężkich agentów APM.

Integracja nagłówka w stosie aplikacji wymaga minimalnych zmian. Przykłady implementacji dla popularnych języków:

Go (net/http):

start := time.Now()
rows, err := db.QueryContext(ctx, query)
dbDur := time.Since(start)

w.Header().Set("Server-Timing",
    fmt.Sprintf("db;dur=%.2f", float64(dbDur.Microseconds())/1000))

Python (Django middleware):

class ServerTimingMiddleware:
    def __init__(self, get_response):
        self.get_response = get_response

    def __call__(self, request):
        start = time.monotonic()
        response = self.get_response(request)
        dur = (time.monotonic() - start) * 1000
        response["Server-Timing"] = f"app;dur={dur:.2f}"
        return response

Node.js (Express):

app.use((req, res, next) => {
  const start = process.hrtime.bigint();
  res.on('finish', () => {
    const ms = Number(process.hrtime.bigint() - start) / 1e6;
    // już wysłano, ale do logowania:
    console.log(`Server-Timing: app;dur=${ms.toFixed(2)}`);
  });
  // do nagłówka — mierzymy do odpowiedzi:
  const origEnd = res.end;
  res.end = function(...args) {
    const ms = Number(process.hrtime.bigint() - start) / 1e6;
    res.setHeader('Server-Timing', `app;dur=${ms.toFixed(2)}`);
    origEnd.apply(this, args);
  };
  next();
});

Aby przekazywać metryki samego Nginx przez Server-Timing, należy użyć dyrektywy map, aby uniknąć przekazywania pustych wartości przy obsłudze statyki lub błędów:

Nginx (timing upstream jako Server-Timing):

      # W bloku http {} nginx.conf:
      map $upstream_header_time $server_timing_upstream {
      "-"     "";
       default "ngx-upstream;dur=$upstream_header_time;desc=\"NgxUpstream\"";
      }

      # W bloku location {} serwera:
      add_header Server-Timing-Ngx "ngx-total;dur=$request_time;desc=\"NgxTotal\"" always;
      add_header Server-Timing-Ngx $server_timing_upstream always;

Zwróć uwagę na użycie prefiksu Server-Timing-Ngx i zmiennej $upstream_header_time. Przeglądarki oczekują wartości w milisekundach, a Nginx zwraca sekundy. Ponadto $upstream_header_time rejestruje moment otrzymania nagłówków od upstream, co poprawnie odzwierciedla czas generowania odpowiedzi, w przeciwieństwie do $upstream_response_time, który może być zerowany w pewnych warunkach buforowania.

Analiza uzyskanych danych pozwala szybko sklasyfikować incydent:

• Dominacja db;dur wskazuje na nieoptymalne zapytania SQL, brak indeksów lub blokady tabel.
• Wysoki pool-wait;dur sygnalizuje wyczerpanie limitu połączeń w PgBouncer lub podobnym pulerze.
• Duży app;dur przy małym db;dur świadczy o operacjach zależnych od CPU, blokującym I/O lub wyciekach pamięci w runtime.
• Błędy 502/504 na równoważycielu przy normalnych timingach zwykle oznaczają crash procesu aplikacji lub przekroczenie timeoutu na poziomie orkiestratora.

Segment sieciowy: fazy HTTP i metryki jądra

Jeśli upstream odpowiada szybko, a ogólne opóźnienie rośnie, problem kryje się w ścieżce sieciowej. Każde żądanie HTTP przechodzi przez sześć sekwencyjnych faz: DNS, Connect (uścisk TCP), TLS handshake, Send, Wait (TTFB) i Receive. Anomalie w konkretnych fazach natychmiast zawężają krąg poszukiwań. Długi DNS wskazuje na problemy resolvera lub skomplikowane łańcuchy CNAME. Wysokie wartości Connect i TLS świadczą o opóźnieniach sieciowych do edge-uzła CDN, braku wznowienia sesji TLS lub użyciu przestarzałych protokołów. Jeśli Connect i TLS są minimalne, ale Wait anomalnie wysoki, opóźnienie arises na poziomie WAF, workerów CDN lub przy fetch do origin.

Do głębokiej diagnostyki problemów sieciowych standardowy podział HTTP jest niewystarczający. Należy sięgnąć do metryk jądra Linux za pomocą getsockopt(TCP_INFO). Jądro śledzi każde połączenie TCP i dostarcza precyzyjne dane: RTT, liczbę retransmisji, rozmiar okna zatykania (cwnd) i RTO. Te wskaźniki są kluczowe, ponieważ timingi HTTP nie pozwalają oddzielić opóźnienia sieciowego od czasu przetwarzania serwera, gdy odpowiedź mieści się w jednym segmencie TCP. Odejmując RTT jądra od fazy Wait, inżynier uzyskuje rzeczywisty czas przetwarzania żądania. Retransmisje i skompresowany cwnd bezpośrednio wskazują na utratę pakietów i działanie algorytmów kontroli przeciążenia, które dodają setki milisekund do każdego żądania. Kombinacja nagłówków aplikacyjnych i niskopoziomowych metryk sieciowych tworzy pełny obraz observability bez zależności od zewnętrznych vendorów.

Co ważne

• Porównanie $request_time i $upstream_response_time w Nginx natychmiast dzieli strefy odpowiedzialności między siecią a aplikacją.
• Nagłówek Server-Timing zapewnia granularną widoczność wewnętrznych opóźnień (bazy danych, pule, runtime) bez wdrażania ciężkich systemów APM.
• Analiza faz żądania HTTP pozwala precyzyjnie zidentyfikować problemy DNS, uścisków TLS i routingu CDN.
• Metryki TCP_INFO z jądra Linux dają obiektywny obraz strat sieciowych i opóźnień, których nie da się wychwycić na poziomie aplikacyjnym.
• Podejście systemowe do diagnostyki latencji skraca MTTR i eliminuje chaotyczne restarty serwisów podczas incydentów.

— Editorial Team