El representante de nuestro cliente, cuya pila de aplicaciones vive en la nube de Microsoft (Azure), se enfrentó a un problema: recientemente, parte de las solicitudes de algunos clientes de Europa comenzaron a terminar con el error 400 (
Solicitud incorrecta ). Todas las aplicaciones están escritas en .NET, implementadas en Kubernetes ...
Una aplicación es la API a través de la cual finalmente llega todo el tráfico. Este tráfico es escuchado por el servidor HTTP
Kestrel configurado por el cliente .NET y alojado en el pod. Con la depuración, tuvimos suerte en el sentido de que había un usuario específico que tenía un problema reproducido estable. Sin embargo, todo fue complicado por la cadena de tráfico:
El error en Ingress se veía así:
{ "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":{} }
Al mismo tiempo, Kestrel dio:
HTTP/1.1 400 Bad Request Connection: close Date: Wed, 06 Mar 2019 12:34:20 GMT Server: Kestrel Content-Length: 0
Incluso con la máxima verbosidad, el error de Kestrel contenía muy
poca información útil :
{ "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":{} }
Parece que solo tcpdump ayudará a resolver este problema ... pero repetiré sobre la cadena de tráfico:
Investigación
Obviamente, es mejor escuchar el tráfico
en ese nodo en particular donde Kubernetes desplegó el pod: el volumen de volcado será tal que será posible encontrar al menos algo con bastante rapidez. De hecho, al considerarlo, se notó dicho marco:
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
Tras un examen cuidadoso del vertedero, se notó la palabra
M.laga . Es fácil adivinar que en España no hay ciudad M.laga (pero sí
Málaga ). Aprovechando esta idea, miramos las configuraciones de Ingress, donde vimos un
fragmento "inofensivo" insertado hace un mes (a pedido del cliente):
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;
Cuando deshabilita el reenvío de estos encabezados, ¡todo se volvió bueno! (Pronto quedó claro que la aplicación misma ya no necesitaba estos encabezados).
Ahora veamos el problema
de una manera más general . Se puede reproducir fácilmente dentro de la aplicación si realiza una solicitud telnet a
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 , como se esperaba. Y qué pasa si lo hacemos:
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 : en el registro de la aplicación obtendremos el error que ya conocemos:
{ "@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 }
Resumen
Específicamente, Kestrel
no puede procesar correctamente los encabezados HTTP con los caracteres correctos en UTF-8, que están contenidos en los nombres de un número bastante grande de ciudades.
Un factor adicional en nuestro caso es que el cliente actualmente no planea cambiar la implementación de Kestrel en la aplicación. Sin embargo, los problemas en AspNetCore (
No. 4318 ,
No. 7707 ) dicen que esto no ayudará ...
Para resumir: la nota ya no trata sobre los problemas específicos de Kestrel o UTF-8 (¡en 2019, el año?!), Sino que la
atención y el estudio constante de cada paso durante la búsqueda de un problema tarde o temprano dará sus frutos. Buena suerte
PS
Lea también en nuestro blog: