Handle more logging for getting ha userdetails
authorMarcel van der Veldt <m.vanderveldt@outlook.com>
Fri, 19 Dec 2025 07:12:40 +0000 (08:12 +0100)
committerMarcel van der Veldt <m.vanderveldt@outlook.com>
Fri, 19 Dec 2025 07:12:40 +0000 (08:12 +0100)
music_assistant/controllers/webserver/helpers/auth_middleware.py
music_assistant/controllers/webserver/helpers/auth_providers.py
music_assistant/controllers/webserver/websocket_client.py
music_assistant/providers/hass/__init__.py

index b05c5a720de71547a6925793f4cc5eda393c05ea..e9ddb8fea7ede2454b4c3c81022556f9fc9ccc76 100644 (file)
@@ -2,16 +2,19 @@
 
 from __future__ import annotations
 
+import logging
 from contextvars import ContextVar
 from typing import TYPE_CHECKING, Any, cast
 
 from aiohttp import web
 from music_assistant_models.auth import AuthProviderType, User, UserRole
 
-from music_assistant.constants import HOMEASSISTANT_SYSTEM_USER
+from music_assistant.constants import HOMEASSISTANT_SYSTEM_USER, MASS_LOGGER_NAME
 
 from .auth_providers import get_ha_user_details, get_ha_user_role
 
+LOGGER = logging.getLogger(f"{MASS_LOGGER_NAME}.auth")
+
 if TYPE_CHECKING:
     from music_assistant import MusicAssistant
 
@@ -69,13 +72,30 @@ async def get_authenticated_user(request: web.Request) -> User | None:
             )
 
         # Update user with HA details if available (HA is source of truth)
+        # Fall back to ingress headers if API lookup doesn't return values
         _, ha_display_name, avatar_url = await get_ha_user_details(mass, ingress_user_id)
-        if ha_display_name or avatar_url:
+        final_display_name = ha_display_name or ingress_display_name
+        LOGGER.debug(
+            "Ingress auth for user %s: ha_display_name=%s, ingress_display_name=%s, "
+            "final_display_name=%s, avatar_url=%s",
+            user.username,
+            ha_display_name,
+            ingress_display_name,
+            final_display_name,
+            avatar_url,
+        )
+        if final_display_name or avatar_url:
             user = await mass.webserver.auth.update_user(
                 user,
-                display_name=ha_display_name,
+                display_name=final_display_name,
                 avatar_url=avatar_url,
             )
+            LOGGER.debug(
+                "Updated user %s: display_name=%s, avatar_url=%s",
+                user.username,
+                user.display_name,
+                user.avatar_url,
+            )
 
         # Store in request context
         request[USER_CONTEXT_KEY] = user
index 09b99b9b1c2c22195bfe8a7d4049a49b35c2d245..97c8009a5914e39a22460258c175c3ec8314189c 100644 (file)
@@ -41,7 +41,7 @@ def normalize_username(username: str) -> str:
 
 
 async def get_ha_user_details(
-    mass: MusicAssistant, ha_user_id: str
+    mass: MusicAssistant, ha_user_id: str, wait_timeout: float = 30.0
 ) -> tuple[str | None, str | None, str | None]:
     """
     Get user username, display name and avatar URL from Home Assistant.
@@ -51,10 +51,23 @@ async def get_ha_user_details(
 
     :param mass: MusicAssistant instance.
     :param ha_user_id: Home Assistant user ID.
+    :param wait_timeout: Maximum time to wait for HA provider to become available (default 30s).
     :return: Tuple of (username, display_name, avatar_url) or all None if not found.
     """
-    hass_prov = mass.get_provider("hass")
-    if not hass_prov or not hass_prov.available:
+    # Wait for the HA provider to become available (handles race condition at startup)
+    hass_prov = None
+    wait_interval = 0.5
+    elapsed = 0.0
+    while elapsed < wait_timeout:
+        hass_prov = mass.get_provider("hass")
+        if hass_prov is not None and hass_prov.available:
+            break
+        await asyncio.sleep(wait_interval)
+        elapsed += wait_interval
+        hass_prov = None  # Reset to None for the final check
+
+    if hass_prov is None or not hass_prov.available:
+        LOGGER.debug("HA provider not available after %.1fs, cannot fetch user details", elapsed)
         return None, None, None
 
     hass_prov = cast("HomeAssistantProvider", hass_prov)
index 18c3111f6fb139b61373cadc62887a4326329791..b9c693951904a5b1d93572c12870c0d12a9b5b1d 100644 (file)
@@ -391,11 +391,13 @@ class WebsocketClientHandler:
                 )
 
             # Update user with HA details if available (HA is source of truth)
+            # Fall back to ingress headers if API lookup doesn't return values
             _, ha_display_name, avatar_url = await get_ha_user_details(self.mass, ingress_user_id)
-            if ha_display_name or avatar_url:
+            final_display_name = ha_display_name or ingress_display_name
+            if final_display_name or avatar_url:
                 user = await self.webserver.auth.update_user(
                     user,
-                    display_name=ha_display_name,
+                    display_name=final_display_name,
                     avatar_url=avatar_url,
                 )
 
index 59c6aedfa1e0c89364089f006380208003ab5624..26742e37fe3155fe168e11512fb6f87ba34dfc19 100644 (file)
@@ -545,7 +545,7 @@ class HomeAssistantProvider(PluginProvider):
                             display_name = user.get("name")
                         break
             except Exception as err:
-                self.logger.debug("Failed to get HA user list: %s", err)
+                self.logger.warning("Failed to get HA user list: %s", err)
 
             # Get external URL for building avatar URL
             ha_url: str | None = None
@@ -554,7 +554,7 @@ class HomeAssistantProvider(PluginProvider):
                 if network_urls:
                     ha_url = network_urls.get("external") or network_urls.get("internal")
             except Exception as err:
-                self.logger.debug("Failed to get HA network URLs: %s", err)
+                self.logger.warning("Failed to get HA network URLs: %s", err)
 
             # Find person linked to this HA user ID for display name and avatar
             try:
@@ -570,9 +570,16 @@ class HomeAssistantProvider(PluginProvider):
                             avatar_url = f"{ha_url.rstrip('/')}{person_picture}"
                         break
             except Exception as err:
-                self.logger.debug("Failed to get HA person details: %s", err)
-
+                self.logger.warning("Failed to get HA person details: %s", err)
+
+            self.logger.debug(
+                "get_user_details for %s: username=%s, display_name=%s, avatar_url=%s",
+                ha_user_id,
+                username,
+                display_name,
+                avatar_url,
+            )
             return username, display_name, avatar_url
         except Exception as err:
-            self.logger.debug("Failed to get HA user details: %s", err)
+            self.logger.warning("Failed to get HA user details: %s", err)
             return None, None, None