From 2e4e921317903f5152ce17bc7aa9fdf278b45f15 Mon Sep 17 00:00:00 2001 From: Alessandro Astone Date: Sun, 24 Aug 2025 16:48:50 +0200 Subject: [PATCH] logging: Use RotatingFileHandler to trim logfile at 5MB Remove all direct uses of args.logfd: everything goes through the logger now. Only the container manager process is allowed to write to the log, which now has 0o644 permissions. Other commands will only log to stdout. Logs that would previously appear in the logfile will now only be visible with --details-to-stdout. --- tools/helpers/logging.py | 70 ++++++++++++++------------------------- tools/helpers/run_core.py | 22 ++++++++---- 2 files changed, 39 insertions(+), 53 deletions(-) diff --git a/tools/helpers/logging.py b/tools/helpers/logging.py index 768f2bf..4b33735 100644 --- a/tools/helpers/logging.py +++ b/tools/helpers/logging.py @@ -1,33 +1,30 @@ # Copyright 2021 Oliver Smith # SPDX-License-Identifier: GPL-3.0-or-later import logging +from logging.handlers import RotatingFileHandler import os import sys -class log_handler(logging.StreamHandler): +class stdout_logger(logging.StreamHandler): """ Write to stdout and to the already opened log file. """ _args = None def emit(self, record): + # INFO or higher: Write to stdout + if self._args.quiet or ( + record.levelno < logging.INFO and + not self._args.details_to_stdout): + return + try: msg = self.format(record) - - # INFO or higher: Write to stdout - if (not self._args.details_to_stdout and - not self._args.quiet and - record.levelno >= logging.INFO): - stream = self.stream - stream.write(msg) - stream.write(self.terminator) - self.flush() - - # Everything: Write to logfd - msg = "(" + str(os.getpid()).zfill(6) + ") " + msg - self._args.logfd.write(msg + "\n") - self._args.logfd.flush() + stream = self.stream + stream.write(msg) + stream.write(self.terminator) + self.flush() except (KeyboardInterrupt, SystemExit): raise @@ -55,35 +52,8 @@ def add_verbose_log_level(): def init(args): - """ - Set log format and add the log file descriptor to args.logfd, add the - verbose log level. - """ - # Set log file descriptor (logfd) - if args.details_to_stdout: - setattr(args, "logfd", sys.stdout) - else: - # Require containing directory to exist (so we don't create the work - # folder and break the folder migration logic, which needs to set the - # version upon creation) - dir = os.path.dirname(args.log) - if os.path.exists(dir): - setattr(args, "logfd", open(args.log, "a+")) - try: - os.chmod(args.log, 0o666) - except PermissionError: - pass - else: - setattr(args, "logfd", open(os.devnull, "a+")) - if args.action != "init": - print("WARNING: Can't create log file in '" + dir + "', path" - " does not exist!") - - # Set log format root_logger = logging.getLogger() root_logger.handlers = [] - formatter = logging.Formatter("[%(asctime)s] %(message)s", - datefmt="%H:%M:%S") # Set log level add_verbose_log_level() @@ -91,12 +61,20 @@ def init(args): if args.verbose: root_logger.setLevel(logging.VERBOSE) - # Add a custom log handler - handler = log_handler() - log_handler._args = args - handler.setFormatter(formatter) + # Add custom stdout log handler + handler = stdout_logger() + handler._args = args + handler.setFormatter(logging.Formatter("[%(asctime)s] %(message)s", + datefmt="%H:%M:%S")) root_logger.addHandler(handler) + # Add file log handler + if args.action == "container" and not args.details_to_stdout: + os.chmod(args.log, 0o644) + handler = RotatingFileHandler(args.log, maxBytes=5*1024*1024) + handler.setFormatter(logging.Formatter("(%(process)d) [%(asctime)s] %(message)s", + datefmt="%H:%M:%S")) + root_logger.addHandler(handler) def disable(): logger = logging.getLogger() diff --git a/tools/helpers/run_core.py b/tools/helpers/run_core.py index dcc4c53..8832216 100644 --- a/tools/helpers/run_core.py +++ b/tools/helpers/run_core.py @@ -35,18 +35,27 @@ def sanity_checks(output="log", output_return=False, check=None): raise RuntimeError("Can't use output_return with output: " + output) +def forward_stream(pipe, level): + with pipe: + for line in iter(pipe.readline, b''): + logging.log(level, line.decode(errors="replace").rstrip()) + + def background(args, cmd, working_dir=None): """ Run a subprocess in background and redirect its output to the log. """ - ret = subprocess.Popen(cmd, stdout=args.logfd, stderr=args.logfd, - cwd=working_dir) - logging.debug("New background process: pid={}, output=background".format(ret.pid)) - return ret + proc = subprocess.Popen(cmd, stdout=subprocess.PIPE, stderr=subprocess.PIPE, + cwd=working_dir) + threading.Thread(target=forward_stream, args=(proc.stdout, logging.DEBUG), daemon=True).start() + threading.Thread(target=forward_stream, args=(proc.stderr, logging.DEBUG), daemon=True).start() + logging.debug("New background process: pid={}, output=background".format(proc.pid)) + return proc def pipe(args, cmd, working_dir=None): """ Run a subprocess in background and redirect its output to a pipe. """ - ret = subprocess.Popen(cmd, stdout=subprocess.PIPE, stderr=args.logfd, + ret = subprocess.Popen(cmd, stdout=subprocess.PIPE, stderr=subprocess.PIPE, cwd=working_dir) + threading.Thread(target=forward_stream, args=(proc.stderr, logging.DEBUG), daemon=True).start() logging.verbose("New background process: pid={}, output=pipe".format(ret.pid)) return ret @@ -69,7 +78,7 @@ def pipe_read(args, process, output_to_stdout=False, output_return=False, # Copy available output out = process.stdout.readline() if len(out): - args.logfd.buffer.write(out) + logging.debug(out.decode(errors="replace").rstrip()) if output_to_stdout: sys.stdout.buffer.write(out) if output_return: @@ -77,7 +86,6 @@ def pipe_read(args, process, output_to_stdout=False, output_return=False, continue # No more output (flush buffers) - args.logfd.flush() if output_to_stdout: sys.stdout.flush() return -- 2.47.3