mvdwetering / huesyncbox

Custom integration for Home Assistant to control the Philips Hue Play HDMI Sync Box 4K or 8K
Apache License 2.0
114 stars 8 forks source link

Cannot connect to Hue Sync Box from HA #72

Closed smithey253 closed 9 months ago

smithey253 commented 10 months ago

Describe the bug I am unable to connect to the Hue Sync Box using the integration in Home Assistant. I get the 'Connection Failed' error. This happens when connecting automatically when suggested through HA and also manually by selecting the integration and entering the details. I have power cycled the sync box, the router, restarted HA numerous times.

To Reproduce Steps to reproduce the behavior: I choose the Hue Sync Box Integration Enter the IP address and Device ID from the Hue app Click next The error appears

Expected behavior Home Assistant should connect to the Hue Sync Box

Diagnostics No diagnostics as the integration has not yet connected.

Logging Nothing in HA logs about the integration

Environment Core 2023.12.0 Supervisor 2023.12.0 Operating System 11.2 Frontend 20231206.0

Additional info Initially I thought that it was due to me not using the Hue integration as I bring Hue bulbs in through Smartthings but after adding the Hue Integration, the issue persists.

mvdwetering commented 10 months ago

Since the integration is not loading at all enabling debug logging is a bit more complicated than usual.

Can you add the following section to your configuration.yaml, restart Home Assistant and try again? I hope there is something in the logs then.

logger:
  default: info
  logs:
    custom_components.huesyncbox: debug
    aiohuesyncbox: debug
smithey253 commented 10 months ago

Brings back this on the logs:

2023-12-19 20:32:32.228 DEBUG (MainThread) [custom_components.huesyncbox.config_flow] async_step_zeroconf, ZeroconfServiceInfo(ip_address=IPv4Address('192.168.86.71'), ip_addresses=[IPv4Address('192.168.86.71')], port=443, hostname='C42996038704.local.', type='_huesync._tcp.local.', name='HueSyncBox-C42996038704._huesync._tcp.local.', properties={'name': 'Sync Box', 'devicetype': 'HSB1', 'uniqueid': 'C42996038704', 'path': '/api'}) 2023-12-19 20:32:32.231 DEBUG (MainThread) [custom_components.huesyncbox.config_flow] async_step_zeroconf_confirm, None 2023-12-19 20:32:54.399 DEBUG (MainThread) [custom_components.huesyncbox.config_flow] async_step_zeroconf_confirm, None 2023-12-19 20:32:55.753 DEBUG (MainThread) [custom_components.huesyncbox.config_flow] async_step_zeroconf_confirm, {} 2023-12-19 20:32:55.754 DEBUG (MainThread) [custom_components.huesyncbox.config_flow] async_step_link, None 2023-12-19 20:32:55.756 DEBUG (MainThread) [custom_components.huesyncbox.config_flow] _async_register, ConnectionInfo(host='192.168.86.71', unique_id='C42996038704', access_token=None, registration_id=None, port=443, path='/api') 2023-12-19 20:32:55.763 DEBUG (MainThread) [aiohuesyncbox.huesyncbox] post, https://_192.168.86.71:443/api/v1/registrations, {'appName': 'Home Assistant', 'instanceName': 'Home'} 2023-12-19 20:32:55.788 DEBUG (MainThread) [custom_components.huesyncbox.config_flow] async_step_link, None 2023-12-19 20:32:55.799 DEBUG (MainThread) [custom_components.huesyncbox.config_flow] _async_register, asyncio.CancelledError 2023-12-19 20:32:55.800 DEBUG (MainThread) [custom_components.huesyncbox.config_flow] _async_register, finally, True 2023-12-19 20:32:55.809 DEBUG (MainThread) [custom_components.huesyncbox.config_flow] async_step_abort, None 2023-12-19 20:32:55.809 DEBUG (MainThread) [custom_components.huesyncbox.config_flow] async_remove, True 2023-12-19 20:33:02.420 DEBUG (MainThread) [custom_components.huesyncbox.config_flow] async_step_user, None 2023-12-19 20:33:04.368 INFO (MainThread) [hass_nabucasa.google_report_state] Connected 2023-12-19 20:34:33.304 DEBUG (MainThread) [custom_components.huesyncbox.config_flow] async_step_user, {'host': '192.168.86.71', 'unique_id': 'C42996038704'} 2023-12-19 20:34:33.308 DEBUG (MainThread) [aiohuesyncbox.huesyncbox] get, https://_192.168.86.71:443/api/v1/registrations, None 2023-12-19 20:34:34.975 DEBUG (MainThread) [aiohuesyncbox.huesyncbox] 401, {"code": 2, "message": "Invalid Token"} 2023-12-19 20:34:34.978 DEBUG (MainThread) [custom_components.huesyncbox.config_flow] async_step_link, None 2023-12-19 20:34:34.981 DEBUG (MainThread) [custom_components.huesyncbox.config_flow] _async_register, ConnectionInfo(host='192.168.86.71', unique_id='C42996038704', access_token=None, registration_id=None, port=443, path='/api') 2023-12-19 20:34:34.985 DEBUG (MainThread) [aiohuesyncbox.huesyncbox] post, https://_192.168.86.71:443/api/v1/registrations, {'appName': 'Home Assistant', 'instanceName': 'Home'} 2023-12-19 20:34:35.164 DEBUG (MainThread) [custom_components.huesyncbox.config_flow] async_step_link, None 2023-12-19 20:34:35.172 DEBUG (MainThread) [custom_components.huesyncbox.config_flow] _async_register, asyncio.CancelledError 2023-12-19 20:34:35.173 DEBUG (MainThread) [custom_components.huesyncbox.config_flow] _async_register, finally, True 2023-12-19 20:34:35.179 DEBUG (MainThread) [custom_components.huesyncbox.config_flow] async_step_abort, None 2023-12-19 20:34:35.180 DEBUG (MainThread) [custom_components.huesyncbox.config_flow] async_remove, True

mvdwetering commented 10 months ago

This is a tough one, for some reason the linking process gets cancelled, but I can't see from the logging.

I added a bit of additional logging to the dev branch, maybe that gives an idea of what could be the cause. Could you install the "dev" version and try again?

If you are using HACS, choose redownload and make sure the "beta" switch is enabled and then select "dev" from the version list.

smithey253 commented 10 months ago

I've installed the DEV version, restarted HA and then ran the connection helper again. Here is the log:

2023-12-20 21:48:32.425 DEBUG (MainThread) [custom_components.huesyncbox.config_flow] async_step_user, None 2023-12-20 21:49:13.925 DEBUG (MainThread) [custom_components.huesyncbox.config_flow] async_step_user, {'host': '192.168.86.71', 'unique_id': 'C42996038704'} 2023-12-20 21:49:13.929 DEBUG (MainThread) [aiohuesyncbox.huesyncbox] get, https://_192.168.86.71:443/api/v1/registrations, None 2023-12-20 21:49:15.152 DEBUG (MainThread) [aiohuesyncbox.huesyncbox] 401, {"code": 2, "message": "Invalid Token"} 2023-12-20 21:49:15.155 DEBUG (MainThread) [custom_components.huesyncbox.config_flow] async_step_link, None 2023-12-20 21:49:15.158 DEBUG (MainThread) [custom_components.huesyncbox.config_flow] _async_register, ConnectionInfo(host='192.168.86.71', unique_id='C42996038704', access_token=None, registration_id=None, port=443, path='/api') 2023-12-20 21:49:15.162 DEBUG (MainThread) [aiohuesyncbox.huesyncbox] post, https://_192.168.86.71:443/api/v1/registrations, {'appName': 'Home Assistant', 'instanceName': 'Home'} 2023-12-20 21:49:15.191 DEBUG (MainThread) [custom_components.huesyncbox.config_flow] async_step_link, None 2023-12-20 21:49:15.200 DEBUG (MainThread) [custom_components.huesyncbox.config_flow] _async_register, asyncio.CancelledError 2023-12-20 21:49:15.200 DEBUG (MainThread) [custom_components.huesyncbox.config_flow] _async_register, finally, True 2023-12-20 21:49:15.208 DEBUG (MainThread) [custom_components.huesyncbox.config_flow] async_step_abort, None 2023-12-20 21:49:15.209 DEBUG (MainThread) [custom_components.huesyncbox.config_flow] async_remove, True 2023-12-20 21:51:37.151 DEBUG (MainThread) [custom_components.huesyncbox.config_flow] async_step_user, None 2023-12-20 21:52:10.098 DEBUG (MainThread) [custom_components.huesyncbox.config_flow] async_step_user, {'host': '192.168.86.71', 'unique_id': 'C42996038704'} 2023-12-20 21:52:10.101 DEBUG (MainThread) [aiohuesyncbox.huesyncbox] get, https://_192.168.86.71:443/api/v1/registrations, None 2023-12-20 21:52:11.403 DEBUG (MainThread) [aiohuesyncbox.huesyncbox] 401, {"code": 2, "message": "Invalid Token"} 2023-12-20 21:52:11.406 DEBUG (MainThread) [custom_components.huesyncbox.config_flow] async_step_link, None 2023-12-20 21:52:11.410 DEBUG (MainThread) [custom_components.huesyncbox.config_flow] _async_register, ConnectionInfo(host='192.168.86.71', unique_id='C42996038704', access_token=None, registration_id=None, port=443, path='/api') 2023-12-20 21:52:11.413 DEBUG (MainThread) [aiohuesyncbox.huesyncbox] post, https://_192.168.86.71:443/api/v1/registrations, {'appName': 'Home Assistant', 'instanceName': 'Home'} 2023-12-20 21:52:11.425 DEBUG (MainThread) [custom_components.huesyncbox.config_flow] async_step_link, None 2023-12-20 21:52:11.433 DEBUG (MainThread) [custom_components.huesyncbox.config_flow] _async_register, asyncio.CancelledError 2023-12-20 21:52:11.433 DEBUG (MainThread) [custom_components.huesyncbox.config_flow] _async_register, finally, True 2023-12-20 21:52:11.442 DEBUG (MainThread) [custom_components.huesyncbox.config_flow] async_step_abort, None 2023-12-20 21:52:11.442 DEBUG (MainThread) [custom_components.huesyncbox.config_flow] async_remove, True

mvdwetering commented 10 months ago

Weird... the additional info I expected to be there is not showing. Can you please double check if you are running dev?

In HACS it should show the text "986a1c7" instead of a normal version like 2.0.1 at the top left. image

smithey253 commented 10 months ago

I've redownloaded and it is definitely on the dev version now

Here is the log info after running the connection helper again:

2023-12-23 16:39:12.104 DEBUG (MainThread) [custom_components.huesyncbox.config_flow] async_step_user, None 2023-12-23 16:40:06.729 DEBUG (MainThread) [custom_components.huesyncbox.config_flow] async_step_user, {'host': '192.168.86.71', 'unique_id': 'C42996038704'} 2023-12-23 16:40:06.733 DEBUG (MainThread) [aiohuesyncbox.huesyncbox] get, https://_192.168.86.71:443/api/v1/registrations, None 2023-12-23 16:40:07.976 DEBUG (MainThread) [aiohuesyncbox.huesyncbox] 401, {"code": 2, "message": "Invalid Token"} 2023-12-23 16:40:07.979 DEBUG (MainThread) [custom_components.huesyncbox.config_flow] async_step_link, None 2023-12-23 16:40:07.982 DEBUG (MainThread) [custom_components.huesyncbox.config_flow] _async_register, ConnectionInfo(host='192.168.86.71', unique_id='C42996038704', access_token=None, registration_id=None, port=443, path='/api') 2023-12-23 16:40:07.989 DEBUG (MainThread) [aiohuesyncbox.huesyncbox] post, https://_192.168.86.71:443/api/v1/registrations, {'appName': 'Home Assistant', 'instanceName': 'Home'} 2023-12-23 16:40:08.010 DEBUG (MainThread) [custom_components.huesyncbox.config_flow] async_step_link, None 2023-12-23 16:40:08.020 DEBUG (MainThread) [custom_components.huesyncbox.config_flow] _async_register, asyncio.CancelledError Traceback (most recent call last): File "/config/custom_components/huesyncbox/config_flow.py", line 195, in _async_register registration_info = await huesyncbox.register( ^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/aiohuesyncbox/huesyncbox.py", line 139, in register response = await self.request( ^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/aiohuesyncbox/huesyncbox.py", line 216, in request async with self._clientsession.request( File "/usr/local/lib/python3.11/site-packages/aiohttp/client.py", line 1187, in aenter self._resp = await self._coro ^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/aiohttp/client.py", line 574, in _request conn = await self._connector.connect( ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/aiohttp/connector.py", line 544, in connect proto = await self._create_connection(req, traces, timeout) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/aiohttp/connector.py", line 911, in _createconnection , proto = await self._create_direct_connection(req, traces, timeout) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/aiohttp/connector.py", line 1204, in _create_direct_connection transp, proto = await self._wrap_create_connection( ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/aiohttp/connector.py", line 992, in _wrap_create_connection return await self._loop.create_connection(*args, **kwargs) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/asyncio/base_events.py", line 1112, in create_connection transport, protocol = await self._create_connection_transport( ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/asyncio/base_events.py", line 1145, in _create_connection_transport await waiter asyncio.exceptions.CancelledError 2023-12-23 16:40:08.036 DEBUG (MainThread) [custom_components.huesyncbox.config_flow] _async_register, finally, True 2023-12-23 16:40:08.040 DEBUG (MainThread) [custom_components.huesyncbox.config_flow] async_step_abort, None 2023-12-23 16:40:08.040 DEBUG (MainThread) [custom_components.huesyncbox.config_flow] async_remove, True

mvdwetering commented 10 months ago

I have been looking into this, but unfortunately I am running out of ideas.

With the latest logging I can see that it gets Cancelled somewhere deep in standard Python code, but I can't see why it is cancelled or by whom. Searching on the internet did not result in any good leads.

So not sure what to try next :(

smithey253 commented 10 months ago

No worries, thank you so much for trying to get it working! Much appreciated.

smithey253 commented 9 months ago

Hey

Coming back to this, the issue has now been resolved and I have connected to HueSync through HA.

Thanks for all of your help!

mvdwetering commented 9 months ago

Great to hear it works now.

Do you happen to know what solved it? It might help out someone in the future that has the same issue

smithey253 commented 9 months ago

Hey

Unfortunately I do not, HueSyncBox was still on the dev version when it started working. It could have been a HA update that had fixed it. Updated to the most recent version of HueSyncBox and still working.

mvdwetering commented 9 months ago

Ok, I will close the issue then