Мониторинг приложений при помощи Logger.Backends

Elixir в полной мере использует инфраструктуру ведения журнала Erlang для создания логов. Начиная с версии 1.10, которая должна быть выпущена в ближайшее время, нам становятся доступны новые пользовательские функции ведения журнала, которые появились в Erlang/OTP 21+.

В то время как OTP предоставляет всю инфраструктуру для доставки журнальных событий (ивентов) абонентам, само протоколирование, если понимать его как хранение и/или отображение событий журнала, должно быть реализовано приложением. С этой целью вводится соответствующая абстракция Logger.Backend.

Вот выдержка из официальной документации:

Logger поддерживает различные бэкэнды, куда записываются сообщения журнала.

Доступные бэкенды по умолчанию ограничиваются одним:

• :console — регистрирует сообщения в консоли (включено по умолчанию)

Любой разработчик может создать свой собственный жать, как бэкэнд для Logger. Поскольку Logger — это менеджер событий, реализующий эрланговский :gen_event behaviour, написание нового бэкэнда — просто вопрос создания своего обработчика событий, согласно тому, как это описано в документации для :gen_event.

Используемые бэкенды загружаются через :backends секцию в конфигурационном файле, которая должна быть обработана до запуска приложения :logger.

Наиболее распространенный подход, подаривший жизнь многим однотипным библиотекам на hex.pm ^[1], состоит в том, чтобы создать Logger.Backend, который понимает и выплевывает в консоль JSON, и прикрутить какую-нибудь доставку журнала куда нужно (обычно, это какой-нибудь LaaS). Таким образом все логи обычно попадают в базу данных NoSQL, типа Elastic, или чего-то похожего.

Мы не стали оригинальничать, и тоже храним наши логи в Elastic, но нынче одних логов уже недостаточно: современные модные пацаны цепляют ко всем сообщениям в логах — метрики на все про все. Стандартом де-факто для работы с метриками в приложениях OTP недавно стала библиотека Telemetry ^[2], относительно свежий проект с открытым исходным кодом, направленный на унификацию и стандартизацию того, как библиотеки и приложения на BEAM инструментируются и контролируются.

Подход, принятый в Telemetry прост до ужаса: мы зовете :telemetry.execute/2 ^[3] всякий раз, когда в приложении возникает потребность что-нибудь замерить, и библитека в ответ дернет зарегистрированный при старте приложения коллбэк. Кроме того, есть возможность прицепить Telemetry.Poller ^[4] и выполнять запросы метрик периодически. Пример в статье, на которую я дал ссылку выше, предлагает вызывать Logger.log/3 ^[5] из внутреннего обработчика событий Telemetry.

Gelato

Я ненавижу шаблонный код, который приходится таскать за собой копи-пастом из проекта в проект, из файла — в файл. Я хочу, чтобы все, что может быть сделано компилятором, планировщиком и воркерами — было сделано так, чтобы я об этом даже не думал. Для этого я часто упаковываю шаблонный код в крошечные библиотеки, которые скрывают весь необходимый boilerplate под капотом и предоставляют чистые интерфейсы для выполнения действий, необходимых нашему приложению. Мне просто хотелось бы, чтобы что-то, что можно вызвать как report("message", payload) — создавало запись, добавляло телеметрические данные, и отправляло эту запись в наше эластичное хранилище.

Оказывается, это не так уж и сложно сделать.

Мы решили использовать стандартные вызовы Logger в качестве интерфейса, чтобы простым изменением конфигов можно было бы внедрить желаемую функциональность в уже существующие проекты. Просто добавить новый Logger.Backend к существующему проекту:

config :logger, backends: [Our.Fancy.Logger.Backend]

— и voilà — логи с телеметрией теперь отправляются в эластичный бункер.

Вот так и появилась библиотека Gelato ^[6]. Я знаю, что настоящие суровые вдумчивые разработчики любят, чтобы библиотеки назывались чуть менее эзотерически, но я не настоящий разработчик. Какой есть, придется смириться. Хотя, gelato (в переводе с испанского — мороженое, кстати) даже немного созвучен эластику.

Библиотека сильно заточена на то, как вижу правильный мир я, и в хвост и в гриву использует подход «конвенция превыше конфигурации». Она упаковывает все, что может понадобиться, в один JSON и отправляет его на предварительно настроенный эластичный сервер простым HTTP-запросом. Она также прикрепляет все метаданные, до которых может дотянуться, типа метрик, полученных с помощью Process.info/1 ^[7] и т. п.

Чтобы начать использовать эту библиотеку в проекте, необходимо добавить в свой config/releases.exs файл следующее:

config :gelato,
  uri: "http://127.0.0.1:9200", # Elastic API endoint
  events: [:foo, :bar],         # attached telemetry events  
  handler: :elastic             # or :console for tests

config :logger,
  backends: [Gelato.Logger.Backend],
  level: :info

После этого любой вызов Logger.log/3, подобный приведенному ниже, будет передан telemetry и отправлен настроенному эластичному серверу.

Logger.info "foo",
  question: "why?",
  answer: 42,
  now: System.monotonic_time(:microsecond)

Еще библиотека представляет макрос Gelato.bench/4 ^[8], который принимает блок и выполняет два вызова Logger.log/3: один до выполнения блока и другой сразу после него, по типу аспектов в джаве.

Gelato ненавязчиво настаивает на лучшей организации интерфейсов внутри поектов при помощи макроса Gelato.defdelegatelog/2 ^[9], простой композиции Gelato.bench/4 и Kernel.defdelegate/2. Используя этот макрос, можно извлечь все интерфейсы проекта в ограниченный набор модулей верхнего уровня, и сделать эти вызовы логгируемыми с телеметрией из коробки.

Envío.Log

Еще одна реализация Logger.Backend, которая родилась в нашем закутке технологического аффекта, — это Envío.Log ^[10]. Он использует библиотеку Envío ^[11] для отправки сообщений в выделенный канал Slack. У этого логгера своя собственную настройка log_level, значение которой обычно устанавливается в :warn либо :error, для предотвращения заспамливания канала Slack, и все вызовы на уровнях меньше настроенного удаляются из BEAM во время компиляции.

Типичная конфигурация будет выглядеть так:

config :envio, :log,
  level: :warn,        # do not send :info to Slack
  process_info: false  # do not attach process info

config :logger, backends: [Envio.Log.Backend], level: :debug

config :envio, :backends, %{
  Envio.Slack => %{
    {Envio.Log.Publisher, :info} => [
      hook_url: {:system, "YOUR_SLACK_CHANNEL_API_ENDPOINT"}
    ]
  }
}

После настройки все вызовы Logger.{warn,error}/2 будут отправлены в соответствующий канал Slack. Это очень удобно для мониторинга рабочих процессов в производстве в режиме реального времени.

Удачного логгинга!

Автор: Aleksei Matiushkin

Источник ^[12]