From 98692ac3bdb3011bcaee708fad5c8b666f738258 Mon Sep 17 00:00:00 2001 From: Egor Date: Sat, 1 Nov 2025 04:30:32 +0300 Subject: [PATCH] Improve timezone-aware logging --- app/config.py | 16 +++++- app/database/crud/subscription.py | 9 +++- app/services/maintenance_service.py | 64 ++++++++++++++++------ app/services/remnawave_service.py | 12 +---- app/utils/timezone.py | 82 +++++++++++++++++++++++++++++ main.py | 18 +++++-- 6 files changed, 169 insertions(+), 32 deletions(-) create mode 100644 app/utils/timezone.py diff --git a/app/config.py b/app/config.py index e29f9ae4..025e4719 100644 --- a/app/config.py +++ b/app/config.py @@ -7,6 +7,7 @@ import html from collections import defaultdict from datetime import time from typing import List, Optional, Union, Dict +from zoneinfo import ZoneInfo from pydantic_settings import BaseSettings from pydantic import field_validator, Field from pathlib import Path @@ -60,6 +61,8 @@ class Settings(BaseSettings): SQLITE_PATH: str = "./data/bot.db" LOCALES_PATH: str = "./locales" + + TIMEZONE: str = Field(default_factory=lambda: os.getenv("TZ", "UTC")) DATABASE_MODE: str = "auto" @@ -1424,9 +1427,20 @@ class Settings(BaseSettings): model_config = { "env_file": ".env", "env_file_encoding": "utf-8", - "extra": "ignore" + "extra": "ignore" } + @field_validator("TIMEZONE") + @classmethod + def validate_timezone(cls, value: str) -> str: + try: + ZoneInfo(value) + except Exception as exc: # pragma: no cover - defensive validation + raise ValueError( + f"Некорректный идентификатор часового пояса: {value}" + ) from exc + return value + settings = Settings() ENV_OVERRIDE_KEYS = set(settings.model_fields_set) diff --git a/app/database/crud/subscription.py b/app/database/crud/subscription.py index 7421ff72..6f5691fe 100644 --- a/app/database/crud/subscription.py +++ b/app/database/crud/subscription.py @@ -15,6 +15,7 @@ from app.database.models import ( from app.database.crud.notification import clear_notifications from app.utils.pricing_utils import calculate_months_from_days, get_remaining_months from app.config import settings +from app.utils.timezone import format_local_datetime logger = logging.getLogger(__name__) @@ -1131,7 +1132,13 @@ async def check_and_update_subscription_status( current_time = datetime.utcnow() - logger.info(f"🔍 Проверка статуса подписки {subscription.id}, текущий статус: {subscription.status}, дата окончания: {subscription.end_date}, текущее время: {current_time}") + logger.info( + "🔍 Проверка статуса подписки %s, текущий статус: %s, дата окончания: %s, текущее время: %s", + subscription.id, + subscription.status, + format_local_datetime(subscription.end_date), + format_local_datetime(current_time), + ) if (subscription.status == SubscriptionStatus.ACTIVE.value and subscription.end_date <= current_time): diff --git a/app/services/maintenance_service.py b/app/services/maintenance_service.py index df183d0e..7180a2d1 100644 --- a/app/services/maintenance_service.py +++ b/app/services/maintenance_service.py @@ -7,6 +7,7 @@ from dataclasses import dataclass from app.config import settings from app.external.remnawave_api import RemnaWaveAPI, test_api_connection from app.utils.cache import cache +from app.utils.timezone import format_local_datetime logger = logging.getLogger(__name__) @@ -45,6 +46,9 @@ class MaintenanceService: def get_maintenance_message(self) -> str: if self._status.auto_enabled: + last_check_display = format_local_datetime( + self._status.last_check, "%H:%M:%S", "неизвестно" + ) return f""" 🔧 Технические работы! @@ -52,7 +56,7 @@ class MaintenanceService: ⏰ Мы работаем над восстановлением. Попробуйте через несколько минут. -🔄 Последняя проверка: {self._status.last_check.strftime('%H:%M:%S') if self._status.last_check else 'неизвестно'} +🔄 Последняя проверка: {last_check_display} """ else: return settings.get_maintenance_message() @@ -79,7 +83,12 @@ class MaintenanceService: } emoji = emoji_map.get(alert_type, "ℹ️") - formatted_message = f"{emoji} ТЕХНИЧЕСКИЕ РАБОТЫ\n\n{message}\n\n⏰ {datetime.now().strftime('%d.%m.%Y %H:%M:%S')}" + timestamp = format_local_datetime( + datetime.utcnow(), "%d.%m.%Y %H:%M:%S %Z" + ) + formatted_message = ( + f"{emoji} ТЕХНИЧЕСКИЕ РАБОТЫ\n\n{message}\n\n⏰ {timestamp}" + ) return await notification_service._send_message(formatted_message) @@ -152,11 +161,14 @@ class MaintenanceService: await self._save_status_to_cache() + enabled_time = format_local_datetime( + self._status.enabled_at, "%d.%m.%Y %H:%M:%S %Z" + ) notification_msg = f"""Режим технических работ ВКЛЮЧЕН 📋 Причина: {self._status.reason} 🤖 Автоматически: {'Да' if auto else 'Нет'} -🕐 Время: {self._status.enabled_at.strftime('%d.%m.%Y %H:%M:%S')} +🕐 Время: {enabled_time} Обычные пользователи временно не смогут использовать бота.""" @@ -197,10 +209,13 @@ class MaintenanceService: else: duration_str = f"\n⏱️ Длительность: {minutes}мин" + notification_time = format_local_datetime( + datetime.utcnow(), "%d.%m.%Y %H:%M:%S %Z" + ) notification_msg = f"""Режим технических работ ВЫКЛЮЧЕН 🤖 Автоматически: {'Да' if was_auto else 'Нет'} -🕐 Время: {datetime.utcnow().strftime('%d.%m.%Y %H:%M:%S')} +🕐 Время: {notification_time} {duration_str} Сервис снова доступен для пользователей.""" @@ -229,14 +244,17 @@ class MaintenanceService: settings.get_maintenance_retry_attempts(), ) - await self._notify_admins(f"""Мониторинг технических работ запущен + await self._notify_admins( + f"""Мониторинг технических работ запущен 🔄 Интервал проверки: {settings.get_maintenance_check_interval()} секунд 🤖 Автовключение: {'Включено' if settings.is_maintenance_auto_enable() else 'Отключено'} 🎯 Порог ошибок: {self._max_consecutive_failures} 🔁 Повторных попыток: {settings.get_maintenance_retry_attempts()} -Система будет следить за доступностью API.""", "info") +Система будет следить за доступностью API.""", + "info", + ) return True @@ -291,13 +309,19 @@ class MaintenanceService: ) if not self._status.api_status: - await self._notify_admins(f"""API Remnawave восстановлено! + recovery_time = format_local_datetime( + self._status.last_check, "%H:%M:%S %Z" + ) + await self._notify_admins( + f"""API Remnawave восстановлено! ✅ Статус: Доступно -🕐 Время восстановления: {self._status.last_check.strftime('%H:%M:%S')} +🕐 Время восстановления: {recovery_time} 🔄 Неудачных попыток было: {self._status.consecutive_failures} -API снова отвечает на запросы.""", "success") +API снова отвечает на запросы.""", + "success", + ) self._status.api_status = True self._status.consecutive_failures = 0 @@ -321,13 +345,19 @@ API снова отвечает на запросы.""", "success") self._status.consecutive_failures += 1 if was_available: - await self._notify_admins(f"""API Remnawave недоступно! + detection_time = format_local_datetime( + self._status.last_check, "%H:%M:%S %Z" + ) + await self._notify_admins( + f"""API Remnawave недоступно! ❌ Статус: Недоступно -🕐 Время обнаружения: {self._status.last_check.strftime('%H:%M:%S')} +🕐 Время обнаружения: {detection_time} 🔄 Попытка: {self._status.consecutive_failures} -Началась серия неудачных проверок API.""", "error") +Началась серия неудачных проверок API.""", + "error", + ) if ( self._status.consecutive_failures >= self._max_consecutive_failures @@ -349,12 +379,16 @@ API снова отвечает на запросы.""", "success") logger.error(f"Ошибка проверки API: {e}") if self._status.api_status: - await self._notify_admins(f"""Ошибка при проверке API Remnawave + error_time = format_local_datetime(datetime.utcnow(), "%H:%M:%S %Z") + await self._notify_admins( + f"""Ошибка при проверке API Remnawave ❌ Ошибка: {str(e)} -🕐 Время: {datetime.utcnow().strftime('%H:%M:%S')} +🕐 Время: {error_time} -Не удалось выполнить проверку доступности API.""", "error") +Не удалось выполнить проверку доступности API.""", + "error", + ) self._status.api_status = False self._status.consecutive_failures += 1 diff --git a/app/services/remnawave_service.py b/app/services/remnawave_service.py index 72607382..e1bf5802 100644 --- a/app/services/remnawave_service.py +++ b/app/services/remnawave_service.py @@ -1,6 +1,5 @@ import asyncio import logging -import os import re from contextlib import AsyncExitStack, asynccontextmanager from datetime import datetime, timedelta @@ -42,6 +41,7 @@ from app.database.models import ( from app.utils.subscription_utils import ( resolve_hwid_device_limit_for_payload, ) +from app.utils.timezone import get_local_timezone logger = logging.getLogger(__name__) @@ -59,15 +59,7 @@ class RemnaWaveService: self._config_error: Optional[str] = None - tz_name = os.getenv("TZ", "UTC") - try: - self._panel_timezone = ZoneInfo(tz_name) - except Exception: - logger.warning( - "⚠️ Не удалось загрузить временную зону '%s'. Используется UTC.", - tz_name, - ) - self._panel_timezone = ZoneInfo("UTC") + self._panel_timezone = get_local_timezone() if not base_url: self._config_error = "REMNAWAVE_API_URL не настроен" diff --git a/app/utils/timezone.py b/app/utils/timezone.py new file mode 100644 index 00000000..83af1aa1 --- /dev/null +++ b/app/utils/timezone.py @@ -0,0 +1,82 @@ +"""Timezone utilities for consistent local time handling.""" + +from __future__ import annotations + +import logging +from datetime import datetime, timezone as dt_timezone +from functools import lru_cache +from typing import Optional +from zoneinfo import ZoneInfo + +from app.config import settings + +logger = logging.getLogger(__name__) + + +@lru_cache(maxsize=1) +def get_local_timezone() -> ZoneInfo: + """Return the configured local timezone. + + Falls back to UTC if the configured timezone cannot be loaded. The + fallback is logged once and cached for subsequent calls. + """ + + tz_name = settings.TIMEZONE + + try: + return ZoneInfo(tz_name) + except Exception as exc: # pragma: no cover - defensive branch + logger.warning( + "⚠️ Не удалось загрузить временную зону '%s': %s. Используем UTC.", + tz_name, + exc, + ) + return ZoneInfo("UTC") + + +def to_local_datetime(dt: Optional[datetime]) -> Optional[datetime]: + """Convert a datetime value to the configured local timezone.""" + + if dt is None: + return None + + aware_dt = dt if dt.tzinfo is not None else dt.replace(tzinfo=dt_timezone.utc) + return aware_dt.astimezone(get_local_timezone()) + + +def format_local_datetime( + dt: Optional[datetime], + fmt: str = "%Y-%m-%d %H:%M:%S %Z", + na_placeholder: str = "N/A", +) -> str: + """Format a datetime value in the configured local timezone.""" + + localized = to_local_datetime(dt) + if localized is None: + return na_placeholder + return localized.strftime(fmt) + + +class TimezoneAwareFormatter(logging.Formatter): + """Logging formatter that renders timestamps in the configured timezone.""" + + def __init__(self, *args, timezone_name: Optional[str] = None, **kwargs): + super().__init__(*args, **kwargs) + if timezone_name: + try: + self._timezone = ZoneInfo(timezone_name) + except Exception as exc: # pragma: no cover - defensive branch + logger.warning( + "⚠️ Не удалось загрузить временную зону '%s': %s. Используем UTC.", + timezone_name, + exc, + ) + self._timezone = ZoneInfo("UTC") + else: + self._timezone = get_local_timezone() + + def formatTime(self, record, datefmt=None): # noqa: N802 - inherited method name + dt = datetime.fromtimestamp(record.created, tz=self._timezone) + if datefmt: + return dt.strftime(datefmt) + return dt.strftime("%Y-%m-%d %H:%M:%S,%f")[:-3] diff --git a/main.py b/main.py index d50e4689..30ec2c5d 100644 --- a/main.py +++ b/main.py @@ -36,6 +36,7 @@ from app.services.system_settings_service import bot_configuration_service from app.services.external_admin_service import ensure_external_admin_token from app.services.broadcast_service import broadcast_service from app.utils.startup_timeline import StartupTimeline +from app.utils.timezone import TimezoneAwareFormatter class GracefulExit: @@ -49,13 +50,20 @@ class GracefulExit: async def main(): + formatter = TimezoneAwareFormatter( + '%(asctime)s - %(name)s - %(levelname)s - %(message)s', + timezone_name=settings.TIMEZONE, + ) + + file_handler = logging.FileHandler(settings.LOG_FILE, encoding='utf-8') + file_handler.setFormatter(formatter) + + stream_handler = logging.StreamHandler(sys.stdout) + stream_handler.setFormatter(formatter) + logging.basicConfig( level=getattr(logging, settings.LOG_LEVEL), - format='%(asctime)s - %(name)s - %(levelname)s - %(message)s', - handlers=[ - logging.FileHandler(settings.LOG_FILE, encoding='utf-8'), - logging.StreamHandler(sys.stdout) - ] + handlers=[file_handler, stream_handler], ) logger = logging.getLogger(__name__)