En representant för vår klient, vars applikationsstack finns i Microsofts moln (Azure), åtgärdade ett problem: nyligen började några förfrågningar från vissa klienter från Europa sluta med fel 400 (). Alla applikationer är skrivna i .NET, distribuerade i Kubernetes...
En av applikationerna är API:t, genom vilket all trafik i slutändan kommer. Denna trafik lyssnas på av HTTP-servern , konfigurerad av .NET-klienten och värd i en pod. Med felsökning hade vi tur i den meningen att det fanns en specifik användare som konsekvent reproducerade problemet. Men allt komplicerades av trafikkedjan:
Felet i Ingress såg ut så här:
{
"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":{}
}Samtidigt gav Kestrel:
HTTP/1.1 400 Bad Request
Connection: close
Date: Wed, 06 Mar 2019 12:34:20 GMT
Server: Kestrel
Content-Length: 0Även med maximal verbositet innehöll Kestrel-felet extremt lite användbar information:
{
"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":{}
}Det verkar som att endast tcpdump hjälper till att lösa det här problemet... men jag ska upprepa om trafikkedjan:
Undersökning
Självklart är det bättre att lyssna på trafiken på den specifika noden, där Kubernetes har distribuerat en pod: volymen på dumpningen kommer att vara sådan att det kommer att vara möjligt att hitta åtminstone något ganska snabbt. Och faktiskt, när man undersökte det, märktes följande ram:
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
Vid närmare granskning av soptippen märktes ordet M.laga. Det är lätt att gissa att det inte finns någon stad i M.laga i Spanien (men det finns det ). Med tanke på den här idén tittade vi på Ingress-konfigurationerna, där vi såg den infogade för en månad sedan (på kundens begäran) "ofarligt" utdrag:
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;Efter att ha inaktiverat vidarebefordran av dessa rubriker blev allt bra! (Det stod snart klart att själva applikationen inte längre behövde dessa rubriker.)
Låt oss nu titta på problemet mer allmänt. Det kan enkelt reproduceras i applikationen genom att göra en telnet-förfrågan till 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
... återvänder 401 Unauthorized, som förväntat. Vad händer om vi gör:
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?
Kommer att återvända 400 Bad request — i applikationsloggen kommer vi att få ett fel som redan är bekant för oss:
{
"@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
}Resultat av
Närmare bestämt Kestrel korrekt bearbeta HTTP-rubriker med rätt tecken i UTF-8, som finns i namnen på ett ganska stort antal städer.
En ytterligare faktor i vårt fall är att kunden för närvarande inte planerar att ändra implementeringen av Kestrel i applikationen. Men problem i själva AspNetCore (, ) de säger att det här inte kommer att hjälpa...
För att sammanfatta: anteckningen handlar inte längre om de specifika problemen med Kestrel eller UTF-8 (år 2019?!), utan om det faktum att mindfulness och konsekventa studier Varje steg du tar när du letar efter problem kommer förr eller senare att bära frukt. Lycka till!
PS
Läs även på vår blogg:
- «";
- «";
- «";
- «";
- «".
Källa: will.com