Iz življenja s Kubernetesom: Kako strežnik HTTP ni bil naklonjen Špancem

Predstavnik našega odjemalca, katerega sklad aplikacij se nahaja v Microsoftovem oblaku (Azure), je obravnaval težavo: pred kratkim so se nekatere zahteve nekaterih odjemalcev iz Evrope začele končati z napako 400 (Slaba prošnja). Vse aplikacije so napisane v .NET, nameščene v Kubernetesu ...

Ena od aplikacij je API, prek katerega na koncu pride ves promet. Ta promet posluša strežnik HTTP Kestrel, ki ga konfigurira odjemalec .NET in gostuje v pod. Pri odpravljanju napak smo imeli srečo v smislu, da je obstajal določen uporabnik, ki je dosledno ponavljal težavo. Vse pa je zapletla prometna veriga:

Napaka v Ingressu je izgledala takole:

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

Hkrati je Kestrel dal:

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

Tudi z največjo natančnostjo je napaka Kestrel vsebovala izjemno malo koristnih informacij:

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

Zdi se, da bo le tcpdump pomagal rešiti to težavo ... vendar bom ponovil o prometni verigi:

Preiskava

Očitno je bolje poslušati promet na tem specifičnem vozlišču, kjer je Kubernetes postavil pod: prostornina odlagališča bo tolikšna, da bo mogoče kaj hitro najti vsaj nekaj. In res, pri pregledu je bil opažen naslednji okvir:

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

Ob natančnejšem ogledu odlagališča je bilo opaziti slov M.laga. Zlahka je uganiti, da v Španiji ni mesta M.laga (je pa Malaga). Pograbili smo to idejo in pogledali konfiguracije Ingressa, kjer smo videli tisto, ki je bila vstavljena pred mesecem dni (na zahtevo stranke) "neškodljiv" delček:

    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;

Po onemogočanju posredovanja teh glav je bilo vse v redu! (Kmalu je postalo jasno, da sama aplikacija ne potrebuje več teh glav.)

Zdaj pa poglejmo težavo bolj na splošno. Z lahkoto ga je mogoče reproducirati v aplikaciji tako, da pošljete zahtevo po telnetu 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

... vrača 401 Unauthorized, kot je bilo pričakovano. Kaj se zgodi, če naredimo:

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

?

Se bo vrnil 400 Bad request — v dnevniku aplikacije bomo prejeli napako, ki nam je že poznana:

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

Rezultati

Natančneje Kestrel ne morem pravilno obdelati glave HTTP s pravilnimi znaki v UTF-8, ki jih vsebujejo imena dokaj velikega števila mest.

Dodaten dejavnik v našem primeru je, da naročnik trenutno ne namerava spreminjati implementacije Kestrela v aplikaciji. Vendar težave v samem AspNetCore (№ 4318, № 7707) pravijo, da to ne bo pomagalo ...

Če povzamem: zapis ne govori več o specifičnih težavah Kestrela ali UTF-8 (leta 2019?!), temveč o tem, da pozornost in dosleden študij Vsak korak, ki ga naredite pri iskanju težav, bo prej ali slej obrodil sadove. Vso srečo!

PS

Preberite tudi na našem blogu:

• «6 zabavnih sistemskih hroščev v delovanju Kubernetesa [in njihova rešitev]»;
• «Namigi in triki Kubernetes: strani z napakami po meri v NGINX Ingress»;
• «Pregled in primerjava krmilnikov Ingress za Kubernetes»;
• «Spremljanje pingov med vozlišči Kubernetes – naš recept»;
• «3 nenavadni primeri o omrežnem podsistemu Linux".

Vir: www.habr.com