Files
MeshTerm/meshterm/persistence/logging.py
T
Jean-Pierre MartineauandClaude Opus 5 bdc16fc448 The log is a text file that records what went wrong
Three things were true of the log at once: it was JSON Lines, it never rotated,
and it almost never recorded a failure. Of the last twenty thousand records in a
real one, nine were warnings and three were errors. It faithfully kept the boring
parts and missed the interesting ones, which is exactly backwards for the only
job it has.

It is plain text now, `~/.meshterm/meshterm.log`, one line per record with the
traceback indented under the line that raised it. JSON Lines was there in case
something replayed it; nothing ever did, and the actual reader is a person who has
hit a problem and is about to paste the last twenty lines into an issue. That
reader has a text editor.

It rotates, at 2MB across three files. The old handler grew without limit and a
real one reached 11MB over ten weeks — a lot of disk on a handheld, and an
unreasonable thing to ask someone to attach.

How much it keeps is a preference, `log_level` under a new Diagnostics group,
defaulting to WARNING. That is what makes the file useful rather than large: it
holds the problems, and turning it up to DEBUG for one run is how you chase
something. Loaded before logging is configured, since it decides how logging is
configured, and handed to the context afterwards so the file is not read twice.

And failures are written down at last. Every unhandled error reaches the log with
its traceback and the terminal says where to find it; expected errors — an
ambiguous device, a bad preference — go in as warnings, because a log that only
holds crashes cannot answer "what happened just before". The bug form now asks for
the file, which it had no reason to before.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
2026-09-07 14:43:13 -04:00

176 lines
6.6 KiB
Python

"""Logging setup: a plain text file you can open, and a console that stays out of the way.
Two sinks. The console handler is Rich-formatted and shows what a person watching the
terminal should see. The file handler writes ordinary log lines to
``<config_dir>/meshterm.log`` — one record per line, timestamp, level, logger, message,
with a traceback indented under the line that raised it.
Plain text on purpose. The file used to be JSON Lines, on the theory that something might
replay it; nothing ever did, and the one job it actually has is being opened by a person
who has hit a problem — often the person reporting it, who then pastes the last twenty
lines into an issue. That reader has a text editor, not a JSON parser.
The file rotates. It used to be a single :class:`~logging.FileHandler`, which grows
without limit: a real one reached 11MB over ten weeks, which is both a lot of disk on a
handheld and an unreasonable thing to attach to a bug report.
How much is written is a preference — ``log_level``, defaulting to ``WARNING``, so the
file holds the problems rather than a narration of a working session. Turn it down to
``INFO`` or ``DEBUG`` when chasing something.
"""
from __future__ import annotations
import logging
from logging.handlers import RotatingFileHandler
from pathlib import Path
from rich.console import Console
from rich.logging import RichHandler
_LOGGER_NAME = "meshterm"
#: The log file, in the config directory beside the data it describes.
LOG_FILENAME = "meshterm.log"
#: Keep this much before rolling over, and this many rolled files. Roughly a fortnight of
#: a chatty session at DEBUG, and small enough that the whole set can be attached to an
#: issue without apology.
_MAX_BYTES = 2 * 1024 * 1024
_BACKUP_COUNT = 3
#: ``2026-09-07 14:23:11 WARNING meshterm.core.connection: link lost, retrying``
#: Level is padded so the messages line up; the logger name says which part spoke.
_LINE_FORMAT = "%(asctime)s %(levelname)-8s %(name)s: %(message)s"
_TIME_FORMAT = "%Y-%m-%d %H:%M:%S"
#: The levels the ``log_level`` preference offers, by their own names. Spelled out rather
#: than taken from ``logging.getLevelName``, whose string-to-number direction is deprecated,
#: or ``getLevelNamesMapping``, which arrived in 3.11 and this package supports 3.10.
_LEVELS: dict[str, int] = {
"ERROR": logging.ERROR,
"WARNING": logging.WARNING,
"INFO": logging.INFO,
"DEBUG": logging.DEBUG,
}
def level_from_name(name: str, *, fallback: int = logging.WARNING) -> int:
"""Turn a ``log_level`` preference value into a level number.
Args:
name: A level name, in any case.
fallback: Used when the name is unrecognised — a hand-edited ``preferences.yaml``
with a typo in it should lose some log detail, not stop the app from starting.
Returns:
The matching level number.
"""
return _LEVELS.get(name.strip().upper(), fallback)
def log_path(log_dir: Path) -> Path:
"""Return the log file's path, for an error message that wants to name it."""
return log_dir / LOG_FILENAME
def configure_logging(
console: Console,
log_dir: Path,
*,
level: int = logging.INFO,
file_level: int = logging.WARNING,
quiet: bool = False,
) -> logging.Logger:
"""Configure and return the application logger.
Args:
console: The Rich console the handler should render to.
log_dir: Directory for the ``meshterm.log`` file.
level: Console log level.
file_level: File log level, from the ``log_level`` preference.
quiet: When ``True``, suppress console output (file logging continues).
Returns:
The configured ``meshterm`` logger.
"""
logger = logging.getLogger(_LOGGER_NAME)
logger.setLevel(logging.DEBUG)
logger.handlers.clear()
logger.propagate = False
if not quiet:
rich_handler = RichHandler(
console=console, rich_tracebacks=True, show_path=False, markup=True
)
rich_handler.setLevel(level)
logger.addHandler(rich_handler)
log_dir.mkdir(parents=True, exist_ok=True)
file_handler = RotatingFileHandler(
log_path(log_dir),
maxBytes=_MAX_BYTES,
backupCount=_BACKUP_COUNT,
encoding="utf-8",
)
file_handler.setLevel(file_level)
file_handler.setFormatter(logging.Formatter(_LINE_FORMAT, datefmt=_TIME_FORMAT))
logger.addHandler(file_handler)
_quiet_library_console(file_handler)
return logger
#: Third-party loggers that must never write to the terminal — their records would print
#: straight over the full-screen TUI. Routed to the file handler instead so they stay
#: captured for debugging. ``meshcore`` is the notable offender: it calls
#: ``logging.basicConfig(level=INFO)`` on import (e.g. "INFO:meshcore:Serial Connection
#: started"). ``asyncio`` is included so its default exception handler — the one that
#: reports stray background-task errors once prompt_toolkit's screen-dumping handler is
#: disabled — logs to the file instead of the console.
_LIBRARY_LOGGERS: tuple[str, ...] = ("meshcore", "asyncio")
def _quiet_library_console(file_handler: logging.Handler) -> None:
"""Keep noisy third-party libraries off the terminal (they corrupt the TUI).
The ``meshcore`` client calls ``logging.basicConfig(level=INFO)`` when it is imported,
which installs a stream handler on the *root* logger that prints its INFO lines straight
over the screen. Two guards prevent that:
1. Give the root logger a :class:`~logging.NullHandler` so ``basicConfig`` — which only
acts when the root has no handlers — becomes a no-op and never adds its stream handler.
2. Take each known library logger off propagation and attach only ``file_handler``, so
its records are still captured to the log but never reach the console, even if some
other code path installs a root stream handler anyway.
Args:
file_handler: The application's file handler to also capture library records to.
"""
root = logging.getLogger()
if not any(isinstance(h, logging.NullHandler) for h in root.handlers):
root.addHandler(logging.NullHandler())
for name in _LIBRARY_LOGGERS:
lib = logging.getLogger(name)
lib.handlers.clear()
lib.setLevel(logging.INFO)
lib.propagate = False
lib.addHandler(file_handler)
def get_logger(name: str | None = None) -> logging.Logger:
"""Return a child of the application logger.
Args:
name: Optional child name; when ``None`` the root app logger is returned.
Returns:
The requested logger.
"""
if name is None:
return logging.getLogger(_LOGGER_NAME)
return logging.getLogger(f"{_LOGGER_NAME}.{name}")