Телеметрия, диагностики и компилятор

В современном мире невозможно себе представить взрослое приложение, которое не экспортирует телеметрию. Метрики — важнейший атрибут поддерживаемого софта; для всех более-менее профессиональных технических специалистов термин «visibility» давно вытеснил прочие остальные баззворды наподобие «test coverage» и «continious integration».

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

Отсюда вырос знаменитый «слоган» эрланга «Let It Crash!», высмеиваемый и всегда неверно трактуемый теми, кто неутомимо отслеживает все исключительные ситуации… и спотыкается об отсутствие нужного для их корректной обработки контекста в месте ловли. «Let It Crash» — означает не «Хрен с ними, с ошибками», а «Случилась ошибка выполнения, но мы к ней готовы».

Когда где-то в недрах приложения случается ошибка — её можно отловить через сито логов и дампа памяти. Явная ошибка, приводящая к взрыву — это далеко не самый страшный зверь. Куда страшнее потенциальная ситуация, когда один из миллиона ваших процессов начинает спорадически чудить. Например, ваш код обрабатывает сто тысяч активных соединений (заказов, турникетов, да чего угодно) — корректно, всё, в принципе, работает; но раз в сутки пара заказов обрабатываются по часу (или некорректно, или не обрабатываются вовсе). В логах нет ошибок, потому что как таковой ошибки не случилось: просто ваш электронный кассир возомнил себя продавцом из советской бакалеи: «Сорок и сорок — рупь сорок, спичек вы не брали — с вас два семьдесят». И ушел на перекур, оставив покупателя в недоумении на полчаса.

Отлавливать такого рода внезапности — призваны метрики. Самой простой из них — является время нахождения в функции/методе. К этим наносекундам обычно цепляют общее состояние системы (количество процессов, используемая память, переменные среды окружения, размеры кучи и стека, и так далее). Просто сплёвывать такие данные в лог — не особо эффективно, из-за сложности анализа, поэтому люди придумали всякие красивые дэшбоарды, типа Графаны. Осталось научиться правильно эти самые метрики выплёвывать.

Стандартом de facto в кросс-платформенных средах стала OpenTelementry. В эрланге и эликсире люди больше тяготеют к гораздо более легковесной telemetry. Обе они отмечены тавром плохого дизайна (на мой, разумеется, взгляд) — код, посвященный observability проникает в бизнес-логику. Так быть не должно по двум причинам: ① Quae sunt Caesaris Caesari et quae sunt Dei Deo (тесты, метрики, и прочий инструментарий должен быть не только легко отчуждаемым, он вообще не должен попадать в некоторые среды исполнения) и ② вспомогательный код не должен быть источником возникновения ошибок в бизнес-логике.

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

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

# OpenTelemetry
# https://opentelemetry.io/docs/languages/erlang/instrumentation/#create-spans

require OpenTelemetry.Tracer

def parent_function() do
  OpenTelemetry.Tracer.with_span :parent do
    child_function()
  end
end

def child_function() do
  # this is the same process, so the span :parent set as the active
  # span in the with_span call above will be the active span in this function
  OpenTelemetry.Tracer.with_span :child do
    ## do work here. when this function returns, :child will complete.
  end
end

# telemetry
# https://hexdocs.pm/telemetry/readme.html#spans

def process_message(message) do
  start_metadata = %{message: message}

  result =
    :telemetry.span(
      [:worker, :processing],
      start_metadata,
      fn ->
        result = ... # Process the message
        {result, %{metadata: "Some additional info"}}
      end
    )
end

Оба способа вызывают у меня лично почечные колики. Как это спагетти вообще читать, если собственно полезный код — спрятан на третьем уровне вложенности?

Делаем правильно

В общем, как всегда: придётся городить собственный велосипед. Как бы вы хотели добавлять в код отсылку метрик? Я — аннотациями (кстати, я заглянул в реализации OpenTelemetry SDK для остальных языков, и нигде не используются аннотации, даже в джаве, дотнете, го и расте).

В эликсире для аннотаций принято использовать атрибуты модуля, что (пока в псевдокоде) будет выглядеть как-то вот так:

@telemetria level: :warning, span: :my_business_logic_span, …
def my_business_logic(arg1) do
  …
end

Функция оборачивается в условный with_span/2, в метадату отгружаются входные аргументы, результат и всевозможные метрики, и voilà. Понятно, что включить/отключить так определенную observability примерно в миллион раз проще, чем искать по всему коду вхождения прямых вызовов OpenTelemetry.Tracer.with_span/2.

Есть только одна проблема: чтобы превратить атрибуты модуля в вызовы функций, придется менять абстрактное синтаксическое дерево исполняемого кода (функции my_business_logic/1 в примере выше).

Как это правильно сделать в эликсире? — Добавить хуки времени компиляции @on_definition и @before_compile, конечно же. Внутри __before_compile__/1 мы будем издеваться над нашим абстрактным синтаксическим деревом, в внутри __on_definition__/6 — собирать информацию из последнего встреченного необработанного атрибута и приклеивать её к собственно сигнатуре и коду функции.

Когда компилятор встречает определение нашего атрибута, он еще ничего не знает про функцию, к которой мы планируем его приклеить, поэтому внутри хука на определение функции (помимо всяких проверок) — будет примерно вот что:

Module.put_attribute(
  env.module,
  :telemetria_hooks,
  struct(__MODULE__,
    annotation_type: type,
    env: env,
    kind: kind,
    fun: fun,
    arity: length(args),
    args: args,
    guards: guards,
    body: body,
    conditional: conditional,
    options: options
  )
)

Module.delete_attribute(env.module, :telemetria)

Мы добавили полную информацию о функции и её аннотации в накапливаемый атрибут @telemetria_hooks, и удалили обработанный пользовательский атрибут, чтобы избежать варнингов о переопределении на следующей функции (вы тоже, надеюсь, всегда собираете все ваши проекты с опцией --warnings-as-errors, или как там она называется у вашего компилятора?).

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

Приводить весь код я не буду, он доступен по ссылке (и довольно заковырист из-за необходимости корректно отработать всякие гарды и значения по умолчанию), остановлюсь на двух важных моментах: я разбираю AST функции на head и body, а потом с телом делаю буквально следующее:

body =
  Telemetria.telemetry_wrap(
    info.body,
    {info.fun, [line: meta.line], info.args},
    meta,
    options: info.options,
    conditional: info.conditional
  )

Функция telemetry_wrap/4 приклеит всё, что нужно, к метадате — и вызовет сконфигурированный хендлер (можно и свой добавить, или даже банальный логгер использовать).

Осталось только обмануть компилятор, подсунув ему свою функцию вместо объявленной пользователем. Начал я, разумеется, с эрланговского parse_transform, но потом сообразил, что можно просто перезаписать функцию, успокоив компилятор: «я знаю, что я тут делаю, дружище»:

[{:defoverridable, [context: Elixir, import: Kernel], [overrides]} | clauses]

Оно так выглядит, потому что из предкомпиляционного хука надо инжектить AST.

Вот и всё. Теперь можно добавить настройки, с которыми мы можем сверяться при решении, менять AST, или нет. А самое главное, мы можем продолжать добавлять изящные опции в нашу аннотацию, которая на данный момент поддерживает (это копипаста из документации):

• true — attach the telemetry to the function

• if: boolean() — compile-time condition

• if: (result -> boolean()) — runtime condition

• level: Logger.level() — specify a min logger level to attach telemetry

• group: atom() — the configured group to manage event throttling, see :throttle setting in Telemetria.Options

• locals: [atom()] — the list of names of local variables to be exported to the telemetry call

• transform: [{:args, (list() -> list())}, {:result, (any() -> any())}] — the functions to be called on the incoming attributes and/or result to reshape them

• reshape: (map() -> map()) — the function to be called on the resulting attributes to reshape them before sending to the actual telemetry handler; the default application-wide reshaper might be set in :telemetria, :reshaper config

• messenger_channels: %{optional(atom()) => {module, keyword()} — more handy messenger management, several channels config with channels names associated with their implementations and properties

Да, мы даже умеем слать опциональные нотификации во всякие там слаки и телеграмы. Просто потому, что меня попросили коллеги (или пользователи на гитхабе, не помню точно).

Диагностики

Я стараюсь помогать пользователям, насколько это в моих силах. Поэтому библиотека экспортирует свой компилятор, который собирает все аннотации в проекте, сверяет их с конфигурацией и предоставляет провайдеру серверу языка (LSP) дополнительную информацию, наподобие «этот вызов выключен в конфиге», «этот вызов будет выполнен только в prod’е», и т. д. Если кому-то интересно, как писать свои компиляторы для эликсира — мяукните в комментариях, расскажу.

Удачной обзёрвабилити!