Логирование редко воспринимают как отдельную инженерную задачу. Обычно оно появляется «по пути»: написал сервис, добавил несколько logging.info() и забыл. Но когда сервисов становится десятки, оказывается, что качество логов влияет на разработку не меньше, чем качество кода.

Привет! Меня зовут Александра Бадасян, я ML‑инженер в команде обработки речи и аудио в RUTUBE TECH. По образованию я лингвист, а по типу личности — зануда.

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

Мы довольно быстро стандартизировали код: подключили Ruff, типизацию и тесты. И обнаружили, что следующий источник неоднозначности — логирование. Даже после перехода на structlog одинаковые события продолжали называться по‑разному. Именно тогда мы решили посмотреть на логирование как на язык.

Какие проблемы были

Изначально логирование было реализовано через стандартную библиотеку logging. И выглядело так:

logging.info(f'{uuid} - New task created, total tasks: {self._tasks_counter}')

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

Пример:

logging.info(f'{uuid} - New task created, total tasks: {self._tasks_counter}')
logging.info(f'{uuid} - New task created')
logging.info(f'{uuid} - Task for ASR created with params: {recognition_params.model_dump()}')

Это все означало одно и то же событие — задача создана.

logging.info(f'{uuid} - Extracting audio')
logging.info(f'{uuid} - Loading audio file')
logging.info(f'{uuid} - extracting audio from: {file_url}')
logging.info(f'{uuid} - Source audio/video path: {audio_path}')

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

Все это вместе приводило к вполне конкретным проблемам:

• дублирование одной и той же информации,

• несогласованные формулировки,

• логи в виде сплошного текста,

• формирование логов f‑строками,

• отсутствие структурированных полей

• и, как следствие, невозможность построить стабильную аналитику.

Все это не просто существовало, а накапливалось и множилось от проекта к проекту, которых уже было больше 15. Это осложняло и сопровождение существующих сервисов, и внедрение любых новых инструментов разработки.

Так, перед нами встала задача стандартизировать логирование. И для ее решения мы предприняли несколько шагов.

Шаг 1. Зафиксировали структуру лога

Переход на structlog сделал логи структурированными: вместо сплошного текста они превратились в набор именованных полей. Но сами поля оставались никак не регламентированы. Поэтому следующим этапом мы ограничили набор полей и строго зафиксировали их имена и их порядок, создав лог‑схему.

Так, мы смогли вылечить сразу несколько болей: 

1. Все необходимые для логирования данные стали легко встраиваться в схему;

2. Для разработки и отладки добавлено поле params: dict[str, Any], позволяющее контролируемо расширять лог‑схему. Этот процесс тоже имеет ряд правил, но в этой статье разбирать их мы не будем;

3. Разработчики время от времени забывали указывать uuid, что могло значительно усложнить аналитику. Лог‑схема закрепила uuid как обязательное поле, устранив человеческий фактор;

4. В лог выводятся только поля, зафиксированные в схеме. Поля всегда выводятся в фиксированном порядке. За счет этого получилось упростить и ускорить поиск необходимой информации глазами в логах сервиса.

Благодаря возможности выбора рендера в structlog, мы разделили вывод логов на 2 режима: стандартный (JSON для машинной обработки и систем мониторинга) и для разработки (в виде таблицы). В этой статье будет описан второй режим, так как именно этот режим чаще всего используется инженерами в процессе работы.

Примеры вывода лога в разных режимах

logger.debug('ASR prediction runtime', uuid=uuid, runtime=prediction_runtime)

Позже мы добавили цветной рендеринг и уже на этом этапе получили довольно крутой результат. Сравните.

Так было до:

logging.info(f'{self._uuid} - Loading audio file')
logging.info(f'{self._uuid} - Local file path: {file_path}')
logging.info(f'{self._uuid} - Audio duration: {duration} seconds ({duration_h} hours)')

И вот такую красоту мы получили после:

self._logger = logger.bind(uuid=self._uuid)
self._logger.info('Loading audio file')
self._logger.info('Local file path', path=file_path)
self._logger.info('Audio duration', duration={'sec': duration, 'h': duration_h})

Фиксированный uuid и вывод в виде цветной таблицы, где легко отследить любую необходимую информацию.

Еще одним важным преимуществом фиксированной лог‑схемы стала стабильная интеграция с системами мониторинга. Мы используем Kibana, однако этот подход применим и к другим платформам, работающим со структурированными логами.

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

Благодаря этому Kibana автоматически разбирает записи на отдельные столбцы. Поиск информации на production свелся к фильтрации по значениям полей (uuid, service, error и др.), а не к поиску фрагментов текста. Это сделало анализ инцидентов заметно быстрее и избавило от необходимости поддерживать собственные правила парсинга логов.

Пример отображения логов в Kibana

Логирование как язык

Но и на этом мы не остановились. В текущем варианте оставалась одна неконтролируемая зона: текст сообщения лог‑события — поле event. Именно здесь скрывалась проблема, которую мы видели в самом начале: одно и то же событие можно было описать десятками разных способов.

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

С точки зрения теоретической лингвистики, любой естественный язык характеризуется следующими фундаментальными свойствами:

• представляет собой систему знаков;

• обладает внутренней структурой и системной организацией;

• имеет лексическую систему;

• обладает грамматикой и правилами функционирования;

• позволяет на основе конечного числа единиц и правил порождать потенциально бесконечное множество новых высказываний.

В контексте разговора о логах можно провести следующие аналогии:

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

Шаг 2. Добавили грамматику лог‑сообщений

Основной тезис мы сформулировали так:

Поле event является человекочитаемым описанием лог‑события и должно оставаться стабильным для корректной аналитики и поиска.

Помимо общих правил и ограничений, мы описали грамматические режимы лог‑сообщений:

• ACTION: Verb (Past Simple) → Object → [optional details] — завершенное событие (наиболее предпочтительный);

• PROGRESS: Verb (Present Participle) → Object → [optional details] — текущее состояние;

• STATUS: State / Fact — факт, итоговое состояние или состояние ошибки (наименее предпочтительный).

Отдельно мы зафиксировали правила логирования ошибок:

• Ошибка как событие описывается режимом ACTION и должна начинаться глаголом failed to (не удалось);

• Ошибка как состояние может описываться режимом STATUS, но только для высокоуровневых ошибок;

• Причина ошибки, если она известна, указывается словами через предлог due to (вследствие).

Чтобы не приходилось каждый раз выбирать режим «на глаз», мы свели правила к небольшому алгоритму принятия решения:

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

Как изменились логи

Давайте вернемся к примеру, который мы разбирали выше — про загрузку аудио. После обновления по новому стандарту три лог‑события объединились в одно:

self._logger = logger.bind(uuid=self._uuid)
self._logger.info(
    'Loaded audio file',
    path=file_path,
    duration={'sec': duration, 'h': duration_h},
)

logging.info(f'{uuid} - New task created, total tasks: {self._tasks_counter}')

logger.info('Created new task', uuid=uuid, count=self._tasks_counter)

logging.exception(f'{self._uuid} - Failed to prepare connection')

logger.exception(
    'Failed to prepare connection due to AioRpcError',
    uuid=self._uuid,
    error=str(error),
)

В результате получился не просто набор правил для логирования, а формальный язык описания событий платформы: с собственной структурой, словарем, грамматикой и правилами расширения. Все это было оформлено в единый стандарт логирования для сервисов платформы. В рамках этой статьи мы рассмотрели его ключевые элементы: фиксированную лог‑схему и правила построения лог‑сообщений. На практике же итоговый стандарт оказался значительно шире и включил:

• принципы детализации по лог‑уровням,

• саму лог‑схему и принципы ее расширения,

• правила построения сообщений,

• единый словарь событий с примерами.

Практический эффект не заставил себя ждать. Унифицировано 13 групп лог‑сообщений, описывающих одни и те же события, новые сервисы стали писать логи в едином стиле, а из код‑ревью, наконец, исчезло обсуждение формулировок. Поиск информации в Kibana практически полностью свелся к фильтрации по полям вместо поиска по тексту, что заметно ускорило анализ логов и расследование инцидентов.

Вывод

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

И если оглянуться назад, оказалось, что стандартизировать текст все‑таки сложнее, чем стандартизировать код. Код можно проверить автоматически. А язык приходится описывать самостоятельно.

Подписывайтесь на этот блог и канал Смотри за IT, если хотите знать больше о создании медиасервисов. Там рассказываем об инженерных тонкостях и продуктовых находках, делимся видео выступлений и кадрами из жизни команд Цифровых активов «Газпром-Медиа Холдинга» таких, как RUTUBE, PREMIER, Yappy.