Aus dem Leben mit Kubernetes: Warum der HTTP-Server der Spanier nicht gefiel

Der Vertreter unseres Kunden, dessen Anwendungsarchitektur in der Microsoft-Cloud (Azure) gehostet wird, hat uns ein Problem mitgeteilt: Seit kurzem enden einige Anfragen von europäischen Kunden mit dem Fehler 400 (Bad Request). Alle Anwendungen sind in .NET geschrieben und in Kubernetes bereitgestellt…

Eine der Anwendungen ist ein API, über das der gesamte Datenverkehr letztendlich läuft. Dieser Datenverkehr wird von dem HTTP-Server Kestrel, der vom Kunden konfiguriert wurde und sich in einem Pod befindet, empfangen. Bei der Fehlersuche hatten wir das Glück, dass es einen spezifischen Benutzer gab, bei dem das Problem konstant reproduzierbar war. Allerdings wurde alles durch die Kette des Datenverkehrs kompliziert:

Der Fehler im Ingress sah wie folgt aus:

{
   "number_fields":{
      "status":400,
      "request_time":0.001,
      "bytes_sent":465,
      "upstream_response_time":0,
      "upstream_retries":0,
      "bytes_received":2328
   },
   "stream":"stdout",
   "string_fields":{
      "ingress":"app",
      "protocol":"HTTP/1.1",
      "request_id":"f9ab8540407208a119463975afda90bc",
      "path":"/api/sign-in",
      "nginx_upstream_status":"400",
      "service":"app",
      "namespace":"production",
      "location":"/front",
      "scheme":"https",
      "method":"POST",
      "nginx_upstream_response_time":"0.000",
      "nginx_upstream_bytes_received":"120",
      "vhost":"api.app.example.com",
      "host":"api.app.example.com",
      "user":"",
      "address":"83.41.81.250",
      "nginx_upstream_addr":"10.240.0.110:80",
      "referrer":"https://api.app.example.com/auth/login?long_encrypted_header",
      "service_port":"http",
      "user_agent":"Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/72.0.3626.121 Safari/537.36",
      "time":"2019-03-06T18:29:16+00:00",
      "content_kind":"cache-headers-not-present",
      "request_query":""
   },
   "timestamp":"2019-03-06 18:29:16",
   "labels":{
      "app":"nginx",
      "pod-template-generation":"6",
      "controller-revision-hash":"1682636041"
   },
   "namespace":"kube-nginx-ingress",
   "nsec":6726612,
   "source":"kubernetes",
   "host":"k8s-node-55555-0",
   "pod_name":"nginx-v2hcb",
   "container_name":"nginx",
   "boolean_fields":{}
}

In der Zwischenzeit gab Kestrel aus:

HTTP/1.1 400 Bad Request
Connection: close
Date: Wed, 06 Mar 2019 12:34:20 GMT
Server: Kestrel
Content-Length: 0

Selbst bei maximaler Detailgenauigkeit enthielt der Kestrel-Fehler extrem wenig nützliche Informationen:

{
   "number_fields":{"ThreadId":76},
   "stream":"stdout",
   "string_fields":{
      "EventId":"{"Id"=>17, "Name"=>"ConnectionBadRequest"}",
      "SourceContext":"Microsoft.AspNetCore.Server.Kestrel",
      "ConnectionId":"0HLL2VJSST5KV",
      "@mt":"Verbindungs-ID "{ConnectionId}" ungültige Anforderungsdaten: "{message}"",
      "@t":"2019-03-07T13:06:48.1449083Z",
      "@x":"Microsoft.AspNetCore.Server.Kestrel.Core.BadHttpRequestException: Ungültige Anforderung: fehlerhafte Header.n   bei Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.Http1Connection.TryParseRequest(ReadResult result, Boolean& endConnection)n   bei Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.<ProcessRequestsAsync>d__185`1.MoveNext()",
      "message":"Ungültige Anforderung: fehlerhafte Header."
   },
   "timestamp":"2019-03-07 13:06:48",
   "labels":{
      "pod-template-hash":"2368795483",
      "service":"app"
   },
   "namespace":"produktion",
   "nsec":145341848,
   "source":"kubernetes",
   "host":"k8s-node-55555-1",
   "pod_name":"app-67bdcf98d7-mhktx",
   "container_name":"app",
   "boolean_fields":{}
}

Es scheint, dass nur tcpdump bei der Lösung dieses Problems helfen kann… aber ich wiederhole die Verkehrskette:

Untersuchung

Offensichtlich ist es besser, den Verkehr zu belauschen auf dem spezifischen Knoten, wo Kubernetes das Pod bereitgestellt hat: Das Volumen des Dumps wird so groß sein, dass man schnell etwas finden kann. Und tatsächlich wurde bei seiner Betrachtung ein solches Frame bemerkt:

GET /back/user HTTP/1.1
Host: api.app.example.com
X-Request-ID: 27ceb14972da8c21a8f92904b3eff1e5
X-Real-IP: 83.41.81.250
X-Forwarded-For: 83.41.81.250
X-Forwarded-Host: api.app.example.com
X-Forwarded-Port: 443
X-Forwarded-Proto: https
X-Original-URI: /front/back/user
X-Scheme: https
X-Original-Forwarded-For: 83.41.81.250
X-Nginx-Geo-Client-Country: Spanien
X-Nginx-Geo-Client-City: M.laga
Accept-Encoding: gzip
CF-IPCountry: ES
CF-RAY: 4b345cfd1c4ac691-MAD
CF-Visitor: {"scheme":"https"}
pragma: no-cache
cache-control: no-cache
accept: application/json, text/plain, *
origin: https://app.example.com
user-agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, wie Gecko) Chrome/72.0.3626.119 Safari/537.36
referer: https://app.example.com/auth/login
accept-language: en-US,en;q=0.9,en-GB;q=0.8,pl;q=0.7
cookie: viele_verschlüsselte_cookies; .AspNetCore.Identity.Application=something_encrypted; 
CF-Connecting-IP: 83.41.81.250
True-Client-IP: 83.41.81.250
CDN-Loop: cloudflare

HTTP/1.1 400 Bad Request
Connection: close
Date: Wed, 06 Mar 2019 12:34:20 GMT
Server: Kestrel
Content-Length: 0

Bei genauerer Betrachtung des Dumps wurde das Wort bemerkt M.laga. Es ist leicht zu erraten, dass es in Spanien keine Stadt namens M.laga gibt (aber es gibt Málaga). Angetrieben von dieser Idee sahen wir uns die Ingress-Konfigurationen an, wo wir vor einem Monat auf Kundenanfrage hinein eingefügte „harmlosen“ Snippet:

    ingress.kubernetes.io/configuration-snippet: |
      proxy_set_header X-Nginx-Geo-Client-Country $geoip_country_name;
      proxy_set_header X-Nginx-Geo-Client-City $geoip_city;

Nachdem wir das Durchleiten dieser Header deaktiviert hatten, war alles gut! (Bald stellte sich heraus, dass diese Header für die Anwendung selbst nicht mehr benötigt wurden.)

Nun schauen wir uns das Problem in allgemeinerer Form. Es ist leicht, es innerhalb der Anwendung nachzustellen, wenn man eine telnet-Anfrage an localhost:80:

GET /back/user HTTP/1.1
Host: api.app.example.com
cache-control: no-cache
accept: application/json, text/plain, */*
origin: https://app.example.com
Cookie: test=Desiree

… wird zurückgegeben 401 Unauthorized, wie erwartet. Was passiert, wenn wir Folgendes tun:

GET /back/user HTTP/1.1
Host: api.app.example.com
cache-control: no-cache
accept: application/json, text/plain, */*
origin: https://app.example.com
Cookie: test=Désirée

?

Wird zurückgegeben 400 Bad request — im Anwendungsprotokoll erhalten wir bereits den bekannten Fehler:

{
   "@t":"2019-03-31T12:59:54.3746446Z",
   "@mt":"Verbindungs-ID "{ConnectionId}" ungültige Anfragedaten: "{message}"",
   "@x":"Microsoft.AspNetCore.Server.Kestrel.Core.BadHttpRequestException: Fehlgeschlagene Anfrage: ungültige Header.n   bei Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.Http1Connection.TryParseRequest(ReadResult result, Boolean& endConnection)n   bei Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.<ProcessRequestsAsync>d__185`1.MoveNext()",
   "ConnectionId":"0HLLLR1J974L9",
   "message":"Fehlgeschlagene Anfrage: ungültige Header.",
   "EventId":{
      "Id":17,
      "Name":"ConnectionBadRequest"
   },
   "SourceContext":"Microsoft.AspNetCore.Server.Kestrel",
   "ThreadId":71
}

Ergebnisse

Konkret Kestrel kann HTTP-Header mit korrekten Zeichen in UTF-8, die in den Namen einer ziemlich großen Anzahl von Städten enthalten sind, nicht korrekt verarbeiten.

Ein zusätzlicher Faktor in unserem Fall — die Implementierung von Kestrel in der Clientanwendung wird derzeit nicht geändert. Allerdings zeigen die Issues in AspNetCore (Nr. 4318, Nr. 7707) dass dies auch nicht helfen wird…

Zusammenfassend: Diese Notiz handelt nicht mehr von spezifischen Problemen mit Kestrel oder UTF-8 (im Jahr 2019?!), sondern davon, dass Aufmerksamkeit und systematisches Lernen jeden Schritt beim Auffinden des Problems früher oder später Früchte tragen. Viel Erfolg!

P.S.

Lesen Sie auch in unserem Blog:

• «6 interessante systematische Fehler bei der Nutzung von Kubernetes [und deren Lösung]»;
• «Kubernetes Tipps & Tricks: personalisierte Fehlerseiten in NGINX Ingress»;
• «Überblick und Vergleich von Ingress-Controllern für Kubernetes»;
• «Überwachung von Pings zwischen Kubernetes-Knoten — unser Rezept»;
• «3 ungewöhnliche Fälle zur Netzwerksubsystem von Linux».

Quelle: habr.com