Привет, Хабр!

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

Ведь кто из нас не любит починить что-то за 5 минут, вместо того чтобы провести в поисках проблемы целый день?

Библиотека logging

logging — это стандартная библиотека Python, предназначенная для записи логов. Она мощная, гибкая и легко настраиваемая.

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

Импорт и базовая настройка:

import logging

# Базовая конфигурация: уровень логирования и формат сообщения
logging.basicConfig(level=logging.INFO, format='%(asctime)s - %(name)s - %(levelname)s - %(message)s')

Уровни логирования:

• DEBUG: подробная информация, обычно интересная только при диагностике проблем.

• INFO: подтверждение того, что вещи работают как ожидается.

• WARNING: индикация некоторого неожиданного события или проблемы в будущем.

• ERROR: ошибка из-за которой выполнение определенной задачи не было завершено.

• CRITICAL: серьезная ошибка, указывающая на то, что программа может не справиться с продолжением работы.

Запись логов:

logging.debug('Это сообщение уровня DEBUG')
logging.info('Это сообщение уровня INFO')
logging.warning('Это сообщение уровня WARNING')
logging.error('Это сообщение уровня ERROR')
logging.critical('Это сообщение уровня CRITICAL')

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

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

Некоторые форматы выглядят так::

• %(asctime)s - время события.

• %(name)s - имя логгера.

• %(levelname)s - уровень логирования (DEBUG, INFO, WARNING, ERROR, CRITICAL).

• %(message)s - текст сообщения.

• %(filename)s и %(lineno)d - имя файла и номер строки, где было сгенерировано лог-сообщение.

Подключаем логирование

Первым делом настроим логгер.

import logging

logging.basicConfig(level=logging.INFO,
                    format='%(asctime)s - %(name)s - %(levelname)s - %(message)s')
logger = logging.getLogger(__name__)

Теперь интегрируем логирование в наши обработчики.

from telegram.ext import Updater, CommandHandler, MessageHandler, Filters

def start(update, context):
    logger.info("User %s started the conversation.", update.message.from_user)
    update.message.reply_text('Привет! Я твой логирующий бот.')

def help_command(update, context):
    logger.info("User %s asked for help.", update.message.from_user)
    update.message.reply_text('Спроси, и я отвечу!')

def echo(update, context):
    user_text = update.message.text
    logger.info("User %s said: %s", update.message.from_user, user_text)
    update.message.reply_text(user_text)

Не забудем про ошибки!

def error(update, context):
    logger.warning('Update "%s" caused error "%s"', update, context.error)

Соберем нашего бота:

def main():
    updater = Updater("YOUR_TELEGRAM_TOKEN", use_context=True)
    dp = updater.dispatcher

    dp.add_handler(CommandHandler("start", start))
    dp.add_handler(CommandHandler("help", help_command))
    dp.add_handler(MessageHandler(Filters.text & ~Filters.command, echo))

    dp.add_error_handler(error)

    updater.start_polling()
    updater.idle()

if __name__ == '__main__':
    main()

Когда и какой уровень использовать?

Debug:

Когда вам нужна подробная информация для диагностики проблемы. Это ваш инструментальный набор для отладки.

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

Info:

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

Записывайте основные моменты выполнения бота, такие как начало и конец работы бота к примеру

Warning:

Когда происходит что-то неожиданное, или есть потенциальная проблема на горизонте. Это ваш сигнал обратить внимание.

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

Error:

Когда произошла ошибка из-за которой выполнение определенной задачи не было завершено. Это ваш красный флаг.

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

Critical:

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

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

Куда отправлять логи

Самый базовый и понятный способ — запись логов в файл на сервере, где работает ваш ботик. Это может быть как простой текстовый файл, так и файл в формате JSON.

Для начала, нам нужно настроить логгер в Python, используя logging. Мы установим базовую конфигурацию, чтобы логи записывались в файл.

import logging

logging.basicConfig(filename='bot.log', level=logging.INFO, 
                    format='%(asctime)s - %(name)s - %(levelname)s - %(message)s')
logger = logging.getLogger(__name__)

filename='bot.log' указывает, что все логи будут записываться в файл bot.log.

level=logging.INFO означает, что будут записываться сообщения уровня INFO и выше (WARNING, ERROR, CRITICAL).

format='...' определяет формат наших логов.

Сообщения в канал или группу

import logging
from telegram import Bot
from telegram.ext import Updater, CommandHandler

TOKEN = 'YOUR_BOT_TOKEN'
# ID вашего канала или группы (например, -100123456789)
LOG_CHANNEL = 'YOUR_CHANNEL_OR_GROUP_ID'

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

# создадимм экземпляра бота
bot = Bot(token=TOKEN)

def log_to_channel(level, message):
    """
    Функция для отправки логов в канал или группу.
    """
    try:
        # Отправка сообщения в канал/группу
        bot.send_message(chat_id=LOG_CHANNEL, text=f"{level}: {message}")
    except Exception as e:
        # Логирование ошибки, если сообщение не было отправлено
        logger.error(f"Ошибка при отправке сообщения в канал: {e}")

# Пример использования функции для отправки лога
log_to_channel('INFO', 'Бот запущен и готов к работе!')

def start(update, context):
    user = update.message.from_user
    # Отправка лога при начале разговора с пользователем
    log_to_channel('INFO', f"Пользователь {user.username} ({user.id}) начал разговор.")
    update.message.reply_text('Привет! Я твой бот.')

def main():
    updater = Updater(TOKEN, use_context=True)
    dp = updater.dispatcher
    dp.add_handler(CommandHandler("start", start))
    updater.start_polling()
    # Отправка лога о начале работы бота
    log_to_channel('INFO', 'Бот начал работу.')
    updater.idle()

if __name__ == '__main__':
    main()

log_to_channel принимает уровень логирования и сообщение, а затем отправляет это сообщение в ваш канал или группу.

Ловим и логируем исключения

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

В Python исключения ловятся с помощью конструкции try-except. В коде бота вы, скорее всего, будете использовать это внутри обработчиков команд или в методах, которые вызываются в ответ на действия пользователя:

def some_bot_operation(update, context):
    try:
        risky_operation()
    except Exception as e:
        logger.error(f"Произошла ошибка: {e}")
        update.message.reply_text('Упс! Что-то пошло не так.')

python-telegram-bot дает нам специальный обработчик для ловли всех исключений, которые не были пойманы внутри обработчиков команд:

from telegram.ext import Updater, CommandHandler

def error_handler(update, context):
    logger.error(f"Ошибка в обработчике {update}: {context.error}")

def main():
    updater = Updater("YOUR_TOKEN", use_context=True)
    dp = updater.dispatcher
    dp.add_error_handler(error_handler)
    updater.start_polling()
    updater.idle()

if __name__ == '__main__':
    main()

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

def error_handler(update, context):
    user = update.message.from_user
    logger.error(f"Ошибка от пользователя {user.username} ({user.id}): {context.error}")

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

Пример реализации

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

Для начала настроим логирование в файл и в телега канал.

import logging
from pythonjsonlogger import jsonlogger
from telegram import Bot

TOKEN = 'YOUR_BOT_TOKEN'
LOG_CHANNEL = 'YOUR_CHANNEL_OR_GROUP_ID'

# настроем логирование в файл в формате JSON
logHandler = logging.FileHandler('pizza_bot.log')
formatter = jsonlogger.JsonFormatter('%(asctime)s %(levelname)s %(message)s')
logHandler.setFormatter(formatter)

# настроим логер
logger = logging.getLogger(__name__)
logger.addHandler(logHandler)
logger.setLevel(logging.INFO)

# функция для отправки логов в Telegram-канал
bot = Bot(token=TOKEN)
def log_to_channel(message):
    try:
        bot.send_message(chat_id=LOG_CHANNEL, text=message)
    except Exception as e:
        logger.error(f"Ошибка при отправке сообщения в канал: {e}")

Создадим основную логику нашего бота для заказа пиццы

from telegram.ext import Updater, CommandHandler, MessageHandler, Filters, ConversationHandler

# оппеделение состояний разговора
(CHOOSING_PIZZA, CHOOSING_DRINK) = range(2)

# Словарь с пиццами и напитками
PIZZAS = {'Маргарита': 5, 'Пепперони': 6, 'Гавайская': 7}
DRINKS = {'Кока-Кола': 2, 'Спрайт': 2, 'Фанта': 2}

# Обработчики команд
def start(update, context):
    update.message.reply_text('Привет! Я бот для заказа пиццы. Что вы хотите заказать?')
    logger.info(f"Пользователь {update.message.from_user.username} начал разговор.")
    log_to_channel(f"Пользователь {update.message.from_user.username} начал разговор.")
    return CHOOSING_PIZZA

def choose_pizza(update, context):
    user_choice = update.message.text
    if user_choice in PIZZAS:
        price = PIZZAS[user_choice]
        update.message.reply_text(f"Вы выбрали {user_choice}. Хотите что-нибудь к пицце?")
        logger.info(f"Пользователь {update.message.from_user.username} выбрал пиццу {user_choice}.")
        log_to_channel(f"Пользователь {update.message.from_user.username} выбрал пиццу {user_choice}.")
        return CHOOSING_DRINK
    else:
        update.message.reply_text("Пожалуйста, выберите пиццу из списка.")
        return CHOOSING_PIZZA

def choose_drink(update, context):
    user_choice = update.message.text
    if user_choice in DRINKS:
        price = DRINKS[user_choice]
        update.message.reply_text(f"Вы добавили {user_choice} к заказу. Спасибо за заказ!")
        logger.info(f"Пользователь {update.message.from_user.username} добавил к заказу {user_choice}.")
        log_to_channel(f"Пользователь {update.message.from_user.username} добавил к заказу {user_choice}.")
    else:
        update.message.reply_text("Пожалуйста, выберите напиток из списка.")
    return ConversationHandler.END

def cancel(update, context):
    update.message.reply_text('Заказ отменен. До свидания!')
    logger.info(f"Пользователь {update.message.from_user.username} отменил заказ.")
    log_to_channel(f"Пользователь {update.message.from_user.username} отменил заказ.")
    return ConversationHandler.END

# Основная функция
def main():
    updater = Updater(TOKEN, use_context=True)
    dp = updater.dispatcher

    # Настройка разговорного обработчика
    conv_handler = ConversationHandler(
        entry_points=[CommandHandler('start', start)],
        states={
            CHOOSING_PIZZA: [MessageHandler(Filters.text, choose_pizza)],
            CHOOSING_DRINK: [MessageHandler(Filters.text, choose_drink)]
        },
        fallbacks=[CommandHandler('cancel', cancel)]
    )

    dp.add_handler(conv_handler)

    # Начать опрос и работу бота
    updater.start_polling()
    updater.idle()

if __name__ == '__main__':
    main()

Мы определили несколько состояний для разговора: выбор пиццы и выбор напитка. У нас есть словари PIZZAS и DRINKS с доступными вариантами и ценами. Функции start, choose_pizza, choose_drink и cancel обрабатывают различные этапы заказа.

Мы используем ConversationHandler для управления потоком разговора.

В каждой функции мы логируем события как в файл, так и в Telegram-канал.

Как не терять логи

Rotating File Handler — это специальный обработчик в модуле logging. Он позволяет "ротировать" логи, то есть автоматически создавать новые файлы логов по достижении определенного размера или периода времени, и, при необходимости, удалять старые

Без ротации файлов логов, вы рискуете столкнуться с несколькими проблемами:

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

Ну и вообще в большом файле логов легко пропустить важные сообщения.

Импорт необходимых модулей:

import logging
from logging.handlers import RotatingFileHandler

Настройка Rotating File Handler:

logger = logging.getLogger(__name__)
logger.setLevel(logging.INFO)  # Устанавливаем уровень логирования

# настроим rfl
handler = RotatingFileHandler('bot.log', maxBytes=5000000, backupCount=5)
formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
handler.setFormatter(formatter)

# Добавляем обработчик к логгеру
logger.addHandler(handler)

'bot.log' — имя файла лога. maxBytes=5000000 — максимальный размер файла в байтах (в этом случае 5 МБ) перед его ротацией. backupCount=5 — количество файлов логов, которые будут храниться. После достижения этого числа самый старый файл будет удаляться.

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

Хорошо настроенное логирование помогает вам не только в его работе, но и в улучшение работы. Понять в чем косяки, что исправить и как оптимизировать бота. А получить практические навыки по логированию, аналитике и разработке можно в рамках онлайн-курсов от ведущих экспертов рынка. Заглядывайте в каталог, к моим коллегам из OTUS и выбирайте подходящее направление.

Keep coding, keep improving, и до новых встреч на Хабре.

и... с наступающим Новым Годом! ????