home-assistant / core

:house_with_garden: Open source home automation that puts local control and privacy first.
https://www.home-assistant.io
Apache License 2.0
72.61k stars 30.37k forks source link

Error received and ignored in this codepath: [Errno 113] Host is unreachable #80071

Closed smartmatic closed 1 year ago

smartmatic commented 2 years ago

The problem

I've added two Thread devices yesterday. A Eve Energy and a Nanoleaf Essentials Strip. Both devices were reachable after the integration and i was able to control the. But this morning i see the error message in the logs below and the Home Controller does not reach them.

Now the logs are flooded with the below messages as Homekit Controller tries to reconnect.

Bildschirmfoto 2022-10-11 um 08 41 05

What version of Home Assistant Core has the issue?

2022.10.3

What was the last working version of Home Assistant Core?

No response

What type of installation are you running?

Home Assistant OS

Integration causing the issue

HomeKit Controller

Link to integration documentation on our website

https://www.home-assistant.io/integrations/homekit_controller/

Diagnostics information

No response

Example YAML snippet

No response

Anything in the logs that might be useful for us?

Logger: homeassistant.config_entries
Source: config_entries.py:1088
First occurred: 7:19:05 AM (17 occurrences)
Last logged: 8:35:01 AM

Config entry 'Nanoleaf Essentials' for homekit_controller integration not ready yet: failed to connect; Retrying in background
Config entry 'Eve Energy' for homekit_controller integration not ready yet: failed to connect; Retrying in background

Logger: coap-server
Source: runner.py:119
First occurred: 7:12:32 AM (175 occurrences)
Last logged: 8:35:09 AM

Error received and ignored in this codepath: [Errno 113] Host is unreachable

Additional information

No response

homeassistant commented 2 years ago

Hey there @jc2k, @bdraco, mind taking a look at this issue as it has been labeled with an integration (homekit_controller) you are listed as a code owner for? Thanks! (message by CodeOwnersMention)


homekit_controller documentation homekit_controller source (message by IssueLinks)

Jc2k commented 2 years ago

Are your WiFi repeaters still off?

smartmatic commented 2 years ago

No, i thought it's enough to take them off during setup. I need my repeaters.

Jc2k commented 2 years ago

It looks like the way they work or the way they are configured is incompatible with thread. There aren't any code changes I can make to workaround this. You need a thread compatible network, for this and ultimately for matter too.

I don't know enough about your repeaters are or how you have them set up to help with that yet.

My guesses so far as to main culprits are either filtering in the repeaters blocking mdns - so when the thread devices change their ip address you loose access. Or the repeaters are doing their own dhcp and in effect acting like a vlan. The thread routes don't propagate between segments like that. It needs to be a flat l2 WiFi bridge. It would have broken if the HomePod switched to the repeater.

Are your repeaters doing wifi or Ethernet uplink? What make are they?

Is your ha box connected to your router via Ethernet?

smartmatic commented 2 years ago

I running HA OS on a RPI4 connected via LAN.

Basically my repeaters taking over the configuration from my router (Master). The router is also acting as DHCP server. The repeaters do not have their own DHCP. Means they have the same SSID and WLAN password like the router in order to guarantee a seamless switch from one access point to another access point.

What does Uplink exactly mean?

L2 means i must make sure that HomePod and thread devices talking only over the same device. Either the router or one of my two WLAN repeaters?

Jc2k commented 2 years ago

Basically, do you plug them in via Ethernet, do they send data over your mains wiring or do they act as a WiFi client and hotspot at the same time?

smartmatic commented 2 years ago

One of the repeater is connected via Ethernet the second only via WLAN

Jc2k commented 2 years ago

You could try it with one of them on at a time and see if the problem is limited to wifi mode or lan mode.

You could also have multiple ssids. Just use the repeaters for your main ssid, but then have your router advertise a separate ssid that the repeaters don't know about. Then homepod would only connect to your router ssid directly and never to repeaters. The rest of your stuff would just use the repeaters. As far as your phone/tablet/etc was concerned there would still just be one ssid.

smartmatic commented 2 years ago

Thanks a again for your pretty well detailed guidance! I've switched my Ethernet connected WLAN repeater to WiFi and then both Thread devices were reachable again in HA. So far they are working and both repeaters are on connected via WiFi!

Let me please ask one thing where you might help? The energy values from eve Energy are not correct formated. There are a lot of descendants. Bildschirmfoto 2022-10-12 um 08 06 51

Do you know how why that is the case and how to fix it?

smartmatic commented 2 years ago

The behaviour is is really wired. Basically it's working but after some hours the devices became unavailable

Bildschirmfoto 2022-10-14 um 08 13 03

What can cause this issue?

Jc2k commented 2 years ago

There are many possible causes, and you are an early adopter of this tech so we don't have a list of "usual" causes yet.

I'm pretty sure that your WiFi repeaters were interfering with mdns, as discovery didn't work with them in place.

In normal operation mdns needs to work, but not constantly. So it's possibly your HomePod is on your main WiFi hotspot. Then you turned on the repeaters and and after some hours the HomePod happened to roam to a repeater. It's mdns broke but it didn't notice at first. Then the IPs of the thread devices changed. You would then be in the state we see here.

But this is just a guess. If you could run without the repeaters a few days, we'd be able to rule out the repeaters as a cause.

smartmatic commented 2 years ago

Hmm, ok thanks for the explanation. I will give it a try. When i disconnect my repeaters and all WiFi devices are automatically connect to the router should then the Thread devices automatically turn back to available? Or do you think a restart of my router is needed?

Jc2k commented 2 years ago

I think they should all come back online. In my testing my HomePod sent the router advertisements every 5 minutes or so, I'm not sure about mdns stuff. So you can disconnect them and wait a little bit. Or you could restart HA. That should force Ha to send the mdns packets that will wake the HomePod up.

smartmatic commented 2 years ago

Devices back but I am getting this warning:

`Logger: aiohomekit.controller.coap.connection Source: components/homekit_controller/connection.py:612 First occurred: 9:25:52 PM (9 occurrences) Last logged: 9:29:52 PM

Decryption failed, desynchronized? Counter=22/23 Failed flailing attempts to resynchronize, self-destructing in 3, 2, 1... CoAP POST returned unexpected code <aiocoap.Message at 0x7f5acaaad0: Type.ACK 4.04 Not Found (MID 18657, token 2ef0) remote <UDP6EndpointAddress [fdbe:986f:7dcd:0:23a7:aec8:d3a8:b9e] (locally fd0c:2a70:34e8:46b7:2966:39bc:dfdf:a7a4%eth0)>> Decryption failed, desynchronized? Counter=12/13 CoAP POST returned unexpected code <aiocoap.Message at 0x7f5acacbb0: Type.ACK 4.04 Not Found (MID 23253, token 02c0) remote <UDP6EndpointAddress [fdbe:986f:7dcd:0:76ab:ac54:d0ac:f67e] (locally fd0c:2a70:34e8:46b7:2966:39bc:dfdf:a7a4%eth0)>>

`

What i also like to mention is that i have a LAN connected ATV4.

How does Thread work if there multiple border routers?

Jc2k commented 2 years ago

I'm not entirely sure what happens with multiple border routers. It's possible there will just be 2 routes published on your lan, and it's up to HA to pick the best route. Or it's possible one will go into standby mode.

The errors are a bit verbose. The desynchronise happens because udp is not a stateful protocol - thinks can get out of order and unfortunately the encryption is in order. So we can sometimes se an encrypted payload we can't decide because it is too old or too new. It could be a sign of WiFi fragility, thread network fragility, some device using too much cpu somewhere, but it should recover.

We will probably make it a debug level warning rather than what it is now.

smartmatic commented 2 years ago

Last night i did not have any disconnections of my Thread devices. This was the case the nights before. Only thing i've changed is that i've not powered off my ATV4. The days before i have turned of my power cord to save stand-by energy of connected devices like TV and so on. I thought it should not make a difference as my Homepod is always connected via WiFi and i thought that my Thread devices are probably connected to the Homepod. I am curious what will happen next night.

smartmatic commented 2 years ago

I've changed my network settings. My Homepod is now connected directly to my router with an own SSID. Thee same for my ATV4. It's connected via Ethernet directly to the router Then i've paired my Thread devices again and they had worked. This morning after i tried to turn on my Nanoleaf Lighstrip i got this error:

`Logger: homeassistant.components.automation.buro_arbeitslicht_anschalten Source: components/homekit_controller/connection.py:616 Integration: Automation (documentation, issues) First occurred: 8:19:26 AM (2 occurrences) Last logged: 8:19:26 AM

Büro: Arbeitslicht schalten: Error executing script. Unexpected error for device at pos 2: Decryption of PDU POST response failed While executing automation automation.buro_arbeitslicht_anschalten Traceback (most recent call last): File "/usr/local/lib/python3.10/site-packages/aiohomekit/controller/coap/connection.py", line 117, in _decrypt_response return self.decrypt(response.payload) File "/usr/local/lib/python3.10/site-packages/aiohomekit/controller/coap/connection.py", line 94, in decrypt dec_data = self.recv_ctx.decrypt( File "/usr/local/lib/python3.10/site-packages/cryptography/hazmat/primitives/ciphers/aead.py", line 62, in decrypt return aead._decrypt(backend, self, nonce, data, [associated_data], 16) File "/usr/local/lib/python3.10/site-packages/cryptography/hazmat/backends/openssl/aead.py", line 207, in _decrypt raise InvalidTag cryptography.exceptions.InvalidTag

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 451, in _async_step await getattr(self, handler)() File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 692, in _async_device_step await device_action.async_call_action_from_config( File "/usr/src/homeassistant/homeassistant/components/device_automation/action.py", line 76, in async_call_action_from_config await platform.async_call_action_from_config(hass, config, variables, context) File "/usr/src/homeassistant/homeassistant/components/light/device_action.py", line 65, in async_call_action_from_config await toggle_entity.async_call_action_from_config( File "/usr/src/homeassistant/homeassistant/components/device_automation/toggle_entity.py", line 123, in async_call_action_from_config await hass.services.async_call( File "/usr/src/homeassistant/homeassistant/core.py", line 1738, in async_call task.result() File "/usr/src/homeassistant/homeassistant/core.py", line 1775, in _execute_service await cast(Callable[[ServiceCall], Awaitable[None]], handler.job.target)( File "/usr/src/homeassistant/homeassistant/helpers/entity_component.py", line 207, in handle_service await service.entity_service_call( File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 678, in entity_service_call future.result() # pop exception if have File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 931, in async_request_call await coro File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 715, in _handle_entity_call await result File "/usr/src/homeassistant/homeassistant/components/light/init.py", line 566, in async_handle_toggle_service await async_handle_light_on_service(light, call) File "/usr/src/homeassistant/homeassistant/components/light/init.py", line 546, in async_handle_light_on_service await light.async_turn_on(**filter_turn_on_params(light, params)) File "/usr/src/homeassistant/homeassistant/components/homekit_controller/light.py", line 157, in async_turn_on await self.async_put_characteristics(characteristics) File "/usr/src/homeassistant/homeassistant/components/homekit_controller/entity.py", line 91, in async_put_characteristics return await self._accessory.put_characteristics(payload) File "/usr/src/homeassistant/homeassistant/components/homekit_controller/connection.py", line 616, in put_characteristics results = await self.pairing.put_characteristics(characteristics) File "/usr/local/lib/python3.10/site-packages/aiohomekit/controller/coap/pairing.py", line 202, in put_characteristics return await self.connection.write_characteristics(characteristics) File "/usr/local/lib/python3.10/site-packages/aiohomekit/controller/coap/connection.py", line 559, in write_characteristics pdu_results = await self.enc_ctx.post_all( File "/usr/local/lib/python3.10/site-packages/aiohomekit/controller/coap/connection.py", line 190, in post_all res_pdu = await self.post_bytes(req_pdu) File "/usr/local/lib/python3.10/site-packages/aiohomekit/controller/coap/connection.py", line 176, in post_bytes return await self._decrypt_response(response) File "/usr/local/lib/python3.10/site-packages/aiohomekit/controller/coap/connection.py", line 159, in _decrypt_response raise EncryptionError("Decryption of PDU POST response failed") aiohomekit.exceptions.EncryptionError: Decryption of PDU POST response failed ` And this Warning

`Logger: aiohomekit.controller.coap.connection Source: components/homekit_controller/connection.py:612 First occurred: 7:29:07 AM (33 occurrences) Last logged: 8:20:07 AM

CoAP POST returned unexpected code <aiocoap.Message at 0x7f5eb9d690: Type.ACK 4.04 Not Found (MID 54691, token a11b) remote <UDP6EndpointAddress [fdbe:986f:7dcd:0:db5a:fbbd:9c6d:1e2e] (locally 2001:9e8:21d2:6100:1524:fd70:fc33:30ed%eth0)>> Decryption failed, desynchronized? Counter=20/21 Failed flailing attempts to resynchronize, self-destructing in 3, 2, 1... CoAP POST returned unexpected code <aiocoap.Message at 0x7f5278bf10: Type.ACK 4.04 Not Found (MID 47687, token 57ed) remote <UDP6EndpointAddress [fdbe:986f:7dcd:0:db5a:fbbd:9c6d:1e2e] (locally 2001:9e8:21d2:6100:1524:fd70:fc33:30ed%eth0)>> Decryption failed, desynchronized? Counter=13/14`

smartmatic commented 1 year ago

Want share my latest experience. Basically are both devices continiously connected. Only thing which appears from time to time is that the devices loses somehow the connection. Reload of the integrated device does not help in such case. Today i’ve restarted both border router and after that they come back again.

Do you has an explanation for that?

Jc2k commented 1 year ago

It's hard to say. Mine are pretty rock solid apart from the HomePod intermittently loses its WiFi connection and needs restarting.

Next time it breaks, can you ping6 the thread devices as well as the router from your home assistant instance.

smartmatic commented 1 year ago

After some days working i lost now again the connection to Nanoleaf Essentials Strip. Ping to my router is successful but ping6 send this answer:

Bildschirm­foto 2022-10-31 um 10 51 43

Maybe you can find some hints in the diagnostic? homekit_controller-0402093e4bb29323b9352c657382eaf4-Nanoleaf Strip 3HZD-e9762f31ee904948732730adcfcaa566.json.txt

Jc2k commented 1 year ago

Sorry I should have been more specific - you need to give ping6 the ip address of the nanoleaf device.

"ip -6 route" and "ip -6 a" from your ha container would be good too.

smartmatic commented 1 year ago

Sorry I should have been more specific - you need to give ping6 the ip address of the nanoleaf device.

"ip -6 route" and "ip -6 a" from your ha container would be good too.

Both Devices are no WiFi devices and therefore i don‘t see an IP in my router. Where can i find the IP?

Jc2k commented 1 year ago

You need to find a tool that can do mdns lookups and tell it to browse for _hap._udp.local devices. Or if you look in /config/.storage/core.config_entries you can see what HA is using.

issue-triage-workflows[bot] commented 1 year ago

There hasn't been any activity on this issue recently. Due to the high number of incoming GitHub notifications, we have to clean some of the old issues, as many of them have already been resolved with the latest updates. Please make sure to update to the latest Home Assistant version and check if that solves the issue. Let us know if that works for you by adding a comment 👍 This issue has now been marked as stale and will be closed if no further activity occurs. Thank you for your contributions.