Логирование редко воспринимают как отдельную инженерную задачу. Обычно оно появляется «по пути»: написал сервис, добавил несколько 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 сделал логи структурированными: вместо сплошного текста они превратились в набор именованных полей. Но сами поля оставались никак не регламентированы. Поэтому следующим этапом мы ограничили набор полей и строго зафиксировали их имена и их порядок, создав лог‑схему.
Примеры полей из лог‑схемы
Поле | Тип | Заполняется автоматически | Обязательный | Описание |
|
| ✅ | ✅ | Уровень логгирования |
|
| ✅ | ✅ | Дата и время лог‑события |
|
| ✅ | ✅ | Файл, где произошло лог‑событие |
|
| ❌ | ✅ | Идентификатор |
|
| ❌ | ✅ | Лог‑сообщение |
|
| ❌ | ❌ | Произвольные параметры |
|
| ❌ | ❌ | Длительность аудио/видео в виде словаря {единица измерения: значение} |
|
| ❌ | ❌ | Путь к объекту или название объекта |
|
| ❌ | ❌ | Счетчик |
|
| ❌ | ❌ | Текст ошибки |
Так, мы смогли вылечить сразу несколько болей:
Все необходимые для логирования данные стали легко встраиваться в схему;
Для разработки и отладки добавлено поле
params: dict[str, Any], позволяющее контролируемо расширять лог‑схему. Этот процесс тоже имеет ряд правил, но в этой статье разбирать их мы не будем;Разработчики время от времени забывали указывать
uuid, что могло значительно усложнить аналитику. Лог‑схема закрепилаuuidкак обязательное поле, устранив человеческий фактор;В лог выводятся только поля, зафиксированные в схеме. Поля всегда выводятся в фиксированном порядке. За счет этого получилось упростить и ускорить поиск необходимой информации глазами в логах сервиса.
Благодаря возможности выбора рендера в 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. Именно здесь скрывалась проблема, которую мы видели в самом начале: одно и то же событие можно было описать десятками разных способов.
Я решила посмотреть на эту проблему как лингвист, и обнаружила, что логирование — это тоже язык, специализированный язык взаимодействия между сервисами и разработчиками.
С точки зрения теоретической лингвистики, любой естественный язык характеризуется следующими фундаментальными свойствами:
представляет собой систему знаков;
обладает внутренней структурой и системной организацией;
имеет лексическую систему;
обладает грамматикой и правилами функционирования;
позволяет на основе конечного числа единиц и правил порождать потенциально бесконечное множество новых высказываний.
Классические работы по языкознанию
de Saussure, F. Cours de linguistique générale. Lausanne; Paris: Payot, 1916.
Маслов Ю. С. Введение в языкознание. М.: Высшая школа, 1987.
Chomsky, N. Syntactic Structures. The Hague: Mouton, 1957; Chomsky, N. Aspects of the Theory of Syntax. Cambridge, MA: MIT Press, 1965.
В контексте разговора о логах можно провести следующие аналогии:
Свойство естественного языка | Аналог в системе логирования |
Система знаков | Лог состоит из стандартизированных сообщений и полей, каждое из которых имеет закрепленное значение |
Внутренняя структура и системная организация | Логи имеют единый формат, набор обязательных полей, уровни логирования, правила именования и общие правила построения сообщений, одинаковые для всех сервисов платформы |
Лексическая система | В платформе используется ограниченный словарь терминов: названия сущностей, действий, состояний, типов ошибок, атрибутов и так далее |
Грамматика и правила функционирования | Сообщения должны строиться по единым грамматическим шаблонам, использовать фиксированные правила формирования текста и структурирования данных |
Порождение бесконечного числа высказываний | Ограниченный словарь и набор шаблонов позволяют описывать практически любое событие, возникающее в любом сервисе платформы |
Такая интерпретация делает возможным применение лингвистических подходов к проектированию единого стандарта логирования. В частности, мы сконцентрировались на описании собственной грамматики лог‑сообщений.
Шаг 2. Добавили грамматику лог‑сообщений
Основной тезис мы сформулировали так:
Поле
eventявляется человекочитаемым описанием лог‑события и должно оставаться стабильным для корректной аналитики и поиска.
Помимо общих правил и ограничений, мы описали грамматические режимы лог‑сообщений:
ACTION:
Verb (Past Simple) → Object → [optional details]— завершенное событие (наиболее предпочтительный);PROGRESS:
Verb (Present Participle) → Object → [optional details]— текущее состояние;STATUS:
State / Fact— факт, итоговое состояние или состояние ошибки (наименее предпочтительный).
Почему именно такие формы
Past Simple (V2 / ‑ed) используется для завершенных действий, поэтому подходит для обозначения уже произошедшего события (Created new task, Loaded audio file).
Present Participle (‑ing) используется для длительных действий, поэтому подходит для обозначения процесса, который выполняется прямо сейчас (Loading audio file, Waiting for response).
State — состояние объекта или системы (Validation error, Service unavailable).
Fact — факт или утверждение, не описывающее действие (Model name, Task already exists).
Отдельно мы зафиксировали правила логирования ошибок:
Ошибка как событие описывается режимом ACTION и должна начинаться глаголом failed to (не удалось);
Ошибка как состояние может описываться режимом STATUS, но только для высокоуровневых ошибок;
Причина ошибки, если она известна, указывается словами через предлог due to (вследствие).
Примеры для режима ACTION
Завершенные действия:
Created new task
Sent result to Kafka
Действия, завершенные с ошибкой:
без указания причины — Failed to find record in DB
с указанием причины — Failed to create task due to task limit
Примеры для режима PROGRESS
Uploading subtitles
Updating record in DB
Waiting for external stage
Примеры для режима STATUS
Факты:
Model name
Task already exists
Итоговые состояния:
Service started
PostgreSQL constants loaded
Состояния ошибки:
Service unavailable
Connection timeout
Чтобы не приходилось каждый раз выбирать режим «на глаз», мы свели правила к небольшому алгоритму принятия решения:
Для выбора грамматического режима достаточно последовательно ответить на несколько вопросов, представленных на рисунке. Зеленым цветом отмечена рекомендация по исправлению: на практике сообщения нередко записываются до выполнения кратковременного действия. Такие сообщения рекомендуется перенести после выполнения операции и оформить как завершенное действие в режиме 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.
