mirror of
https://github.com/jxxghp/MoviePilot.git
synced 2026-11-10 15:50:24 +08:00
483 lines
18 KiB
Python
483 lines
18 KiB
Python
from __future__ import annotations
|
||
|
||
import asyncio
|
||
import logging
|
||
import os
|
||
import queue
|
||
import sys
|
||
import threading
|
||
import time
|
||
from collections import deque
|
||
from concurrent.futures import ThreadPoolExecutor
|
||
from datetime import datetime
|
||
from logging.handlers import RotatingFileHandler
|
||
from pathlib import Path
|
||
from typing import Any, Callable, Dict, Optional, Protocol
|
||
|
||
import click
|
||
from pydantic import BaseModel, ConfigDict
|
||
|
||
class LogConfigModel(BaseModel):
|
||
"""描述日志级别、格式和文件写入策略。"""
|
||
|
||
model_config = ConfigDict(extra="ignore")
|
||
|
||
CONFIG_DIR: Optional[str] = None
|
||
DEBUG: bool = False
|
||
LOG_LEVEL: str = "INFO"
|
||
LOG_MAX_FILE_SIZE: int = 5
|
||
LOG_BACKUP_COUNT: int = 10
|
||
LOG_CONSOLE_FORMAT: str = (
|
||
"%(leveltext)s[%(name)s] %(asctime)s [%(correlation_id)s] %(message)s"
|
||
)
|
||
LOG_FILE_FORMAT: str = (
|
||
"【%(levelname)s】%(asctime)s [%(correlation_id)s] - %(message)s"
|
||
)
|
||
ASYNC_FILE_QUEUE_SIZE: int = 1000
|
||
ASYNC_FILE_WORKERS: int = 2
|
||
BATCH_WRITE_SIZE: int = 50
|
||
WRITE_TIMEOUT: float = 3.0
|
||
|
||
@property
|
||
def LOG_MAX_FILE_SIZE_BYTES(self) -> int:
|
||
"""将日志文件大小从 MB 转换为字节。"""
|
||
return self.LOG_MAX_FILE_SIZE * 1024 * 1024
|
||
|
||
|
||
class LogSettings(LogConfigModel):
|
||
"""保存当前进程已经生效的日志策略。"""
|
||
|
||
|
||
class LogEntry:
|
||
"""表示一条等待基础设施写入的文件日志。"""
|
||
|
||
def __init__(
|
||
self,
|
||
level: str,
|
||
message: str,
|
||
file_path: Path,
|
||
timestamp: datetime | None = None,
|
||
) -> None:
|
||
"""记录日志级别、格式化文本和目标文件。"""
|
||
self.level = level
|
||
self.message = message
|
||
self.file_path = file_path
|
||
self.timestamp = timestamp or datetime.now()
|
||
self.correlation_id = _get_log_correlation_id()
|
||
|
||
|
||
class LogWriter(Protocol):
|
||
"""平台日志门面使用的文件写入端口。"""
|
||
|
||
def write_log(self, level: str, message: str, file_path: Path) -> None:
|
||
"""将一条日志写入指定文件。"""
|
||
|
||
def shutdown(self) -> None:
|
||
"""排空待写日志并释放写入资源。"""
|
||
|
||
|
||
log_settings = LogSettings()
|
||
_correlation_id_provider: Callable[[], str | None] = lambda: None
|
||
|
||
|
||
def configure_correlation_id_provider(provider: Callable[[], str | None]) -> None:
|
||
"""由组合根注入日志关联 ID 读取端口，保持日志模块为依赖叶节点。"""
|
||
global _correlation_id_provider
|
||
_correlation_id_provider = provider
|
||
|
||
|
||
def _get_log_correlation_id() -> str:
|
||
"""读取当前关联 ID；未装配或无请求上下文时返回稳定占位符。"""
|
||
return _correlation_id_provider() or "-"
|
||
|
||
|
||
class NonBlockingFileHandler:
|
||
"""使用后台队列和滚动文件处理器写入业务日志。"""
|
||
|
||
_instance = None
|
||
_lock = threading.Lock()
|
||
_stop_sentinel = object()
|
||
|
||
def __new__(cls):
|
||
"""返回进程内唯一的文件写入器。"""
|
||
if cls._instance is None:
|
||
with cls._lock:
|
||
if cls._instance is None:
|
||
cls._instance = super().__new__(cls)
|
||
return cls._instance
|
||
|
||
def __init__(self) -> None:
|
||
"""初始化文件处理器缓存、异步队列和后台写线程。"""
|
||
if hasattr(self, "_initialized"):
|
||
return
|
||
self._initialized = True
|
||
self._state_lock = threading.RLock()
|
||
self._handlers_lock = threading.Lock()
|
||
self._rotating_handlers: dict[Path, RotatingFileHandler] = {}
|
||
self._write_queue = queue.Queue(maxsize=log_settings.ASYNC_FILE_QUEUE_SIZE)
|
||
self._executor = ThreadPoolExecutor(
|
||
max_workers=log_settings.ASYNC_FILE_WORKERS,
|
||
thread_name_prefix="LogWriter",
|
||
)
|
||
self._running = True
|
||
self._write_thread = threading.Thread(
|
||
target=self._batch_writer,
|
||
daemon=True,
|
||
name="LogBatchWriter",
|
||
)
|
||
self._write_thread.start()
|
||
|
||
def _get_rotating_handler(self, file_path: Path) -> RotatingFileHandler:
|
||
"""按目标路径复用滚动文件处理器。"""
|
||
with self._handlers_lock:
|
||
handler = self._rotating_handlers.get(file_path)
|
||
if handler:
|
||
return handler
|
||
file_path.parent.mkdir(parents=True, exist_ok=True)
|
||
handler = RotatingFileHandler(
|
||
filename=str(file_path),
|
||
maxBytes=log_settings.LOG_MAX_FILE_SIZE_BYTES,
|
||
backupCount=log_settings.LOG_BACKUP_COUNT,
|
||
encoding="utf-8",
|
||
)
|
||
handler.setFormatter(logging.Formatter(log_settings.LOG_FILE_FORMAT))
|
||
self._rotating_handlers[file_path] = handler
|
||
return handler
|
||
|
||
def write_log(self, level: str, message: str, file_path: Path) -> None:
|
||
"""根据当前线程是否运行事件循环选择异步或同步文件写入。"""
|
||
entry = LogEntry(level, message, file_path)
|
||
if self._is_in_event_loop():
|
||
self._write_non_blocking(entry)
|
||
return
|
||
with self._state_lock:
|
||
if self._running:
|
||
self._write_sync(entry)
|
||
|
||
@staticmethod
|
||
def _is_in_event_loop() -> bool:
|
||
"""判断当前线程是否正在运行 asyncio 事件循环。"""
|
||
try:
|
||
return asyncio.get_running_loop() is not None
|
||
except RuntimeError:
|
||
return False
|
||
|
||
def _write_non_blocking(self, entry: LogEntry) -> bool:
|
||
"""将协程环境产生的日志无阻塞地放入写队列。"""
|
||
with self._state_lock:
|
||
if not self._running:
|
||
return False
|
||
try:
|
||
self._write_queue.put_nowait(entry)
|
||
except queue.Full:
|
||
self._executor.submit(self._write_sync, entry)
|
||
return True
|
||
|
||
def _write_sync(self, entry: LogEntry) -> None:
|
||
"""立即将单条日志写入滚动文件。"""
|
||
try:
|
||
handler = self._get_rotating_handler(entry.file_path)
|
||
handler.handle(self._to_record(entry))
|
||
except Exception as err:
|
||
print(f"日志写入失败 {entry.file_path}: {err}")
|
||
print(f"【{entry.level.upper()}】{entry.timestamp} - {entry.message}")
|
||
|
||
@staticmethod
|
||
def _to_record(entry: LogEntry) -> logging.LogRecord:
|
||
"""把日志条目转换为标准库日志记录。"""
|
||
record = logging.LogRecord(
|
||
name="",
|
||
level=getattr(logging, entry.level.upper(), logging.INFO),
|
||
pathname="",
|
||
lineno=0,
|
||
msg=entry.message,
|
||
args=(),
|
||
exc_info=None,
|
||
created=entry.timestamp.timestamp(),
|
||
)
|
||
record.correlation_id = entry.correlation_id
|
||
return record
|
||
|
||
def _batch_writer(self) -> None:
|
||
"""持续收集队列日志，并在停止哨兵后排空已有批次。"""
|
||
while True:
|
||
try:
|
||
batch = []
|
||
should_stop = False
|
||
end_time = time.time() + log_settings.WRITE_TIMEOUT
|
||
while (
|
||
len(batch) < log_settings.BATCH_WRITE_SIZE
|
||
and time.time() < end_time
|
||
):
|
||
try:
|
||
remaining_time = max(0, end_time - time.time())
|
||
entry = self._write_queue.get(timeout=remaining_time)
|
||
if entry is self._stop_sentinel:
|
||
should_stop = True
|
||
break
|
||
batch.append(entry)
|
||
except queue.Empty:
|
||
break
|
||
if batch:
|
||
self._write_batch(batch)
|
||
if should_stop:
|
||
break
|
||
except Exception as err:
|
||
print(f"批量写入线程错误: {err}")
|
||
time.sleep(0.1)
|
||
|
||
def _write_batch(self, batch: list[LogEntry]) -> None:
|
||
"""按目标文件分组写入一批日志。"""
|
||
file_groups: dict[Path, list[LogEntry]] = {}
|
||
for entry in batch:
|
||
file_groups.setdefault(entry.file_path, []).append(entry)
|
||
for file_path, entries in file_groups.items():
|
||
try:
|
||
handler = self._get_rotating_handler(file_path)
|
||
for entry in entries:
|
||
handler.handle(self._to_record(entry))
|
||
except Exception as err:
|
||
print(f"批量写入失败 {file_path}: {err}")
|
||
for entry in entries:
|
||
self._write_sync(entry)
|
||
|
||
def shutdown(self) -> None:
|
||
"""停止接收新日志，排空队列并关闭线程池和文件处理器。"""
|
||
with self._state_lock:
|
||
if not self._running:
|
||
return
|
||
self._running = False
|
||
if self._write_thread.is_alive():
|
||
self._write_queue.put(self._stop_sentinel)
|
||
if self._write_thread.is_alive():
|
||
self._write_thread.join()
|
||
self._executor.shutdown(wait=True)
|
||
for handler in self._rotating_handlers.values():
|
||
handler.flush()
|
||
handler.close()
|
||
self._rotating_handlers.clear()
|
||
|
||
_LEVEL_NAME_COLORS = {
|
||
logging.DEBUG: lambda level_name: click.style(str(level_name), fg="cyan"),
|
||
logging.INFO: lambda level_name: click.style(str(level_name), fg="green"),
|
||
logging.WARNING: lambda level_name: click.style(str(level_name), fg="yellow"),
|
||
logging.ERROR: lambda level_name: click.style(str(level_name), fg="red"),
|
||
logging.CRITICAL: lambda level_name: click.style(
|
||
str(level_name), fg="bright_red"
|
||
),
|
||
}
|
||
|
||
|
||
class CustomFormatter(logging.Formatter):
|
||
"""为控制台日志级别添加颜色和对齐文本。"""
|
||
|
||
def format(self, record: logging.LogRecord) -> str:
|
||
"""格式化一条控制台日志记录。"""
|
||
separator = " " * max(8 - len(record.levelname), 0)
|
||
colorizer = _LEVEL_NAME_COLORS.get(record.levelno, str)
|
||
record.leveltext = colorizer(record.levelname + ":") + separator
|
||
record.correlation_id = _get_log_correlation_id()
|
||
return super().format(record)
|
||
|
||
|
||
class LoggerManager:
|
||
"""
|
||
管理进程级日志策略、控制台输出和插件日志路由。
|
||
|
||
文件 I/O 由启动层注入的 :class:`LogWriter` 完成；在写入器装配之前产生的
|
||
少量启动日志会暂存，装配完成后只补写文件，不重复输出到控制台。
|
||
"""
|
||
|
||
_loggers: Dict[str, logging.Logger] = {}
|
||
_default_log_file = Path("moviepilot.log")
|
||
_lock = threading.RLock()
|
||
_writer: Optional[LogWriter] = None
|
||
_log_path: Optional[Path] = None
|
||
_pending_file_logs: deque[tuple[str, str, Path]] = deque(maxlen=1000)
|
||
|
||
def get_logger(self, name: str) -> logging.Logger:
|
||
"""返回使用当前控制台策略的命名标准库日志器。"""
|
||
logfile = Path(f"{name}.log")
|
||
return self._get_console_logger(logfile)
|
||
|
||
@staticmethod
|
||
def _get_caller() -> tuple[str, Optional[str]]:
|
||
"""
|
||
识别日志调用文件和插件来源。
|
||
|
||
插件调用宿主公共方法时，调用栈中仍保留插件帧，因此日志继续进入该插件
|
||
的独立文件，而不是混入主程序日志。
|
||
"""
|
||
caller_name = None
|
||
plugin_name = None
|
||
try:
|
||
frame = sys._getframe(3) # noqa: SLF001
|
||
except (AttributeError, ValueError):
|
||
return "log.py", None
|
||
|
||
while frame:
|
||
filepath = Path(frame.f_code.co_filename)
|
||
parts = filepath.parts
|
||
if not caller_name:
|
||
caller_name = parts[-2] if parts[-1] == "__init__.py" and len(parts) >= 2 else parts[-1]
|
||
if "app" in parts:
|
||
if not plugin_name and "plugins" in parts:
|
||
try:
|
||
plugins_index = parts.index("plugins")
|
||
if plugins_index + 1 < len(parts):
|
||
plugin_name = parts[plugins_index + 1]
|
||
break
|
||
except ValueError:
|
||
pass
|
||
if "main.py" in parts:
|
||
break
|
||
elif len(parts) != 1:
|
||
break
|
||
frame = frame.f_back
|
||
return caller_name or "log.py", plugin_name
|
||
|
||
@classmethod
|
||
def _setup_console_logger(cls, logfile: Path) -> logging.Logger:
|
||
"""创建只负责控制台输出的标准库日志器。"""
|
||
logger_name = str(logfile.with_suffix(""))
|
||
configured_logger = logging.getLogger(logger_name)
|
||
configured_logger.setLevel(cls._get_log_level())
|
||
configured_logger.handlers.clear()
|
||
if os.getenv("MOVIEPILOT_DISABLE_CONSOLE_LOG") != "1":
|
||
console_handler = logging.StreamHandler()
|
||
console_handler.setFormatter(
|
||
CustomFormatter(log_settings.LOG_CONSOLE_FORMAT)
|
||
)
|
||
configured_logger.addHandler(console_handler)
|
||
configured_logger.propagate = False
|
||
return configured_logger
|
||
|
||
@classmethod
|
||
def _get_console_logger(cls, logfile: Path) -> logging.Logger:
|
||
"""按日志文件语境复用控制台日志器。"""
|
||
logger_key = str(logfile)
|
||
with cls._lock:
|
||
configured_logger = cls._loggers.get(logger_key)
|
||
if not configured_logger:
|
||
configured_logger = cls._setup_console_logger(logfile)
|
||
cls._loggers[logger_key] = configured_logger
|
||
return configured_logger
|
||
|
||
@classmethod
|
||
def configure_writer(cls, writer: LogWriter, log_path: Path) -> None:
|
||
"""装配文件写入器，并补写装配前暂存的启动日志。"""
|
||
with cls._lock:
|
||
previous_writer = cls._writer
|
||
cls._writer = writer
|
||
cls._log_path = Path(log_path)
|
||
pending = list(cls._pending_file_logs)
|
||
cls._pending_file_logs.clear()
|
||
if previous_writer and previous_writer is not writer:
|
||
previous_writer.shutdown()
|
||
for level, message, logfile in pending:
|
||
writer.write_log(level, message, Path(log_path) / logfile)
|
||
|
||
def update_loggers(self) -> None:
|
||
"""让已创建的控制台日志器应用最新级别和格式。"""
|
||
with self._lock:
|
||
for configured_logger in self._loggers.values():
|
||
for handler in configured_logger.handlers:
|
||
if isinstance(handler, logging.StreamHandler):
|
||
handler.setFormatter(
|
||
CustomFormatter(log_settings.LOG_CONSOLE_FORMAT)
|
||
)
|
||
configured_logger.setLevel(self._get_log_level())
|
||
|
||
@staticmethod
|
||
def _get_log_level() -> int:
|
||
"""返回当前日志策略对应的标准库日志级别。"""
|
||
if log_settings.DEBUG:
|
||
return logging.DEBUG
|
||
return getattr(logging, log_settings.LOG_LEVEL.upper(), logging.INFO)
|
||
|
||
@classmethod
|
||
def _write_file_log(cls, level: str, message: str, logfile: Path) -> None:
|
||
"""写入文件，或在启动装配完成前暂存日志。"""
|
||
with cls._lock:
|
||
writer = cls._writer
|
||
log_path = cls._log_path
|
||
if not writer or not log_path:
|
||
cls._pending_file_logs.append((level, message, logfile))
|
||
return
|
||
writer.write_log(level, message, log_path / logfile)
|
||
|
||
def logger(self, method: str, msg: str, *args: Any, **kwargs: Any) -> None:
|
||
"""按调用来源路由并输出一条日志。"""
|
||
method_level = getattr(logging, method.upper(), logging.INFO)
|
||
if method_level < self._get_log_level():
|
||
return
|
||
|
||
caller_name, plugin_name = self._get_caller()
|
||
formatted_msg = f"{caller_name} - {msg}"
|
||
if args:
|
||
try:
|
||
formatted_msg = formatted_msg % args
|
||
except (TypeError, ValueError):
|
||
formatted_msg = f"{formatted_msg} {' '.join(str(arg) for arg in args)}"
|
||
|
||
logfile = (
|
||
Path("plugins") / f"{plugin_name}.log"
|
||
if plugin_name
|
||
else self._default_log_file
|
||
)
|
||
self._write_file_log(method.upper(), formatted_msg, logfile)
|
||
|
||
configured_logger = self._get_console_logger(logfile)
|
||
log_method = getattr(configured_logger, method, configured_logger.info)
|
||
log_method(formatted_msg, **kwargs)
|
||
|
||
def info(self, msg: str, *args: Any, **kwargs: Any) -> None:
|
||
"""输出 INFO 日志。"""
|
||
self.logger("info", msg, *args, **kwargs)
|
||
|
||
def debug(self, msg: str, *args: Any, **kwargs: Any) -> None:
|
||
"""输出 DEBUG 日志。"""
|
||
self.logger("debug", msg, *args, **kwargs)
|
||
|
||
def warning(self, msg: str, *args: Any, **kwargs: Any) -> None:
|
||
"""输出 WARNING 日志。"""
|
||
self.logger("warning", msg, *args, **kwargs)
|
||
|
||
def warn(self, msg: str, *args: Any, **kwargs: Any) -> None:
|
||
"""兼容历史调用并输出 WARNING 日志。"""
|
||
self.warning(msg, *args, **kwargs)
|
||
|
||
def error(self, msg: str, *args: Any, **kwargs: Any) -> None:
|
||
"""输出 ERROR 日志。"""
|
||
self.logger("error", msg, *args, **kwargs)
|
||
|
||
def critical(self, msg: str, *args: Any, **kwargs: Any) -> None:
|
||
"""输出 CRITICAL 日志。"""
|
||
self.logger("critical", msg, *args, **kwargs)
|
||
|
||
@classmethod
|
||
def shutdown(cls) -> None:
|
||
"""断开并关闭当前文件写入器。"""
|
||
with cls._lock:
|
||
writer = cls._writer
|
||
cls._writer = None
|
||
cls._log_path = None
|
||
if writer:
|
||
writer.shutdown()
|
||
|
||
|
||
logger = LoggerManager()
|
||
|
||
|
||
def configure_log_settings(source: object) -> None:
|
||
"""从完整系统配置同步日志相关字段并刷新控制台策略。"""
|
||
for field_name in LogConfigModel.model_fields:
|
||
if hasattr(source, field_name):
|
||
setattr(log_settings, field_name, getattr(source, field_name))
|
||
logger.update_loggers()
|
||
|
||
|
||
def configure_log_writer(writer: LogWriter, log_path: Path) -> None:
|
||
"""把基础设施文件写入器装配到平台日志门面。"""
|
||
LoggerManager.configure_writer(writer=writer, log_path=log_path)
|