mandarons / ha-bouncie

Home Assistant custom integration for Bouncie.com - track your car stuff in Home Assistant
BSD 3-Clause "New" or "Revised" License
32 stars 3 forks source link

[BUG] - Integration Hangs When Attempting to Reload #47

Open TMarzullo opened 3 months ago

TMarzullo commented 3 months ago

Describe the bug There seems to be an issue when attempting to reload the integration to pull down new devices.

To Reproduce

  1. Have the integration already setup with at least one vehicle.
  2. Do the setup on the Bouncie side to add a new vehicle. Update the Smart Application in the Bouncie Developer portal to authorize the new device.
  3. Attempt to reload the integration on the Home Assistant side.
  4. Integration will hang at "initializing" indefinitely.

The only way I found to fix the situation was to delete the integration, then restart HA entirely. Then re-add the integration.

Expected behavior A reload of the integration should just pull down the new vehicles and setup the entities I would expect.

Screenshots If applicable, add screenshots to help explain your problem.

Configuration Integration Version: 0.7.0 HA Core: Version 2024.7.4 HA OS: Version 12.4 Hardware: Home Assistant Blue / Hardkernel ODROID-N2/N2+

Additional context This happened when I went to set up my second vehicle so when I went to setup my third vehicle, I had debug running and pulled some logs. Not sure how much help they will be....

These occurred when I attempted to reload the integration:

2024-08-02 11:36:44.478 DEBUG (MainThread) [custom_components.bouncie.const] Finished fetching bouncie data in 0.116 seconds (success: True) 2024-08-02 11:36:54.465 DEBUG (MainThread) [custom_components.bouncie.const] Finished fetching bouncie data in 0.102 seconds (success: True) 2024-08-02 11:37:04.487 DEBUG (MainThread) [custom_components.bouncie.const] Finished fetching bouncie data in 0.124 seconds (success: True) 2024-08-02 11:37:14.469 DEBUG (MainThread) [custom_components.bouncie.const] Finished fetching bouncie data in 0.106 seconds (success: True) 2024-08-02 11:37:24.474 DEBUG (MainThread) [custom_components.bouncie.const] Finished fetching bouncie data in 0.111 seconds (success: True) 2024-08-02 11:37:34.469 DEBUG (MainThread) [custom_components.bouncie.const] Finished fetching bouncie data in 0.107 seconds (success: True) 2024-08-02 11:37:44.453 DEBUG (MainThread) [custom_components.bouncie.const] Finished fetching bouncie data in 0.091 seconds (success: True) 2024-08-02 11:37:54.465 DEBUG (MainThread) [custom_components.bouncie.const] Finished fetching bouncie data in 0.103 seconds (success: True) 2024-08-02 11:38:04.449 DEBUG (MainThread) [custom_components.bouncie.const] Finished fetching bouncie data in 0.087 seconds (success: True) 2024-08-02 11:38:14.448 DEBUG (MainThread) [custom_components.bouncie.const] Finished fetching bouncie data in 0.086 seconds (success: True) 2024-08-02 11:38:24.464 DEBUG (MainThread) [custom_components.bouncie.const] Finished fetching bouncie data in 0.101 seconds (success: True) 2024-08-02 11:38:34.492 DEBUG (MainThread) [custom_components.bouncie.const] Finished fetching bouncie data in 0.129 seconds (success: True) 2024-08-02 11:38:44.456 DEBUG (MainThread) [custom_components.bouncie.const] Finished fetching bouncie data in 0.094 seconds (success: True) 2024-08-02 11:38:54.465 DEBUG (MainThread) [custom_components.bouncie.const] Finished fetching bouncie data in 0.102 seconds (success: True) 2024-08-02 11:39:04.570 DEBUG (MainThread) [custom_components.bouncie.const] Finished fetching bouncie data in 0.208 seconds (success: True) 2024-08-02 11:39:14.460 DEBUG (MainThread) [custom_components.bouncie.const] Finished fetching bouncie data in 0.097 seconds (success: True) 2024-08-02 11:39:24.453 DEBUG (MainThread) [custom_components.bouncie.const] Finished fetching bouncie data in 0.088 seconds (success: True) 2024-08-02 11:39:34.448 DEBUG (MainThread) [custom_components.bouncie.const] Finished fetching bouncie data in 0.086 seconds (success: True) 2024-08-02 11:39:44.451 DEBUG (MainThread) [custom_components.bouncie.const] Finished fetching bouncie data in 0.089 seconds (success: True) 2024-08-02 11:39:54.474 DEBUG (MainThread) [custom_components.bouncie.const] Finished fetching bouncie data in 0.109 seconds (success: True) 2024-08-02 11:40:04.521 DEBUG (MainThread) [custom_components.bouncie.const] Finished fetching bouncie data in 0.157 seconds (success: True) 2024-08-02 11:40:14.459 DEBUG (MainThread) [custom_components.bouncie.const] Finished fetching bouncie data in 0.097 seconds (success: True) 2024-08-02 11:40:24.499 DEBUG (MainThread) [custom_components.bouncie.const] Finished fetching bouncie data in 0.136 seconds (success: True) 2024-08-02 11:40:34.461 DEBUG (MainThread) [custom_components.bouncie.const] Finished fetching bouncie data in 0.099 seconds (success: True) 2024-08-02 11:40:44.450 DEBUG (MainThread) [custom_components.bouncie.const] Finished fetching bouncie data in 0.088 seconds (success: True) 2024-08-02 11:40:54.460 DEBUG (MainThread) [custom_components.bouncie.const] Finished fetching bouncie data in 0.094 seconds (success: True) 2024-08-02 11:41:04.464 DEBUG (MainThread) [custom_components.bouncie.const] Finished fetching bouncie data in 0.101 seconds (success: True) 2024-08-02 11:41:14.461 DEBUG (MainThread) [custom_components.bouncie.const] Finished fetching bouncie data in 0.099 seconds (success: True) 2024-08-02 11:41:24.476 DEBUG (MainThread) [custom_components.bouncie.const] Finished fetching bouncie data in 0.113 seconds (success: True) 2024-08-02 11:41:34.472 DEBUG (MainThread) [custom_components.bouncie.const] Finished fetching bouncie data in 0.110 seconds (success: True) 2024-08-02 11:41:44.461 DEBUG (MainThread) [custom_components.bouncie.const] Finished fetching bouncie data in 0.099 seconds (success: True) 2024-08-02 11:41:54.461 DEBUG (MainThread) [custom_components.bouncie.const] Finished fetching bouncie data in 0.099 seconds (success: True) 2024-08-02 11:42:04.475 DEBUG (MainThread) [custom_components.bouncie.const] Finished fetching bouncie data in 0.113 seconds (success: True) 2024-08-02 11:42:14.464 DEBUG (MainThread) [custom_components.bouncie.const] Finished fetching bouncie data in 0.101 seconds (success: True) 2024-08-02 11:42:24.464 DEBUG (MainThread) [custom_components.bouncie.const] Finished fetching bouncie data in 0.101 seconds (success: True) 2024-08-02 11:42:34.478 DEBUG (MainThread) [custom_components.bouncie.const] Finished fetching bouncie data in 0.114 seconds (success: True) 2024-08-02 11:42:44.482 DEBUG (MainThread) [custom_components.bouncie.const] Finished fetching bouncie data in 0.119 seconds (success: True) 2024-08-02 11:42:54.482 DEBUG (MainThread) [custom_components.bouncie.const] Finished fetching bouncie data in 0.120 seconds (success: True) 2024-08-02 11:43:04.456 DEBUG (MainThread) [custom_components.bouncie.const] Finished fetching bouncie data in 0.093 seconds (success: True) 2024-08-02 11:43:14.448 DEBUG (MainThread) [custom_components.bouncie.const] Finished fetching bouncie data in 0.085 seconds (success: True) 2024-08-02 11:43:24.454 DEBUG (MainThread) [custom_components.bouncie.const] Finished fetching bouncie data in 0.092 seconds (success: True) 2024-08-02 11:43:34.465 DEBUG (MainThread) [custom_components.bouncie.const] Finished fetching bouncie data in 0.102 seconds (success: True) 2024-08-02 11:43:44.457 DEBUG (MainThread) [custom_components.bouncie.const] Finished fetching bouncie data in 0.095 seconds (success: True) 2024-08-02 11:43:54.472 DEBUG (MainThread) [custom_components.bouncie.const] Finished fetching bouncie data in 0.110 seconds (success: True) 2024-08-02 11:44:04.457 DEBUG (MainThread) [custom_components.bouncie.const] Finished fetching bouncie data in 0.094 seconds (success: True) 2024-08-02 11:44:14.450 DEBUG (MainThread) [custom_components.bouncie.const] Finished fetching bouncie data in 0.087 seconds (success: True) 2024-08-02 11:44:24.448 DEBUG (MainThread) [custom_components.bouncie.const] Finished fetching bouncie data in 0.086 seconds (success: True) 2024-08-02 11:44:34.465 DEBUG (MainThread) [custom_components.bouncie.const] Finished fetching bouncie data in 0.102 seconds (success: True) 2024-08-02 11:44:44.446 DEBUG (MainThread) [custom_components.bouncie.const] Finished fetching bouncie data in 0.083 seconds (success: True) 2024-08-02 11:44:54.483 DEBUG (MainThread) [custom_components.bouncie.const] Finished fetching bouncie data in 0.120 seconds (success: True) 2024-08-02 11:45:04.469 DEBUG (MainThread) [custom_components.bouncie.const] Finished fetching bouncie data in 0.106 seconds (success: True) 2024-08-02 11:45:14.466 DEBUG (MainThread) [custom_components.bouncie.const] Finished fetching bouncie data in 0.103 seconds (success: True) 2024-08-02 11:45:24.499 DEBUG (MainThread) [custom_components.bouncie.const] Finished fetching bouncie data in 0.136 seconds (success: True) 2024-08-02 11:45:34.475 DEBUG (MainThread) [custom_components.bouncie.const] Finished fetching bouncie data in 0.111 seconds (success: True) 2024-08-02 11:45:44.465 DEBUG (MainThread) [custom_components.bouncie.const] Finished fetching bouncie data in 0.103 seconds (success: True) 2024-08-02 11:45:54.459 DEBUG (MainThread) [custom_components.bouncie.const] Finished fetching bouncie data in 0.096 seconds (success: True) 2024-08-02 11:46:04.482 DEBUG (MainThread) [custom_components.bouncie.const] Finished fetching bouncie data in 0.120 seconds (success: True)

After I restarted I found this in the logs:

`Logger: homeassistant.config_entries Source: config_entries.py:586 First occurred: 12:00:59 PM (1 occurrences) Last logged: 12:00:59 PM

Error setting up entry Bouncie for bouncie Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/config_entries.py", line 586, in async_setup result = await component.async_setup_entry(hass, self) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/config/custom_components/bouncie/init.py", line 30, in async_setup_entry await coordinator.async_config_entry_first_refresh() File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 277, in async_config_entry_first_refresh await self._async_refresh( File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 312, in _async_refresh self.data = await self._async_update_data() ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/config/custom_components/bouncie/coordinator.py", line 49, in _async_update_data all_vehicles = await self.bouncie_client.get_all_vehicles() ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.12/site-packages/bounciepy/async_rest_api_client.py", line 117, in get_all_vehicles vehicles_data = await self.http_get(f"{REST_API_BASE_URL}/vehicles") ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.12/site-packages/bounciepy/async_rest_api_client.py", line 97, in http_get response = await current_session.get( ^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.12/site-packages/aiohttp/client.py", line 608, in _request await resp.start(conn) File "/usr/local/lib/python3.12/site-packages/aiohttp/client_reqrep.py", line 976, in start message, payload = await protocol.read() # type: ignore[union-attr] ^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.12/site-packages/aiohttp/streams.py", line 640, in read await self._waiter asyncio.exceptions.CancelledError: Global task timeout`

mandarons commented 2 months ago

Is it still happening? This seem like some timeout issue that can happen for variety of reasons, not related to the integration code.

TMarzullo commented 1 month ago

I haven't needed to add a new device, so I don't know without deleting one of my existing devices and trying to add it again. As for the timing issue theory, I would be inclined to agree with you, except that it never resolved but the entries in the log persisted and kept appearing. So it looked like it was retrying but still failing.

Basically, what it appeared to be is that whatever devices you currently have on your Bouncie account, those will get pulled down just fine on initial setup/installation in HA. But after that, if you add another device onto your Bouncie account, the integration won't know what to do with it. The only way I found to make it work was to uninstall the integration and reinstall it after I had added the new device to my Bouncie account.

mandarons commented 1 week ago

From the logs, it seems like the task of getting list of all vehicles from bouncie servers using {REST_API_BASE_URL}/vehicles endpoint is getting killed for some reason. Not sure why is it happening as I am not able to reproduce it on my end (besides I don't have bouncie device/account to experiment further).

Try upgrading to latest version of HA and see if that helps.