diff --git a/bot/middlewares/time_mdw.py b/bot/middlewares/time_mdw.py new file mode 100644 index 0000000..2333c7b --- /dev/null +++ b/bot/middlewares/time_mdw.py @@ -0,0 +1,311 @@ +""" +Middleware для измерения времени выполнения хендлеров +""" +from time import time +from typing import Callable, Awaitable, Any, Dict, Optional +from dataclasses import dataclass +from collections import defaultdict +from datetime import datetime + +from aiogram import BaseMiddleware +from aiogram.types import TelegramObject, Message, CallbackQuery, Update, User + +from middleware.loggers import logger + +__all__ = ('TimingMiddleware', 'TimingStats') + + +@dataclass +class HandlerMetrics: + """Метрики одного хендлера""" + total_calls: int = 0 + total_time: float = 0.0 + min_time: float = float('inf') + max_time: float = 0.0 + last_call: Optional[datetime] = None + + @property + def avg_time(self) -> float: + """Среднее время выполнения""" + return self.total_time / self.total_calls if self.total_calls > 0 else 0.0 + + def update(self, execution_time: float) -> None: + """Обновляет метрики""" + self.total_calls += 1 + self.total_time += execution_time + self.min_time = min(self.min_time, execution_time) + self.max_time = max(self.max_time, execution_time) + self.last_call = datetime.now() + + +class TimingStats: + """ + Глобальная статистика времени выполнения хендлеров. + + Хранит метрики для каждого хендлера и предоставляет методы для анализа. + """ + + def __init__(self): + self.metrics: Dict[str, HandlerMetrics] = defaultdict(HandlerMetrics) + + def record(self, handler_name: str, execution_time: float) -> None: + """ + Записывает время выполнения хендлера. + + Args: + handler_name: Имя хендлера + execution_time: Время выполнения в секундах + """ + self.metrics[handler_name].update(execution_time) + + def get_stats(self, handler_name: Optional[str] = None) -> Dict[str, Any]: + """ + Возвращает статистику по хендлеру или всем хендлерам. + + Args: + handler_name: Имя конкретного хендлера (если None, возвращает все) + + Returns: + Dict с метриками + """ + if handler_name: + metrics = self.metrics.get(handler_name) + if not metrics: + return {} + + return { + 'handler': handler_name, + 'total_calls': metrics.total_calls, + 'avg_time': f"{metrics.avg_time:.3f}s", + 'min_time': f"{metrics.min_time:.3f}s", + 'max_time': f"{metrics.max_time:.3f}s", + 'last_call': metrics.last_call.strftime('%Y-%m-%d %H:%M:%S') if metrics.last_call else None + } + + # Возвращаем статистику по всем хендлерам + return { + name: { + 'total_calls': m.total_calls, + 'avg_time': f"{m.avg_time:.3f}s", + 'min_time': f"{m.min_time:.3f}s", + 'max_time': f"{m.max_time:.3f}s" + } + for name, m in sorted( + self.metrics.items(), + key=lambda x: x[1].avg_time, + reverse=True + ) + } + + def get_slowest(self, limit: int = 10) -> list[tuple[str, float]]: + """ + Возвращает список самых медленных хендлеров. + + Args: + limit: Количество хендлеров в результате + + Returns: + List кортежей (имя_хендлера, среднее_время) + """ + sorted_handlers = sorted( + self.metrics.items(), + key=lambda x: x[1].avg_time, + reverse=True + ) + return [(name, m.avg_time) for name, m in sorted_handlers[:limit]] + + def reset(self, handler_name: Optional[str] = None) -> None: + """ + Сбрасывает статистику. + + Args: + handler_name: Имя хендлера для сброса (если None, сбрасывает все) + """ + if handler_name: + if handler_name in self.metrics: + del self.metrics[handler_name] + else: + self.metrics.clear() + + +# Глобальный экземпляр статистики +timing_stats = TimingStats() + + +class TimingMiddleware(BaseMiddleware): + """ + Middleware для измерения времени выполнения хендлеров. + + Возможности: + - Измерение времени выполнения каждого хендлера + - Автоматическая классификация (быстрый/средний/медленный) + - Сбор статистики + - Логирование медленных хендлеров + - Предупреждения о критически медленных запросах + + Attributes: + slow_threshold: Порог медленного хендлера (сек) + warning_threshold: Порог критически медленного хендлера (сек) + log_all: Логировать все хендлеры (даже быстрые) + collect_stats: Собирать статистику + + Example: + ```python + from middleware.timing import TimingMiddleware, timing_stats + + # Регистрация middleware + dp.message.middleware(TimingMiddleware(slow_threshold=0.5)) + + # Получение статистики + stats = timing_stats.get_slowest(5) + for handler, avg_time in stats: + print(f"{handler}: {avg_time:.3f}s") + ``` + """ + + def __init__( + self, + slow_threshold: float = 1.0, + warning_threshold: float = 3.0, + log_all: bool = False, + collect_stats: bool = True + ): + """ + Инициализация middleware. + + Args: + slow_threshold: Порог медленного хендлера в секундах + warning_threshold: Порог критически медленного хендлера + log_all: Логировать все хендлеры (иначе только медленные) + collect_stats: Собирать статистику выполнения + """ + super().__init__() + self.slow_threshold = slow_threshold + self.warning_threshold = warning_threshold + self.log_all = log_all + self.collect_stats = collect_stats + + @staticmethod + def _extract_user_info(event: TelegramObject) -> str: + """ + Извлекает информацию о пользователе из события. + + Args: + event: Объект события + + Returns: + str: Форматированная строка с информацией о пользователе + """ + user: Optional[User] = None + + # Прямое извлечение из Message/CallbackQuery + if isinstance(event, (Message, CallbackQuery)): + user = getattr(event, 'from_user', None) + + # Извлечение из Update + elif isinstance(event, Update): + for attr in ['message', 'edited_message', 'callback_query', + 'channel_post', 'edited_channel_post', 'inline_query', + 'chosen_inline_result', 'my_chat_member', 'chat_member']: + obj = getattr(event, attr, None) + if obj and hasattr(obj, 'from_user'): + user = obj.from_user + break + + if user: + return f"@{user.username}" if user.username else f"id{user.id}" + + return "@System" + + @staticmethod + def _get_handler_name(handler: Callable) -> str: + """ + Получает имя хендлера для логирования. + + Args: + handler: Функция хендлера + + Returns: + str: Имя хендлера + """ + # Пытаемся получить полное имя с модулем + if hasattr(handler, '__module__') and hasattr(handler, '__name__'): + return f"{handler.__module__}.{handler.__name__}" + elif hasattr(handler, '__name__'): + return handler.__name__ + else: + return str(handler) + + def _classify_speed(self, execution_time: float) -> tuple[str, str]: + """ + Классифицирует скорость выполнения. + + Args: + execution_time: Время выполнения в секундах + + Returns: + tuple: (уровень_лога, тип_лога) + """ + if execution_time >= self.warning_threshold: + return 'ERROR', 'CRITICAL_SLOW' + elif execution_time >= self.slow_threshold: + return 'WARNING', 'SLOW_HANDLER' + elif execution_time >= self.slow_threshold / 2: + return 'INFO', 'MEDIUM_HANDLER' + else: + return 'DEBUG', 'FAST_HANDLER' + + async def __call__( + self, + handler: Callable[[TelegramObject, Dict[str, Any]], Awaitable[Any]], + event: TelegramObject, + data: Dict[str, Any] + ) -> Any: + """ + Основной метод middleware. + + Args: + handler: Функция хендлера + event: Объект события + data: Дополнительные данные + + Returns: + Результат выполнения хендлера + """ + start_time = time() + handler_name = self._get_handler_name(handler) + user_str = self._extract_user_info(event) + + # Выполняем хендлер + try: + result = await handler(event, data) + return result + + finally: + # Измеряем время + execution_time = time() - start_time + + # Собираем статистику + if self.collect_stats: + timing_stats.record(handler_name, execution_time) + + # Классифицируем скорость + log_level, log_type = self._classify_speed(execution_time) + + # Логируем результат + if self.log_all or execution_time >= self.slow_threshold / 2: + # Формируем сообщение + if execution_time >= self.warning_threshold: + message = f"⚠️ КРИТИЧЕСКИ медленный хендлер '{handler_name}': {execution_time:.3f}с" + elif execution_time >= self.slow_threshold: + message = f"🐌 Медленный хендлер '{handler_name}': {execution_time:.3f}с" + else: + message = f"⏱️ Хендлер '{handler_name}': {execution_time:.3f}с" + + # Логируем + logger.log_entry( + level=log_level, + text=message, + log_type=log_type, + user=user_str + )