search

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
74.01k stars 31.05k forks source link

Homekit controller drops connection to Netatmo Weather station #123456

Open Bothygesen opened 3 months ago

Bothygesen commented 3 months ago

The problem

Hi, The connection between my Netatmo Weather station and Homekit is dropped 2-3 times per day. It only start to work again when restarting the Netatmo Weather station main unit.

When the connection to homekit is lost, the Netatmo weather station still works via the netatmo app.

This has been an ongoing issue for more than a month.

What version of Home Assistant Core has the issue?

core-2024.8.0

What was the last working version of Home Assistant Core?

core-2024.6.0

What type of installation are you running?

Home Assistant OS

Integration causing the issue

Netatmo Weather station

Link to integration documentation on our website

https://github.com/home-assistant/core/issues?q=is%3Aissue+is%3Aopen+label%3A%22integration%3A+homekit_controller%22

Diagnostics information

config_entry-homekit_controller-f29e30816943ffb2ec9d4d9d64c7a0fc (1).json

Example YAML snippet

No response

Anything in the logs that might be useful for us?

No response

Additional information

No response

Bothygesen commented 3 months ago

HA netatmo homekit

home-assistant[bot] commented 3 months 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!

Code owner commands Code owners of `homekit_controller` can trigger bot actions by commenting: - `@home-assistant close` Closes the issue. - `@home-assistant rename Awesome new title` Renames the issue. - `@home-assistant reopen` Reopen the issue. - `@home-assistant unassign homekit_controller` Removes the current integration label and assignees on the issue, add the integration domain after the command. - `@home-assistant add-label needs-more-information` Add a label (needs-more-information, problem in dependency, problem in custom component) to the issue. - `@home-assistant remove-label needs-more-information` Remove a label (needs-more-information, problem in dependency, problem in custom component) on the issue.

(message by CodeOwnersMention)

homekit_controller documentation homekit_controller source (message by IssueLinks)

LarsTh86 commented 2 months ago

same Issue for 2024.9.0. Is there a solution?

bdraco commented 2 months ago

Please follow the steps to provide debug logs https://www.home-assistant.io/docs/configuration/troubleshooting/#debug-logs-and-diagnostics

LarsTh86 commented 2 months ago

home-assistant_homekit_controller_2024-09-04T21-22-42.474Z.log home-assistant_homekit_controller_2024-09-04T21-20-04.662Z.log

bdraco commented 2 months ago

It looks like the device is closing the connection as soon as it attempts to verify the pairing

2024-09-04 23:20:01.317 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.128.0.69: raw request: b"POST /pair-verify HTTP/1.1\r\nHost: 192.128.0.69\r\nContent-Length: 37\r\nContent-Type: application/pairing+tlv8\r\n\r\n\x06\x01\x01\x03 \xd8\xa3N<\xc2`+S:\xc7\xbe\xd6'\xa0\xcc\xbaT\xbf\xd5\xf5\x83\xb5m\xcb\x941c.\x13\xed\x88A"
2024-09-04 23:20:01.401 DEBUG (MainThread) [aiohomekit.controller.ip.connection] Connection HomeKitConnection(host='192.128.0.69', port=5001) lost.
2024-09-04 23:20:01.402 DEBUG (MainThread) [aiohomekit.controller.ip.connection] [192.128.0.69:5001] (id=04:7A:81:54:DD:9B): Connecting to accessory failed: Connection closed; Retrying in 2 seconds

Is that the correct IP?

LarsTh86 commented 2 months ago

Yes, that is correct and before the update to 2024.9.0 everything works fineGesendet von Outlook für AndroidVon: J. Nick Koston @.>Gesendet: Mittwoch, September 4, 2024 11:32:17 PMAn: home-assistant/core @.>Cc: LarsTh86 @.>; Comment @.>Betreff: Re: [home-assistant/core] Homekit controller drops connection to Netatmo Weather station (Issue #123456) It looks like the device is closing the connection as soon as it attempt to verify the pairing 2024-09-04 23:20:01.317 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.128.0.69: raw request: b"POST /pair-verify HTTP/1.1\r\nHost: 192.128.0.69\r\nContent-Length: 37\r\nContent-Type: application/pairing+tlv8\r\n\r\n\x06\x01\x01\x03 \xd8\xa3N<\xc2`+S:\xc7\xbe\xd6'\xa0\xcc\xbaT\xbf\xd5\xf5\x83\xb5m\xcb\x941c.\x13\xed\x88A" 2024-09-04 23:20:01.401 DEBUG (MainThread) [aiohomekit.controller.ip.connection] Connection HomeKitConnection(host='192.128.0.69', port=5001) lost 2024-09-04 23:20:01.402 DEBUG (MainThread) [aiohomekit.controller.ip.connection] [192.128.0.69:5001] (id=04:7A:81:54:DD:9B): Connecting to accessory failed: Connection closed; Retrying in 2 seconds

Is that the correct IP?

—Reply to this email directly, view it on GitHub, or unsubscribe.You are receiving this because you commented.Message ID: @.***>

LarsTh86 commented 2 months ago

Yes, the ip is correct. And also for the update to 2024.9.0 everything works fine

makah21803 commented 2 months ago

I have the same issue, is there a solution yet?

Bothygesen commented 1 month ago

Hello all, Anyone has any idea how we can get this sorted?

Is it an issue on HA side or Netatmo side?

It has been quite a while now...

/Bo Thygesen

Jc2k commented 1 month ago

This seems to be specific to Netatmo. I don't have one, and my homekit devices have been working fine this entire time. So i'm not able to help.

It would be good if you could also provide logs as requested in the ticket template and by bdraco. See https://www.home-assistant.io/docs/configuration/troubleshooting/#debug-logs-and-diagnostics.

From the logs we do have, it looks like the device is non responsive on its homekit port. The netatmo app won't be using the homekit protocol, so that the fact that it works is not useful from a diagnostic point of view.

Getting logs before, during and after power cycling the netatmo device might be useful. (I want to see if it gives a useful error even once before getting stuck, or if we make a particular API call that causes it to get stuck).

Bothygesen commented 1 month ago

Hi, thank you for your response and the effort and time you put into this. Highly appreciated...

I have attached 3 logs.

01 While the Netatmo devices did not work/ respond and i get the following error message when reloading the integration in HA. Screenshot 2024-10-15 08 51 19

02 While the Netatmo devices did not work/ respond and i get the error message above when reloading the integration in HA. I then power the main Netatmo weather unit off and on again (only way to make the Netatmo devices work again in HA is to restart the main module by unplugging it from electricity) after which i can reload the integration successfully.

03 The Netatmo integration works and i reload it.

Thank you again Bo Thygesen

03 home-assistant_homekit_controller_2024-10-15T05-52-04.755Z.log 02 home-assistant_homekit_controller_2024-10-15T05-51-39.343Z.log 01 home-assistant_homekit_controller_2024-10-15T05-50-21.515Z.log

bdraco commented 1 month ago 
2024-10-14 12:05:47.043 ERROR (MainThread) [aiohomekit.controller.ip.connection] Weather Station [192.168.86.35:5001] (id=3D:55:CE:8D:7F:C1): Unexpected error whilst trying to connect to accessory. Will retry.
Traceback (most recent call last):
  File "/usr/local/lib/python3.12/site-packages/aiohomekit/controller/ip/connection.py", line 647, in _reconnect
    return await self._connect_once()
           ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/aiohomekit/controller/ip/connection.py", line 743, in _connect_once
    await super()._connect_once()
  File "/usr/local/lib/python3.12/site-packages/aiohomekit/controller/ip/connection.py", line 611, in _connect_once
    connected_host = sock.getpeername()[0]
                     ^^^^^^^^^^^^^^^^^^
OSError: [Errno 107] Socket not connected
bdraco commented 1 month ago

Which version of aiohappyeyeballs do you have installed?

bdraco commented 1 month ago 
docker exec -it homeassistant /bin/bash
pip3 show aiohappyeyeballs
bdraco commented 1 month ago

Might also try moving sock.setsockopt(socket.SOL_SOCKET, socket.SO_KEEPALIVE, 1) to the end of the function or turning it off

Bothygesen commented 1 month ago

Hi again, Not sure about the happy eye ball thingy.... How can i find that info?

I am running HA on a HA Green and with all latest updates installed...

/Bo

bdraco commented 1 month ago

https://github.com/Jc2k/aiohomekit/blob/29b77e72d391d4bf0f4a3a0b17fe6ce0d2047f77/aiohomekit/controller/ip/connection.py#L611C9-L611C47 could be moved into the try https://github.com/Jc2k/aiohomekit/blob/29b77e72d391d4bf0f4a3a0b17fe6ce0d2047f77/aiohomekit/controller/ip/connection.py#L587

We probably need to add some more logging as well as its not clear whats going on.

The device seems to be dropping the connections right away for some reason

bdraco commented 1 month ago

It also looks like the lib reties too soon, and we don't log the failure exception

024-10-14 17:52:04.154 DEBUG (MainThread) [aiohomekit.protocol.tlv] sending [
  6 (State): (1 bytes/<class 'bytearray'>) 0x01
  3 (PublicKey): (32 bytes/<class 'bytes'>) b'_\xd2\xe0t\x88\xdeHi\x80\xfe\x80\xe3\xfd%\xfd\xc0\xc6]p\x8c\xd7]<\r\x87\xd7\x86\xe4\xc4\xd7\xfel'
]

2024-10-14 17:52:04.155 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.86.35: raw request: b'POST /pair-verify HTTP/1.1\r\nHost: 192.168.86.35\r\nContent-Length: 37\r\nContent-Type: application/pairing+tlv8\r\n\r\n\x06\x01\x01\x03 _\xd2\xe0t\x88\xdeHi\x80\xfe\x80\xe3\xfd%\xfd\xc0\xc6]p\x8c\xd7]<\r\x87\xd7\x86\xe4\xc4\xd7\xfel'
2024-10-14 17:52:04.159 DEBUG (MainThread) [aiohomekit.controller.ip.connection] Connection HomeKitConnection(host='192.168.86.35', port=5001) lost.
2024-10-14 17:52:04.166 DEBUG (MainThread) [aiohomekit.controller.ip.connection] Weather Station [192.168.86.35:5001] (id=3D:55:CE:8D:7F:C1): Connecting to accessory failed: Connection closed; Retrying in 0 seconds
2024-10-14 17:52:04.652 WARNING (MainThread) [custom_components.localtuya.common] Missing device configuration for device_id 1702537170039f2aaae6
2024-10-14 17:52:04.917 DEBUG (MainThread) [aiohomekit.controller.ip.connection] Attempting connection to ['192.168.86.35']:5001
2024-10-14 17:52:04.925 DEBUG (MainThread) [aiohomekit.protocol.tlv] sending [
  6 (State): (1 bytes/<class 'bytearray'>) 0x01
  3 (PublicKey): (32 bytes/<class 'bytes'>) b'\x8a\xf0\xc5\xb5\rT\x97ox\xcbc\xf9\xbe\x1c\xf2\xfe\x18\xc0\xe6${\xa7\xe6Q\xc1\xd1f\xc4,\xbe\x93E'
]

2024-10-14 17:52:04.925 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.86.35: raw request: b'POST /pair-verify HTTP/1.1\r\nHost: 192.168.86.35\r\nContent-Length: 37\r\nContent-Type: application/pairing+tlv8\r\n\r\n\x06\x01\x01\x03 \x8a\xf0\xc5\xb5\rT\x97ox\xcbc\xf9\xbe\x1c\xf2\xfe\x18\xc0\xe6${\xa7\xe6Q\xc1\xd1f\xc4,\xbe\x93E'
2024-10-14 17:52:04.933 DEBUG (MainThread) [aiohomekit.controller.ip.connection] Connection HomeKitConnection(host='192.168.86.35', port=5001) lost.
2024-10-14 17:52:04.935 DEBUG (MainThread) [aiohomekit.controller.ip.connection] Weather Station [192.168.86.35:5001] (id=3D:55:CE:8D:7F:C1): Connecting to accessory failed: Connection closed; Retrying in 0 seconds
2024-10-14 17:52:05.501 WARNING (MainThread) [custom_components.localtuya.common] Missing device configuration for device_id bffa9c2163f89886a5mm8u
2024-10-14 17:52:06.061 DEBUG (MainThread) [aiohomekit.controller.ip.connection] Attempting connection to ['192.168.86.35']:5001
2024-10-14 17:52:06.069 DEBUG (MainThread) [aiohomekit.protocol.tlv] sending [
  6 (State): (1 bytes/<class 'bytearray'>) 0x01
  3 (PublicKey): (32 bytes/<class 'bytes'>) b"s\xd2\xd7\xc2\xb2\xc8ClxhiZI\xedM9X\xda<\xfa\xfa\xd1\x10\xde'\xa1\xac\xb6\xb6\xe2\x8a<"
]

2024-10-14 17:52:06.070 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.86.35: raw request: b"POST /pair-verify HTTP/1.1\r\nHost: 192.168.86.35\r\nContent-Length: 37\r\nContent-Type: application/pairing+tlv8\r\n\r\n\x06\x01\x01\x03 s\xd2\xd7\xc2\xb2\xc8ClxhiZI\xedM9X\xda<\xfa\xfa\xd1\x10\xde'\xa1\xac\xb6\xb6\xe2\x8a<"
2024-10-14 17:52:06.071 DEBUG (MainThread) [aiohomekit.controller.ip.connection] Connection HomeKitConnection(host='192.168.86.35', port=5001) lost.
2024-10-14 17:52:06.073 DEBUG (MainThread) [aiohomekit.controller.ip.connection] Weather Station [192.168.86.35:5001] (id=3D:55:CE:8D:7F:C1): Connecting to accessory failed: Connection closed; Retrying in 1 seconds
2024-10-14 17:52:08.033 DEBUG (MainThread) [aiohomekit.controller.ip.connection] Attempting connection to ['192.168.86.35']:5001
2024-10-14 17:52:08.049 DEBUG (MainThread) [aiohomekit.protocol.tlv] sending [
  6 (State): (1 bytes/<class 'bytearray'>) 0x01
  3 (PublicKey): (32 bytes/<class 'bytes'>) b'\xca\x84\x19\x979\xfb\x85\x17?\x89\xbe.H\x1fw"j}\xa4\xc9\xf0\xb2T1J]\xeby\xf2\xd8Sy'
]

2024-10-14 17:52:08.049 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.86.35: raw request: b'POST /pair-verify HTTP/1.1\r\nHost: 192.168.86.35\r\nContent-Length: 37\r\nContent-Type: application/pairing+tlv8\r\n\r\n\x06\x01\x01\x03 \xca\x84\x19\x979\xfb\x85\x17?\x89\xbe.H\x1fw"j}\xa4\xc9\xf0\xb2T1J]\xeby\xf2\xd8Sy'
2024-10-14 17:52:08.051 DEBUG (MainThread) [aiohomekit.controller.ip.connection] Connection HomeKitConnection(host='192.168.86.35', port=5001) lost.
2024-10-14 17:52:08.052 DEBUG (MainThread) [aiohomekit.controller.ip.connection] Weather Station [192.168.86.35:5001] (id=3D:55:CE:8D:7F:C1): Connecting to accessory failed: Connection closed; Retrying in 1 seconds
2024-10-14 17:52:09.663 WARNING (MainThread) [custom_components.localtuya.common] Missing device configuration for device_id 1702537170039f2aaae6
2024-10-14 17:52:09.676 WARNING (Recorder) [homeassistant.components.recorder.db_schema] State attributes for sensor.flightradar24_current_in_area exceed maximum size of 16384 bytes. This can cause database performance issues; Attributes will not be stored
2024-10-14 17:52:10.498 WARNING (MainThread) [custom_components.localtuya.common] Missing device configuration for device_id bffa9c2163f89886a5mm8u
2024-10-14 17:52:10.585 DEBUG (MainThread) [aiohomekit.controller.ip.connection] Attempting connection to ['192.168.86.35']:5001
2024-10-14 17:52:10.604 DEBUG (MainThread) [aiohomekit.protocol.tlv] sending [
  6 (State): (1 bytes/<class 'bytearray'>) 0x01
  3 (PublicKey): (32 bytes/<class 'bytes'>) b"\xec\xcf\xc1\x14\xc2\xf4\x81'BQ\rI\x92\x0c\xc1-d\xd9\xa9[\xf2s\xd09\xa1XT\x83\xbb\x1d\xd1\x1e"
]

2024-10-14 17:52:10.605 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.86.35: raw request: b"POST /pair-verify HTTP/1.1\r\nHost: 192.168.86.35\r\nContent-Length: 37\r\nContent-Type: application/pairing+tlv8\r\n\r\n\x06\x01\x01\x03 \xec\xcf\xc1\x14\xc2\xf4\x81'BQ\rI\x92\x0c\xc1-d\xd9\xa9[\xf2s\xd09\xa1XT\x83\xbb\x1d\xd1\x1e"
2024-10-14 17:52:10.606 DEBUG (MainThread) [aiohomekit.controller.ip.connection] Connection HomeKitConnection(host='192.168.86.35', port=5001) lost.
2024-10-14 17:52:10.607 DEBUG (MainThread) [aiohomekit.controller.ip.connection] Weather Station [192.168.86.35:5001] (id=3D:55:CE:8D:7F:C1): Connecting to accessory failed: Connection closed; Retrying in 2 seconds
2024-10-14 17:52:14.673 WARNING (MainThread) [custom_components.localtuya.common] Missing device configuration for device_id 1702537170039f2aaae6
bdraco commented 1 month ago

Can you try https://github.com/Jc2k/aiohomekit/pull/381 and see if you get a better error?

Bothygesen commented 1 month ago

Hi, not sure exactly what it is that you are asking me to do and how i will do it.

If you tell me in laymans terms what is needed i will do it..

Thx Bo

bdraco commented 2 weeks ago

Has the logged error changed on 2024.10.x?