Logging

duho.logging

TRACE module-attribute

TRACEBACK_ENV = 'DUHO_TRACEBACK' module-attribute

VERBOSE_HELP = '' module-attribute

VERBOSE_LEVELS = {} module-attribute

__all__ = ['add_logging_level', 'DefaultFormatter', 'VERBOSE_LEVELS', 'VERBOSE_HELP', 'parse_loglevels', 'init_stderr_logging', 'initverbose', 'TRACEBACK_ENV', 'traceback_enabled', 'log_exception'] module-attribute

DefaultFormatter(fmt='%(asctime)s | %(levelname)8s | %(name)s: %(message)s', datefmt=None, style='%', validate=True, *, color=True)

Bases: Formatter

Log formatter with colored output.

Source code in src/duho/logging.py

def __init__(
    self,
    fmt: _ty.Optional[str] = "%(asctime)s | %(levelname)8s | %(name)s: %(message)s",
    datefmt: _ty.Optional[str] = None,
    style: _ty.Literal["%", "{", "$"] = "%",
    validate: bool = True,
    *,
    color: bool = True,
) -> None:
    # Direct construction stays always colored (tests/test_logging_color.py
    # pins it); `init_stderr_logging` passes `color=False` for a non-TTY or
    # NO_COLOR/FORCE_COLOR.
    self._duho_color_enabled = color
    super().__init__(fmt, datefmt, style, validate)

COLORS = {_logging.DEBUG: _asicode(34), _logging.INFO: _asicode(32), _logging.WARNING: _asicode(33), _logging.ERROR: _asicode(31), _logging.CRITICAL: _asicode(31, 47)} class-attribute instance-attribute

RESET_ALL = _asicode(0) class-attribute instance-attribute

format(record)

Source code in src/duho/logging.py

def format(self, record: _logging.LogRecord) -> str:
    record = _copy.copy(record)
    record.levelname = record.levelname.center(_LEVELSIZE)
    if self._duho_color_enabled:
        color = self.COLORS.get(record.levelno, None)
        if color:
            record.levelname = f"{color}{record.levelname}{self.RESET_ALL}"
    return super().format(record)

__getattr__(name)

Source code in src/duho/logging.py

def __getattr__(name: str):
    # Forward only public stdlib names: forwarding dunders made ``__path__``
    # resolve to stdlib logging's, so ``import duho.logging.handlers`` silently
    # loaded a second copy of ``logging/handlers.py`` instead of raising.
    if name.startswith("_"):
        raise AttributeError(name)
    return getattr(_logging, name)

add_logging_level(name, level, force=False, color=None)

Register a custom log level.

Installs NAME on the logging module and the method name on the module, on logging.Logger, on the current logging.getLoggerClass() and on logging.LoggerAdapter (so logging.name(...), logger.name(...) and adapter.name(...) all work; the adapter's applies its process()), registers the level name, refreshes the -v/-q verbosity table (:func:initverbose) so the new level immediately participates in it regardless of whether anything has configured logging yet, and optionally gives it a color for :class:DefaultFormatter.

Unless force is set, refuses (ValueError) to clobber an existing logging/Logger/LoggerAdapter attribute that duho itself did not install -- guarding both the given NAME (as before) and its lower-cased method name: a level named e.g. LOG or EXCEPTION would otherwise silently replace logging.log/Logger.exception. A repeat call for a name duho already installed itself (tracked in :data:_installed_level_names) at the same number is a harmless no-op either way, but at a different number it raises (renumber with force=True); a name that collides with something duho did NOT install -- an unrelated stdlib constant like logging.BASIC_FORMAT, not just a level/method name -- raises instead of silently no-oping, the same guard the lower-cased check below already gave method names.

Source code in src/duho/logging.py

def add_logging_level(
    name: str, level: int, force: bool = False, color: _ty.Optional[str] = None
) -> None:
    """Register a custom log level.

    Installs ``NAME`` on the ``logging`` module and the method ``name`` on the
    module, on ``logging.Logger``, on the current ``logging.getLoggerClass()`` and
    on ``logging.LoggerAdapter`` (so ``logging.name(...)``, ``logger.name(...)``
    and ``adapter.name(...)`` all work; the adapter's applies its ``process()``),
    registers the level name, refreshes the ``-v``/``-q`` verbosity table
    (:func:`initverbose`) so the new level immediately participates in it
    regardless of whether anything has configured logging yet, and optionally
    gives it a color for :class:`DefaultFormatter`.

    Unless ``force`` is set, refuses (``ValueError``) to clobber an existing
    ``logging``/``Logger``/``LoggerAdapter`` attribute that duho itself did not
    install -- guarding both the given ``NAME`` (as before) and its lower-cased method
    name: a level named e.g. ``LOG`` or ``EXCEPTION`` would otherwise
    silently replace ``logging.log``/``Logger.exception``. A repeat call for
    a name duho already installed itself (tracked in
    :data:`_installed_level_names`) at the same number is a harmless no-op
    either way, but at a different number it raises (renumber with
    ``force=True``); a name that collides with something duho did NOT install --
    an unrelated stdlib constant like ``logging.BASIC_FORMAT``, not just a level/method name --
    raises instead of silently no-oping, the same guard the lower-cased
    check below already gave method names.
    """
    name = name.upper()
    lname = name.lower()
    if not force:
        if name in _installed_level_names:
            if getattr(_logging, name, level) == level:
                return
            raise ValueError(
                f"add_logging_level: {name!r} is already registered at level "
                f"{getattr(_logging, name)}, not {level}; pass force=True to "
                "renumber it deliberately"
            )
        if hasattr(_logging, name):
            raise ValueError(
                f"add_logging_level: {name!r} already exists as a logging "
                "attribute that duho did not install; pass force=True to "
                "replace it deliberately"
            )
        for existing in (
            getattr(_logging, lname, None),
            getattr(_logging.Logger, lname, None),
            getattr(_logging.getLoggerClass(), lname, None),
            getattr(_logging.LoggerAdapter, lname, None),
        ):
            if existing is not None and getattr(existing, "_duho_level_", None) is None:
                raise ValueError(
                    f"add_logging_level: {lname!r} already exists as a "
                    "logging attribute/method that duho did not install; "
                    "pass force=True to replace it deliberately"
                )

    _install_level(name, level, color, tolerant=False)
    initverbose()

init_stderr_logging(name=None, level=None)

Initialize logging to stderr with color support.

Idempotent: a repeat call on the same logger (directly, or via duho.main/duho.app each time they run) finds the handler this function installed last time (tagged, never matched by identity/count) and does not add a second one -- calling it twice does not duplicate log lines. level, when given, is still (re)applied.

Color is gated the same way duho's own --help formatters are: ANSI only when the stream is a TTY, off when NO_COLOR is set, forced on with FORCE_COLOR -- so redirecting/piping output, or a CI log, never receives raw escape bytes. When color is enabled and colorama is importable, colorama.just_fix_windows_console() is called so a legacy Windows console renders the codes instead of showing them literally.

Source code in src/duho/logging.py

def init_stderr_logging(
    name: _ty.Optional[str] = None, level: _ty.Optional[int] = None
) -> _logging.Logger:
    """Initialize logging to stderr with color support.

    Idempotent: a repeat call on the same logger (directly, or via
    ``duho.main``/``duho.app`` each time they run) finds the handler this
    function installed last time (tagged, never matched by identity/count)
    and does not add a second one -- calling it twice does not duplicate
    log lines. ``level``, when given, is still (re)applied.

    Color is gated the same way duho's own ``--help`` formatters are:
    ANSI only when the stream is a TTY, off when ``NO_COLOR`` is set, forced
    on with ``FORCE_COLOR`` -- so redirecting/piping output, or a CI log,
    never receives raw escape bytes. When color is enabled and colorama is
    importable, ``colorama.just_fix_windows_console()`` is called so a legacy
    Windows console renders the codes instead of showing them literally.
    """
    initverbose()
    logger = _logging.getLogger(name)
    if not any(getattr(h, _STDERR_HANDLER_TAG, False) for h in logger.handlers):
        # Lazy: `formatters` imports from this module (`_asicode`), so a
        # top-level import would be a cycle.
        from . import formatters as _formatters

        color = _formatters._color_enabled(_sys.stderr)
        if color:
            colorama = _resolve_colorama()
            just_fix = getattr(colorama, "just_fix_windows_console", None)
            if callable(just_fix):
                just_fix()
        handler = _StderrHandler()
        setattr(handler, _STDERR_HANDLER_TAG, True)
        handler.setFormatter(DefaultFormatter(color=color))
        logger.addHandler(handler)
    if level:
        logger.setLevel(level)
    return logger

initverbose()

Initialize verbose level mappings.

Source code in src/duho/logging.py

def initverbose() -> None:
    """Initialize verbose level mappings."""
    global VERBOSE_LEVELS, VERBOSE_HELP, _LEVELSIZE

    levels: dict[int, list[str]] = {}
    for name, loglevel in get_level_names_mapping().items():
        if not loglevel:
            continue
        aliases: list[str] = levels.setdefault(loglevel, [])
        _LEVELSIZE = max(_LEVELSIZE, len(name))
        if name not in aliases:
            aliases.append(name)

    # Show the canonical name (`logging.getLevelName`) first: the mapping lists
    # the deprecated "WARN" before "WARNING".
    for loglevel, aliases in levels.items():
        canonical = _logging.getLevelName(loglevel)
        if canonical in aliases and aliases[0] != canonical:
            aliases.remove(canonical)
            aliases.insert(0, canonical)

    VERBOSE_LEVELS = dict(sorted(levels.items(), key=lambda l: l[0], reverse=True))
    VERBOSE_HELP = ", ".join([aliases[0] for aliases in VERBOSE_LEVELS.values()])

log_exception(logger, msg, *args, level=_logging.ERROR)

Log a caught exception, with a traceback iff DUHO_TRACEBACK is set.

The framework's resilient paths (discovery skipping a bad command, a runpath step failing, a fan-out target raising) deliberately do NOT propagate the exception, which means the stack -- the only thing that says where it broke -- is lost unless it is logged. Logging it unconditionally would bury an ordinary "optional dependency missing" warning under 30 frames, so this helper makes it opt-in via :func:traceback_enabled.

Call it from inside an except block, where exc_info has an exception to render. When disabled the exc_info kwarg is omitted entirely rather than passed as False -- both suppress the traceback, but False is recorded verbatim on LogRecord.exc_info, so a handler or test inspecting that attribute would see False where every other un-decorated record in the process carries None.

stacklevel=2 skips this helper's own frame, so the record attributes the caller's except-block, not duho/logging.py:log_exception, as the log site.

Source code in src/duho/logging.py

def log_exception(
    logger: _logging.Logger,
    msg: str,
    *args: object,
    level: int = _logging.ERROR,
) -> None:
    """Log a caught exception, with a traceback iff ``DUHO_TRACEBACK`` is set.

    The framework's resilient paths (discovery skipping a bad command, a runpath
    step failing, a fan-out target raising) deliberately do NOT propagate the
    exception, which means the stack -- the only thing that says *where* it broke
    -- is lost unless it is logged. Logging it unconditionally would bury an
    ordinary "optional dependency missing" warning under 30 frames, so this
    helper makes it opt-in via :func:`traceback_enabled`.

    Call it from inside an ``except`` block, where ``exc_info`` has an exception
    to render. When disabled the ``exc_info`` kwarg is omitted entirely rather
    than passed as ``False`` -- both suppress the traceback, but ``False`` is
    recorded verbatim on ``LogRecord.exc_info``, so a handler or test inspecting
    that attribute would see ``False`` where every other un-decorated record in
    the process carries ``None``.

    ``stacklevel=2`` skips this helper's own frame, so the record attributes
    the caller's except-block, not ``duho/logging.py:log_exception``, as the
    log site.
    """
    if traceback_enabled():
        logger.log(level, msg, *args, exc_info=True, stacklevel=2)
    else:
        logger.log(level, msg, *args, stacklevel=2)

parse_loglevels(text, itemdivider=',', valkey_separator=':')

Parse a [NAME:]LEVEL[,NAME:LEVEL...] log level specification.

LEVEL is matched against the registered level names -- first by its EXACT text (so a custom level registered under a lowercase/mixed-case name, e.g. logging.addLevelName(25, "notice"), matches directly), then by its upper-cased form (so the standard DEBUG, debug and Debug spellings are all still accepted) -- or may be a plain integer. Surrounding whitespace around a name or level is stripped. An entry that resolves to neither raises argparse.ArgumentTypeError naming the bad token -- argparse reports this as a normal "invalid value" usage error instead of the entry silently disappearing from the returned mapping.

Source code in src/duho/logging.py

def parse_loglevels(
    text: str, itemdivider: str = ",", valkey_separator: str = ":"
) -> dict[str, int]:
    """Parse a ``[NAME:]LEVEL[,NAME:LEVEL...]`` log level specification.

    ``LEVEL`` is matched against the registered level names -- first by its
    EXACT text (so a custom level registered under a lowercase/mixed-case
    name, e.g. ``logging.addLevelName(25, "notice")``, matches directly),
    then by its upper-cased form (so the standard ``DEBUG``, ``debug`` and
    ``Debug`` spellings are all still accepted) -- or may be a plain integer.
    Surrounding whitespace around a name or level is stripped. An entry that
    resolves to neither raises ``argparse.ArgumentTypeError`` naming the bad
    token -- argparse reports this as a normal "invalid value" usage error
    instead of the entry silently disappearing from the returned mapping.
    """
    levels: dict[str, int] = {}
    levelmapping = get_level_names_mapping()

    for entry in text.split(itemdivider):
        name, *level = entry.split(valkey_separator, maxsplit=1)
        if not level:
            level_text = name.strip()
            name = ""
        else:
            level_text = level[0].strip()
        name = name.strip()

        resolved = levelmapping.get(level_text)
        if resolved is None:
            resolved = levelmapping.get(level_text.upper())
        if resolved is None:
            if _re.fullmatch(r"-?[0-9]+", level_text):
                resolved = int(level_text)
            else:
                raise _argparse.ArgumentTypeError(
                    f"invalid log level {level_text!r} in {entry!r} (expected "
                    f"one of {', '.join(levelmapping)}, or an integer)"
                )
        levels[name] = resolved
    return levels

traceback_enabled()

Return whether framework error logs should carry a full traceback.

Reads :data:TRACEBACK_ENV (DUHO_TRACEBACK) from the process environment on EVERY call, or the variable a running program's root names with _traceback_env_ instead rather than caching it, so a test (or an app that sets it mid-run) can flip the switch without re-importing duho. The read is a dict lookup -- cheap enough to sit on an error path.

Off by default: a CLI user seeing a framework warning wants the message, not a stack. A developer debugging where a step/command/target actually failed exports DUHO_TRACEBACK=1 and gets the traceback for free at every site.

Source code in src/duho/logging.py

def traceback_enabled() -> bool:
    """Return whether framework error logs should carry a full traceback.

    Reads :data:`TRACEBACK_ENV` (``DUHO_TRACEBACK``) from the process
    environment on EVERY call, or the variable a running program's root names
    with ``_traceback_env_`` instead rather than caching it, so a test (or an app that
    sets it mid-run) can flip the switch without re-importing duho. The read is
    a dict lookup -- cheap enough to sit on an error path.

    Off by default: a CLI user seeing a framework warning wants the message, not
    a stack. A developer debugging *where* a step/command/target actually failed
    exports ``DUHO_TRACEBACK=1`` and gets the traceback for free at every site.
    """
    name = _TRACEBACK_VAR.get() or TRACEBACK_ENV
    return _os.environ.get(name, "").strip().lower() in _TRUTHY