Le représentant de notre client, dont la pile d'applications vit dans le cloud de Microsoft (Azure), a rencontré un problème: récemment, une partie des demandes de certains clients européens a commencé à se terminer avec l'erreur 400 (
Bad Request ). Toutes les applications sont écrites en .NET, déployées dans Kubernetes ...
Une application est l'API à travers laquelle, finalement, tout le trafic passe. Ce trafic est écouté par le serveur HTTP
Kestrel configuré par le client .NET et hébergé dans le pod. Avec le débogage, nous avons eu de la chance dans le sens où un utilisateur spécifique avait un problème de reproduction stable. Cependant, tout était compliqué par la chaîne de trafic:
L'erreur dans Ingress ressemblait à ceci:
{ "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":{} }
En même temps, Kestrel a donné:
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 une verbosité maximale, l'erreur Kestrel contenait extrêmement
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":"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":{} }
Il semblerait que seul tcpdump aidera à résoudre ce problème ... mais je répéterai à propos de la chaîne de trafic:
Enquête
Évidemment, il vaut mieux écouter le trafic
sur ce nœud particulier où Kubernetes a déployé le pod: le volume de vidage sera tel qu'il sera possible de trouver au moins quelque chose assez rapidement. En effet, lors de son examen, un tel cadre 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: 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
Après un examen attentif de la décharge, le mot
M.laga été remarqué. Il est facile de deviner qu'en Espagne il n'y a pas de ville M.laga (mais il y a
Málaga ). Saisissant cette idée, nous avons examiné les configurations d'Ingress, où nous avons vu un
extrait de code "inoffensif" inséré il y a un mois (à la demande du client):
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;
Lorsque vous désactivez le transfert de ces en-têtes, tout s'est bien passé! (Il est rapidement devenu évident que l'application elle-même n'avait plus besoin de ces en-têtes.)
Examinons maintenant le problème
d'une manière plus générale . Il peut être facilement reproduit à l'intérieur de l'application si vous faites une demande telnet à
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
...
401 Unauthorized Retours
401 Unauthorized , comme prévu. Et que se passe-t-il si nous le 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
?
400 Bad request renvoyée - dans le journal des applications, nous obtiendrons l'erreur que nous connaissons déjà:
{ "@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 }
Résumé
Plus précisément, Kestrel
ne peut pas gérer correctement les en-têtes HTTP avec les caractères corrects en UTF-8, qui sont contenus dans les noms d'un assez grand nombre de villes.
Un facteur supplémentaire dans notre cas est que le client ne prévoit pas actuellement de modifier l'implémentation de Kestrel dans l'application. Cependant, des problèmes dans AspNetCore lui-même (
n ° 4318 ,
n ° 7707 ) disent que cela n'aidera pas ...
Pour résumer: la note ne concerne plus les problèmes spécifiques de Kestrel ou UTF-8 (en 2019, l'année?!), Mais que l'
attention et l'étude cohérente de chaque étape lors de la recherche d'un problème porteront tôt ou tard leurs fruits. Bonne chance!
PS
Lisez aussi dans notre blog: