Vector.dev: как упростить подсчет метрик по логам. Снег сошел — нашли грабли

fc7e71115737cc94a20e9d6d788964ad.jpg

Меня зовут Дима Синявский, я SRE-инженер в Ви.Tech — это IT-дочка ВсеИнструменты.ру.

За полгода до этой статьи я рассказал вам в материале Vector.dev: как упростить подсчет метрик по логам как мы сделали удобный для нас подсчет метрик по логам.

И вот недавно мы поняли — что-то не так. Метрик иногда становилось много и появились те, которых быть не должно. Нас это удивило. Оказалось, мы себе оставили грабли в огороде, но удача нам улыбалась и мы их обходили.

Удивительно, что решение почти 2 года нас устраивало и прекрасно решало наши задачи!

Время рассказать вам о граблях: как и где ОНИ нас нашли, каким образом нам удалось от них избавиться.

Ищем грабли в огороде

Мы проверили правила в metrics-catalog.yml — все правильно. Проверили исходные логи — изменений не было. Но всплески в количестве метрик никуда не делись, как и неожиданные метрики, которых быть не должно было. На эндпоинте /metrics агрегатора vector мы видели то 1.2 Мб, то 2.5 Мб метрик в ответе. Заметили, что это происходит в те моменты, когда на наш сайт приходят боты, и это происходит в одно и тоже время.

В сырой выдаче метрик в формате Prometheus, которые выдает vector, мы обнаружили, что метрики vi_http_requests_total и vi_http_request_duration_seconds имеют серии метрик с всевозможными значениями path, но в metrics-catalog.yml для этого не было определено фильтров. Т.е. сюда попадали лишние, чего ранее мы не наблюдали.

Гипотеза первая

Подозрение пало на регулярные выражения в недавно добавленном новом правиле подсчета метрик vi_kubedns_http_requests_total. Если ранее правила были достаточно специфичны и выглядели как:

vi_http:
      requests_total:
        metric_type: counter
        group_by_logfield: http_status_code 
        label_logfield_mapping:
          path: "http_path"
          method: "http_method"
          status: "http_status_code"
          cluster_name: "cluster_name"
          container_name: "container_name"
          service_name: "service_name"
        event_selectors: 
          - selector: "Избранное. Добавить"
            filter:
              http_path:
                eq: "/favorites/"
              namespace:
                eq: "web-shop"
              service_name:
                re: "^web-shop(?:-canary)?$"
              http_method:
                eq: "POST"

То недавно добавленное выглядело так:

vi_kubedns_http:
    requests_total:
      metric_type: counter
      group_by_logfield: http_status_code
      label_logfield_mapping:
        vhost: "http_host"
        service_name: "service_name"
        k8s_cluster: "cluster_name"
        namespace: "namespace"
        method: "http_method"
        status: "http_status_code"
      event_selectors:
        - selector: входящие запросы по kubedns
          filter:
            namespace:
              eq: "web-shop"
            http_host:
              re: ".*local"

Подозрение пало на фильтр «входящие запросы по kubedns» (selector) в vi_kubedns_http он выглядел слишком общим и был таковым, в нем было только 2 условия. Причем получаемая из него метрика не содержала метку path, т.е. не могла давать взрыв кардинальности, который мы увидели.

Гипотеза с неправильно заданным фильтром не подтвердилась.

Гипотеза вторая

Возможно это баг при генерации трансформа фильтра для метрик. В трансформе [transforms.metrics-http-accesslog-k8s_filter] (код v1 на github)

В первой версии реализации мы имели следующую топологию трансформов (пайплайн)

Граф трансформов vector.dev для преобразования логов в метрики v1
Граф трансформов vector.dev для преобразования логов в метрики v1

Фильтр metrics-http-accesslog-k8s_filter отвечает за выбор подходящих событий логов. И, действительно, если запустить генерацию кода и посмотреть сгенерированный конфиг файл .generated/vector_config/aggregator_transforms_logs-to-metrics.toml, то мы увидим такое:

# Трансформ для отбора подходящих записей логов для учета в метрике
# Формируем выражение по metrics-catalog.yml
[transforms.metrics-http-accesslog-k8s_filter]
type = "filter"
inputs = ["metrics-http-accesslog-k8s_exclude_filter"]
condition = '''
# Проходим по всем namespace и метрикам, создаем условия отбора для событий из input
is_event_matched = false  || # selector_id: vi_http/requests_total/selectors/0
 ((  true  && includes([to_string!(.http_path)], "/") && includes([to_string!(.namespace)], "shop-production") && match(to_string!(.service_name), r'^shop-service(?:-canary)?$') && includes([to_string!(.http_method)], "GET")  ))  || # selector_id: vi_http/requests_total/selectors/1
 ((  true  && match(to_string!(.http_path), r'^/order$|^/order-fast$') && includes([to_string!(.namespace)], "shop-production") && match(to_string!(.service_name), r'^shop-service(?:-canary)?$')  ))  || # selector_id: vi_http/requests_total/selectors/2
 ((  true  && match(to_string!(.http_path), r'^/vendor/(?P([^/]+/)+)$') && includes([to_string!(.namespace)], "shop-production") && match(to_string!(.service_name), r'^shop-service(?:-canary)?$')  ))  || # selector_id: vi_http/request_duration_seconds/selectors/0
 ((  true  && includes([to_string!(.http_path)], "/") && includes([to_string!(.namespace)], "shop-production") && match(to_string!(.service_name), r'^shop-service(?:-canary)?$') && includes([to_string!(.http_method)], "GET")  ))  || # selector_id: vi_http/request_duration_seconds/selectors/1
 ((  true  && match(to_string!(.http_path), r'^/order$|^/order-fast$') && includes([to_string!(.namespace)], "shop-production") && match(to_string!(.service_name), r'^shop-service(?:-canary)?$')  ))  || # selector_id: vi_http/request_duration_seconds/selectors/2
 ((  true  && match(to_string!(.http_path), r'^/vendor/(?P([^/]+/)+)$') && includes([to_string!(.namespace)], "shop-production") && match(to_string!(.service_name), r'^shop-service(?:-canary)?$')  ))  || # selector_id: vi_kubedns_http/requests_total/selectors/0
 ((  true  && includes([to_string!(.namespace)], "shop-production") && match(to_string!(.http_host), r'.*local')  ))  || # selector_id: vi_kubedns_http/request_duration_seconds/selectors/0
 ((  true  && includes([to_string!(.namespace)], "shop-production") && match(to_string!(.http_host), r'.*local')  ))
is_allowed = is_event_matched
# решение подходит ли событие
is_allowed
'''

Как видно из кода, сюда попали фильтры и для метрики vi_kubedns_http, хотя ожидаем мы, что события для этой метрики считаются отдельно.

Вот так, элегантно ступая, мы нашли те самые грабли!
Оказалось, наш код объединяет все условия отбора событий метрик в один фильтр, потому в метриках vi_http_requests_total и vi_http_request_duration_seconds стали появляться серии по событиями предназначенным для vi_kubedns_http_requests_total.

Как же так, Карл! Как это не заметили?

Наш баг на протяжении 2 лет
Наш баг на протяжении 2 лет

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

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

Приводим грядки в порядок, грабли ставим в сарай

Для правильной работы этого решения каждый набор фильтров должен обрабатывать поток событий независимо. Кроме того, у нас есть код для замены значений меток для снижения кардинальности (label_override), про него тоже нельзя забыть. Предстояло правильно разделить потоки и затем посчитанные метрики собрать в единый поток для выдачи на чтение в /metrics.

Граф компонентов после генерации выглядит так (полное изображение тут в SVG)

Часть нового пайплайна подсчета метрик по логам (v1.1)
Часть нового пайплайна подсчета метрик по логам (v1.1)

Теперь для каждой метрики генерируется свой набор компонентов:

  • Фильтр отбора событий в метрику *-filter-metric_ — собирается из всех фильтров событий одной метрики

  • Сокращатель кардинальности значений *_reducer_ — если условие для поля определено, как регулярное выражение, то меняет значение на указанное в label_override.
    Пример:

    filter:
      http_path:
        re: "^/orders/([0-9]{5,20})/$"
        label_override: "/orders/:id/"
  • Определение метрики (счетчик или гистограмма) *-metric- — указывает как считать поступающие события в метрике, список ее меток и откуда брать значения.

Это делает возможным нормальный подсчет события независимо. В каждой метрике, теперь только свой набор событий. При этом фильтры независимы. Вы можете определить даже несколько метрик с разными именами и с одинаковыми фильтрами, но разными метками — это будет работать.

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

Мы не задавались вопросом насколько vector.dev потянет большое количество разнообразных метрик по логам, т.к. нам пока хватает 6 метрик на более чем 150 сервисов. Потому что в нашей практике логи по метрикам — это скорее исключение, чем правило.

Улучшения версии v1.1

Кроме устранения бага мы улучшили удобство пользования и отладки подсчета метрик по логам.

Сделали поддержку нескольких сред

Мы добавили возможность сборки нескольких конфигураций — под несколько сред (environment). Каждая среда имеет имя и свой файл metrics-catalog.yml. Это было сделано для того, чтобы отделить тестовый набор metrics-catalog.yml используемый в тестах трансформов для подсчета метрик по логам от используемого в проде.

Сделали тесты надежными

Ранее. Это была достаточно хрупкая конструкция из жестко связанных друг с другом metrics-catalog.yml, трансформов и тестам к ним. Меняя metrics-catalog.yml на прод-среде, нужно было следить и сопровождать тесты, хотя логика обработки логов в самих трансформах (в коде vrl для vector.dev) никак не менялась.

Теперь. Тесты генерируются по определениям внутри metrics-catalog.*.yml

  • metrics-catalog.testing.yml — содержит определения метрик и тестовые данные для проверки работоспособности самого пайплайна преобразования логов в метрики (его мы не трогаем)

  • metrics-catalog.production.yml — содержит определения метрик используемых для подсчета метрик в прод-среде (сюда вносим определения новых метрик)

Тесты определяем прямо в файле metrics-catalog.*.yml . Для каждого фильтра filter можно указать тестовые данные входные данные и ожидаемые выходные данные метрики, на их основе генерируются тесты. JSON Schema обновлена для поддержки секций данных testdata для тестов.

Попробуйте запустить код у себя

Весь код расположен в репозитории https://github.com/vseinstrumentiru/vector.dev-metrics-to-logs-helper.git (релиз 1.1.0)

Для запуска локально

Воспользуйтесь Linux системой для запуска кода. Мы проверяли на Ubuntu 24.04.

Cклонируйте наш код себе, переключитесь на ветку 1.1.0. Скачайте нужные утилиты и vector.dev:

make install-dependencies
make install-dev-dependencies

Запустите тесты (выполнится и генерация файлов конфигов vector.dev)

make test-vector-transforms

Попробуйте менять тестовые данные или определения в metrics-catalog.testing.yml. Если захочется запустить тесты для metrics-catalog.production.yml, то добавьте их в файл, выполните export VECTOR_ENV=production и снова запустите тесты.

Продолжение будет

Мы выловили баг, сделали улучшение, но все еще остались привязаны жестко к одному источнику логов — логи http сервера. Это значит для другого источника логов нужно будет снова писать код VRL для трансформов, чтобы применить этот подход.

Мы уже разработали более гибкое решение, которое позволяет не трогать код, а обходиться yaml-программистом.

Я расскажу о нем на ближайшей конференции DevOpsConf 2025 (Сколково) в своем докладе «Укрощение хаоса логов с помощью модели OpenTelemetry, Vector и ClickHouse. Итоги за два года». Увидимся 7 апреля, 15:50, Зал «Дели+Калькутта»

d7cc4a5dcf808654598ef057698df841.jpg

© Habrahabr.ru