Add debug logs to trace enphase auth process at load. (#148117)

homeassistant/components/enphase_envoy/coordinator.py

@@ -220,6 +220,7 @@ class EnphaseUpdateCoordinator(DataUpdateCoordinator[dict[str, Any]]):
         await envoy.setup()
         assert envoy.serial_number is not None
         self.envoy_serial_number = envoy.serial_number
+        _LOGGER.debug("Envoy setup complete for serial: %s", self.envoy_serial_number)
         if token := self.config_entry.data.get(CONF_TOKEN):
             with contextlib.suppress(*INVALID_AUTH_ERRORS):
                 # Always set the username and password
@@ -227,6 +228,7 @@ class EnphaseUpdateCoordinator(DataUpdateCoordinator[dict[str, Any]]):
                 await envoy.authenticate(
                     username=self.username, password=self.password, token=token
                 )
+                _LOGGER.debug("Authorized, validating token lifetime")
                 # The token is valid, but we still want
                 # to refresh it if it's stale right away
                 self._async_refresh_token_if_needed(dt_util.utcnow())
@@ -234,6 +236,8 @@ class EnphaseUpdateCoordinator(DataUpdateCoordinator[dict[str, Any]]):
             # token likely expired or firmware changed
             # so we fall through to authenticate with
             # username/password
+            _LOGGER.debug("setup and auth got INVALID_AUTH_ERRORS")
+        _LOGGER.debug("Authenticate with username/password only")
         await self.envoy.authenticate(username=self.username, password=self.password)
         # Password auth succeeded, so we can update the token
         # if we are using EnvoyTokenAuth
@@ -262,13 +266,16 @@ class EnphaseUpdateCoordinator(DataUpdateCoordinator[dict[str, Any]]):
         for tries in range(2):
             try:
                 if not self._setup_complete:
+                    _LOGGER.debug("update on try %s, setup not complete", tries)
                     await self._async_setup_and_authenticate()
                     self._async_mark_setup_complete()
                 # dump all received data in debug mode to assist troubleshooting
                 envoy_data = await envoy.update()
             except INVALID_AUTH_ERRORS as err:
+                _LOGGER.debug("update on try %s, INVALID_AUTH_ERRORS %s", tries, err)
                 if self._setup_complete and tries == 0:
                     # token likely expired or firmware changed, try to re-authenticate
+                    _LOGGER.debug("update on try %s, setup was complete, retry", tries)
                     self._setup_complete = False
                     continue
                 raise ConfigEntryAuthFailed(
@@ -280,6 +287,7 @@ class EnphaseUpdateCoordinator(DataUpdateCoordinator[dict[str, Any]]):
                     },
                 ) from err
             except EnvoyError as err:
+                _LOGGER.debug("update on try %s, EnvoyError %s", tries, err)
                 raise UpdateFailed(
                     translation_domain=DOMAIN,
                     translation_key="envoy_error",

tests/components/enphase_envoy/test_init.py

@@ -229,6 +229,45 @@ async def test_coordinator_token_refresh_error(
     assert entity_state.state == "116"
 
 
+@respx.mock
+@pytest.mark.freeze_time("2024-07-23 00:00:00+00:00")
+async def test_coordinator_first_update_auth_error(
+    hass: HomeAssistant,
+    mock_envoy: AsyncMock,
+) -> None:
+    """Test coordinator update error handling."""
+    current_token = encode(
+        # some time in future
+        payload={"name": "envoy", "exp": 1927314600},
+        key="secret",
+        algorithm="HS256",
+    )
+
+    # mock envoy with expired token in config
+    entry = MockConfigEntry(
+        domain=DOMAIN,
+        entry_id="45a36e55aaddb2007c5f6602e0c38e72",
+        title="Envoy 1234",
+        unique_id="1234",
+        data={
+            CONF_HOST: "1.1.1.1",
+            CONF_NAME: "Envoy 1234",
+            CONF_USERNAME: "test-username",
+            CONF_PASSWORD: "test-password",
+            CONF_TOKEN: current_token,
+        },
+    )
+    mock_envoy.auth = EnvoyTokenAuth(
+        "127.0.0.1",
+        token=current_token,
+        envoy_serial="1234",
+        cloud_username="test_username",
+        cloud_password="test_password",
+    )
+    mock_envoy.authenticate.side_effect = EnvoyAuthenticationError("Failing test")
+    await setup_integration(hass, entry, ConfigEntryState.SETUP_ERROR)
+
+
 async def test_config_no_unique_id(
     hass: HomeAssistant,
     mock_envoy: AsyncMock,