16 апреля 2026 г.

Логирование в Python: практика для аналитика

Зачем логирование

Когда аналитик пишет скрипт для разовой задачи — достаточно print. Прогнал, увидел вывод, отдал результат. Но как только скрипт становится регулярным (ежедневный ETL, автоматический отчёт, monitoring) — print перестаёт работать.

Представьте: ваш скрипт запускается каждую ночь из cron. Утром PM говорит «почему данные за вчера пустые». Вы заходите — а вывода никакого, скрипт успешно завершился, но данные не туда попали. Как понять, что случилось?

Логирование решает эту проблему. Вы пишете в лог не только ошибки, но и нормальный ход выполнения: «начал загрузку», «прочитал 1M строк», «завершил за 30 секунд». При инциденте лог рассказывает историю.

Базовое использование

import logging

logging.basicConfig(level=logging.INFO)
logger = logging.getLogger(__name__)

logger.info('Starting data load')
logger.warning('Found %d rows with NULL values', null_count)
logger.error('Failed to connect to DB')

Вывод:

INFO:__main__:Starting data load
WARNING:__main__:Found 150 rows with NULL values
ERROR:__main__:Failed to connect to DB

Вместо print — logger.info/warning/error. Различие — уровни и структура.

Уровни

Python определяет 5 стандартных уровней:

DEBUG — детальная информация для отладки. Обычно выключено в production.

INFO — нормальный ход выполнения. «Скрипт начал работу», «загрузил 1000 строк», «запись в БД».

WARNING — что-то подозрительное, но не блокирующее. «Нашёл дубликаты», «API вернул меньше данных, чем ожидалось».

ERROR — что-то пошло не так, но скрипт может продолжить. «Не смог обработать запись X».

CRITICAL — катастрофа, скрипт должен остановиться. «Не могу подключиться к БД».

Через level=logging.INFO вы задаёте minimum. Всё ниже этого уровня игнорируется. В production обычно INFO или WARNING. Для отладки можно DEBUG.

Формат сообщений

По умолчанию формат бедный. Настроить:

logging.basicConfig(
    level=logging.INFO,
    format='%(asctime)s - %(name)s - %(levelname)s - %(message)s',
    datefmt='%Y-%m-%d %H:%M:%S'
)

logger.info('Load started')
# 2026-04-16 10:30:45 - __main__ - INFO - Load started

Полный список переменных:

  • %(asctime)s — время.
  • %(name)s — имя logger'а.
  • %(levelname)s — INFO / WARNING / etc.
  • %(message)s — само сообщение.
  • %(filename)s — имя файла.
  • %(lineno)d — номер строки.
  • %(funcName)s — имя функции.

Для production полезно включить filename и lineno — помогает при debugging.

Запись в файл

Чтобы логи сохранялись на диск:

logging.basicConfig(
    filename='etl.log',
    level=logging.INFO,
    format='%(asctime)s - %(levelname)s - %(message)s'
)

Теперь все logger.info записываются в etl.log. Для долгоживущих скриптов обязательно.

Проблема: файл растёт бесконечно. Решение — rotating handler:

from logging.handlers import RotatingFileHandler

handler = RotatingFileHandler(
    'etl.log',
    maxBytes=10 * 1024 * 1024,  # 10 MB
    backupCount=5  # хранить 5 старых файлов
)

logger = logging.getLogger('etl')
logger.setLevel(logging.INFO)
logger.addHandler(handler)

Когда файл дорастает до 10 MB, он переименовывается в etl.log.1, создаётся новый etl.log. Последние 5 версий хранятся, старые удаляются.

Несколько handler-ов

Logger может писать в несколько мест одновременно:

import logging
from logging.handlers import RotatingFileHandler

logger = logging.getLogger('etl')
logger.setLevel(logging.DEBUG)

# В файл — всё, включая DEBUG
file_handler = RotatingFileHandler('etl.log', maxBytes=10*1024*1024)
file_handler.setLevel(logging.DEBUG)
file_handler.setFormatter(
    logging.Formatter('%(asctime)s - %(levelname)s - %(message)s')
)
logger.addHandler(file_handler)

# В консоль — только WARNING и выше
console_handler = logging.StreamHandler()
console_handler.setLevel(logging.WARNING)
console_handler.setFormatter(
    logging.Formatter('%(levelname)s: %(message)s')
)
logger.addHandler(console_handler)

В файл идут все детали. В консоль — только важное. Полезно для interactive запуска.

Структурированное логирование

Для production лучше структурированные логи (JSON), которые легко парсятся:

import logging
import json

class JsonFormatter(logging.Formatter):
    def format(self, record):
        return json.dumps({
            'timestamp': self.formatTime(record),
            'level': record.levelname,
            'message': record.getMessage(),
            'module': record.module,
            'function': record.funcName,
            'line': record.lineno
        })

handler = logging.FileHandler('etl.log')
handler.setFormatter(JsonFormatter())

logger = logging.getLogger('etl')
logger.addHandler(handler)

Результат — JSON-строки, которые можно загрузить в Elasticsearch, Grafana Loki, Datadog для search и analysis.

Контекст через extra

Добавление контекста к сообщениям:

logger.info('Processing user', extra={'user_id': 12345, 'step': 'load'})

В кастомном formatter можно использовать:

class ContextFormatter(logging.Formatter):
    def format(self, record):
        extras = ''
        if hasattr(record, 'user_id'):
            extras += f' user_id={record.user_id}'
        if hasattr(record, 'step'):
            extras += f' step={record.step}'
        return f'{record.asctime} [{record.levelname}] {record.getMessage()}{extras}'

Для простых случаев можно встраивать прямо в сообщение:

logger.info(f'Processing user_id={user_id} step={step}')

Владение логированием отличает качественный production-код от рутинных скриптов. В тренажёре Карьерник есть задачи на написание production-ready Python-кода для аналитических задач.

Отправка в Slack

Для критических ошибок — автоматическое уведомление в Slack:

import logging
import requests

class SlackHandler(logging.Handler):
    def __init__(self, webhook_url):
        super().__init__()
        self.webhook_url = webhook_url

    def emit(self, record):
        message = self.format(record)
        requests.post(self.webhook_url, json={'text': message})

slack_handler = SlackHandler('https://hooks.slack.com/services/...')
slack_handler.setLevel(logging.ERROR)  # только ERROR и выше
logger.addHandler(slack_handler)

Любой logger.error(...) автоматически улетает в Slack. Удобно для ETL, который работает ночью.

Логирование exceptions

При поимке exception — логируйте traceback:

try:
    risky_operation()
except Exception as e:
    logger.exception('Failed to process user %d', user_id)

logger.exception записывает сообщение + полный traceback. Без этого в логе только ошибка, без понимания, где именно упало.

Best practices

Не используйте print в production. Всегда logger. print идёт в stdout, может потеряться. Logger — контролируемый.

Уровни имеют значение. INFO для нормальной работы, не ERROR. Слишком много ERROR — они перестают быть важными.

Структурированные сообщения. Не «Обработали 1000 строк», а «Processed 1000 rows from table=X, duration=2.3s». Легче искать и фильтровать.

Контекст в каждом сообщении. В больших скриптах добавляйте user_id, request_id, task_id. Без этого логи — каша.

Не логируйте sensitive. Пароли, tokens, PII не должны попадать в логи.

Ротация. Всегда используйте rotating handler для файлов. Иначе диск закончится.

Logging в Airflow

В Airflow DAG-ах logger подключается автоматически:

from airflow.decorators import task
import logging

@task
def extract_data():
    logger = logging.getLogger(__name__)
    logger.info('Starting extraction')
    data = ...
    logger.info('Extracted %d rows', len(data))
    return data

Сообщения видны в Airflow UI → Task Instance → Logs. Это стандартный способ отладки DAG-ов.

Debugging level

Для глубокого debugging временно переключите на DEBUG:

logger.setLevel(logging.DEBUG)
logger.debug('Variable X = %s', variable_x)
logger.debug('Query result: %d rows', len(result))

В DEBUG-логе куча деталей. После исправления проблемы — вернитесь на INFO, иначе логи заспамят production.

Типичные ошибки

Логировать в цикле. for user in users: logger.info(...) на миллионе итераций забивает лог. Используйте aggregated logging: «Processed 1M users».

Игнорировать ошибки. try: ... except: pass плюс нет logging — невидимые проблемы. Хотя бы logger.exception.

F-strings в низко-уровневом логе. logger.debug(f'Debug data: {expensive_call()}'). F-string вычисляется всегда, даже если DEBUG выключен. Используйте lazy формат: logger.debug('Debug data: %s', ...).

Нет rotation. Через полгода log-файл 100 GB, диск заполнен, сервер падает.

Читайте также

FAQ

Logging vs print?

Logging для production — уровни, форматы, handlers. Print для interactive/debug.

Loguru вместо logging?

Loguru — современная альтернатива, проще API. Хороша для новых проектов. Для существующих — logging стандарт.

Как не записывать лишнее?

Уровень INFO как базовый. Debug только для отладки. Уберите лишние info-сообщения после стабилизации кода.

Logging в production-ETL?

Обязательно. Без логов непонятно, что сломалось ночью.

Тренироваться в Telegram