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>
176 lines
6.6 KiB
Python
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}")
|