Implement logging through Systemd native Journal protocol #6006
Conversation
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/
|
|
||
| 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) |
There was a problem hiding this comment.
It appears that nothing else is using this facility in HAOS currently so it's fairly reliable indicator it's "our" logs.. Facility.LOCAL7 == 23 is the default in JournaldLogHandler as well but I defined it on the HAOSLogHandler class to be explicit and stable.
There was a problem hiding this comment.
Hm, I see this is syslog backward compatibility, and the numbers are from RFC5424, interesting.
It seems in my logs that quite some entries omit any SYSLOG_FACILITY. I wonder if we really want to use that as the means to identify our logs? 🤔
I see the library currently maps the standard logging priorities to the systemd-journald priority levels, maybe it would be better to store the Python logging level (which also can have custom levels) as a separate field (e.,g. PYTHON_LEVEL), and use that as a means to detect "our" logs? 🤔 I guess it would involve some changes to the library, but could be a good way to test how active that upstream project is.
| self.listener = None | ||
|
|
||
|
|
||
| class HAOSLogHandler(JournaldLogHandler): |
There was a problem hiding this comment.
If the Core should log through Systemd as well, I think it would be good to extract this to a shared Python package.
There was a problem hiding this comment.
Yeah make sense, it is fine by me to have this in Supervisor for the time being.
| for line in f: | ||
| if b"/docker/containers/" in line: | ||
| container_id = line.split(b"/docker/containers/")[-1] | ||
| return str(container_id.split(b"/")[0]) |
There was a problem hiding this comment.
We've discussed it elsewhere, but this seems a bit brittle.
Using the Docker --cidfile and bind mount that into the container seems a better approach. I think we need to store it somewhere persistent, as we don't recreate containers on restart. E.g. /mnt/data/supervisor/cidfiles/${containername}. For now, I'd do it just for Supervisor and Core, eventually we could add it to all the containers if there is a need. Probably best is to create this as a separate PR.
|
|
||
| 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) |
There was a problem hiding this comment.
Hm, I see this is syslog backward compatibility, and the numbers are from RFC5424, interesting.
It seems in my logs that quite some entries omit any SYSLOG_FACILITY. I wonder if we really want to use that as the means to identify our logs? 🤔
I see the library currently maps the standard logging priorities to the systemd-journald priority levels, maybe it would be better to store the Python logging level (which also can have custom levels) as a separate field (e.,g. PYTHON_LEVEL), and use that as a means to detect "our" logs? 🤔 I guess it would involve some changes to the library, but could be a good way to test how active that upstream project is.
| self.listener = None | ||
|
|
||
|
|
||
| class HAOSLogHandler(JournaldLogHandler): |
There was a problem hiding this comment.
Yeah make sense, it is fine by me to have this in Supervisor for the time being.
|
There hasn't been any activity on this pull request recently. This pull request has been automatically marked as stale because of that and will be closed if no further activity occurs within 7 days. |
Use the --cidfile Docker CLI argument when starting the container and bind-mount the generated file containing full ID of the container to the container itself. Using --mount instead of --volume is needed, as --volume is racy and creates empty directory volume at the destination path instead. This is prerequisite for home-assistant/supervisor#6006 but can come handy for other cases too.
…un/cid There is no standard way to get the container ID in the container itself, which can be needed for instance for #6006. The usual pattern is to use the --cidfile argument of Docker CLI and mount the generated file to the container. However, this is feature of Docker CLI and we can't use it when creating the containers via API. To get container ID to implement native logging in e.g. Core as well, we need the help of the Supervisor. This change implements similar feature fully in Supervisor's DockerAPI class that orchestrates lifetime of all containers managed by Supervisor. The files are created in the SUPERVISOR_DATA directory, as it needs to be persisted between reboots, just as the instances of Docker containers are. Supervisor's cidfile must be created when starting the Supervisor itself, for that see home-assistant/operating-system#4276.
| ) | ||
| for profile in card.profile_list | ||
| if profile.available | ||
| if profile.is_available |
There was a problem hiding this comment.
Huh, this is probably side-effect of the IDE refactoring tool, shouldn't be here.
…un/cid There is no standard way to get the container ID in the container itself, which can be needed for instance for #6006. The usual pattern is to use the --cidfile argument of Docker CLI and mount the generated file to the container. However, this is feature of Docker CLI and we can't use it when creating the containers via API. To get container ID to implement native logging in e.g. Core as well, we need the help of the Supervisor. This change implements similar feature fully in Supervisor's DockerAPI class that orchestrates lifetime of all containers managed by Supervisor. The files are created in the SUPERVISOR_DATA directory, as it needs to be persisted between reboots, just as the instances of Docker containers are. Supervisor's cidfile must be created when starting the Supervisor itself, for that see home-assistant/operating-system#4276.
…un/cid (#6154) * Write cidfiles of Docker containers and mount them individually to /run/cid There is no standard way to get the container ID in the container itself, which can be needed for instance for #6006. The usual pattern is to use the --cidfile argument of Docker CLI and mount the generated file to the container. However, this is feature of Docker CLI and we can't use it when creating the containers via API. To get container ID to implement native logging in e.g. Core as well, we need the help of the Supervisor. This change implements similar feature fully in Supervisor's DockerAPI class that orchestrates lifetime of all containers managed by Supervisor. The files are created in the SUPERVISOR_DATA directory, as it needs to be persisted between reboots, just as the instances of Docker containers are. Supervisor's cidfile must be created when starting the Supervisor itself, for that see home-assistant/operating-system#4276. * Address review comments, fix mounting of the cidfile
Use the --cidfile Docker CLI argument when starting the container and bind-mount the generated file containing full ID of the container to the container itself. Using --mount instead of --volume is needed, as --volume is racy and creates empty directory volume at the destination path instead. This is prerequisite for home-assistant/supervisor#6006 but can come handy for other cases too.
Proposed change
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/
Type of change
Additional information
Checklist
ruff format supervisor tests)If API endpoints or add-on configuration are added/changed: