Replace non-UTF-8 characters in log messages (#6227)

* Fix CID file handling to prevent directory creation

It seems that under certain conditions Docker creates a directory
instead of a file for the CID file. This change ensures that
the CID file is always created as a file, and any existing directory
is removed before creating the file.

* Fix tests

* Fix pytest

supervisor/addons/addon.py

@@ -72,7 +72,6 @@ from ..exceptions import (
     AddonsJobError,
     ConfigurationFileError,
     DockerError,
-    HomeAssistantAPIError,
     HostAppArmorError,
 )
 from ..hardware.data import Device
@@ -842,8 +841,7 @@ class Addon(AddonModel):
         # Cleanup Ingress panel from sidebar
         if self.ingress_panel:
             self.ingress_panel = False
-            with suppress(HomeAssistantAPIError):
-                await self.sys_ingress.update_hass_panel(self)
+            await self.sys_ingress.update_hass_panel(self)
 
         # Cleanup Ingress dynamic port assignment
         need_ingress_token_cleanup = False

supervisor/addons/manager.py

@@ -20,7 +20,6 @@ from ..exceptions import (
     CoreDNSError,
     DockerError,
     HassioError,
-    HomeAssistantAPIError,
 )
 from ..jobs.decorator import Job, JobCondition
 from ..resolution.const import ContextType, IssueType, SuggestionType
@@ -351,8 +350,7 @@ class AddonManager(CoreSysAttributes):
         # Update ingress
         if had_ingress != addon.ingress_panel:
             await self.sys_ingress.reload()
-            with suppress(HomeAssistantAPIError):
-                await self.sys_ingress.update_hass_panel(addon)
+            await self.sys_ingress.update_hass_panel(addon)
 
         return wait_for_start
 

supervisor/api/proxy.py

@@ -77,10 +77,10 @@ class APIProxy(CoreSysAttributes):
                 yield resp
                 return
 
-        except HomeAssistantAuthError:
-            _LOGGER.error("Authenticate error on API for request %s", path)
-        except HomeAssistantAPIError:
-            _LOGGER.error("Error on API for request %s", path)
+        except HomeAssistantAuthError as err:
+            _LOGGER.error("Authenticate error on API for request %s: %s", path, err)
+        except HomeAssistantAPIError as err:
+            _LOGGER.error("Error on API for request %s: %s", path, err)
         except aiohttp.ClientError as err:
             _LOGGER.error("Client error on API %s request %s", path, err)
         except TimeoutError:

supervisor/auth.py

@@ -132,8 +132,8 @@ class Auth(FileConfiguration, CoreSysAttributes):
                 _LOGGER.warning("Unauthorized login for '%s'", username)
                 await self._dismatch_cache(username, password)
                 return False
-        except HomeAssistantAPIError:
-            _LOGGER.error("Can't request auth on Home Assistant!")
+        except HomeAssistantAPIError as err:
+            _LOGGER.error("Can't request auth on Home Assistant: %s", err)
         finally:
             self._running.pop(username, None)
 
@@ -152,8 +152,8 @@ class Auth(FileConfiguration, CoreSysAttributes):
                     return
 
                 _LOGGER.warning("The user '%s' is not registered", username)
-        except HomeAssistantAPIError:
-            _LOGGER.error("Can't request password reset on Home Assistant!")
+        except HomeAssistantAPIError as err:
+            _LOGGER.error("Can't request password reset on Home Assistant: %s", err)
 
         raise AuthPasswordResetError()
 

supervisor/discovery/__init__.py

@@ -2,7 +2,6 @@
 
 from __future__ import annotations
 
-from contextlib import suppress
 import logging
 from typing import TYPE_CHECKING, Any
 from uuid import uuid4
@@ -119,7 +118,7 @@ class Discovery(CoreSysAttributes, FileConfiguration):
         data = attr.asdict(message)
         data.pop(ATTR_CONFIG)
 
-        with suppress(HomeAssistantAPIError):
+        try:
             async with self.sys_homeassistant.api.make_request(
                 command,
                 f"api/hassio_push/discovery/{message.uuid}",
@@ -128,5 +127,5 @@ class Discovery(CoreSysAttributes, FileConfiguration):
             ):
                 _LOGGER.info("Discovery %s message send", message.uuid)
                 return
-
-        _LOGGER.warning("Discovery %s message fail", message.uuid)
+        except HomeAssistantAPIError as err:
+            _LOGGER.error("Discovery %s message failed: %s", message.uuid, err)

supervisor/docker/manager.py

@@ -326,11 +326,19 @@ class DockerAPI(CoreSysAttributes):
         if name:
             cidfile_path = self.coresys.config.path_cid_files / f"{name}.cid"
 
-            # Remove the file if it exists e.g. as a leftover from unclean shutdown
-            if cidfile_path.is_file():
-                with suppress(OSError):
+            # Remove the file/directory if it exists e.g. as a leftover from unclean shutdown
+            # Note: Can be a directory if Docker auto-started container with restart policy
+            # before Supervisor could write the CID file
+            with suppress(OSError):
+                if cidfile_path.is_dir():
+                    cidfile_path.rmdir()
+                elif cidfile_path.is_file():
                     cidfile_path.unlink(missing_ok=True)
 
+            # Create empty CID file before adding it to volumes to prevent Docker
+            # from creating it as a directory if container auto-starts
+            cidfile_path.touch()
+
             extern_cidfile_path = (
                 self.coresys.config.path_extern_cid_files / f"{name}.cid"
             )

supervisor/homeassistant/api.py

@@ -2,7 +2,7 @@
 
 import asyncio
 from collections.abc import AsyncIterator
-from contextlib import asynccontextmanager, suppress
+from contextlib import asynccontextmanager
 from dataclasses import dataclass
 from datetime import UTC, datetime, timedelta
 import logging
@@ -15,9 +15,7 @@ from multidict import MultiMapping
 
 from ..coresys import CoreSys, CoreSysAttributes
 from ..exceptions import HomeAssistantAPIError, HomeAssistantAuthError
-from ..jobs.const import JobConcurrency
-from ..jobs.decorator import Job
-from ..utils import check_port, version_is_new_enough
+from ..utils import version_is_new_enough
 from .const import LANDINGPAGE
 
 _LOGGER: logging.Logger = logging.getLogger(__name__)
@@ -43,14 +41,19 @@ class HomeAssistantAPI(CoreSysAttributes):
         # We don't persist access tokens. Instead we fetch new ones when needed
         self.access_token: str | None = None
         self._access_token_expires: datetime | None = None
+        self._token_lock: asyncio.Lock = asyncio.Lock()
 
-    @Job(
-        name="home_assistant_api_ensure_access_token",
-        internal=True,
-        concurrency=JobConcurrency.QUEUE,
-    )
     async def ensure_access_token(self) -> None:
-        """Ensure there is an access token."""
+        """Ensure there is a valid access token.
+
+        Raises:
+            HomeAssistantAuthError: When we cannot get a valid token
+            aiohttp.ClientError: On network or connection errors
+            TimeoutError: On request timeouts
+
+        """
+        # Fast path check without lock (avoid unnecessary locking
+        # for the majority of calls).
         if (
             self.access_token
             and self._access_token_expires
@@ -58,7 +61,15 @@ class HomeAssistantAPI(CoreSysAttributes):
         ):
             return
 
-        with suppress(asyncio.TimeoutError, aiohttp.ClientError):
+        async with self._token_lock:
+            # Double-check after acquiring lock (avoid race condition)
+            if (
+                self.access_token
+                and self._access_token_expires
+                and self._access_token_expires > datetime.now(tz=UTC)
+            ):
+                return
+
             async with self.sys_websession.post(
                 f"{self.sys_homeassistant.api_url}/auth/token",
                 timeout=aiohttp.ClientTimeout(total=30),
@@ -92,7 +103,36 @@ class HomeAssistantAPI(CoreSysAttributes):
         params: MultiMapping[str] | None = None,
         headers: dict[str, str] | None = None,
     ) -> AsyncIterator[aiohttp.ClientResponse]:
-        """Async context manager to make a request with right auth."""
+        """Async context manager to make authenticated requests to Home Assistant API.
+
+        This context manager handles authentication token management automatically,
+        including token refresh on 401 responses. It yields the HTTP response
+        for the caller to handle.
+
+        Error Handling:
+        - HTTP error status codes (4xx, 5xx) are preserved in the response
+        - Authentication is handled transparently with one retry on 401
+        - Network/connection failures raise HomeAssistantAPIError
+        - No logging is performed - callers should handle logging as needed
+
+        Args:
+            method: HTTP method (get, post, etc.)
+            path: API path relative to Home Assistant base URL
+            json: JSON data to send in request body
+            content_type: Override content-type header
+            data: Raw data to send in request body
+            timeout: Request timeout in seconds
+            params: URL query parameters
+            headers: Additional HTTP headers
+
+        Yields:
+            aiohttp.ClientResponse: The HTTP response object
+
+        Raises:
+            HomeAssistantAPIError: When request cannot be completed due to
+                network errors, timeouts, or connection failures
+
+        """
         url = f"{self.sys_homeassistant.api_url}/{path}"
         headers = headers or {}
 
@@ -101,10 +141,9 @@ class HomeAssistantAPI(CoreSysAttributes):
             headers[hdrs.CONTENT_TYPE] = content_type
 
         for _ in (1, 2):
-            await self.ensure_access_token()
-            headers[hdrs.AUTHORIZATION] = f"Bearer {self.access_token}"
-
             try:
+                await self.ensure_access_token()
+                headers[hdrs.AUTHORIZATION] = f"Bearer {self.access_token}"
                 async with getattr(self.sys_websession, method)(
                     url,
                     data=data,
@@ -120,23 +159,19 @@ class HomeAssistantAPI(CoreSysAttributes):
                         continue
                     yield resp
                     return
-            except TimeoutError:
-                _LOGGER.error("Timeout on call %s.", url)
-                break
+            except TimeoutError as err:
+                _LOGGER.debug("Timeout on call %s.", url)
+                raise HomeAssistantAPIError(str(err)) from err
             except aiohttp.ClientError as err:
-                _LOGGER.error("Error on call %s: %s", url, err)
-                break
-
-        raise HomeAssistantAPIError()
+                _LOGGER.debug("Error on call %s: %s", url, err)
+                raise HomeAssistantAPIError(str(err)) from err
 
     async def _get_json(self, path: str) -> dict[str, Any]:
         """Return Home Assistant get API."""
         async with self.make_request("get", path) as resp:
             if resp.status in (200, 201):
                 return await resp.json()
-            else:
-                _LOGGER.debug("Home Assistant API return: %d", resp.status)
-        raise HomeAssistantAPIError()
+            raise HomeAssistantAPIError(f"Home Assistant Core API return {resp.status}")
 
     async def get_config(self) -> dict[str, Any]:
         """Return Home Assistant config."""
@@ -155,15 +190,8 @@ class HomeAssistantAPI(CoreSysAttributes):
         ):
             return None
 
-        # Check if port is up
-        if not await check_port(
-            self.sys_homeassistant.ip_address,
-            self.sys_homeassistant.api_port,
-        ):
-            return None
-
         # Check if API is up
-        with suppress(HomeAssistantAPIError):
+        try:
             # get_core_state is available since 2023.8.0 and preferred
             # since it is significantly faster than get_config because
             # it does not require serializing the entire config
@@ -181,6 +209,8 @@ class HomeAssistantAPI(CoreSysAttributes):
                 migrating = recorder_state.get("migration_in_progress", False)
                 live_migration = recorder_state.get("migration_is_live", False)
                 return APIState(state, migrating and not live_migration)
+        except HomeAssistantAPIError as err:
+            _LOGGER.debug("Can't connect to Home Assistant API: %s", err)
 
         return None
 

supervisor/homeassistant/websocket.py

@@ -3,6 +3,7 @@
 from __future__ import annotations
 
 import asyncio
+from contextlib import suppress
 import logging
 from typing import Any, TypeVar, cast
 
@@ -202,7 +203,8 @@ class HomeAssistantWebSocket(CoreSysAttributes):
             if self._client is not None and self._client.connected:
                 return self._client
 
-            await self.sys_homeassistant.api.ensure_access_token()
+            with suppress(asyncio.TimeoutError, aiohttp.ClientError):
+                await self.sys_homeassistant.api.ensure_access_token()
             client = await WSClient.connect_with_auth(
                 self.sys_websession,
                 self.sys_loop,

supervisor/ingress.py

@@ -15,6 +15,7 @@ from .const import (
     IngressSessionDataDict,
 )
 from .coresys import CoreSys, CoreSysAttributes
+from .exceptions import HomeAssistantAPIError
 from .utils import check_port
 from .utils.common import FileConfiguration
 from .utils.dt import utc_from_timestamp, utcnow
@@ -191,12 +192,17 @@ class Ingress(FileConfiguration, CoreSysAttributes):
 
         # Update UI
         method = "post" if addon.ingress_panel else "delete"
-        async with self.sys_homeassistant.api.make_request(
-            method, f"api/hassio_push/panel/{addon.slug}"
-        ) as resp:
-            if resp.status in (200, 201):
-                _LOGGER.info("Update Ingress as panel for %s", addon.slug)
-            else:
-                _LOGGER.warning(
-                    "Fails Ingress panel for %s with %i", addon.slug, resp.status
-                )
+        try:
+            async with self.sys_homeassistant.api.make_request(
+                method, f"api/hassio_push/panel/{addon.slug}"
+            ) as resp:
+                if resp.status in (200, 201):
+                    _LOGGER.info("Update Ingress as panel for %s", addon.slug)
+                else:
+                    _LOGGER.warning(
+                        "Failed to update the Ingress panel for %s with %i",
+                        addon.slug,
+                        resp.status,
+                    )
+        except HomeAssistantAPIError as err:
+            _LOGGER.error("Panel update request failed for %s: %s", addon.slug, err)

supervisor/resolution/notify.py

@@ -52,5 +52,5 @@ class ResolutionNotify(CoreSysAttributes):
                         _LOGGER.debug("Successfully created persistent_notification")
                     else:
                         _LOGGER.error("Can't create persistant notification")
-            except HomeAssistantAPIError:
-                _LOGGER.error("Can't create persistant notification")
+            except HomeAssistantAPIError as err:
+                _LOGGER.error("Can't create persistant notification: %s", err)

supervisor/utils/systemd_journal.py

@@ -117,7 +117,7 @@ async def journal_logs_reader(
                 continue
 
             # strip \n for simple fields before decoding
-            entries[field_name] = data[:-1].decode("utf-8")
+            entries[field_name] = data[:-1].decode("utf-8", errors="replace")
 
 
 def _parse_boot_json(boot_json_bytes: bytes) -> tuple[int, str]:

tests/docker/test_addon.py

@@ -318,7 +318,10 @@ def test_not_journald_addon(
 
 
 async def test_addon_run_docker_error(
-    coresys: CoreSys, addonsdata_system: dict[str, Data], path_extern
+    coresys: CoreSys,
+    addonsdata_system: dict[str, Data],
+    path_extern,
+    tmp_supervisor_data: Path,
 ):
     """Test docker error when addon is run."""
     await coresys.dbus.timedate.connect(coresys.dbus.bus)

tests/docker/test_interface.py

@@ -1,6 +1,7 @@
 """Test Docker interface."""
 
 import asyncio
+from pathlib import Path
 from typing import Any
 from unittest.mock import ANY, AsyncMock, MagicMock, Mock, PropertyMock, call, patch
 
@@ -281,6 +282,7 @@ async def test_run_missing_image(
     container: MagicMock,
     capture_exception: Mock,
     path_extern,
+    tmp_supervisor_data: Path,
 ):
     """Test run captures the exception when image is missing."""
     coresys.docker.containers.create.side_effect = [NotFound("missing"), MagicMock()]

tests/docker/test_manager.py

@@ -293,6 +293,8 @@ async def test_cidfile_cleanup_handles_oserror(
     # Mock the containers.get method and cidfile cleanup to raise OSError
     with (
         patch.object(docker.containers, "get", return_value=mock_container),
+        patch("pathlib.Path.is_dir", return_value=False),
+        patch("pathlib.Path.is_file", return_value=True),
         patch(
             "pathlib.Path.unlink", side_effect=OSError("File not found")
         ) as mock_unlink,
@@ -306,3 +308,46 @@ async def test_cidfile_cleanup_handles_oserror(
 
         # Verify cidfile cleanup was attempted
         mock_unlink.assert_called_once_with(missing_ok=True)
+
+
+async def test_run_container_with_leftover_cidfile_directory(
+    coresys: CoreSys, docker: DockerAPI, path_extern, tmp_supervisor_data
+):
+    """Test container creation removes leftover cidfile directory before creating new one.
+
+    This can happen when Docker auto-starts a container with restart policy
+    before Supervisor could write the CID file, causing Docker to create
+    the bind mount source as a directory.
+    """
+    # Mock container
+    mock_container = MagicMock()
+    mock_container.id = "test_container_id_new"
+
+    container_name = "test_container"
+    cidfile_path = coresys.config.path_cid_files / f"{container_name}.cid"
+
+    # Create a leftover directory (simulating Docker's behavior)
+    cidfile_path.mkdir()
+    assert cidfile_path.is_dir()
+
+    # Mock container creation
+    with patch.object(
+        docker.containers, "create", return_value=mock_container
+    ) as create_mock:
+        # Execute run with a container name
+        loop = asyncio.get_event_loop()
+        result = await loop.run_in_executor(
+            None,
+            lambda kwrgs: docker.run(**kwrgs),
+            {"image": "test_image", "tag": "latest", "name": container_name},
+        )
+
+        # Verify container was created
+        create_mock.assert_called_once()
+
+        # Verify new cidfile was written as a file (not directory)
+        assert cidfile_path.exists()
+        assert cidfile_path.is_file()
+        assert cidfile_path.read_text() == mock_container.id
+
+        assert result == mock_container

tests/utils/test_systemd_journal.py

@@ -275,3 +275,25 @@ async def test_parsing_boots_none():
         boots.append((index, boot_id))
 
     assert boots == []
+
+
+async def test_parsing_non_utf8_message():
+    """Test that non-UTF-8 bytes in message are replaced with replacement character."""
+    journal_logs, stream = _journal_logs_mock()
+    # Include invalid UTF-8 sequence (0xff is not valid UTF-8)
+    stream.feed_data(b"MESSAGE=Hello, \xff world!\n\n")
+    _, line = await anext(journal_logs_reader(journal_logs))
+    assert line == "Hello, \ufffd world!"
+
+
+async def test_parsing_non_utf8_in_binary_message():
+    """Test that non-UTF-8 bytes in binary format message are replaced."""
+    journal_logs, stream = _journal_logs_mock()
+    # Binary format with invalid UTF-8 sequence
+    stream.feed_data(
+        b"ID=1\n"
+        b"MESSAGE\n\x0f\x00\x00\x00\x00\x00\x00\x00Hello, \xff world!\n"
+        b"AFTER=after\n\n"
+    )
+    _, line = await anext(journal_logs_reader(journal_logs))
+    assert line == "Hello, \ufffd world!"