[merge-to-it] logging_config: console format API, dotted-prefix colours, cached lookups

.github/workflows/build-ubuntu.yml

@@ -875,7 +875,9 @@ jobs:
         # proxy up. This is the primary bring-up marker.
         BRINGUP_MARKER="CloudXR runtime and WSS proxy started"
         SESSION_MARKER="TeleopSession started successfully"
-        PLUGIN_MARKER_RE="wuji_glove\.WujiGlovePlugin\].*initialized and running"
+        # The console names a logger by its last segment only (logging_config's
+        # default), so the plugin's line reads "[WujiGlovePlugin] ...".
+        PLUGIN_MARKER_RE="\[WujiGlovePlugin\].*initialized and running"
         # Hard failures from the launcher, runtime, or plugin lifecycle.
         FAIL_RE="CloudXR runtime failed to start|SDK missing libcloudxr.so|CloudXR EULA was not accepted|CloudXR launcher is not running|runtime process exited unexpectedly|WSS proxy thread stopped unexpectedly|Plugin process exited immediately|Required plugin .* was not discovered"
 

src/core/log_bridge/cpp/sink_config.cpp

@@ -45,8 +45,10 @@ namespace
 
 constexpr std::size_t kFileMaxBytes = 10 * 1024 * 1024; // 10 MiB
 constexpr std::size_t kFileBackupCount = 5;
-// Match Python's LINE_FORMAT; %* renders Python-style level names.
-constexpr const char* kPattern = "[%Y-%m-%d %H:%M:%S.%e] [%*] [%n] [pid:%P] %v";
+// Match Python's LINE_FORMAT; %* renders Python-style level names. Only the console
+// drops the date: log files need it across midnight, rotation and processes.
+constexpr const char* kFilePattern = "[%Y-%m-%d %H:%M:%S.%e] [%*] [%n] [pid:%P] %v";
+constexpr const char* kConsolePattern = "[%H:%M:%S.%e] [%*] [%n] [pid:%P] %v";
 
 // Map spdlog levels to Python's display names.
 std::string_view python_level_name(spdlog::level::level_enum level)
@@ -91,10 +93,10 @@ class PythonLevelFormatter : public spdlog::custom_flag_formatter
 };
 
 // Each sink owns its formatter.
-std::unique_ptr<spdlog::pattern_formatter> make_formatter()
+std::unique_ptr<spdlog::pattern_formatter> make_formatter(const char* pattern)
 {
     auto formatter = std::make_unique<spdlog::pattern_formatter>();
-    formatter->add_flag<PythonLevelFormatter>('*').set_pattern(kPattern);
+    formatter->add_flag<PythonLevelFormatter>('*').set_pattern(pattern);
     return formatter;
 }
 
@@ -337,7 +339,7 @@ const std::vector<spdlog::sink_ptr>& local_sinks()
         {
             auto console = std::make_shared<spdlog::sinks::stderr_color_sink_mt>();
             console->set_level(spdlog::level::trace);
-            console->set_formatter(make_formatter());
+            console->set_formatter(make_formatter(kConsolePattern));
             return std::vector<spdlog::sink_ptr>{ console };
         }
 
@@ -352,7 +354,7 @@ const std::vector<spdlog::sink_ptr>& local_sinks()
         // Build the infallible stderr sink before optional file setup.
         auto console = std::make_shared<spdlog::sinks::stderr_color_sink_mt>();
         console->set_level(console_level());
-        console->set_formatter(make_formatter());
+        console->set_formatter(make_formatter(kConsolePattern));
 
         auto dir = log_dir();
 #ifndef _WIN32
@@ -399,7 +401,7 @@ const std::vector<spdlog::sink_ptr>& local_sinks()
             auto file = std::make_shared<spdlog::sinks::rotating_file_sink_mt>(
                 filename.string(), kFileMaxBytes, kFileBackupCount, false, events);
             file->set_level(spdlog::level::trace); // always captures everything.
-            file->set_formatter(make_formatter());
+            file->set_formatter(make_formatter(kFilePattern));
             return std::vector<spdlog::sink_ptr>{ console, file };
         }
         catch (const spdlog::spdlog_ex&)

src/python/isaaccapture/logging_config/__init__.py

@@ -10,6 +10,9 @@
 """
 
 from ._console import set_console_filter, set_console_level, set_logger_colors
+from ._console import (
+    set_console_format,
+)
 
 # Internal bootstrap; intentionally excluded from ``__all__``.
 from ._setup import install as install
@@ -18,6 +21,7 @@
 # Public configuration API.
 __all__ = [
     "set_console_filter",
+    "set_console_format",
     "set_console_level",
     "set_logger_colors",
     "set_propagate_to_root",

src/python/isaaccapture/logging_config/_console.py

@@ -5,16 +5,17 @@
 
 from __future__ import annotations
 
+import functools
 import logging
 import os
 import re
 import threading
+from collections.abc import Callable, Mapping
+from typing import TypedDict, TypeVar
 
 from . import _forwarding, _native_fd
 from ._core import (
     _LEVEL_NAME_BY_VALUE,
-    DATE_FORMAT,
-    LINE_FORMAT,
     TRACE,
     env_console_level,
     logging_enabled,
@@ -50,13 +51,36 @@ def filter(self, record: logging.LogRecord) -> bool:
 # Accept only SGR color escapes such as ``\x1b[36m``.
 _SGR_ESCAPE = re.compile(r"(?:\x1b\[[0-9;]*m)+")
 
-# Exact logger name to ANSI emphasis.
+# Logger name to ANSI emphasis; a name's colour also covers its dotted descendants.
 _logger_colors: dict[str, str] = {
     # cloudxr.oob_teleop_env contains [setup-oob] / [usb-local] progress.
     "isaaccapture.cloudxr.oob_teleop_env": "\033[36m",
 }
 
 
+_V = TypeVar("_V")
+
+
+def _prefix_lookup(name: str, table: Mapping[str, _V]) -> _V | None:
+    """*table*'s value for *name* or its nearest dotted ancestor, else ``None``."""
+    while name not in table and "." in name:
+        name = name.rpartition(".")[0]
+    return table.get(name)
+
+
+def _cached_prefix_lookup(table: Mapping[str, _V]) -> Callable[[str], _V | None]:
+    """``_prefix_lookup`` over a copy of *table*, cached per logger name.
+
+    The copy keeps every cached result valid, so a change to *table* needs a new lookup.
+    """
+    table = dict(table)
+    return functools.cache(lambda name: _prefix_lookup(name, table))
+
+
+# set_logger_colors() replaces this lookup after every change, so it never goes stale.
+_logger_color = _cached_prefix_lookup(_logger_colors)
+
+
 #: Color only WARNING and ERROR+ so severity remains distinctive.
 _LEVEL_WARNING_COLOR = "\033[33m"
 _LEVEL_ERROR_COLOR = "\033[31m"
@@ -72,12 +96,19 @@ def _level_color(levelno: int) -> str | None:
 
 
 class _LoggerNameColorFormatter(logging.Formatter):
-    """Color terminal lines by level and optionally emphasize the logger name."""
-
-    def __init__(self, *args, handler: logging.StreamHandler, **kwargs) -> None:
+    """Color terminal lines by level; optionally emphasize or shorten logger names."""
+
+    def __init__(
+        self,
+        *args,
+        handler: logging.StreamHandler,
+        use_short_name: bool = False,
+        **kwargs,
+    ) -> None:
         super().__init__(*args, **kwargs)
         # Capture scopes can replace the handler stream after construction.
         self._handler = handler
+        self._use_short_name = use_short_name
 
     def _is_terminal(self) -> bool:
         stream = getattr(self._handler, "stream", None)
@@ -87,18 +118,18 @@ def _is_terminal(self) -> bool:
             return False
 
     def format(self, record: logging.LogRecord) -> str:
-        if not self._is_terminal():
-            return super().format(record)
-
-        level = _level_color(record.levelno)
-        emphasis = _logger_colors.get(record.name)
-        if level is None and emphasis is None:
+        terminal = self._is_terminal()
+        level = _level_color(record.levelno) if terminal else None
+        emphasis = _logger_color(record.name) if terminal else None
+        if level is None and emphasis is None and not self._use_short_name:
             return super().format(record)
 
         # Restore the shared record before the file handler formats it.
         original = record.name
+        name = original.rpartition(".")[2] if self._use_short_name else original
         if emphasis is not None:
-            record.name = f"{emphasis}{original}{level or _ANSI_RESET}"
+            name = f"{emphasis}{name}{level or _ANSI_RESET}"
+        record.name = name
         try:
             line = super().format(record)
         finally:
@@ -120,9 +151,7 @@ def ensure_handler() -> logging.StreamHandler:
         if _handler is not None:
             return _handler
         handler = logging.StreamHandler()
-        handler.setFormatter(
-            _LoggerNameColorFormatter(LINE_FORMAT, datefmt=DATE_FORMAT, handler=handler)
-        )
+        handler.setFormatter(_console_formatter(handler))
         handler.setLevel(env_console_level())
         if not logging_enabled():
             _handler = handler
@@ -172,11 +201,81 @@ def set_console_filter(pattern: str | None, target: str = "both") -> None:
         handler.addFilter(replacement)
 
 
+class _ConsoleFormat(TypedDict, total=False):
+    show_time: bool
+    show_level: bool
+    show_logger_name: bool
+    show_pid: bool
+
+    use_short_name: bool  # True: only the last dotted segment
+
+
+# Console only: log files keep DATE_FORMAT's date, which sessions crossing midnight,
+# rotated logs and cross-process correlation need.
+_CONSOLE_DATE_FORMAT = "%H:%M:%S"
+
+# The console's current columns, starting from the defaults the handler is built with.
+_console_format: dict[str, bool] = {
+    "show_time": True,
+    "show_level": True,
+    "show_logger_name": True,
+    "show_pid": False,
+    "use_short_name": True,
+}
+
+
+def _console_formatter(handler: logging.StreamHandler) -> _LoggerNameColorFormatter:
+    """Build the console formatter from the current ``_console_format`` columns."""
+    columns = [
+        "[%(asctime)s.%(msecs)03d]" if _console_format["show_time"] else "",
+        "[%(levelname)-5s]" if _console_format["show_level"] else "",
+        "[%(name)s]" if _console_format["show_logger_name"] else "",
+        "[pid:%(process)d]" if _console_format["show_pid"] else "",
+        "%(message)s",
+    ]
+    return _LoggerNameColorFormatter(
+        " ".join(column for column in columns if column),
+        datefmt=_CONSOLE_DATE_FORMAT,
+        handler=handler,
+        use_short_name=_console_format["use_short_name"],
+    )
+
+
+def set_console_format(changes: _ConsoleFormat) -> None:
+    """Update the console columns, changing only the given keys.
+
+    Keys left out keep their current setting, which starts as time, level and the
+    last logger-name segment, without the pid; an unknown key or a non-bool value
+    is logged as an error and skipped. Columns keep the ``LINE_FORMAT`` order with
+    the time as ``HH:MM:SS.mmm``; log files from both halves keep the full
+    ``LINE_FORMAT``, date included, and logger colours still match the full name.
+    """
+    for key, value in changes.items():
+        if key not in _console_format:
+            root_logger.error(
+                "Unknown console format key %r, expected one of %s; ignoring it.",
+                key,
+                sorted(_console_format),
+            )
+            continue
+        if not isinstance(value, bool):
+            root_logger.error(
+                "Console format %r must be a bool, got %r; ignoring it.", key, value
+            )
+            continue
+        _console_format[key] = value
+
+    handler = ensure_handler()
+    handler.setFormatter(_console_formatter(handler))
+
+
 def set_logger_colors(colors: dict[str, str | None]) -> None:
-    """Set terminal-only SGR emphasis by exact logger name; ``None`` removes it.
+    """Set terminal-only SGR emphasis by logger name; ``None`` removes it.
 
+    A colour also covers the name's dotted descendants; the most specific name wins.
     A value that is not purely SGR escapes is logged as an error and skipped.
     """
+    global _logger_color
     ensure_handler()
     for name, color in colors.items():
         if color is None:
@@ -191,3 +290,4 @@ def set_logger_colors(colors: dict[str, str | None]) -> None:
             )
             continue
         _logger_colors[name] = color
+    _logger_color = _cached_prefix_lookup(_logger_colors)

tests/python/core/logging_config/conftest.py

@@ -47,6 +47,12 @@
     r"\[(?P<level>[A-Z]+ *)\] \[(?P<name>[^]]+)\] \[pid:(?P<pid>\d+)\] (?P<message>.*)$"
 )
 
+#: A C++ console line: ``LINE_FORMAT`` without the date, which only files keep.
+CPP_CONSOLE_LINE_RE = re.compile(
+    r"^\[(?P<time>\d{2}:\d{2}:\d{2})\.(?P<msecs>\d{3})\] "
+    r"\[(?P<level>[A-Z]+ *)\] \[(?P<name>[^]]+)\] \[pid:(?P<pid>\d+)\] (?P<message>.*)$"
+)
+
 _EMITTER = os.environ.get("LOG_BRIDGE_TEST_EMITTER", "")
 
 #: The standalone C++ emitter is built by tests/cpp/core/log_bridge and located