mirror of
https://github.com/home-assistant/supervisor.git
synced 2026-07-07 22:05:06 +01:00
apps: log container exit code when app exits non-zero (#6848)
* apps: log container exit code when app exits non-zero Issue #6840 reports that stopping an app whose process exits 143 (SIGTERM default disposition) leaves the app in AppState.ERROR. ERROR is the right state for that — Docker itself treats any non-zero exit as a failure (e.g. `--restart on-failure`), and 143 specifically means the SIGTERM grace period was wasted because the app never installed a handler. But Supervisor previously logged nothing about it, leaving authors with no hint that their image is misbehaving. Plumb the exit code through DockerContainerStateEvent and log it from App.container_state_changed on transitions to FAILED: a warning for 143 nudging the author to trap SIGTERM and exit 0, and an error for any other non-zero code (crashes, SIGKILL after grace, app's own error exit). Refactor _container_state_from_model to return (state, exit_code) so the docker event monitor and DockerInterface.attach feed the same exit code through one code path instead of re-reading State.ExitCode in the caller. Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com> * apps: address review feedback on exit-code logging - Replace bare 143 with EXIT_CODE_SIGTERM_DEFAULT (128 + signal.SIGTERM) in supervisor/docker/const.py so the reasoning is documented in code, not just in the log string. - Stop populating exit_code on STOPPED transitions. Previously the refactor made DockerInterface.attach emit exit_code=0 for cleanly stopped containers, while the monitor only emitted an exit code for abnormal exits. Align both paths so exit_code is only set on FAILED. - Add test_app_failed_logs_exit_code covering the three new branches (warning on 143, error on other non-zero, silent when None) and extend test_attach_existing_container to assert the event's exit_code field per state. Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com> * docker/monitor: flatten exit_code branch to satisfy pylint The previous if/else inside the `die` branch pushed the function over pylint's too-many-nested-blocks threshold (6/5). Collapse it back into a pair of conditional expressions: container_state via ternary on the exit code, exit_code via `die_exit_code or None` so 0 stays None. Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com> * Potential fix for pull request finding Co-authored-by: Copilot Autofix powered by AI <175728472+Copilot@users.noreply.github.com> * Update supervisor/apps/app.py Co-authored-by: Mike Degatano <michael.degatano@gmail.com> --------- Co-authored-by: Claude Opus 4.7 (1M context) <noreply@anthropic.com> Co-authored-by: Copilot Autofix powered by AI <175728472+Copilot@users.noreply.github.com> Co-authored-by: Mike Degatano <michael.degatano@gmail.com>
This commit is contained in:
+16
-1
@@ -59,7 +59,7 @@ from ..const import (
|
||||
)
|
||||
from ..coresys import CoreSys
|
||||
from ..docker.app import DockerApp
|
||||
from ..docker.const import ContainerState
|
||||
from ..docker.const import EXIT_CODE_SIGTERM_DEFAULT, ContainerState
|
||||
from ..docker.manager import ExecReturn
|
||||
from ..docker.monitor import DockerContainerStateEvent
|
||||
from ..docker.stats import DockerStats
|
||||
@@ -1669,6 +1669,21 @@ class App(AppModel):
|
||||
elif event.state == ContainerState.STOPPED:
|
||||
self.state = AppState.STOPPED
|
||||
elif event.state == ContainerState.FAILED:
|
||||
if event.exit_code == EXIT_CODE_SIGTERM_DEFAULT:
|
||||
_LOGGER.warning(
|
||||
"App %s did not handle SIGTERM and was terminated by the "
|
||||
"default signal handler (exit code %d). The app should "
|
||||
"trap SIGTERM, shut down cleanly, and exit with code 0. "
|
||||
"Please report this to the app developer.",
|
||||
self.name,
|
||||
EXIT_CODE_SIGTERM_DEFAULT,
|
||||
)
|
||||
elif event.exit_code is not None:
|
||||
_LOGGER.error(
|
||||
"App %s exited with non-zero exit code %d",
|
||||
self.name,
|
||||
event.exit_code,
|
||||
)
|
||||
self.state = AppState.ERROR
|
||||
|
||||
async def watchdog_container(self, event: DockerContainerStateEvent) -> None:
|
||||
|
||||
@@ -6,6 +6,7 @@ from dataclasses import dataclass
|
||||
from enum import StrEnum
|
||||
from pathlib import PurePath
|
||||
import re
|
||||
import signal
|
||||
from typing import Any
|
||||
|
||||
from ..const import MACHINE_ID
|
||||
@@ -26,6 +27,10 @@ DOCKER_HUB_LEGACY = "hub.docker.com"
|
||||
# GitHub Container Registry identifier
|
||||
GITHUB_CONTAINER_REGISTRY = "ghcr.io"
|
||||
|
||||
# Exit code reported when a process is terminated by SIGTERM with the default
|
||||
# disposition (i.e. no userspace handler ran). POSIX convention is 128 + signal.
|
||||
EXIT_CODE_SIGTERM_DEFAULT = 128 + signal.SIGTERM
|
||||
|
||||
|
||||
class Capabilities(StrEnum):
|
||||
"""Linux Capabilities."""
|
||||
|
||||
@@ -79,24 +79,29 @@ def _restart_policy_from_model(meta_host: dict[str, Any]) -> RestartPolicy | Non
|
||||
return RestartPolicy.NO
|
||||
|
||||
|
||||
def _container_state_from_model(container_metadata: dict[str, Any]) -> ContainerState:
|
||||
"""Get container state from model."""
|
||||
def _container_state_from_model(
|
||||
container_metadata: dict[str, Any],
|
||||
) -> tuple[ContainerState, int | None]:
|
||||
"""Get container state and exit code from model."""
|
||||
if "State" not in container_metadata:
|
||||
return ContainerState.UNKNOWN
|
||||
return ContainerState.UNKNOWN, None
|
||||
|
||||
if container_metadata["State"]["Status"] == "running":
|
||||
if "Health" in container_metadata["State"]:
|
||||
state_obj = container_metadata["State"]
|
||||
if state_obj["Status"] == "running":
|
||||
if "Health" in state_obj:
|
||||
return (
|
||||
ContainerState.HEALTHY
|
||||
if container_metadata["State"]["Health"]["Status"] == "healthy"
|
||||
else ContainerState.UNHEALTHY
|
||||
if state_obj["Health"]["Status"] == "healthy"
|
||||
else ContainerState.UNHEALTHY,
|
||||
None,
|
||||
)
|
||||
return ContainerState.RUNNING
|
||||
return ContainerState.RUNNING, None
|
||||
|
||||
if container_metadata["State"]["ExitCode"] > 0:
|
||||
return ContainerState.FAILED
|
||||
exit_code = state_obj["ExitCode"]
|
||||
if exit_code > 0:
|
||||
return ContainerState.FAILED, exit_code
|
||||
|
||||
return ContainerState.STOPPED
|
||||
return ContainerState.STOPPED, None
|
||||
|
||||
|
||||
class DockerInterface(JobGroup, ABC):
|
||||
@@ -422,7 +427,8 @@ class DockerInterface(JobGroup, ABC):
|
||||
async def current_state(self) -> ContainerState:
|
||||
"""Return current state of container."""
|
||||
if container_metadata := await self._get_container():
|
||||
return _container_state_from_model(container_metadata)
|
||||
state, _ = _container_state_from_model(container_metadata)
|
||||
return state
|
||||
return ContainerState.UNKNOWN
|
||||
|
||||
@Job(name="docker_interface_attach", concurrency=JobConcurrency.GROUP_QUEUE)
|
||||
@@ -435,7 +441,7 @@ class DockerInterface(JobGroup, ABC):
|
||||
self._meta = await docker_container.show()
|
||||
self.sys_docker.monitor.watch_container(self._meta)
|
||||
|
||||
state = _container_state_from_model(self._meta)
|
||||
state, exit_code = _container_state_from_model(self._meta)
|
||||
if not (
|
||||
skip_state_event_if_down
|
||||
and state in [ContainerState.STOPPED, ContainerState.FAILED]
|
||||
@@ -444,7 +450,7 @@ class DockerInterface(JobGroup, ABC):
|
||||
self.sys_bus.fire_event(
|
||||
BusEvent.DOCKER_CONTAINER_STATE_CHANGE,
|
||||
DockerContainerStateEvent(
|
||||
self.name, state, docker_container.id, int(time())
|
||||
self.name, state, docker_container.id, int(time()), exit_code
|
||||
),
|
||||
)
|
||||
|
||||
|
||||
@@ -21,12 +21,17 @@ STOP_MONITOR_TIMEOUT = 5.0
|
||||
|
||||
@dataclass(slots=True, frozen=True)
|
||||
class DockerContainerStateEvent:
|
||||
"""Event for docker container state change."""
|
||||
"""Event for docker container state change.
|
||||
|
||||
exit_code is populated for FAILED transitions where the source event or
|
||||
inspect data carried an exit code; None otherwise.
|
||||
"""
|
||||
|
||||
name: str
|
||||
state: ContainerState
|
||||
id: str
|
||||
time: int
|
||||
exit_code: int | None = None
|
||||
|
||||
|
||||
@dataclass(slots=True, frozen=True)
|
||||
@@ -109,16 +114,21 @@ class DockerMonitor(CoreSysAttributes):
|
||||
or attributes.get("name") in self._unlabeled_managed_containers
|
||||
):
|
||||
container_state: ContainerState | None = None
|
||||
exit_code: int | None = None
|
||||
action: str = event["Action"]
|
||||
|
||||
if action == "start":
|
||||
container_state = ContainerState.RUNNING
|
||||
elif action == "die":
|
||||
container_state = (
|
||||
ContainerState.STOPPED
|
||||
if int(event["Actor"]["Attributes"]["exitCode"]) == 0
|
||||
else ContainerState.FAILED
|
||||
die_exit_code = int(
|
||||
event["Actor"]["Attributes"]["exitCode"]
|
||||
)
|
||||
container_state = (
|
||||
ContainerState.FAILED
|
||||
if die_exit_code
|
||||
else ContainerState.STOPPED
|
||||
)
|
||||
exit_code = die_exit_code or None
|
||||
elif action == "health_status: healthy":
|
||||
container_state = ContainerState.HEALTHY
|
||||
elif action == "health_status: unhealthy":
|
||||
@@ -130,6 +140,7 @@ class DockerMonitor(CoreSysAttributes):
|
||||
state=container_state,
|
||||
id=event["Actor"]["ID"],
|
||||
time=event["time"],
|
||||
exit_code=exit_code,
|
||||
)
|
||||
tasks = self.sys_bus.fire_event(
|
||||
BusEvent.DOCKER_CONTAINER_STATE_CHANGE, state_event
|
||||
|
||||
+53
-1
@@ -4,6 +4,7 @@ import asyncio
|
||||
from datetime import timedelta
|
||||
import errno
|
||||
from http import HTTPStatus
|
||||
import logging
|
||||
from pathlib import Path, PurePath
|
||||
from typing import Any
|
||||
from unittest.mock import AsyncMock, MagicMock, PropertyMock, call, patch
|
||||
@@ -51,7 +52,12 @@ from tests.common import fire_bus_event, get_fixture_path, is_in_list
|
||||
from tests.const import TEST_ADDON_SLUG
|
||||
|
||||
|
||||
async def _fire_test_event(coresys: CoreSys, name: str, state: ContainerState) -> None:
|
||||
async def _fire_test_event(
|
||||
coresys: CoreSys,
|
||||
name: str,
|
||||
state: ContainerState,
|
||||
exit_code: int | None = None,
|
||||
) -> None:
|
||||
"""Fire a test event and await the listener tasks the bus spawned."""
|
||||
await fire_bus_event(
|
||||
coresys,
|
||||
@@ -61,6 +67,7 @@ async def _fire_test_event(coresys: CoreSys, name: str, state: ContainerState) -
|
||||
state=state,
|
||||
id="abc123",
|
||||
time=1,
|
||||
exit_code=exit_code,
|
||||
),
|
||||
)
|
||||
|
||||
@@ -153,6 +160,51 @@ async def test_app_state_listener(coresys: CoreSys, install_app_ssh: App) -> Non
|
||||
assert install_app_ssh.state == AppState.ERROR
|
||||
|
||||
|
||||
async def test_app_failed_logs_exit_code(
|
||||
coresys: CoreSys,
|
||||
install_app_ssh: App,
|
||||
caplog: pytest.LogCaptureFixture,
|
||||
) -> None:
|
||||
"""Test FAILED transition logs exit code with appropriate severity."""
|
||||
with patch.object(DockerApp, "attach"):
|
||||
await install_app_ssh.load()
|
||||
|
||||
with patch.object(App, "watchdog_container"):
|
||||
# Exit 143 (SIGTERM default disposition): warning nudging author
|
||||
caplog.clear()
|
||||
await _fire_test_event(
|
||||
coresys,
|
||||
f"addon_{TEST_ADDON_SLUG}",
|
||||
ContainerState.FAILED,
|
||||
exit_code=143,
|
||||
)
|
||||
assert install_app_ssh.state == AppState.ERROR
|
||||
warnings = [
|
||||
r for r in caplog.records if r.levelno == logging.WARNING and r.message
|
||||
]
|
||||
assert any("did not handle SIGTERM" in r.message for r in warnings)
|
||||
|
||||
# Any other non-zero exit: error
|
||||
caplog.clear()
|
||||
await _fire_test_event(
|
||||
coresys,
|
||||
f"addon_{TEST_ADDON_SLUG}",
|
||||
ContainerState.FAILED,
|
||||
exit_code=1,
|
||||
)
|
||||
errors = [r for r in caplog.records if r.levelno == logging.ERROR]
|
||||
assert any("exit code 1" in r.message for r in errors)
|
||||
|
||||
# No exit code available: stay silent
|
||||
caplog.clear()
|
||||
await _fire_test_event(
|
||||
coresys, f"addon_{TEST_ADDON_SLUG}", ContainerState.FAILED
|
||||
)
|
||||
assert not any(
|
||||
"exit code" in r.message or "SIGTERM" in r.message for r in caplog.records
|
||||
)
|
||||
|
||||
|
||||
async def test_app_watchdog(coresys: CoreSys, install_app_ssh: App) -> None:
|
||||
"""Test app watchdog works correctly."""
|
||||
with patch.object(DockerApp, "attach"):
|
||||
|
||||
@@ -235,23 +235,31 @@ async def test_current_state_failures(coresys: CoreSys):
|
||||
|
||||
|
||||
@pytest.mark.parametrize(
|
||||
"attrs,expected,fired_when_skip_down",
|
||||
"attrs,expected,expected_exit_code,fired_when_skip_down",
|
||||
[
|
||||
({"State": {"Status": "running"}}, ContainerState.RUNNING, True),
|
||||
({"State": {"Status": "exited", "ExitCode": 0}}, ContainerState.STOPPED, False),
|
||||
({"State": {"Status": "running"}}, ContainerState.RUNNING, None, True),
|
||||
(
|
||||
{"State": {"Status": "exited", "ExitCode": 0}},
|
||||
ContainerState.STOPPED,
|
||||
None,
|
||||
False,
|
||||
),
|
||||
(
|
||||
{"State": {"Status": "exited", "ExitCode": 137}},
|
||||
ContainerState.FAILED,
|
||||
137,
|
||||
False,
|
||||
),
|
||||
(
|
||||
{"State": {"Status": "running", "Health": {"Status": "healthy"}}},
|
||||
ContainerState.HEALTHY,
|
||||
None,
|
||||
True,
|
||||
),
|
||||
(
|
||||
{"State": {"Status": "running", "Health": {"Status": "unhealthy"}}},
|
||||
ContainerState.UNHEALTHY,
|
||||
None,
|
||||
True,
|
||||
),
|
||||
],
|
||||
@@ -261,6 +269,7 @@ async def test_attach_existing_container(
|
||||
container: DockerContainer,
|
||||
attrs: dict[str, Any],
|
||||
expected: ContainerState,
|
||||
expected_exit_code: int | None,
|
||||
fired_when_skip_down: bool,
|
||||
):
|
||||
"""Test attaching to existing container."""
|
||||
@@ -279,7 +288,9 @@ async def test_attach_existing_container(
|
||||
] == [
|
||||
call(
|
||||
BusEvent.DOCKER_CONTAINER_STATE_CHANGE,
|
||||
DockerContainerStateEvent("homeassistant", expected, "abc123", 1),
|
||||
DockerContainerStateEvent(
|
||||
"homeassistant", expected, "abc123", 1, expected_exit_code
|
||||
),
|
||||
)
|
||||
]
|
||||
|
||||
|
||||
@@ -16,7 +16,7 @@ from supervisor.docker.monitor import DockerContainerStateEvent
|
||||
|
||||
|
||||
@pytest.mark.parametrize(
|
||||
"event,expected",
|
||||
"event,expected,expected_exit_code",
|
||||
[
|
||||
(
|
||||
{
|
||||
@@ -25,6 +25,7 @@ from supervisor.docker.monitor import DockerContainerStateEvent
|
||||
"Actor": {"Attributes": {"supervisor_managed": ""}},
|
||||
},
|
||||
ContainerState.RUNNING,
|
||||
None,
|
||||
),
|
||||
(
|
||||
{
|
||||
@@ -33,6 +34,7 @@ from supervisor.docker.monitor import DockerContainerStateEvent
|
||||
"Actor": {"Attributes": {"supervisor_managed": "", "exitCode": "0"}},
|
||||
},
|
||||
ContainerState.STOPPED,
|
||||
None,
|
||||
),
|
||||
(
|
||||
{
|
||||
@@ -41,6 +43,7 @@ from supervisor.docker.monitor import DockerContainerStateEvent
|
||||
"Actor": {"Attributes": {"supervisor_managed": "", "exitCode": "137"}},
|
||||
},
|
||||
ContainerState.FAILED,
|
||||
137,
|
||||
),
|
||||
(
|
||||
{
|
||||
@@ -49,6 +52,7 @@ from supervisor.docker.monitor import DockerContainerStateEvent
|
||||
"Actor": {"Attributes": {"supervisor_managed": ""}},
|
||||
},
|
||||
ContainerState.HEALTHY,
|
||||
None,
|
||||
),
|
||||
(
|
||||
{
|
||||
@@ -57,6 +61,7 @@ from supervisor.docker.monitor import DockerContainerStateEvent
|
||||
"Actor": {"Attributes": {"supervisor_managed": ""}},
|
||||
},
|
||||
ContainerState.UNHEALTHY,
|
||||
None,
|
||||
),
|
||||
(
|
||||
{
|
||||
@@ -65,6 +70,7 @@ from supervisor.docker.monitor import DockerContainerStateEvent
|
||||
"Actor": {"Attributes": {"supervisor_managed": ""}},
|
||||
},
|
||||
None,
|
||||
None,
|
||||
),
|
||||
(
|
||||
{
|
||||
@@ -73,6 +79,7 @@ from supervisor.docker.monitor import DockerContainerStateEvent
|
||||
"Actor": {"Attributes": {}},
|
||||
},
|
||||
None,
|
||||
None,
|
||||
),
|
||||
(
|
||||
{
|
||||
@@ -81,11 +88,15 @@ from supervisor.docker.monitor import DockerContainerStateEvent
|
||||
"Actor": {"Attributes": {}},
|
||||
},
|
||||
None,
|
||||
None,
|
||||
),
|
||||
],
|
||||
)
|
||||
async def test_events(
|
||||
coresys: CoreSys, event: dict[str, Any], expected: ContainerState | None
|
||||
coresys: CoreSys,
|
||||
event: dict[str, Any],
|
||||
expected: ContainerState | None,
|
||||
expected_exit_code: int | None,
|
||||
):
|
||||
"""Test events created from docker events."""
|
||||
event["Actor"]["Attributes"]["name"] = "some_container"
|
||||
@@ -101,7 +112,9 @@ async def test_events(
|
||||
if expected:
|
||||
fire_event.assert_called_once_with(
|
||||
BusEvent.DOCKER_CONTAINER_STATE_CHANGE,
|
||||
DockerContainerStateEvent("some_container", expected, "abc123", 123),
|
||||
DockerContainerStateEvent(
|
||||
"some_container", expected, "abc123", 123, expected_exit_code
|
||||
),
|
||||
)
|
||||
else:
|
||||
fire_event.assert_not_called()
|
||||
@@ -136,6 +149,6 @@ async def test_unlabeled_container(coresys: CoreSys, container: DockerContainer)
|
||||
fire_event.assert_called_once_with(
|
||||
BusEvent.DOCKER_CONTAINER_STATE_CHANGE,
|
||||
DockerContainerStateEvent(
|
||||
"homeassistant", ContainerState.FAILED, "abc123", 123
|
||||
"homeassistant", ContainerState.FAILED, "abc123", 123, 137
|
||||
),
|
||||
)
|
||||
|
||||
Reference in New Issue
Block a user