search

sopelj / hass-ember-mug-component

Ember Mug Integration for Home Assistant
MIT License
112 stars 4 forks source link

HA "sees" Ember mug, but the integration fails to connect to it. #49

Closed Dinth closed 7 months ago

Dinth commented 7 months ago

Description

After setting up the mug, the integration fails to start/connect to the mug.

What I Did

I have installed the integration from HACS, put the mug in a pairing mode, went to devices, chosen the integration, the integration setup window detected my mug's MAC address and i have added that mug to HA.

Logs / Errors

If possible/applicable, please enable logging, reproduce the issue and include any related errors below. This greatly helps with debugging and is much appreciated. (If you aren't sure how to enable it, please see the debugging section in the README)

2024-02-14 10:28:02.818 DEBUG (MainThread) [ember_mug.mug] C6:12:2D:4C:FA:9B: Ember Ceramic Mug: Failed to connect to the mug: (C6:12:2D:4C:FA:9B) - C6:12:2D:4C:FA:9B: Failed to connect after 9 attempt(s): Timeout waiting for connect response while connecting to C6:12:2D:4C:FA:9B after 20.0s, disconnect timed out: False, after 20.0s
2024-02-14 10:28:02.818 DEBUG (MainThread) [custom_components.ember_mug.coordinator] An error occurred trying to update the mug: (C6:12:2D:4C:FA:9B) - C6:12:2D:4C:FA:9B: Failed to connect after 9 attempt(s): Timeout waiting for connect response while connecting to C6:12:2D:4C:FA:9B after 20.0s, disconnect timed out: False, after 20.0s
2024-02-14 10:28:02.819 DEBUG (MainThread) [ember_mug.mug] Unregistered callback: <function async_setup_entry.<locals>.<lambda> at 0x7f7a3f8a85e0>
2024-02-14 10:28:15.359 WARNING (MainThread) [homeassistant.components.rest.util] JSON result was not a dictionary or list with 0th element a dictionary
2024-02-14 10:28:17.342 WARNING (SyncWorker_50) [custom_components.openmediavault.omv_api] OpenMediaVault 10.10.1.13:81 unable to fetch data (500)
2024-02-14 10:28:17.705 ERROR (Thread-4 (RunDocker)) [custom_components.monitor_docker] Failed Docker connect: DockerError(900, "Cannot connect to Docker Engine via tcp://10.10.1.13:2375 [Cannot connect to host 10.10.1.13:2375 ssl:default [Connect call failed ('10.10.1.13', 2375)]]")
2024-02-14 10:28:17.705 ERROR (Thread-4 (RunDocker)) [custom_components.monitor_docker] Retry in 60 seconds
2024-02-14 10:28:19.826 ERROR (SyncWorker_45) [homeassistant] Error doing job: Unclosed client session
2024-02-14 10:28:45.442 WARNING (MainThread) [homeassistant.components.rest.util] JSON result was not a dictionary or list with 0th element a dictionary
2024-02-14 10:28:58.447 ERROR (MainThread) [pynintendoparental] Error updating device 5cedcb8660c73fd5: list index out of range
2024-02-14 10:28:58.447 ERROR (MainThread) [homeassistant] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 256, in _handle_refresh_interval
await self._async_refresh(log_failures=True, scheduled=True)
File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 412, in _async_refresh
self.async_update_listeners()
File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 183, in async_update_listeners
update_callback()
File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 492, in _handle_coordinator_update
self.async_write_ha_state()
File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 989, in async_write_ha_state
self._async_write_ha_state()
File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 1110, in _async_write_ha_state
state, attr, capabilities, shadowed_attr = self.__async_calculate_state()
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 1047, in __async_calculate_state
state = self._stringify_state(available)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 995, in _stringify_state
if (state := self.state) is None:
^^^^^^^^^^
File "/usr/src/homeassistant/homeassistant/components/sensor/__init__.py", line 549, in state
value = self.native_value
^^^^^^^^^^^^^^^^^
File "/config/custom_components/nintendo_parental/sensor.py", line 44, in native_value
return self._device.limit_time - (
^^^^^^^^^^^^^^^^^^^^^^^^^^^
TypeError: unsupported operand type(s) for -: 'NoneType' and 'float'
2024-02-14 10:29:10.144 WARNING (MainThread) [androidtv.adb_manager.adb_manager_async] Couldn't connect to 10.10.25.92:5555. TcpTimeoutException: Connecting to 10.10.25.92:5555 timed out (1.0 seconds)
2024-02-14 10:29:13.956 WARNING (MainThread) [aioesphomeapi.connection] bt-proxy-masterbedroom @ 10.10.10.185: Connection error occurred: [Errno 104] Connection reset by peer
2024-02-14 10:29:22.906 DEBUG (MainThread) [custom_components.ember_mug] Integration setup. Last service info: Device: C6:12:2D:4C:FA:9B: Ember Ceramic Mug, Manufacturer Data: {961: b'\xc1'}
2024-02-14 10:29:22.907 DEBUG (MainThread) [ember_mug.mug] New mug connection initialized.
2024-02-14 10:29:22.907 DEBUG (MainThread) [ember_mug.mug] Registered callback: <bound method MugDataUpdateCoordinator._async_handle_callback of <custom_components.ember_mug.coordinator.MugDataUpdateCoordinator object at 0x7f7a768555e0>>
2024-02-14 10:29:22.907 INFO (MainThread) [custom_components.ember_mug.coordinator] CM19P/CM21L ember-mug-c6122d4cfa9b Setup
2024-02-14 10:29:22.907 DEBUG (MainThread) [ember_mug.mug] Registered callback: <function async_setup_entry.<locals>.<lambda> at 0x7f7a3f8ab7e0>
2024-02-14 10:29:22.907 DEBUG (MainThread) [custom_components.ember_mug.coordinator] Bluetooth event. Service Info: <habluetooth.models.BluetoothServiceInfoBleak object at 0x7f7a2b8c68c0>, change: BluetoothChange.ADVERTISEMENT
2024-02-14 10:29:22.921 DEBUG (MainThread) [ember_mug.mug] Set new device from C6:12:2D:4C:FA:9B: Ember Ceramic Mug to C6:12:2D:4C:FA:9B: Ember Ceramic Mug
2024-02-14 10:29:22.921 DEBUG (MainThread) [ember_mug.mug] Callback <bound method MugDataUpdateCoordinator._async_handle_callback of <custom_components.ember_mug.coordinator.MugDataUpdateCoordinator object at 0x7f7a768555e0>> already registered
2024-02-14 10:29:22.921 DEBUG (MainThread) [custom_components.ember_mug.coordinator] Updating
2024-02-14 10:29:22.921 DEBUG (MainThread) [ember_mug.mug] Updating the following attributes: {'firmware', 'udsk', 'meta', 'date_time_zone', 'dsk'}
2024-02-14 10:29:22.922 DEBUG (MainThread) [ember_mug.mug] Establishing a new connection from mug (ID: 140163951182480) to C6:12:2D:4C:FA:9B: Ember Ceramic Mug
2024-02-14 10:29:22.922 DEBUG (MainThread) [bleak_retry_connector] (C6:12:2D:4C:FA:9B) - C6:12:2D:4C:FA:9B: Connection attempt: 1
2024-02-14 10:29:28.305 ERROR (MainThread) [homeassistant] Error doing job: Unclosed client session
2024-02-14 10:29:45.442 WARNING (MainThread) [homeassistant.components.rest.util] JSON result was not a dictionary or list with 0th element a dictionary
2024-02-14 10:29:46.773 DEBUG (MainThread) [bleak_retry_connector] (C6:12:2D:4C:FA:9B) - C6:12:2D:4C:FA:9B: Timed out trying to connect (attempt: 1, last rssi: None)
2024-02-14 10:29:47.025 DEBUG (MainThread) [bleak_retry_connector] (C6:12:2D:4C:FA:9B) - C6:12:2D:4C:FA:9B: Connection attempt: 2
2024-02-14 10:29:58.320 ERROR (MainThread) [pynintendoparental] Error updating device 5cedcb8660c73fd5: list index out of range
2024-02-14 10:29:58.321 ERROR (MainThread) [homeassistant] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 256, in _handle_refresh_interval
await self._async_refresh(log_failures=True, scheduled=True)
File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 412, in _async_refresh
self.async_update_listeners()
File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 183, in async_update_listeners
update_callback()
File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 492, in _handle_coordinator_update
self.async_write_ha_state()
File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 989, in async_write_ha_state
self._async_write_ha_state()
File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 1110, in _async_write_ha_state
state, attr, capabilities, shadowed_attr = self.__async_calculate_state()
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 1047, in __async_calculate_state
state = self._stringify_state(available)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 995, in _stringify_state
if (state := self.state) is None:
^^^^^^^^^^
File "/usr/src/homeassistant/homeassistant/components/sensor/__init__.py", line 549, in state
value = self.native_value
^^^^^^^^^^^^^^^^^
File "/config/custom_components/nintendo_parental/sensor.py", line 44, in native_value
return self._device.limit_time - (
^^^^^^^^^^^^^^^^^^^^^^^^^^^
TypeError: unsupported operand type(s) for -: 'NoneType' and 'float'
2024-02-14 10:30:00.813 DEBUG (MainThread) [bleak_retry_connector] (C6:12:2D:4C:FA:9B) - C6:12:2D:4C:FA:9B: Failed to connect: Error ESP_GATT_CONN_FAIL_ESTABLISH while connecting: Connection failed to establish, device_missing: False, backing off: 0.5 (attempt: 2, last rssi: None)
2024-02-14 10:30:01.318 DEBUG (MainThread) [bleak_retry_connector] (C6:12:2D:4C:FA:9B) - C6:12:2D:4C:FA:9B: Connection attempt: 3
2024-02-14 10:30:13.961 WARNING (MainThread) [aioesphomeapi.connection] bt-proxy-masterbedroom @ 10.10.10.185: Connection error occurred: [Errno 104] Connection reset by peer
sopelj commented 7 months ago

Hi! Thanks for the detailed logs. There are many errors, but they seem to be from other integrations. From what I can see the mug is indeed detected and is able to sometimes query attributes. However, it seems to fail often and eventually gives up.

I see you're using at least one proxy, do you have just the one or multiple? How close is it to the mug and wifi signal? There are multiple connection errors to your Proxy, perhaps it has a poor wifi signal and cannot properly forward to connection?

bt-proxy-masterbedroom @ 10.10.10.185: Connection error occurred: [Errno 104] Connection reset by peer
Dinth commented 7 months ago

At the moment I’ve got two proxies which should work (GL-S10 model) and both are Ethernet/PoE. I have tried putting the mug literally next to masterbedroom proxy without any luck.

Kind regards, Michal Gawronski-Kot @.***

On Thu, 15 Feb 2024 at 00:05, Jesse Sopel @.***> wrote:

Hi! Thanks for the detailed logs. There are many errors, but they seem to be from other integrations. From what I can see the mug is indeed detected and is able to sometimes query attributes. However, it seems to fail often and eventually gives up.

I see you're using at least one proxy, do you have just the one or multiple? How close is it to the mug and wifi signal? There are multiple connection errors to your Proxy, perhaps it has a poor wifi signal and cannot properly forward to connection?

bt-proxy-masterbedroom @ 10.10.10.185: Connection error occurred: [Errno 104] Connection reset by peer

— Reply to this email directly, view it on GitHub https://github.com/sopelj/hass-ember-mug-component/issues/49#issuecomment-1945097807, or unsubscribe https://github.com/notifications/unsubscribe-auth/AACMSSV7EZJZ6AS6PTYDQMDYTVGMXAVCNFSM6AAAAABDIMFDISVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMYTSNBVGA4TOOBQG4 . You are receiving this because you authored the thread.Message ID: @.***>

sopelj commented 7 months ago

Oh OK, thanks.

I am not familiar with that one. But, googling it does show quite a few issues with packet loss anbd disconnects with that device (eg. this and this), although they are older, so I'm not sure if it is still pertinent, but could be good to look into.

Otherise, perhaps make sure it is using ethernet and the onboard wifi is not used. Also, ensure the settings have the scan type set to active.

If you still have issues, you could try disabling one of them in case the issue is them fighting over the connection, although, only one appears in your log so I don't think that's the issue here.

Dinth commented 7 months ago

I have disconnected GL-S10 and now relying on ESP32 BT proxy in Presence sensors. Unfortunately the problem still persists (although with a different error messages):

2024-02-29 09:23:42.268 ERROR (MainThread) [homeassistant.config_entries] Error setting up entry Ember Ceramic Mug for ember_mug
Traceback (most recent call last):
File "/usr/local/lib/python3.12/site-packages/aioesphomeapi/client.py", line 568, in bluetooth_device_connect
await connect_future
TimeoutError
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "/usr/src/homeassistant/homeassistant/config_entries.py", line 444, in async_setup
result = await component.async_setup_entry(hass, self)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/config/custom_components/ember_mug/__init__.py", line 114, in async_setup_entry
await mug_coordinator.async_config_entry_first_refresh()
File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 278, in async_config_entry_first_refresh
await self._async_refresh(
File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 313, in _async_refresh
self.data = await self._async_update_data()
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/config/custom_components/ember_mug/coordinator.py", line 96, in _async_update_data
changed = await self.mug.update_initial()
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/local/lib/python3.12/site-packages/ember_mug/mug.py", line 400, in update_initial
return await self._update_multiple(INITIAL_ATTRS)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/local/lib/python3.12/site-packages/ember_mug/mug.py", line 411, in _update_multiple
await self._ensure_connection()
File "/usr/local/lib/python3.12/site-packages/ember_mug/mug.py", line 150, in _ensure_connection
client = await establish_connection(
^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/local/lib/python3.12/site-packages/bleak_retry_connector/__init__.py", line 363, in establish_connection
await client.connect(
File "/usr/local/lib/python3.12/site-packages/habluetooth/wrappers.py", line 300, in connect
connected = await super().connect(**kwargs)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/local/lib/python3.12/site-packages/bleak/__init__.py", line 605, in connect
return await self._backend.connect(**kwargs)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/local/lib/python3.12/site-packages/bleak_esphome/backend/client.py", line 77, in _async_wrap_bluetooth_operation
return await func(self, *args, **kwargs)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/local/lib/python3.12/site-packages/bleak_esphome/backend/client.py", line 297, in connect
await self._client.bluetooth_device_connect(
File "/usr/local/lib/python3.12/site-packages/aioesphomeapi/client.py", line 584, in bluetooth_device_connect
not await self._bluetooth_device_disconnect_guard_timeout(
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/local/lib/python3.12/site-packages/aioesphomeapi/client.py", line 609, in _bluetooth_device_disconnect_guard_timeout
await self.bluetooth_device_disconnect(address, timeout=timeout)
File "/usr/local/lib/python3.12/site-packages/aioesphomeapi/client.py", line 660, in bluetooth_device_disconnect
await self._bluetooth_device_request(
File "/usr/local/lib/python3.12/site-packages/aioesphomeapi/client.py", line 714, in _bluetooth_device_request
[response] = await self._get_connection().send_messages_await_response_complex(
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "aioesphomeapi/connection.py", line 816, in send_messages_await_response_complex
asyncio.exceptions.CancelledError
sopelj commented 7 months ago

Thanks for the update. That is strange. It still seems to be a timeout issue. What kind of proxy are you using? Are you just testing with one or still with multiple? Are you certain the active option is enabled in scan_parameters?

Dinth commented 7 months ago

Hi. This morning i have tried again and it just worked straight away.

Just one follow-up question please - if i have multiple BT proxies, will Ember Mug connect to any of them (depending on which one has strongest signal) or will it only keep connecting to the one which was closest during the pairing?

sopelj commented 7 months ago

Hi. This morning i have tried again and it just worked straight away.

Just one follow-up question please - if i have multiple BT proxies, will Ember Mug connect to any of them (depending on which one has strongest signal) or will it only keep connecting to the one which was closest during the pairing?

Thanks! I appreciate the update and I'm glad it works for you.

In theory it should work with multiple proxies and favour the closest. I have not tested this however. If they are too close and the signal is similar strength however you may get a lot of switching. In this case you might want to separate them or adjust signal strength in the proxy settings. If you notice one is not used, you may need to put the device in pairing mode whilst closest to the other so it does an initial pair. Don't hesitate if you have issues, however this is sort of out of control of this integration and falls to how proxies are handled in Home Assistant.