Het leven met Kubernetes: Hoe de HTTP-server van de Spanjaarden niet welkom was.

Een vertegenwoordiger van onze klant, wiens applicatiestack zich in de cloud van Microsoft (Azure) bevindt, heeft ons benaderd met een probleem: sinds kort worden sommige verzoeken van klanten uit Europa afgesloten met een foutmelding 400 (Bad Request). Alle applicaties zijn geschreven in .NET en zijn uitgerold op Kubernetes…

Een van de applicaties is een API, via welke uiteindelijk al het verkeer binnenkomt. Dit verkeer wordt beheerd door de HTTP-server Kestrel, geconfigureerd door de klant in .NET en geplaatst in een pod. We hadden geluk met debuggen in de zin dat er een specifieke gebruiker was die het probleem consequent kon reproduceren. Echter, de keten van verkeer maakte het waar mogelijk ingewikkeld:

De fout in Ingress zag er als volgt uit:

{
   "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":{}
}

Kestrel gaf echter het volgende terug:

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

Zelfs bij maximale gedetailleerdheid bevatte de foutmelding van Kestrel uiterst weinig nuttige informatie:

{
   "number_fields":{"ThreadId":76},
   "stream":"stdout",
   "string_fields":{
      "EventId":"{"Id"=>17, "Name"=>"ConnectionBadRequest"}",
      "SourceContext":"Microsoft.AspNetCore.Server.Kestrel",
      "ConnectionId":"0HLL2VJSST5KV",
      "@mt":"Verbindings-id "{ConnectionId}" foutieve aanvraag gegevens: "{message}"",
      "@t":"2019-03-07T13:06:48.1449083Z",
      "@x":"Microsoft.AspNetCore.Server.Kestrel.Core.BadHttpRequestException: Ongeldige aanvraag: ongeldige headers.n   bij Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.Http1Connection.TryParseRequest(ReadResult result, Boolean& endConnection)n   bij Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.<ProcessRequestsAsync>d__185`1.MoveNext()",
      "message":"Ongeldige aanvraag: ongeldige headers."
   },
   "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":{}
}

Het lijkt erop dat alleen tcpdump kan helpen bij het oplossen van dit probleem... maar laat me herhalen over de verkeersketen:

Onderzoek

Het is duidelijk beter om het verkeer te beluisteren op die specifieke node, waar Kubernetes de pod heeft gedeployed: de volume dump zal zodanig zijn dat we vrij snel iets kunnen vinden. En inderdaad, bij het bekijken ervan werd dit frame opgemerkt:

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: Spanje
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, als 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

Bij het nauwkeurig bekijken van de dump werd het woord opgemerkt M.laga. Het is eenvoudig te raden dat er geen stad M.laga in Spanje is (maar er is wel Málaga). Het idee vastgrijpend, keken we naar de Ingress-configuraties, waar we een maand geleden (op verzoek van de klant) dit "onschuldige" snippet zagen 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;:

    Toen we deze headers stopten, werd alles goed! (Al snel bleek dat deze headers niet meer door de applicatie zelf nodig waren.)

Laten we nu naar het probleem kijken

in meer algemene zin . Het is gemakkelijk te reproduceren binnen de applicatie door een telnet-aanroep te doen naar. Het is gemakkelijk om dit binnen de applicatie te reproduceren door een telnet-verzoek te doen naar 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

… wordt geretourneerd 401 Unauthorized, zoals verwacht. Maar wat gebeurt er als we het volgende doen:

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

?

Zal terugkomen 400 Bad request — in de applicatielogboeken krijgen we dezelfde fout die al bekend is:

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

Conclusies

Specifiek Kestrel kan geen correcte verwerking van HTTP-headers met geldige symbolen in UTF-8 die voorkomen in de namen van een behoorlijk aantal steden.

Een aanvullend feit in ons geval is dat de klant momenteel de implementatie van Kestrel in de applicatie niet van plan is te wijzigen. Echter, de issues in AspNetCore zelf (№4318, №7707) geven aan dat dit ook niet zal helpen...

Samenvattend: deze notitie gaat niet meer over specifieke problemen met Kestrel of UTF-8 (in 2019 toch?!), maar over het feit dat nauwkeurig en systematisch onderzoek van elke stap tijdens het oplossen van problemen vroeg of laat zijn vruchten zal afwerpen. Veel succes!

P.S.

Lees ook op onze blog:

• «6 interessante systeemfouten bij het gebruik van Kubernetes [en hun oplossing]»;
• «Kubernetes tips & tricks: gepersonaliseerde foutpagina's in NGINX Ingress»;
• «Overzicht en vergelijking van Ingress-controllers voor Kubernetes»;
• «Ping-monitoring tussen Kubernetes-nodes — ons recept»;
• «3 ongebruikelijke gevallen over het netwerk subsysteem van Linux».

Bron: habr.com