A Kubernetes életéből: Hogyan nem kedvezett a HTTP-szerver a spanyoloknak

Ügyfelünk képviselője, akinek az alkalmazásverme a Microsoft felhőben (Azure) található, megoldott egy problémát: a közelmúltban egyes európai ügyfelektől érkező kérések 400-as hibával (Rossz kérés). Minden alkalmazás .NET-ben íródott, Kubernetesben telepítve...

Az egyik alkalmazás az API, amelyen keresztül végül minden forgalom érkezik. Ezt a forgalmat a HTTP szerver figyeli Vörös vércse, amelyet a .NET-ügyfél konfigurál, és egy podban tárolja. A hibakereséssel abban az értelemben szerencsénk volt, hogy volt egy konkrét felhasználó, aki következetesen reprodukálta a problémát. A forgalmi lánc azonban mindent bonyolított:

Az Ingress hibája így nézett ki:

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

Ugyanakkor Kestrel ezt mondta:

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

A Kestrel-hiba maximális bőbeszéd mellett is rendkívüli mértékben tartalmazott kevés hasznos információ:

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

Úgy tűnik, hogy csak a tcpdump segít megoldani ezt a problémát... de megismétlem a forgalmi láncot:

Vizsgálat

Nyilván jobb hallgatni a forgalmat az adott csomóponton, ahol a Kubernetes egy podot telepített: a dump térfogata akkora lesz, hogy legalább valamit elég gyorsan meg lehessen találni. És valóban, a vizsgálat során a következő képkockát vettük észre:

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: Spain
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

A szemétlerakó alapos vizsgálatakor észrevették a szót M.laga. Könnyű kitalálni, hogy Spanyolországban nincs M.laga város (de van Málaga). Ezt az ötletet megragadva megnéztük az Ingress konfigokat, ahol az egy hónapja beillesztettet láttuk (a kliens kérésére) "ártalmatlan" részlet:

    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;

A fejlécek továbbításának letiltása után minden rendben lett! (Hamar kiderült, hogy magának az alkalmazásnak már nincs szüksége ezekre a fejlécekre.)

Most nézzük a problémát általánosabban. Könnyen reprodukálható az alkalmazáson belül, ha telnet kérést küld a címre 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

... visszatér 401 Unauthorized, ahogy az várható volt. Mi történik, ha megtesszük:

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

?

Vissza fog térni 400 Bad request — az alkalmazásnaplóban egy számunkra már ismert hibaüzenetet kapunk:

{
   "@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.n   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.Http1Connection.TryParseRequest(ReadResult result, Boolean& endConnection)n   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
}

Eredményei

Pontosabban Kestrel nem tud megfelelően dolgozza fel a HTTP-fejléceket a megfelelő karakterekkel az UTF-8-ban, amelyeket meglehetősen sok város neve tartalmaz.

Esetünkben további tényező, hogy az ügyfél jelenleg nem tervezi megváltoztatni a Kestrel alkalmazásban való megvalósítását. Azonban magában az AspNetCore-ban felmerülő problémák (№ 4318, № 7707) azt mondják, ez nem segít...

Összefoglalva: a jegyzet már nem a Kestrel vagy az UTF-8 konkrét problémáiról szól (2019-ben?!), hanem arról, hogy figyelmesség és következetes tanulás Minden lépés, amit a problémák keresése közben tesz, előbb-utóbb meghozza gyümölcsét. Sok szerencsét!

PS

Olvassa el blogunkon is:

• «6 szórakoztató rendszerhiba a Kubernetes működésében [és megoldásuk]";
• «Kubernetes tippek és trükkök: egyéni hibaoldalak az NGINX Ingressben";
• «A Kubernetes Ingress vezérlőinek áttekintése és összehasonlítása";
• «A Kubernetes csomópontok közötti ping figyelése - receptünk";
• «3 szokatlan eset a Linux hálózati alrendszerről".

Forrás: will.com