Microsoft（Azure）のクラウドにアプリケーションスタックが存在するクライアントの代表者が問題に直面しました。最近、ヨーロッパからの一部の顧客のリクエストの一部がエラー400（ Bad Request ）で終了し始めました。 すべてのアプリケーションは.NETで記述され、Kubernetesにデプロイされます...
1つのアプリケーションは、最終的にすべてのトラフィックが通過するAPIです。 このトラフィックは、.NETクライアントによって構成され、ポッドでホストされるKestrel HTTPサーバーによってリッスンされます。 デバッグでは、安定した再現に問題のある特定のユーザーがいたという意味で幸運でした。 ただし、トラフィックチェーンによってすべてが複雑になりました。
Ingressのエラーは次のようになりました。
{ "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":{} }
同時に、ケストレルは次のことを示しました。
HTTP/1.1 400 Bad Request Connection: close Date: Wed, 06 Mar 2019 12:34:20 GMT Server: Kestrel Content-Length: 0
最大限の冗長性があったとしても、ケストレルエラーには有用な情報はほとんど含まれていませんでした 。
{ "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":{} }
この問題の解決にはtcpdumpのみが役立つように思われますが、トラフィックチェーンについて繰り返します。
調査
明らかに、Kubernetesがポッドを展開した特定のノードのトラフィックをリッスンすることをお勧めします 。ダンプボリュームは、少なくとも何かを非常に迅速に見つけることができるようになります。 確かに、それを検討すると、そのようなフレームに気づきました：
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
/バック/ユーザー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
ダンプを注意深く調べると、
M.laga
という単語が
M.laga
ました。 スペインには都市M.lagaがないことは容易に推測できます（ただし、 Málagaはあります ）。 この考えをつかんで、Ingressの設定を調べました。1か月前に（クライアントの要求で） 「無害な」スニペットが挿入されていました。
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;
これらのヘッダーの転送を無効にすると、すべてがうまくいきました！ （アプリケーション自体がこれらのヘッダーを必要としなくなったことがすぐに明らかになりました。）
では、より一般的な方法で問題を見てみましょう。
localhost:80
telnetリクエストを行うと、アプリケーション内で簡単に再現できます。
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
予想通り、。 そして、私たちが何をしたら：
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
返されます-アプリケーションログに、すでにわかっているエラーが表示されます。
{ "@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 }
まとめ
具体的には、Kestrelは、かなり多数の都市の名前に含まれるUTF-8の正しい文字を持つHTTPヘッダーを正しく処理できません。
私たちの場合の追加の要因は、クライアントが現在、アプリケーションのKestrelの実装を変更する予定がないことです。 ただし、AspNetCore自体（ No. 4318 、No。7707）の問題は、これは役に立たないと言っています...
要約すると、このメモはケストレルやUTF-8の特定の問題に関するものではなく（2019年、今年？！）、問題の検索中の各ステップの注意と一貫した研究は遅かれ早かれ実を結ぶでしょう。 頑張って！
PS
ブログもご覧ください。