diff --git a/moonraker/loghelper.py b/moonraker/loghelper.py new file mode 100644 index 0000000..7ed89a0 --- /dev/null +++ b/moonraker/loghelper.py @@ -0,0 +1,153 @@ +# Log Management +# +# Copyright (C) 2023 Eric Callahan +# +# This file may be distributed under the terms of the GNU GPLv3 license + +from __future__ import annotations +import logging +import logging.handlers +import os +import sys +import asyncio +from queue import SimpleQueue as Queue + +# Annotation imports +from typing import ( + TYPE_CHECKING, + Optional, + Awaitable, + Dict, + List, + Any, +) + +if TYPE_CHECKING: + from moonraker import Server + from websockets import WebRequest + from klippy_connection import KlippyConnection + +# Coroutine friendly QueueHandler courtesy of Martjin Pieters: +# https://www.zopatista.com/python/2019/05/11/asyncio-logging/ +class LocalQueueHandler(logging.handlers.QueueHandler): + def emit(self, record: logging.LogRecord) -> None: + # Removed the call to self.prepare(), handle task cancellation + try: + self.enqueue(record) + except asyncio.CancelledError: + raise + except Exception: + self.handleError(record) + +# Timed Rotating File Handler, based on Klipper's implementation +class MoonrakerLoggingHandler(logging.handlers.TimedRotatingFileHandler): + def __init__(self, app_args: Dict[str, Any], **kwargs) -> None: + super().__init__(app_args['log_file'], **kwargs) + self.rollover_info: Dict[str, str] = { + 'header': f"{'-'*20}Moonraker Log Start{'-'*20}" + } + self.rollover_info['application_args'] = "\n".join( + [f"{k}: {v}" for k, v in app_args.items()]) + lines = [line for line in self.rollover_info.values() if line] + if self.stream is not None: + self.stream.write("\n".join(lines) + "\n") + + def set_rollover_info(self, name: str, item: str) -> None: + self.rollover_info[name] = item + + def doRollover(self) -> None: + super().doRollover() + lines = [line for line in self.rollover_info.values() if line] + if self.stream is not None: + self.stream.write("\n".join(lines) + "\n") + +class LogManager: + def __init__( + self, app_args: Dict[str, Any], startup_warnings: List[str] + ) -> None: + root_logger = logging.getLogger() + queue: Queue = Queue() + queue_handler = LocalQueueHandler(queue) + root_logger.addHandler(queue_handler) + root_logger.setLevel(logging.INFO) + stdout_hdlr = logging.StreamHandler(sys.stdout) + stdout_fmt = logging.Formatter( + '[%(filename)s:%(funcName)s()] - %(message)s') + stdout_hdlr.setFormatter(stdout_fmt) + for name, val in app_args.items(): + logging.info(f"{name}: {val}") + self.file_hdlr: Optional[MoonrakerLoggingHandler] = None + self.listener: Optional[logging.handlers.QueueListener] = None + log_file: str = app_args.get('log_file', "") + if log_file: + try: + self.file_hdlr = MoonrakerLoggingHandler( + app_args, when='midnight', backupCount=2) + formatter = logging.Formatter( + '%(asctime)s [%(filename)s:%(funcName)s()] - %(message)s') + self.file_hdlr.setFormatter(formatter) + self.listener = logging.handlers.QueueListener( + queue, self.file_hdlr, stdout_hdlr) + except Exception: + log_file = os.path.normpath(log_file) + dir_name = os.path.dirname(log_file) + startup_warnings.append( + f"Unable to create log file at '{log_file}'. " + f"Make sure that the folder '{dir_name}' exists " + "and Moonraker has Read/Write access to the folder. " + ) + if self.listener is None: + self.listener = logging.handlers.QueueListener( + queue, stdout_hdlr) + self.listener.start() + + def set_server(self, server: Server) -> None: + self.server = server + self.server.register_endpoint( + "/server/logs/rollover", ['POST'], self._handle_log_rollover + ) + + def set_rollover_info(self, name: str, item: str) -> None: + if self.file_hdlr is not None: + self.file_hdlr.set_rollover_info(name, item) + + def rollover_log(self) -> Awaitable[None]: + if self.file_hdlr is None: + raise self.server.error("File Logging Disabled") + eventloop = self.server.get_event_loop() + return eventloop.run_in_thread(self.file_hdlr.doRollover) + + def stop_logging(self): + self.listener.stop() + + async def _handle_log_rollover( + self, web_request: WebRequest + ) -> Dict[str, Any]: + log_apps = ["moonraker", "klipper"] + app = web_request.get_str("application", None) + result: Dict[str, Any] = {"rolled_over": [], "failed": {}} + if app is not None: + if app not in log_apps: + raise self.server.error(f"Unknown application {app}") + log_apps = [app] + if "moonraker" in log_apps: + try: + ret = self.rollover_log() + if ret is not None: + await ret + except asyncio.CancelledError: + raise + except Exception as e: + result["failed"]["moonraker"] = str(e) + else: + result["rolled_over"].append("moonraker") + if "klipper" in log_apps: + kconn: KlippyConnection + kconn = self.server.lookup_component("klippy_connection") + try: + await kconn.rollover_log() + except self.server.error as e: + result["failed"]["klipper"] = str(e) + else: + result["rolled_over"].append("klipper") + return result diff --git a/moonraker/moonraker.py b/moonraker/moonraker.py index 568ca45..5e71d4e 100755 --- a/moonraker/moonraker.py +++ b/moonraker/moonraker.py @@ -17,12 +17,12 @@ import socket import logging import signal import confighelper -import utils import asyncio from eventloop import EventLoop from app import MoonrakerApp from klippy_connection import KlippyConnection -from utils import ServerError, SentinelClass +from utils import ServerError, SentinelClass, get_software_version +from loghelper import LogManager # Annotation imports from typing import ( @@ -59,11 +59,11 @@ class Server: error = ServerError def __init__(self, args: Dict[str, Any], - file_logger: Optional[utils.MoonrakerLoggingHandler], + log_manager: LogManager, event_loop: EventLoop ) -> None: self.event_loop = event_loop - self.file_logger = file_logger + self.log_manager = log_manager self.app_args = args self.events: Dict[str, List[FlexCallback]] = {} self.components: Dict[str, Any] = {} @@ -92,6 +92,7 @@ class Server: self.register_static_file_handler = app.register_static_file_handler self.register_upload_handler = app.register_upload_handler self.register_api_transport = app.register_api_transport + self.log_manager.set_server(self) for warning in args.get("startup_warnings", []): self.add_warning(warning) @@ -190,8 +191,7 @@ class Server: def add_log_rollover_item(self, name: str, item: str, log: bool = True) -> None: - if self.file_logger is not None: - self.file_logger.set_rollover_info(name, item) + self.log_manager.set_rollover_info(name, item) if log and item is not None: logging.info(item) @@ -479,7 +479,7 @@ def main(cmd_line_args: argparse.Namespace) -> None: } # Setup Logging - version = utils.get_software_version() + version = get_software_version() if cmd_line_args.nologfile: app_args["log_file"] = "" elif cmd_line_args.logfile: @@ -489,9 +489,7 @@ def main(cmd_line_args: argparse.Namespace) -> None: app_args["log_file"] = str(data_path.joinpath("logs/moonraker.log")) app_args["software_version"] = version app_args["python_version"] = sys.version.replace("\n", " ") - ql, file_logger, warning = utils.setup_logging(app_args) - if warning is not None: - startup_warnings.append(warning) + log_manager = LogManager(app_args, startup_warnings) # Start asyncio event loop and server event_loop = EventLoop() @@ -499,7 +497,7 @@ def main(cmd_line_args: argparse.Namespace) -> None: estatus = 0 while True: try: - server = Server(app_args, file_logger, event_loop) + server = Server(app_args, log_manager, event_loop) server.load_components() except confighelper.ConfigError as e: backup_cfg = confighelper.find_config_backup(cfg_file) @@ -548,7 +546,7 @@ def main(cmd_line_args: argparse.Namespace) -> None: event_loop.reset() event_loop.close() logging.info("Server Shutdown") - ql.stop() + log_manager.stop_logging() exit(estatus) diff --git a/moonraker/utils.py b/moonraker/utils.py index f6c8876..fe8cd3a 100644 --- a/moonraker/utils.py +++ b/moonraker/utils.py @@ -6,7 +6,6 @@ from __future__ import annotations import logging -import logging.handlers import os import glob import importlib @@ -20,7 +19,6 @@ import shlex import re import struct import socket -from queue import SimpleQueue as Queue # Annotation imports from typing import ( @@ -30,7 +28,6 @@ from typing import ( ClassVar, Tuple, Dict, - Any, ) if TYPE_CHECKING: @@ -56,40 +53,6 @@ class SentinelClass: SentinelClass._instance = SentinelClass() return SentinelClass._instance -# Coroutine friendly QueueHandler courtesy of Martjin Pieters: -# https://www.zopatista.com/python/2019/05/11/asyncio-logging/ -class LocalQueueHandler(logging.handlers.QueueHandler): - def emit(self, record: logging.LogRecord) -> None: - # Removed the call to self.prepare(), handle task cancellation - try: - self.enqueue(record) - except asyncio.CancelledError: - raise - except Exception: - self.handleError(record) - -# Timed Rotating File Handler, based on Klipper's implementation -class MoonrakerLoggingHandler(logging.handlers.TimedRotatingFileHandler): - def __init__(self, app_args: Dict[str, Any], **kwargs) -> None: - super().__init__(app_args['log_file'], **kwargs) - self.rollover_info: Dict[str, str] = { - 'header': f"{'-'*20}Moonraker Log Start{'-'*20}" - } - self.rollover_info['application_args'] = "\n".join( - [f"{k}: {v}" for k, v in app_args.items()]) - lines = [line for line in self.rollover_info.values() if line] - if self.stream is not None: - self.stream.write("\n".join(lines) + "\n") - - def set_rollover_info(self, name: str, item: str) -> None: - self.rollover_info[name] = item - - def doRollover(self) -> None: - super().doRollover() - lines = [line for line in self.rollover_info.values() if line] - if self.stream is not None: - self.stream.write("\n".join(lines) + "\n") - def _run_git_command(cmd: str) -> str: prog = shlex.split(cmd) process = subprocess.Popen(prog, stdout=subprocess.PIPE, @@ -139,45 +102,6 @@ def get_software_version() -> str: version = "?" return version -def setup_logging(app_args: Dict[str, Any] - ) -> Tuple[logging.handlers.QueueListener, - Optional[MoonrakerLoggingHandler], - Optional[str]]: - root_logger = logging.getLogger() - queue: Queue = Queue() - queue_handler = LocalQueueHandler(queue) - root_logger.addHandler(queue_handler) - root_logger.setLevel(logging.INFO) - stdout_hdlr = logging.StreamHandler(sys.stdout) - stdout_fmt = logging.Formatter( - '[%(filename)s:%(funcName)s()] - %(message)s') - stdout_hdlr.setFormatter(stdout_fmt) - for name, val in app_args.items(): - logging.info(f"{name}: {val}") - warning: Optional[str] = None - file_hdlr: Optional[MoonrakerLoggingHandler] = None - listener: Optional[logging.handlers.QueueListener] = None - log_file: str = app_args.get('log_file', "") - if log_file: - try: - file_hdlr = MoonrakerLoggingHandler( - app_args, when='midnight', backupCount=2) - formatter = logging.Formatter( - '%(asctime)s [%(filename)s:%(funcName)s()] - %(message)s') - file_hdlr.setFormatter(formatter) - listener = logging.handlers.QueueListener( - queue, file_hdlr, stdout_hdlr) - except Exception: - log_file = os.path.normpath(log_file) - dir_name = os.path.dirname(log_file) - warning = f"Unable to create log file at '{log_file}'. " \ - f"Make sure that the folder '{dir_name}' exists " \ - f"and Moonraker has Read/Write access to the folder. " - if listener is None: - listener = logging.handlers.QueueListener( - queue, stdout_hdlr) - listener.start() - return listener, file_hdlr, warning def hash_directory(dir_path: str, ignore_exts: List[str],