2024-02-21 14:23:42 +03:00
|
|
|
|
import logging
|
2025-02-10 18:04:08 +03:00
|
|
|
|
from pathlib import Path
|
2025-06-02 02:56:11 +03:00
|
|
|
|
from typing import Any
|
2024-04-23 15:15:18 +03:00
|
|
|
|
|
2024-02-21 14:23:42 +03:00
|
|
|
|
import colorlog
|
2025-08-28 20:19:30 +03:00
|
|
|
|
from graphql import GraphQLError
|
|
|
|
|
|
|
2025-08-30 21:45:40 +03:00
|
|
|
|
graphql_logger = logging.getLogger("graphql")
|
|
|
|
|
|
graphql_logger.setLevel(logging.WARNING)
|
|
|
|
|
|
|
|
|
|
|
|
ariadne_logger = logging.getLogger("ariadne")
|
|
|
|
|
|
ariadne_logger.setLevel(logging.WARNING)
|
2024-02-21 14:23:42 +03:00
|
|
|
|
|
2025-02-10 18:04:08 +03:00
|
|
|
|
_lib_path = Path(__file__).parents[1]
|
|
|
|
|
|
_leng_path = len(_lib_path.as_posix())
|
|
|
|
|
|
|
2025-02-11 12:00:35 +03:00
|
|
|
|
|
2025-09-25 08:48:36 +03:00
|
|
|
|
def console_filter(record: logging.LogRecord) -> bool:
|
|
|
|
|
|
"""🔍 Фильтр для консольного вывода - подавляет спам авторизации"""
|
2025-02-10 18:04:08 +03:00
|
|
|
|
# Define `package` attribute with the relative path.
|
2025-02-11 12:00:35 +03:00
|
|
|
|
record.package = record.pathname[_leng_path + 1 :].replace(".py", "")
|
|
|
|
|
|
record.emoji = (
|
|
|
|
|
|
"🔍"
|
|
|
|
|
|
if record.levelno == logging.DEBUG
|
2025-03-09 21:01:52 +03:00
|
|
|
|
else "ℹ︎"
|
2025-02-11 12:00:35 +03:00
|
|
|
|
if record.levelno == logging.INFO
|
|
|
|
|
|
else "🚧"
|
|
|
|
|
|
if record.levelno == logging.WARNING
|
|
|
|
|
|
else "❌"
|
|
|
|
|
|
if record.levelno == logging.ERROR
|
|
|
|
|
|
else "🧨"
|
|
|
|
|
|
if record.levelno == logging.CRITICAL
|
2025-02-10 18:04:08 +03:00
|
|
|
|
else ""
|
2025-02-11 12:00:35 +03:00
|
|
|
|
)
|
2025-08-30 21:45:40 +03:00
|
|
|
|
|
2025-09-25 08:48:36 +03:00
|
|
|
|
# 🚫 Подавляем логи ошибок авторизации ТОЛЬКО в консоли (не в Sentry)
|
2025-08-31 22:32:02 +03:00
|
|
|
|
if record.levelno >= logging.ERROR and record.getMessage():
|
2025-08-30 21:45:40 +03:00
|
|
|
|
message = record.getMessage()
|
2025-09-25 08:48:36 +03:00
|
|
|
|
# Подавляем ошибки авторизации в консоли
|
2025-08-31 22:32:02 +03:00
|
|
|
|
if any(
|
|
|
|
|
|
phrase in message
|
|
|
|
|
|
for phrase in [
|
|
|
|
|
|
"Требуется авторизация",
|
|
|
|
|
|
"AuthorizationError",
|
|
|
|
|
|
"GraphQL request:",
|
|
|
|
|
|
"Traceback (most recent call last):",
|
|
|
|
|
|
"graphql.error.graphql_error.GraphQLError: Требуется авторизация",
|
2025-08-31 22:45:51 +03:00
|
|
|
|
"load_drafts",
|
|
|
|
|
|
"GetUserDocuments",
|
|
|
|
|
|
"GetDrafts",
|
|
|
|
|
|
"During handling of the above exception",
|
2025-08-31 23:53:16 +03:00
|
|
|
|
'File "/usr/local/lib/python3.13/site-packages/graphql/execution/execute.py"',
|
|
|
|
|
|
'File "/app/services/auth.py"',
|
|
|
|
|
|
"await_result",
|
|
|
|
|
|
"handle_field_error",
|
2025-08-31 22:45:51 +03:00
|
|
|
|
"await gather",
|
2025-08-31 23:53:16 +03:00
|
|
|
|
"get_results",
|
2025-08-31 22:45:51 +03:00
|
|
|
|
"raise error",
|
2025-08-31 23:53:16 +03:00
|
|
|
|
"return_type, field_nodes, info, path, await result",
|
|
|
|
|
|
'raise AuthorizationError("Требуется авторизация")',
|
|
|
|
|
|
"decorated_function",
|
2025-08-31 22:32:02 +03:00
|
|
|
|
]
|
|
|
|
|
|
):
|
2025-09-25 08:48:36 +03:00
|
|
|
|
return False # Не показываем в консоли ошибки авторизации
|
2025-08-31 22:32:02 +03:00
|
|
|
|
|
2025-09-25 08:48:36 +03:00
|
|
|
|
# Подавляем повторяющиеся Ariadne логи в консоли
|
2025-08-31 22:45:51 +03:00
|
|
|
|
if record.name in ["ariadne", "graphql"]:
|
2025-08-31 22:32:02 +03:00
|
|
|
|
message = record.getMessage()
|
2025-08-31 22:45:51 +03:00
|
|
|
|
if any(
|
|
|
|
|
|
phrase in message
|
|
|
|
|
|
for phrase in [
|
|
|
|
|
|
"Требуется авторизация",
|
|
|
|
|
|
"AuthorizationError",
|
|
|
|
|
|
"load_drafts",
|
|
|
|
|
|
"GraphQL request:",
|
|
|
|
|
|
]
|
|
|
|
|
|
):
|
2025-08-31 22:32:02 +03:00
|
|
|
|
return False
|
2025-08-30 21:45:40 +03:00
|
|
|
|
|
2025-06-02 02:56:11 +03:00
|
|
|
|
return True
|
2025-02-10 18:04:08 +03:00
|
|
|
|
|
2025-02-11 12:00:35 +03:00
|
|
|
|
|
2025-09-25 08:48:36 +03:00
|
|
|
|
def basic_filter(record: logging.LogRecord) -> bool:
|
|
|
|
|
|
"""🔍 Базовый фильтр для всех логов - только добавляет метаданные"""
|
|
|
|
|
|
# Define `package` attribute with the relative path.
|
|
|
|
|
|
record.package = record.pathname[_leng_path + 1 :].replace(".py", "")
|
|
|
|
|
|
record.emoji = (
|
|
|
|
|
|
"🔍"
|
|
|
|
|
|
if record.levelno == logging.DEBUG
|
|
|
|
|
|
else "ℹ︎"
|
|
|
|
|
|
if record.levelno == logging.INFO
|
|
|
|
|
|
else "🚧"
|
|
|
|
|
|
if record.levelno == logging.WARNING
|
|
|
|
|
|
else "❌"
|
|
|
|
|
|
if record.levelno == logging.ERROR
|
|
|
|
|
|
else "🧨"
|
|
|
|
|
|
if record.levelno == logging.CRITICAL
|
|
|
|
|
|
else ""
|
|
|
|
|
|
)
|
|
|
|
|
|
return True
|
|
|
|
|
|
|
|
|
|
|
|
|
2024-02-21 14:23:42 +03:00
|
|
|
|
# Define the color scheme
|
|
|
|
|
|
color_scheme = {
|
2025-02-10 18:04:08 +03:00
|
|
|
|
"DEBUG": "light_black",
|
2024-04-17 18:32:23 +03:00
|
|
|
|
"INFO": "green",
|
|
|
|
|
|
"WARNING": "yellow",
|
|
|
|
|
|
"ERROR": "red",
|
|
|
|
|
|
"CRITICAL": "red,bg_white",
|
2024-02-21 14:23:42 +03:00
|
|
|
|
}
|
|
|
|
|
|
|
|
|
|
|
|
# Define secondary log colors
|
|
|
|
|
|
secondary_colors = {
|
2024-04-17 18:32:23 +03:00
|
|
|
|
"log_name": {"DEBUG": "blue"},
|
|
|
|
|
|
"asctime": {"DEBUG": "cyan"},
|
|
|
|
|
|
"process": {"DEBUG": "purple"},
|
2025-02-10 18:04:08 +03:00
|
|
|
|
"module": {"DEBUG": "light_black,bg_blue"},
|
|
|
|
|
|
"funcName": {"DEBUG": "light_white,bg_blue"}, # Add this line
|
2024-02-21 14:23:42 +03:00
|
|
|
|
}
|
|
|
|
|
|
|
|
|
|
|
|
# Define the log format string
|
2025-02-10 18:04:08 +03:00
|
|
|
|
fmt_string = "%(emoji)s%(log_color)s%(package)s.%(funcName)s%(reset)s %(white)s%(message)s"
|
2024-02-21 14:23:42 +03:00
|
|
|
|
|
|
|
|
|
|
# Define formatting configuration
|
|
|
|
|
|
fmt_config = {
|
2024-04-17 18:32:23 +03:00
|
|
|
|
"log_colors": color_scheme,
|
|
|
|
|
|
"secondary_log_colors": secondary_colors,
|
|
|
|
|
|
"style": "%",
|
|
|
|
|
|
"reset": True,
|
2024-02-21 14:23:42 +03:00
|
|
|
|
}
|
|
|
|
|
|
|
2024-03-03 16:59:15 +03:00
|
|
|
|
|
2024-02-21 14:23:42 +03:00
|
|
|
|
class MultilineColoredFormatter(colorlog.ColoredFormatter):
|
2025-06-02 02:56:11 +03:00
|
|
|
|
def __init__(self, *args: Any, **kwargs: Any) -> None:
|
2024-03-12 18:14:34 +03:00
|
|
|
|
super().__init__(*args, **kwargs)
|
2024-04-17 18:32:23 +03:00
|
|
|
|
self.log_colors = kwargs.pop("log_colors", {})
|
|
|
|
|
|
self.secondary_log_colors = kwargs.pop("secondary_log_colors", {})
|
2024-03-12 18:14:34 +03:00
|
|
|
|
|
2025-06-02 02:56:11 +03:00
|
|
|
|
def format(self, record: logging.LogRecord) -> str:
|
2025-02-10 18:04:08 +03:00
|
|
|
|
# Add default emoji if not present
|
2025-02-11 12:00:35 +03:00
|
|
|
|
if not hasattr(record, "emoji"):
|
2025-06-02 02:56:11 +03:00
|
|
|
|
record.emoji = "📝"
|
|
|
|
|
|
|
|
|
|
|
|
# Add default package if not present
|
|
|
|
|
|
if not hasattr(record, "package"):
|
|
|
|
|
|
record.package = getattr(record, "name", "unknown")
|
|
|
|
|
|
|
|
|
|
|
|
# Format the first line normally
|
|
|
|
|
|
formatted_first_line = super().format(record)
|
|
|
|
|
|
|
|
|
|
|
|
# Check if the message has multiple lines
|
|
|
|
|
|
lines = formatted_first_line.split("\n")
|
|
|
|
|
|
if len(lines) > 1:
|
|
|
|
|
|
# For multiple lines, only apply colors to the first line
|
|
|
|
|
|
# Keep subsequent lines without color formatting
|
2024-03-12 18:27:58 +03:00
|
|
|
|
formatted_lines = [formatted_first_line]
|
2025-06-02 02:56:11 +03:00
|
|
|
|
formatted_lines.extend(lines[1:])
|
2024-04-17 18:32:23 +03:00
|
|
|
|
return "\n".join(formatted_lines)
|
2025-06-02 02:56:11 +03:00
|
|
|
|
return super().format(record)
|
2024-02-21 14:23:42 +03:00
|
|
|
|
|
2024-03-12 18:17:28 +03:00
|
|
|
|
|
2024-02-21 14:23:42 +03:00
|
|
|
|
# Create a MultilineColoredFormatter object for colorized logging
|
|
|
|
|
|
formatter = MultilineColoredFormatter(fmt_string, **fmt_config)
|
|
|
|
|
|
|
2025-09-25 08:48:36 +03:00
|
|
|
|
# Create a stream handler for logging output (только для консоли)
|
2024-02-21 14:23:42 +03:00
|
|
|
|
stream = logging.StreamHandler()
|
|
|
|
|
|
stream.setFormatter(formatter)
|
2025-09-25 08:48:36 +03:00
|
|
|
|
stream.addFilter(console_filter) # 🔍 Применяем фильтр только к консольному выводу
|
2024-02-21 14:23:42 +03:00
|
|
|
|
|
2025-02-10 18:04:08 +03:00
|
|
|
|
|
2025-06-02 02:56:11 +03:00
|
|
|
|
def get_colorful_logger(name: str = "main") -> logging.Logger:
|
2025-02-10 18:04:08 +03:00
|
|
|
|
# Create and configure the logger
|
|
|
|
|
|
logger = logging.getLogger(name)
|
|
|
|
|
|
logger.setLevel(logging.DEBUG)
|
|
|
|
|
|
logger.addHandler(stream)
|
2025-09-25 08:48:36 +03:00
|
|
|
|
logger.addFilter(basic_filter) # 🔍 Базовый фильтр без подавления
|
2025-02-10 18:04:08 +03:00
|
|
|
|
|
|
|
|
|
|
return logger
|
|
|
|
|
|
|
|
|
|
|
|
|
2024-02-21 14:23:42 +03:00
|
|
|
|
# Set up the root logger with the same formatting
|
|
|
|
|
|
root_logger = logging.getLogger()
|
2025-02-10 18:04:08 +03:00
|
|
|
|
root_logger.setLevel(logging.DEBUG)
|
|
|
|
|
|
root_logger.addHandler(stream)
|
2025-09-25 08:48:36 +03:00
|
|
|
|
root_logger.addFilter(basic_filter) # 🔍 Базовый фильтр - позволяет Sentry получать все логи
|
2025-02-10 18:04:08 +03:00
|
|
|
|
|
2025-08-30 21:45:40 +03:00
|
|
|
|
ignore_logs = ["_trace", "httpx", "_client", "atrace", "aiohttp", "_client", "ariadne", "graphql"]
|
2025-02-10 18:04:08 +03:00
|
|
|
|
for lgr in ignore_logs:
|
|
|
|
|
|
loggr = logging.getLogger(lgr)
|
2025-08-31 22:32:02 +03:00
|
|
|
|
loggr.setLevel(logging.CRITICAL) # Подавляем все кроме критических ошибок
|
2025-08-28 20:19:30 +03:00
|
|
|
|
|
2025-08-30 21:45:40 +03:00
|
|
|
|
# Дополнительно подавляем логи GraphQL и Ariadne для ошибок авторизации
|
|
|
|
|
|
graphql_logger = logging.getLogger("graphql")
|
2025-08-31 22:32:02 +03:00
|
|
|
|
graphql_logger.setLevel(logging.CRITICAL) # Подавляем ERROR уровень для авторизации
|
2025-08-30 21:45:40 +03:00
|
|
|
|
|
|
|
|
|
|
ariadne_logger = logging.getLogger("ariadne")
|
2025-08-31 22:32:02 +03:00
|
|
|
|
ariadne_logger.setLevel(logging.CRITICAL) # Подавляем ERROR уровень для авторизации
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
# Создаем специальный фильтр для Ariadne
|
|
|
|
|
|
class AriadneAuthFilter(logging.Filter):
|
|
|
|
|
|
def filter(self, record: logging.LogRecord) -> bool:
|
|
|
|
|
|
message = record.getMessage()
|
|
|
|
|
|
# Полностью блокируем логи связанные с авторизацией в Ariadne
|
|
|
|
|
|
return not any(
|
|
|
|
|
|
phrase in message
|
2025-08-31 22:45:51 +03:00
|
|
|
|
for phrase in [
|
|
|
|
|
|
"Требуется авторизация",
|
|
|
|
|
|
"AuthorizationError",
|
|
|
|
|
|
"GraphQL request:",
|
|
|
|
|
|
"decorated_function",
|
|
|
|
|
|
"load_drafts",
|
|
|
|
|
|
"GetUserDocuments",
|
|
|
|
|
|
"GetDrafts",
|
|
|
|
|
|
"Traceback",
|
|
|
|
|
|
"await gather",
|
|
|
|
|
|
"handle_field_error",
|
|
|
|
|
|
"await_result",
|
|
|
|
|
|
"During handling",
|
|
|
|
|
|
"raise error",
|
|
|
|
|
|
]
|
2025-08-31 22:32:02 +03:00
|
|
|
|
)
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
# Применяем фильтр к Ariadne и GraphQL логгерам
|
|
|
|
|
|
ariadne_logger.addFilter(AriadneAuthFilter())
|
|
|
|
|
|
graphql_logger.addFilter(AriadneAuthFilter())
|
2025-08-30 21:45:40 +03:00
|
|
|
|
|
2025-08-31 22:45:51 +03:00
|
|
|
|
# Дополнительно блокируем логи на уровне модулей
|
2025-08-31 23:53:16 +03:00
|
|
|
|
for logger_name in ["ariadne.log_error", "ariadne", "graphql.execution.execute", "graphql.execution", "graphql.error"]:
|
2025-08-31 22:45:51 +03:00
|
|
|
|
extra_logger = logging.getLogger(logger_name)
|
|
|
|
|
|
extra_logger.setLevel(logging.CRITICAL)
|
|
|
|
|
|
extra_logger.addFilter(AriadneAuthFilter())
|
2025-08-31 23:53:16 +03:00
|
|
|
|
extra_logger.disabled = True # Полностью отключаем этот логгер
|
2025-08-31 22:45:51 +03:00
|
|
|
|
|
2025-08-28 20:19:30 +03:00
|
|
|
|
|
|
|
|
|
|
def custom_error_formatter(error: GraphQLError, debug: bool = False) -> dict[Any, Any]:
|
|
|
|
|
|
"""
|
|
|
|
|
|
Кастомный форматтер ошибок для подавления трейсбеков у ожидаемых ошибок авторизации.
|
|
|
|
|
|
🔍 Логирует AuthorizationError как обычные события, не как исключения
|
|
|
|
|
|
"""
|
|
|
|
|
|
# Преобразуем в словарь для работы с ним
|
|
|
|
|
|
formatted_error: dict[str, Any] = {
|
|
|
|
|
|
"message": error.message,
|
|
|
|
|
|
"locations": getattr(error.formatted, "locations", []),
|
|
|
|
|
|
"path": getattr(error.formatted, "path", []),
|
|
|
|
|
|
"extensions": getattr(error.formatted, "extensions", {}),
|
|
|
|
|
|
}
|
|
|
|
|
|
|
2025-08-30 20:43:13 +03:00
|
|
|
|
# Для ошибок авторизации не показываем трейсбек и НЕ логируем вообще
|
2025-08-28 20:19:30 +03:00
|
|
|
|
# Проверяем по имени класса для избежания циклических импортов
|
|
|
|
|
|
if (
|
|
|
|
|
|
error.original_error
|
|
|
|
|
|
and hasattr(error.original_error, "__class__")
|
|
|
|
|
|
and error.original_error.__class__.__name__ == "AuthorizationError"
|
|
|
|
|
|
):
|
|
|
|
|
|
# Убираем extensions.exception если есть
|
|
|
|
|
|
if "extensions" in formatted_error and "exception" in formatted_error["extensions"]:
|
|
|
|
|
|
del formatted_error["extensions"]["exception"]
|
2025-08-30 20:43:13 +03:00
|
|
|
|
# НЕ логируем ошибки авторизации - они ожидаемы и нормальны
|
2025-08-28 20:19:30 +03:00
|
|
|
|
# Для остальных ошибок используем стандартное логирование
|
|
|
|
|
|
elif debug and error.original_error:
|
|
|
|
|
|
root_logger.error(f"GraphQL error: {error.message}", exc_info=error.original_error)
|
|
|
|
|
|
else:
|
|
|
|
|
|
root_logger.warning(f"GraphQL error: {error.message}")
|
|
|
|
|
|
|
|
|
|
|
|
return formatted_error
|