Implement logging through Systemd native Journal protocol

Use JournaldLogHandler from logging-journald [1] to log events from
Python logging to Systemd journal directly. This makes it possible to
better filter the log messages based on priority and persist more useful
metadata (like filename and line number) for the log events in the
Journal. The Journal log priority is also distingushed based on
different log priorities of logging events.

Another advantage is that stack traces are saved as a single log event
rather than multiple separated lines printed to container stdout/stderr.
The coloring isn't done using ANSI escape sequences from the
ColoredFormatter anymore, resulting in plaintext MESSAGE fields (instead
of byte arrays). Colors are added based on the priority metadata when
the events are read from the Systemd Journal Gatewayd to maintain
backwards compatibility.

To correctly match non-Python error logs, log entries must be written to
the Journal with the same SYSLOG_IDENTIFIER field as the logs coming
form the container directly (e.g. from s6, bashio, etc.). To obtain the
Python logs through the docker logs command, container ID (obtained
though a hacky method currently) is added to the log records as well -
this is useful to keep the falllback method for getting the logs
working.

[1] https://github.com/mosquito/logging-journald/
[2] https://systemd.io/JOURNAL_NATIVE_PROTOCOL/

requirements.txt

@@ -17,6 +17,7 @@ faust-cchardet==2.1.19
 gitpython==3.1.44
 jinja2==3.1.6
 log-rate-limit==1.4.2
+logging-journald==0.6.11
 orjson==3.10.18
 pulsectl==24.12.0
 pyudev==0.24.3

supervisor/bootstrap.py

@@ -46,6 +46,7 @@ from .services import ServiceManager
 from .store import StoreManager
 from .supervisor import Supervisor
 from .updater import Updater
+from .utils.logging import HAOSLogHandler
 from .utils.sentry import capture_exception, init_sentry
 
 _LOGGER: logging.Logger = logging.getLogger(__name__)
@@ -246,20 +247,31 @@ def initialize_logging() -> None:
     # suppress overly verbose logs from libraries that aren't helpful
     logging.getLogger("aiohttp.access").setLevel(logging.WARNING)
 
-    logging.getLogger().handlers[0].setFormatter(
-        ColoredFormatter(
-            colorfmt,
-            datefmt=datefmt,
-            reset=True,
-            log_colors={
-                "DEBUG": "cyan",
-                "INFO": "green",
-                "WARNING": "yellow",
-                "ERROR": "red",
-                "CRITICAL": "red",
-            },
+    default_handler = logging.getLogger().handlers[0]
+
+    if HAOSLogHandler.is_available():
+        # replace the default logging handler with JournaldLogHandler
+        logging.getLogger().removeHandler(default_handler)
+        supervisor_name = os.environ[ENV_SUPERVISOR_NAME]
+        journald_handler = HAOSLogHandler(identifier=supervisor_name)
+        journald_handler.setFormatter(logging.Formatter(fmt, datefmt=datefmt))
+        logging.getLogger().addHandler(journald_handler)
+    else:
+        default_handler.setFormatter(
+            ColoredFormatter(
+                colorfmt,
+                datefmt=datefmt,
+                reset=True,
+                log_colors={
+                    "DEBUG": "cyan",
+                    "INFO": "green",
+                    "WARNING": "yellow",
+                    "ERROR": "red",
+                    "CRITICAL": "red",
+                },
+            )
         )
-    )
+
     warnings.showwarning = warning_handler
 
 

supervisor/host/sound.py

@@ -339,7 +339,7 @@ class SoundControl(CoreSysAttributes):
                                     profile.name == card.profile_active.name,
                                 )
                                 for profile in card.profile_list
-                                if profile.available
+                                if profile.is_available
                             ],
                         )
                         for card in pulse.card_list()

supervisor/utils/logging.py

@@ -7,6 +7,8 @@ import logging.handlers
 import queue
 from typing import Any
 
+from logging_journald import Facility, JournaldLogHandler
+
 
 class AddonLoggerAdapter(logging.LoggerAdapter):
     """Logging Adapter which prepends log entries with add-on name."""
@@ -59,6 +61,52 @@ class SupervisorQueueHandler(logging.handlers.QueueHandler):
         self.listener = None
 
 
+class HAOSLogHandler(JournaldLogHandler):
+    """Log handler for writing logs to the Home Assistant OS Systemd Journal."""
+
+    SYSLOG_FACILITY = Facility.LOCAL7
+
+    def __init__(self, identifier: str | None = None) -> None:
+        """Initialize the HAOS log handler."""
+        super().__init__(identifier=identifier, facility=HAOSLogHandler.SYSLOG_FACILITY)
+        self._container_id = self._get_container_id()
+
+    @staticmethod
+    def _get_container_id() -> str | None:
+        """Get the container ID if running inside a Docker container."""
+        # Currently we only have this hacky way of getting the container ID,
+        # we (probably) cannot get it without having some cgroup namespaces
+        # mounted in the container or passed it there using other means.
+        # Not obtaining it will only result in the logs not being available
+        # through `docker logs` command, so it is not a critical issue.
+        with open("/proc/self/mountinfo") as f:
+            for line in f:
+                if "/docker/containers/" in line:
+                    container_id = line.split("/docker/containers/")[-1]
+                    return container_id.split("/")[0]
+        return None
+
+    @classmethod
+    def is_available(cls) -> bool:
+        """Check if the HAOS log handler can be used."""
+        return cls.SOCKET_PATH.exists()
+
+    def emit(self, record: logging.LogRecord) -> None:
+        """Emit formatted log record to the Systemd Journal.
+
+        If CONTAINER_ID is known, add it to the fields to make the log record
+        available through `docker logs` command.
+        """
+        try:
+            formatted = self._format_record(record)
+            if self._container_id:
+                # only container ID is needed for interpretation through `docker logs`
+                formatted.append(("CONTAINER_ID", self._container_id))
+            self.transport.send(formatted)
+        except Exception:
+            self._fallback(record)
+
+
 def activate_log_queue_handler() -> None:
     """Migrate the existing log handlers to use the queue.
 

supervisor/utils/systemd_journal.py

@@ -5,11 +5,25 @@ from collections.abc import AsyncGenerator
 from datetime import UTC, datetime
 from functools import wraps
 import json
+import logging
+from types import MappingProxyType
 
 from aiohttp import ClientResponse
+from colorlog.escape_codes import escape_codes, parse_colors
 
 from supervisor.exceptions import MalformedBinaryEntryError
 from supervisor.host.const import LogFormatter
+from supervisor.utils.logging import HAOSLogHandler
+
+_LOG_COLORS = MappingProxyType(
+    {
+        HAOSLogHandler.LEVELS[logging.DEBUG]: "cyan",
+        HAOSLogHandler.LEVELS[logging.INFO]: "green",
+        HAOSLogHandler.LEVELS[logging.WARNING]: "yellow",
+        HAOSLogHandler.LEVELS[logging.ERROR]: "red",
+        HAOSLogHandler.LEVELS[logging.CRITICAL]: "red",
+    }
+)
 
 
 def formatter(required_fields: list[str]):
@@ -24,15 +38,34 @@ def formatter(required_fields: list[str]):
         def wrapper(*args, **kwargs):
             return func(*args, **kwargs)
 
-        wrapper.required_fields = ["__CURSOR"] + required_fields
+        implicit_fields = ["__CURSOR", "SYSLOG_FACILITY", "PRIORITY"]
+        wrapper.required_fields = implicit_fields + required_fields
         return wrapper
 
     return decorator
 
 
+def _entry_is_haos_log(entry: dict[str, str]) -> bool:
+    """Check if the entry is a Home Assistant Operating System log entry."""
+    return entry.get("SYSLOG_FACILITY") == str(HAOSLogHandler.SYSLOG_FACILITY)
+
+
+def colorize_message(message: str, priority: str | None = None) -> str:
+    """Colorize a log message using ANSI escape codes based on its priority."""
+    if priority and priority.isdigit():
+        color = _LOG_COLORS.get(int(priority))
+        if color is not None:
+            escape_code = parse_colors(color)
+            return f"{escape_code}{message}{escape_codes['reset']}"
+    return message
+
+
 @formatter(["MESSAGE"])
 def journal_plain_formatter(entries: dict[str, str]) -> str:
     """Format parsed journal entries as a plain message."""
+    if _entry_is_haos_log(entries):
+        return colorize_message(entries["MESSAGE"], entries.get("PRIORITY"))
+
     return entries["MESSAGE"]
 
 
@@ -58,7 +91,11 @@ def journal_verbose_formatter(entries: dict[str, str]) -> str:
         else entries.get("SYSLOG_IDENTIFIER", "_UNKNOWN_")
     )
 
-    return f"{ts} {entries.get('_HOSTNAME', '')} {identifier}: {entries.get('MESSAGE', '')}"
+    message = entries.get("MESSAGE", "")
+    if message and _entry_is_haos_log(entries):
+        message = colorize_message(message, entries.get("PRIORITY"))
+
+    return f"{ts} {entries.get('_HOSTNAME', '')} {identifier}: {message}"
 
 
 async def journal_logs_reader(