Din viața cu Kubernetes: Cum serverul HTTP al spaniolilor nu era pe placul lor

Reprezentantul clientului nostru, a cărui stivă de aplicații se află în cloud-ul Microsoft (Azure), ne-a contactat cu o problemă: recent, o parte dintre cererile unor clienți din Europa au început să se finalizeze cu eroarea 400 (Cerere nevalidă). Toate aplicațiile sunt scrise în .NET, desfășurate în Kubernetes…

Una dintre aplicații este un API, prin care, în cele din urmă, ajunge tot traficul. Acest trafic este ascultat de serverul HTTP Kestrel, configurat de client în .NET și găzduit într-un pod. În ceea ce privește depanarea, am avut noroc în sensul că a existat un utilizator specific, la care problema se reproducea constant. Totuși, situația era complicată de lanțul de trafic:

Eroarea din Ingress a avut următorul aspect:

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

În același timp, Kestrel returna:

HTTP/1.1 400 Cerere nevalidă
Conexiune: închisă
Data: Wed, 06 Mar 2019 12:34:20 GMT
Server: Kestrel
Lungimea conținutului: 0

Chiar și la un nivel maxim de verbositate, eroarea Kestrel conținea extrem de puține informații utile:

{
   "number_fields":{"ThreadId":76},
   "stream":"stdout",
   "string_fields":{
      "EventId":"{"Id"=>17, "Name"=>"ConnectionBadRequest"}",
      "SourceContext":"Microsoft.AspNetCore.Server.Kestrel",
      "ConnectionId":"0HLL2VJSST5KV",
      "@mt":"Connection id "{ConnectionId}" date request data: "{message}"",
      "@t":"2019-03-07T13:06:48.1449083Z",
      "@x":"Microsoft.AspNetCore.Server.Kestrel.Core.BadHttpRequestException: Cerere mal formatată: antete invalide.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":"Cerere mal formatată: antete invalide."
   },
   "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":{}
}

Se părea că doar tcpdump ar putea ajuta la rezolvarea acestei probleme… dar voi repeta despre fluxul de trafic:

Investigație

Este evident că este mai bine să ascultăm traficul pe acel nod specific, unde Kubernetes a desfășurat podul: volumul dump-ului va fi suficient de mare pentru a găsi rapid ceva. Și într-adevăr, la examinarea sa a fost observat un astfel de cadru:

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: Spania
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: multe_cookie_encriptate; .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

La o examinare atentă a dump-ului, a fost observat cuvântul M.laga. E ușor de dedus că în Spania nu există un oraș M.laga (dar există Málaga). Prindându-ne de această idee, am verificat configurațiile Ingress, unde am văzut inserat cu o lună în urmă (la cererea clientului) un snippet „inofensiv”:

    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;

Dezactivând redirecționarea acestor antete, totul a fost bine! (În curând s-a descoperit că aceste antete nu mai erau necesare aplicației.)

Acum să ne uităm la problemă într-o formă mai generală. E ușor de reprodus în cadrul aplicației, dacă facem o solicitare telnet la 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

… se întoarce 401 Unauthorized, așa cum era de așteptat. Ce se va întâmpla dacă facem:

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 va întoarce 400 Cerere incorectă — în jurnalul aplicației vom obține deja cunoscuta noastră eroare:

{
   "@t":"2019-03-31T12:59:54.3746446Z",
   "@mt":"Connection id "{ConnectionId}" date de cerere incorecte: "{message}"",
   "@x":"Microsoft.AspNetCore.Server.Kestrel.Core.BadHttpRequestException: Cerere defectuoasă: antete invalide.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":"Cerere defectuoasă: antete invalide.",
   "EventId":{
      "Id":17,
      "Name":"ConnectionBadRequest"
   },
   "SourceContext":"Microsoft.AspNetCore.Server.Kestrel",
   "ThreadId":71
}

Concluzii

Anume Kestrel nu poate gestiona corect antetele HTTP cu caractere valide în UTF-8, care se regăsesc în numele unui număr considerabil de orașe.

Un alt factor în cazul nostru este că implementarea Kestrel în aplicație nu va fi schimbată în acest moment de client. Cu toate acestea, problemele din AspNetCore (№4318, №7707) sugerează că acest lucru nu va ajuta nici...

În concluzie: observația nu mai este despre problemele specifice Kestrel sau UTF-8 (în 2019?!), ci despre faptul că atentia și studierea consecventă a fiecărui pas în procesul de căutare a problemei va aduce, mai devreme sau mai târziu, roade. Succes!

P.S.

Citiți și în blogul nostru:

• «6 bug-uri sistemice interesante în exploatarea Kubernetes [și soluțiile lor]»;
• «Kubernetes tips & tricks: pagini de eroare personalizate în NGINX Ingress»;
• «Prezentare generală și comparație a controlerelor Ingress pentru Kubernetes»;
• «Monitorizarea ping-urilor între nodurile Kubernetes — rețeta noastră»;
• «3 cazuri neobișnuite despre subsistemul de rețea Linux».

Sursa: habr.com