company_banner

Из жизни с Kubernetes: Как HTTP-сервер испанцев не жаловал



    Представитель нашего клиента, стек приложений которого обитает в облаке от Microsoft (Azure), обратился с проблемой: с недавнего времени часть запросов некоторых клиентов из Европы стала завершаться ошибкой 400 (Bad Request). Все приложения написаны на .NET, развёрнуты в Kubernetes…

    Одно из приложений — API, через который в конечном счёте приходит весь трафик. Этот трафик слушает HTTP-сервер Kestrel, сконфигурированный клиентом .NET и размещённый в pod'е. С отладкой нам повезло в том смысле, что был конкретный пользователь, у которого стабильно воспроизводилась проблема. Однако всё осложнялось цепочкой трафика:



    Ошибка в 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":{}
    }

    При этом Kestrel отдавал:

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

    Даже при максимальном verbosity ошибка Kestrel содержала крайне мало полезной информации:

    {
       "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 развернул pod: объём дампа будет такой, что получится довольно быстро найти хоть что-то. И действительно, при его рассмотрении был замечен такой фрейм:

    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). Ухватившись за эту идею, мы посмотрели конфиги Ingress, где увидели вставленный месяц назад (по запросу клиента) «безобидный» snippet:

        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;

    При отключении проброса этих заголовков всё стало хорошо! (Вскоре и вовсе выяснилось, что эти заголовки самому приложению больше не требовались.)

    Теперь посмотрим на проблему в более общем виде. Её легко воспроизвести внутри приложения, если сделать 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, как и ожидается. А что случится, если мы сделаем:

    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 не может корректно обрабатывать HTTP-заголовки с правильными символами в UTF-8, которые содержатся в названиях довольно большого количества городов.

    Дополнительный фактор в нашем случае — менять реализацию Kestrel в приложении клиент в данный момент не планирует. Впрочем, issues в самом AspNetCore (№4318, №7707) говорят о том, что это и не поможет…

    Подытоживая: заметка больше не о специфических проблемах Kestrel или UTF-8 (в 2019-то году?!), а о том, что внимательность и последовательное изучение каждого шага во время поиска проблемы рано или поздно принесут свои плоды. Успехов!

    P.S.


    Читайте также в нашем блоге:

    Флант
    278,00
    Специалисты по DevOps и Kubernetes
    Поделиться публикацией

    Похожие публикации

    Комментарии 16

      +9
      И вроде бы интересно, но при чем тут k8s? Он не сыграл вообще никакой роли. Или я не прав?
        +6
        Спасибо за замечание. По существу — он разве что «усложнил» цепочку трафика для troubleshooting'а, о чём сказано в тексте. Из хаба Kubernetes статью убрали.

        P.S. А в заголовке K8s по той причине, что хотим сделать такой цикл из материалов, объединённых тем, что все они будут из практики эксплуатации приложений в Kubernetes, однако с самим K8s напрямую могут быть не связаны. Их суть в первую очередь о «просто интересном опыте» и более «системных» выводах из него (что вообще случается в нашей практике, как подходить к вопросам troubleshooting'а и т.п.).
        0
        Казалось бы, на дворе 2019. А про Юникод то тут, то там вообще не слышали. Сам недавно столкнулся с тем, что в Windows 10 клиент NFS не умеет Юникод, только ASCII. Пришлось ради одной машины с Виндой поднимать зеркало на отдельной машине, где уже можно было бы запустить Самбу.
          0

          Больше поражают ответы разработчиков Kestrel в issues на эту тему, лаконично — "Нет!" :-)

            +2
            Программа реализует стандарт, причём реализует правильно, отвергая какашки там, где должен быть ASCII.
            +8
            А при чём тут unicode?

            В стандарте (на него ссылается стандарт HTTP/1.1) написано:
            Each header field can be viewed as a single, logical line of
            ASCII characters, comprising a field-name and a field-body.
            For convenience, the field-body portion of this conceptual
            entity can be split into a multiple-line representation; this
            is called «folding». The general rule is that wherever there
            may be linear-white-space (NOT simply LWSP-chars), a CRLF
            immediately followed by AT LEAST one LWSP-char may instead be
            inserted.

            tools.ietf.org/html/rfc822#section-3.1

            А вот люди, которые решили, что могут писать улыбающиеся какашки с кодом гендера и цвета кожи всюду — немного погорячились.

            Kestrel делает всё правильно, товарищи, дописывающие unicode — нарушают RFC. Хотят юникод? base64 их друг.
              +1

              Тут даже скорее проблема с конца GeoIP.

            +1
            По опыту эксплуатации Ажура в течении года — крайне не советую для каких либо серьезных вещей. Я лично буду всех своих клиентов отговаривать от этого облака — для менеджеров может он и интересен, откаты хорошие, менеджеры работают отлично и продают крайне нестабильный но дешевый и поверхностно понятный продукт, красивый только на бумаге, но по факту это эксплуатационный ад. Проблемы с сетью и дисками там просто из коробки, не взирая на статус клиента. Такое ощущение, будто МС решила выкатывать фичи не тестируя вообще.
            Если вам дорога репутация — выбирайте любые другие стабильные облака и не ведитесь на посулы продажников МС. Себе дороже.
              +2

              Будь это год назад, я бы согласился. Но проблемы становились меньше или уходили с каждой новой версией acs-engine/aks-engine и свежими версиями Kubernetes, поэтому сейчас всё вполне живёт. Есть дискомфорт у инженеров, есть много разных проблем, но в целом — можно жить :-) Мы научились его готовить. Ну и клиент изначально зашёл к нам уже с Azure.

                0

                Насчёт ажура — полностью соглашусь. Причем такие же отзывы слышал от коллег

                  0
                  очень громко и без каких либо фактов, не стоит выставлять себя со стороны «мне не зашло, потому что я не разобрался и не справился»
                  0

                  Ну, засовывать такие вещи в ingress — странно. Вообще, бизнес-логика в ингресс (всякие реврайты и ко) — опасная вещь.
                  В случае этого клиента — почему гео-айпи нельзя было реализовать уже на оконечном контейнере? Ведь "настоящий" ip клиента туда доезжает? И никаких "странных" проблем тогда бы и не получили.

                    0

                    Простите, я не понимаю, почему GeoIP в nginx становится бизнес-логикой? Какая разница, какой nginx будет отправлять хидеры с символами utf-8 с city в Kestrel, который их в итоге и не поймет?

                      0

                      Я задал вполне конкретный вопрос, а Вы вопросом на вопрос — как-то не очень хорошо получается.


                      Какая разница, какой nginx будет отправлять хидеры с символами utf-8 с city в Kestrel, который их в итоге и не поймет?

                      в стоимости отладки, например? Я просто обожаю кейсы с овер-инжинирингом (сам грешен — чего скрывать) и георическими попытами его потом пофиксить.


                      почему GeoIP в nginx становится бизнес-логикой?

                      А зачем он в Ingress — можете объяснить? Какая разница в каком месте трейса запроса появляется GeoIP данные?

                        0

                        Извините, не хотел вас оскорбить ни в коей мере своим вопросом. :-) В этом ингрессе GeoIP просто есть. Можно назвать это стандартным решением, для многих кейсов. Кроме того, заголовки могут улетать не только в одно приложение за этим ингрессом.

                    0

                    Простите, я не понимаю, почему GeoIP в nginx становится бизнес-логикой? Какая разница, какой nginx будет отправлять хидеры с символами utf-8 с city в Kestrel, который их в итоге и не поймет?

                    Только полноправные пользователи могут оставлять комментарии. Войдите, пожалуйста.