The review pass found the CLI breaking its own written rules. A node broadcasts its own name, so every name the CLI prints is remote data — and Rich read `[...]` in it as a style tag. A node called `[bold]Loud` printed as `Loud`, silently no longer the string that identifies it; a node called `[/]Bob` raised MarkupError and took the command down. The log handler then failed the same way while reporting it, replacing the diagnostic with a traceback about the diagnostic. No log line and no scripted line is ever marked up, so all three consoles now say so. `right=` never right-aligned anything. Rich's `Text.wrap` returns early on `overflow="ignore"`, above the justify step, so asking for one threw the other away — every numeric lane in the CLI was left-aligned while CLAUDE.md, script.py's own docstring and the manual all said otherwise. "crop" refuses to elide just as firmly and still aligns. `config show` printed an empty string as `""` and `config set` read those two characters literally, so feeding a dump back in replaced every empty setting with a pair of quote marks — and the next dump looked identical, so nothing ever said so. It also masked an *unreported* PIN behind six bullets, telling the reader the radio was PIN-locked when it was not: `conceal` already declined to mask the menu's absence token and had simply never been shown the CLI's. `meshterm about` drew the `---` above its colophon as a rule sized to the console, which on a 16384-cell console is one 48KB line in a 4KB page. A rule is a frame; the scripted copy drops it with the QR. The contract fixture set only `--db`, which moves the history and nothing else — so the suite read whatever was in the developer's own ~/.meshterm. That is how `[/]Bob`, planted by hand on one machine, could crash the suite there and pass everywhere else. $MESHTERM_HOME moves the whole directory. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
182 lines
7.1 KiB
Python
182 lines
7.1 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:
|
|
# markup=False: a log line carries whatever the device said — a node name, a
|
|
# firmware error — and Rich would read `[...]` in it as a style tag. That made the
|
|
# *error path* the one most likely to fail: reporting a fault on a node called
|
|
# `[/]Bob` raised MarkupError from inside the handler, replacing the diagnostic
|
|
# with a traceback about the diagnostic. No log call in the package marks up its
|
|
# message, so parsing them buys nothing.
|
|
rich_handler = RichHandler(
|
|
console=console, rich_tracebacks=True, show_path=False, markup=False
|
|
)
|
|
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}")
|