La vie avec Kubernetes : Comment le serveur HTTP des Espagnols ne plaisait pas

Le représentant de notre client, dont l'ensemble des applications réside dans le cloud de Microsoft (Azure), a signalé un problème : depuis peu, certaines requêtes de clients européens se terminent par une erreur 400 (Mauvaise demande). Toutes les applications sont écrites en .NET, déployées dans Kubernetes…

L'une des applications est un API, par lequel tout le trafic finit par transiter. Ce trafic est géré par le serveur HTTP Kestrel, configuré par le client en .NET et hébergé dans un pod. Nous avons eu de la chance avec le débogage, car il y avait un utilisateur spécifique pour qui le problème était reproduit de manière constante. Cependant, la chaîne de trafic compliquait les choses :

L'erreur dans Ingress était formulée comme suit :

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

Dans le même temps, Kestrel a renvoyé :

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

Même avec le niveau de verbosité maximal, l'erreur Kestrel contenait très peu d'informations utiles peu d'informations utiles:

{
   "number_fields":{"ThreadId":76},
   "stream":"stdout",
   "string_fields":{
      "EventId":"{"Id"=>17, "Name"=>"ConnectionBadRequest"}",
      "SourceContext":"Microsoft.AspNetCore.Server.Kestrel",
      "ConnectionId":"0HLL2VJSST5KV",
      "@mt":"Données de requête incorrecte pour l'id de connexion "{ConnectionId}" : "{message}"",
      "@t":"2019-03-07T13:06:48.1449083Z",
      "@x":"Microsoft.AspNetCore.Server.Kestrel.Core.BadHttpRequestException : Requête malformée : en-têtes invalides.n   à Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.Http1Connection.TryParseRequest(ReadResult result, Boolean& endConnection)n   à Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.<ProcessRequestsAsync>d__185`1.MoveNext()",
      "message":"Requête malformée : en-têtes invalides."
   },
   "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":{}
}

Il semblerait que seul tcpdump puisse aider à résoudre ce problème… mais je vais répéter l'importance de la chaîne de trafic :

Enquête

Il est évident qu'écouter le trafic est préférable sur ce nœud spécifique, où Kubernetes a déployé le pod : le volume de dump sera tel qu'il sera assez rapide de trouver quelque chose. Et en effet, lors de son examen, un tel paquet a été remarqué :

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: Espagne
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: fr-FR,fr;q=0.9,en;q=0.8,en-GB;q=0.7,pl;q=0.6
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

En examinant de près le dump, le mot a été noté M.laga. Il est facile de deviner qu'il n'y a pas de ville M.laga en Espagne (mais il y a Málaga). En s'accrochant à cette idée, nous avons regardé les configurations Ingress, où nous avons vu un «snippet» inséré il y a un mois (à la demande du client) «inoffensif»:

    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;

Après avoir désactivé le passage de ces en-têtes, tout est devenu normal ! (Il s'est vite avéré que ces en-têtes n'étaient plus nécessaires pour l'application elle-même.)

Regardons maintenant le problème dans un sens plus général. Il est facile de le reproduire à l'intérieur de l'application en envoyant une requête telnet sur 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=Désirée

… est renvoyé 401 Unauthorized, comme prévu. Et que se passera-t-il si nous faisons :

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

?

Sera renvoyé 400 Bad request — dans le journal de l'application, nous obtiendrons déjà l'erreur familière :

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

Résultats

Spécifiquement Kestrel améliorer doit traiter correctement les en-têtes HTTP avec des caractères valides en UTF-8, présents dans les noms d'un nombre considérable de villes.

Un facteur supplémentaire dans notre cas — l'application client ne prévoit actuellement pas de changer l'implémentation de Kestrel. Cependant, les problèmes dans AspNetCore (n°4318, n°7707) indiquent que cela ne sera pas utile…

En résumé : cette note n'est plus sur des problèmes spécifiques de Kestrel ou d'UTF-8 (en 2019, vraiment ?!), mais sur le fait que l'attention et l'étude systématique de chaque étape lors de la recherche d'un problème porteront tôt ou tard leurs fruits. Bonne chance !

P.S.

Lisez aussi dans notre blog :

• «6 bogues système intéressants lors de l'exploitation de Kubernetes [et leurs solutions]»;
• «Kubernetes tips & tricks : pages d'erreur personnalisées dans NGINX Ingress»;
• «Aperçu et comparaison des contrôleurs Ingress pour Kubernetes»;
• «La surveillance des ping entre les nœuds Kubernetes — notre recette»;
• «3 cas atypiques sur le sous-système réseau de Linux».

Source : habr.com