Ein Leben mit Kubernetes: Wie der HTTP-Server der Spanier nicht gemocht wurde

Ein Vertreter unseres Kunden, dessen Anwendungsstack in der Microsoft Cloud (Azure) betrieben wird, kontaktierte uns aufgrund eines Problems: Seit Kurzem führen einige Anfragen von europäischen Kunden zum Fehler 400 (Bad Request). Alle Anwendungen sind in .NET geschrieben und in Kubernetes bereitgestellt…

Eine der Anwendungen ist ein API, über das letztendlich der gesamte Traffic abgewickelt wird. Dieser Traffic wird vom HTTP-Server Kestrel, konfiguriert vom .NET-Kunden und in einem Pod bereitgestellt. Bei der Fehlersuche hatten wir das Glück, dass es einen bestimmten Benutzer gab, bei dem das Problem konstant reproduziert werden konnte. Allerdings wurde die Situation durch die Kette des Traffics kompliziert:

Der Fehler im Ingress sah folgendermaßen 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":{}
}

Gleichzeitig gab Kestrel aus:

HTTP/1.1 400 Bad Request
Connection: close
Date: Mi, 06 Mär 2019 12:34:20 GMT
Server: Kestrel
Content-Length: 0

Selbst bei maximaler Detailgenauigkeit enthielt der Fehler von Kestrel äußerst 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}" fehlerhafte Anfragedaten: "{message}"",
      "@t":"2019-03-07T13:06:48.1449083Z",
      "@x":"Microsoft.AspNetCore.Server.Kestrel.Core.BadHttpRequestException: Fehlerhafte 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()",
      "message":"Fehlerhafte Anfrage: ungültige Header."
   },
   "timestamp":"2019-03-07 13:06:48",
   "labels":{
      "pod-template-hash":"2368795483",
      "service":"app"
   },
   "namespace":"production",
   "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 etwas zur Verkehrskette:

Untersuchung

Offensichtlich ist es besser, den Verkehr abzuhören an dem spezifischen Knoten, an dem Kubernetes den Pod bereitgestellt hat: der Dump- Umfang wird so sein, dass man ziemlich schnell etwas finden kann. Und tatsächlich wurde bei seiner Betrachtung dieses 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, like 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: many_encrypted_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 ein Wort bemerkt M.laga. Es ist leicht zu erraten, dass es in Spanien keine Stadt namens M.laga gibt (aber es gibt Málaga). Diese Idee aufgreifend, schauten wir uns die Ingress-Konfigurationen an, in denen wir vor einem Monat (auf Kundenanfrage) entdeckt haben ein „harmloses“ 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;

Nach der Deaktivierung dieser Header gab es keine Probleme mehr! (Bald stellte sich heraus, dass die Anwendung diese Header eigentlich nicht mehr benötigte.)

Sehen wir uns das Problem nun aus einer allgemeineren Perspektive an. Es ist einfach, das innerhalb der Anwendung zu reproduzieren, 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

… zurückkommt 401 Unauthorized, wie erwartet. Was passiert, wenn wir Folgendes machen:

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

?

Es wird zurückkommen 400 Bad Request — im Anwendungsprotokoll erhalten wir bereits den vertrauten Fehler:

{
   "@t":"2019-03-31T12:59:54.3746446Z",
   "@mt":"Connection id "{ConnectionId}" bad request data: "{message}"",
   "@x":"Microsoft.AspNetCore.Server.Kestrel.Core.BadHttpRequestException: Malformed request: invalid headers.
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.Http1Connection.TryParseRequest(ReadResult result, Boolean& endConnection)
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.<ProcessRequestsAsync>d__185`1.MoveNext()",
   "ConnectionId":"0HLLLR1J974L9",
   "message":"Malformed request: invalid headers.",
   "EventId":{
      "Id":17,
      "Name":"ConnectionBadRequest"
   },
   "SourceContext":"Microsoft.AspNetCore.Server.Kestrel",
   "ThreadId":71
}

Ergebnisse

Insbesondere Kestrel kann Die HTTP-Header korrekt mit den richtigen UTF-8-Zeichen zu verarbeiten, die in den Namen einer Vielzahl von Städten enthalten sind.

Ein zusätzlicher Faktor in unserem Fall ist, dass die Umsetzung von Kestrel im Client-Anwendung derzeit nicht geplant ist. Allerdings zeigen die Issues in AspNetCore (Nr. 4318, Nr. 7707) dass dies wahrscheinlich nicht helfen wird…

Zusammenfassend lässt sich sagen: Es geht nicht mehr um spezifische Probleme mit Kestrel oder UTF-8 (im Jahr 2019?!), sondern darum, dass Aufmerksamkeit und konsequente Untersuchung jeder Schritte während der Fehlersuche früher oder später Früchte tragen werden. Viel Erfolg!

P.S.

Lesen Sie auch in unserem Blog:

• «6 interessante Systemfehler beim Betrieb von Kubernetes [und deren Lösungen]»;
• «Kubernetes Tipps & Tricks: Personalisierte Fehlermeldungsseiten in NGINX Ingress»;
• «Überblick und Vergleich von Ingress-Controllern für Kubernetes»;
• «Das Monitoring der Pings zwischen den Kubernetes-Knoten – unser Rezept.»;
• «3 ungewöhnliche Fälle zur Netzwerksubsystem von Linux.».

Quelle: habr.com