Трассировка и логирование в микросервисах: как мы втаскивали единый стандарт на 30 независимых команд

    Сервисы падали, падают и будут падать

    Когда вы быстро растете, микросервисы начинают появляться буквально по щелчку пальцев и в самых неожиданных местах. В таких условиях каждая команда обычно на ходу решает, где, как и какие логи будет складывать. Когда сначала 10, потом 20, а там и более команд логируют по-своему, начинается хаос.



    Например, наша команда сопровождения маркетинга в Skyeng знала: пользователь с таким-то айдишником нажал в личном кабинете кнопку «Сменить преподавателя» — постучался в наш сервис, дальше ушло три сообщения, в очереди было 2 вызова сервисов и эти сервисы ответили 200. Но на самом деле, что было у команд сопровождения учителей или биллинга, к которым мы стучались, не знал никто…

    Тогда мы придумали инструмент, чтобы маркировать трафик


    В компании есть стандарт окружения: PHP 7.x, Symfony 4.x, RabbitMQ для системы сообщений, GuzzleHTTP для внешних и своих ip, Docker. Благодаря тому, что нам более-менее известно, что будет в каждой команде, мы написали библиотеку, которая помогла бы сделать трассировку запроса по всей системе с первого клика.

    У нас два основных транспорта – HTTP и RabbitMQ. Запрос приходит или от пользователя, или по cron.

    • Мы берем любой HTTP-запрос, а прежде чем прокинуть дальше, добавляем заголовок request-id от NGINX, у которого возможность генерации вшита прямо в модуле.
    • В случае с cron, сами генерируем request-id внутри нашего бандла.

    Дальше прокидываем request-id всем следующим получателям в нашем облаке:

    • Автоматически добавляем в Guzzle-клиент для продолжения передачи request-id через HTTP при синхронных запросах к нашим сервисам.
    • Автоматически добавляем request-id ко всем AMQP-продюсерам для асинхронных запросов к нашим сервисам.
    • Также во всех местах, куда мы вклиниваемся для отправки, прикручен Jaeger opentracing — это поможет построить всё дерево/карту запросов. Таким образом наш внутренний request-id в качестве атрибута уходит в трейсы opentracing.

    Opentracing, маркировка через request-id и складывание в правильные места – первые шаги к тому, чтобы в компании появились хорошие логи. Когда команды подключат нашу библиотеку, схема выше начнет работать: request-id начнет передаваться по HTTP и AMQP, каждый сервис будет знать, в рамках какого глобального запроса он сейчас работает. И мы увидим, как запросы расползаются по нашей инфраструктуре.

    Логирование… inspired by Java


    Мы посчитали, что делая сложную композицию из нескольких классов, логер не нужно вставлять в конструктор. Он должен находиться сбоку и подключаться де-факто. В Java для этого, например, есть SLF4J аннотация.

    В PHP нет таких аннотаций, поэтому многие прокидывают в конструктор логеры, как дополнительную зависимость. Нам не нравился такой подход, поэтому мы сделали trait, который служит почти как аннотация (т.к. мы используем Symfony, то trait опирается на функционал autowiring — в результате получается практически как в Java).

    Что мы логируем? Помимо request-id, это:

    • runtime-id и process-id – идентификаторы текущего потока и процесса, внутри которых может обслуживаться несколько request-id,
    • user-id — так как в приложениях есть авторизация, этот идентификатор должен быть везде,
    • имя канала — канал можно использовать как бэкап для пользователя, если отвалилась база данных и что-то не записалось.
    • id контейнера, id сервиса, id задачи и прочее — все возможные мета-данные о Docker-контейнере. Зачем? У нас был момент, когда приложение было раскатано на 3 контейнера, а взял и сглючил один конкретный, — потому что он был развернут на глючном воркере.
    • Цепочки исключений — на уровне базы, сервиса, всегда создаем исключения более высокого уровня, потому что часто именно в последнем исключении и кроется «А что было-то?».
    • имя приложения — в процессе оказалось, что многие команды ориентируются на имя репозитория, а приложение внутри не знает, как его зовут: пришлось дособирать эту информацию и дописывать upname в yaml-файл.
    • плюс служебные команды и переменные окружения.

    Также есть вещи, которые можно записать заранее: запуск контроллера, запуск консьюмера. Можно заранее проставить уровень debug — он не будет попадать никуда, но если нужно, сможете включить на тестинге или на проде, посмотреть, что у вас происходит — вплоть до запросов в базу.

    В чем хранить логи на проде и тестингах


    На приложения у нас заводится New Relic, но мы дополнительно остановились на разделении записей между Sentry и Kibana.

    В Sentry падает то, что требует немедленной реакции. Мы заходим в отдельный проект, видим, сколько событий конкретного типа ошибок. Так как в Sentry летит только то, что надо исправлять, тут нет оверхеда, пока у нас не появляется куча ошибок.



    Наша панелька с «небоскребами» — если они растут, значит, кто-то сегодня закончит работу попозже.

    Если ткнуть глубже, видно, какие пользователи были затронуты, графики, какой браузер, теги, версия PHP — статистики очень много. Плюс можно сразу сделать таску в Jira из ошибки, настроить алерты, назначить ответственных, которым придет оповещение.



    Самое главное — не класть ошибки, которые вы не собираетесь править. Например, access denied сюда не летит.

    Но в Sentry есть и свой минус – он не очень хорошо справляется с большим потоком. Если вы, например, поделили на 0 и выкатили в прод, хранилище может лечь. Плюс надо помнить о том, что ошибка в одном сервисе может породить вал ошибок в другом сервисе. Решение этой проблемы выходит за тему статьи, но в целом смотрите в сторону паттерна circuit breaker.

    Лог всего, что не ошибки, мы прокидываем как JSON в Kibana. Для этого сборщик Beats ходит, собирает файлы, наш модуль для Filebeat отправляет их в Elasticsearch, а дальше мы уже в Kibana все вычитываем. Правильнее было бы вычитывать логи с вывода контейнера — и местами мы так и делаем.



    Наша Kibana… Выглядит она как Kibana — хороший полнотекстовый поиск, свой язык запросов, всякие поля.

    Хранится все: лог действий пользователя в контроллерах, начало и конец запроса в консьюмере, реббитовые запросы, работа бизнес-логики. А сбоку есть Grafana, по ней можно построить разные метрики.

    Итак, мы молодцы. Сделали полезную вещь. Что должно было быть результатом этих действий? Все команды начнут использовать единообразные библиотеки как часть ядра. Все, от саппорта до CTO, будут знать, где, как искать и что искать в логах. А единая система алертов сделает жизнь еще прекраснее… Внедряем? Да, но есть нюанс.

    Куда вас пошлют Пошаговый разбор, как внедрить у себя


    Зато понимающие люди будут говорить: «Он внедрил логи по всей компании»

    Внедрение — это не про технологии и код. А про политику. Ситуация, когда одна из команд сделала что-то, что неплохо-было-бы затащить к себе и другим, встречается часто. Но у других уже планы и приоритеты на месяцы вперед. У нас тут демократия — кроме критичных вещей вроде единого окружения никто никому ничего не навязывает.

    Чтобы логи стали единообразными, их идею надо «продать». Вот какую многоходовочку соорудили мы.

    Шаг 0. Начните с себя. Чтобы показать другим, как это классно, легко и красиво, вам нужно тестовое внедрение. Мы начали с собственной команды — в маркетинге как раз было около 20 сервисов. Заодно поняли, какие вопросы и сложности скорее всего возникнут — и начали готовиться к ним.

    • Например, сделали документацию с примерами и типовыми кейсами: как искать по логам, что делать, если нужен свой канал. Часть кейсов оказалось удобнее показать на уровне видео. Да, это значит, нужно делать презентацию, писать видео — но в итоге оно того стоит.

    Шаг 1. Вы идете к CTO и тимлидам. Вы думаете на языке PHP, они — уже бизнесом, фичами, деньгами. Аргументируйте на их языке:

    • «С библиотекой все будет быстрее подниматься, снизим шанс падения по той же причине», — в бизнесе заложено, что что-то упало. Теперь заложим, с какой скоростью оно встает: performance, скорость восстановления — это бизнес-метрики.
    • «Будет проще новичкам», — бизнесу зачастую проще нанять дополнительных разработчиков, чем перекидывать людей с других проектов. Но когда компания построена на микросервисах, часто получается, что единообразия в версиях ядра нет. Библиотека дает хотя бы частичное единообразие.

    Шаг 2. Ок, зашли к начальству и возбудили его. Теперь приходим к командам. Их первая и естественная реакция — тебя послать, потому что ты вроде как принес им дополнительной работы, а начальство теперь «может спрашивать про логи».

    • Красота и удобство Sentry продают. Начните с них.
    • Минимизируйте телодвижения разработчиков. Именно поэтому мы выбрали уровень библиотеки. Если делать здоровые конфиги или правила, из-за которых придётся менять код, никто этого делать не будет. А здесь мы сами написали бандлы, которые в большинстве своем конфигурируют себя сами и сами встраиваются, куда им надо. Их можно встраивать без конфигурации вообще — но если надо, их конфигурацию можно перекрыть.
    • Плюс удобный trait для добавления логера, документация с заранее объявленными каналами, готовыми примерами доработок и расширения конфигов. Так, чтобы не надо было городить что-то свое при внедрении.

    Да, часть рабочего времени в ближайшие месяцы вы все равно будете просто ходить по командам, спрашивать «А как оно там?», делать ревью внедрения и так далее. Но поверьте, оно того стоит.

    p.s. Пост основан на опыте и рассказах Вани, Макса и Димы, которые вместе делали этот проект. Мы не придумали, от чьего аккаунта это публиковать, и залили от аккаунта компании. В комментариях ребята готовы ответить от своих аккаунтов.

    p.p.s. В посте использованы цитаты из докладов Макса и Вани про этот проект.
    Skyeng
    Крупнейшая онлайн-школа Европы. Удаленная работа

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

      +3
      jaeger, open telemetry? Зачем вы советуете платные saas решения, не рассказав про существование кучи oss альтернатив, которые можно поставить на своё железо?
        0
        Привет, не понял вопрос.
        Метрики у нас собираются вообще statsd, но это за рамками статьи.
        Ни jaeger, ни open telemetry не имеют экстеншенов для пыха, чтобы маркировать весь трафик. Тут как раз и идет рассказ о том, как мы делали расширения для стандартных библиотек (guzzle, rabbit) откуда уже легко можно слать данные в тот же jaeger.
          0
          open telemetry здесь стоит немного сбоку. и в целом на нее смотрели — но отказались. так как сам подход — хорош, но какой то… обрывочный… просто — что показывает jaeger? окей — трейсы, спаны. но этого мало. и зачастую платный newrelic более продаваем руководству, чем бесплатный (относительно) jaeger.
          плюс там проблемы с интеграцией — newrelic встает и все начинает работать. а open telemetry надо пропихнуть во все запросы (HTTP / AMQP) и ловить везде (HTTP / AMQP). вменяемого бандла для того же symfony нет…

          поэтому обзор бесплатных инструментов в open telemetry оставил двоякое ощущение. да — круто. но пользы по факту мало от этого… надо прям нормальтно все допиливать. и тут получается что для руководства проще платить за newrelic чем оплачивать работу своих кодеров, за поддержку этого всего и прочее…
            0
            Все всегда заканчивается, в тот момент когда тестировать надо в закрытом контуре, без доступа к интернетикам.
              +1
              нууу… что ELK что sentry на dev кластере поднять не проблема… а newrelic… он там не нужен прям до конца… на production нужен… а тут… если чет где то не так — то это покажет либо мониторнинг самого кластера, либо метрики… и там ты уже просто с blackfire залезешь и посмотришь, кто хулиганит… поэтому… вообщем мы не смогли придумать, зачем нам нужен егерь :)
                0
                Не знал, что sentry появился на on-premise, спасибо!
            0

            Sentry можно поставить на своё железо, но не уверен, что Business Source License – oss.

            0
            Так как вы телеметрию делаете, расскажете?

            Вот вы генерируете request-id (aka span id), он потом идет в RabbitMQ например (уже с другим span id), потому идет в другой сервис via HTTP (с другим span id), etc., потом в одном из сервисов это падает с исключением которое вы видите в sentry/kibana. Как вы потом собираете эти отдельные несвязанные куски информации между собой? Jaeger/Zipkin/Google Trace/etc. собрали бы это в одну цепочку, а как вы это делаете с вашим набором инструментов?
              0
              он потом идет в RabbitMQ например (уже с другим span id)

              почему с другим? request-id добавляется в заголовок сообщения рэббита. Как раз сквозная маркировка. Потом можно в кибане по request-id вытащить всех, кого заафектил первичный запрос.
                0
                Спасибо, теперь понятно!
                То есть в вашем случае span id — это, скорее trace id. А в каким порядке они друг с другом связаны вы (как читатель логов) не знаете, но я предполагаю что это не так важно?
                  +3
                  нет, не знаем.
                  да, это не так важно.

                  просто как бы… есть таки еще newrelic, который умеет в и в телеметрию и в services maps, прчием умеет это комплексно и лучше егеря. поэтому всегда можно посмотреть еще и в newrelic. а там еще и APM хороший и вообще… но для логов newrelic не очень… потому получается, что левый глаз смотрит в sentry/ELK а правый еще и в newrelic. чуть неудобно, но в целом ок.
                    0
                    Спасибо за ответы
              0

              А почему отказались от Performance Monitoring в Sentry в пользу Kibana?
              Он в SDK предоставляет неплохой инструментарий для управления транзакциями…


              блок в “нашей панельке с «небоскребами»…”


              У нас разнообразный стек из python, java, kotlin, php, node, c#, javascript и возможно чего-то ещё… Мы "пробовали" openzipkin & kibana, но сейчас переходим на on-premise sentry, т.к. готовый инструментарий гораздо удобнее в поддержке.

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

                тут ведь много факторов. например фактор нагрузки. то есть — решения типа егеря умеют в ловлю логов — но плохо. а скакать между егерем и логами… что куда пошло. не. это не работает. когад система одна (newrelic) — это работает. когда 2 и больше — нет.

                далее — в целом newrelic уже был. и как раз для APM. поэтому когда понимали sentry — не было задачи чтотто делать с APM. как и когда понимали ELK (он тоже умеет в APM).

                далее — Sentry положить нагрузкой — как нефиг делать :) поэтому Sentry у нас — только для явных ошибок. и все. и хорошо что живой :)

                далее — фактор работы-из-коробки. когда ставишь newrelic agent for php — оно просто хоп и заработало. когда ставишь бандл для open telemetry — то надо все приложения перелопачивать, что бы все з0апросы обрабатывались, чтобы rabbitmq бандл правильный использовался и прочее. все тим лиды компании начинают про тебя очень плохзо думать :)

                вооот
                так что — Sentry для логов с ошибками, ELK — для всех логов. для жосткого APM / отладки — blackfire. для APM в проде — newrelic. и он же для services map, немного для логов, алертинга и для картины в целом. метрики — либо прометей (ибо есть экспортеры — поставил и работает) либо statsd (когда надо чтобы приложение чтото пихало) откуда все сводится в графану.

                в результате — то что с приложением все хорошо — просто видно в графане.
                если приложению плохо — то об этом проорет sentry / grafana / newrelic. и мы побежим в sentry / ELK / newrelic APM / newrelic services map.

                все просто.
                0
                У нас примерно также, еще добавили выброс исключения если запрос к сервису пришел без request-id.

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

                Самое читаемое