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
73.56k stars 30.73k forks source link

Legrand Gateway - Homekit-controller - entities unavailable #97871

Closed Vrobenmat closed 1 year ago

Vrobenmat commented 1 year ago

The problem

Legrand smart light switches and sockets loaded through the Legrand Netatmo Gateway using homekit-controller - the entities remain unavailable, becoming available for a few seconds every minute or so.

The logs show the controller appearing to query the gateway, and then the connection drops. relevant log extract below. Possibly the gateway has some kind of overflow due to the large number of devices. Legrand's docs state the gateway can support 100 devices, here there are 92 paired.

Diagnostic and logs attached, showing pairing sequence and the query/drop/reconnect sequence every minute.

In 2023.7.x, entities remained available.

2023-08-05 23:38:47.399 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.1.228: raw request: b'GET /characteristics?id=150.11,124.10,111.10,100.10,100.19,28.12,85.9,138.12,113.10,18.10,97.10,141.10,18.19,22.10,59.11,100.12,91.9,36.9,22.19,19.11,9.10,140.11,154.10,24.10,114.10,101.10,90.10,13.10,13.19,101.19,90.19,18.12,142.11,22.12,102.11,127.10,52.10,131.10,41.10,118.19,13.12,15.9,90.12,101.12,104.11,54.10,144.10,133.10,120.10,109.10,109.19,14.10,93.10,69.10,148.10,28.9,14.19,3.19,138.9,3.10,118.12,16.10,147.11,150.10,136.11,71.10,71.19,20.10,31.10,109.12,134.11,110.10,100.9,97.19,14.12,3.12,94.11,33.10,123.10,112.10,33.19,18.9,71.12,95.11,114.19,110.12,97.12,111.11,21.11,22.9,140.10,105.10,129.10,116.10,33.12,10.10,65.10,113.11,101.9,90.9,13.9,114.12,139.11,142.10,63.10,12.10,102.10,143.11,89.10,12.19,89.19,51.10,27.10,118.9,145.11,146.10,29.10,106.10,95.10,109.9,29.19,12.12,14.9,89.12,55.10,3.9,110.19,107.11,132.10,108.10,108.19,2.10,57.10,147.10,136.10,71.9,112.19,29.12,97.9,69.11,59.10,149.10,125.10,138.10,19.10,33.9,108.12,85.10,85.19,112.12,114.9,20.11,21.10,141.11,47.10,126.10,91.10,36.10,36.19,91.19,85.12,9.11,154.11,49.10,139.10,104.10,128.10,115.10,38.10,12.9,143.10,89.9,36.12,91.12,105.11,10.11,65.11,145.10,121.10,26.10,63.11,29.9,15.10,15.19,144.11,133.11,134.10,110.9,27.11,93.11,107.10,94.10,118.10,108.9,28.19,28.10,138.19,43.10,122.10,146.11,112.9,15.12,106.11 HTTP/1.1\r\nHost: 192.168.1.228\r\n\r\n'

2023-08-05 23:38:47.430 DEBUG (MainThread) [aiohomekit.controller.ip.connection] Connection HomeKitConnection(host='192.168.1.228', port=5001) lost.

What version of Home Assistant Core has the issue?

core-2023.8.1

What was the last working version of Home Assistant Core?

core-2023.7.x

What type of installation are you running?

Home Assistant OS

Integration causing the issue

homekit-controller

Link to integration documentation on our website

No response

Diagnostics information

home-assistant.log config_entry-homekit_controller-301ec0f4e80c0a55ac8f81ff6c7321cc.json.txt

Example YAML snippet

No response

Anything in the logs that might be useful for us?

No response

Additional information

No response

home-assistant[bot] commented 1 year 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.

(message by CodeOwnersMention)


homekit_controller documentation homekit_controller source (message by IssueLinks)

Vrobenmat commented 1 year ago

In 2023.7.x, homekit_controller is querying less device detail, to which the gateway does respond with a status (i.e. doesn't disconnect)

The delta appears to be that 2023.8.x is also asking for iid's 12 & 19 for each aid which has them, where 2023.7.x does not. I guess the gateway craps out on those extra iid's.

The device(s) in question is an unwired remote switch, with 2 microswitches which be interpreted as on/off, up/down, or dim up/dim down. In normal Legrand usage, these remote switches are paired to a real switch, which does the actual lighting or socket control. 2023.7.x doesn't actually expose the microswitches, only the device and battery status. Exposing the remote switch microswitches would be useful in HA (what 2023.8.x is trying to do), but not critical as you can still control the real switch which is exposed with full detail. I'm guessing the apple hubs also don't query these addtional iid's. Weird on Legrand's part to expose something you can't ask detail on (or maybe its part of the spec, don't know enough about it.)

2023.8.x iid 1 = basic device info iid 9 = battery status iid 12 = Programmable Switch Event iid 19 = Programmable Switch Event

2023.7.x iid 1 = basic device info iid 9 = battery status

log 2023.7.x:

2023-08-06 01:04:44.030 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.1.228: raw request: b'GET /characteristics?id=150.11,124.10,100.10,111.10,85.9,113.10,18.10,97.10,141.10,22.10,36.9,59.11,91.9,19.11,9.10,140.11,154.10,13.10,114.10,101.10,90.10,24.10,142.11,102.11,127.10,41.10,131.10,52.10,15.9,104.11,54.10,144.10,109.10,120.10,133.10,14.10,28.9,3.10,148.10,93.10,138.9,69.10,16.10,71.10,150.10,147.11,136.11,31.10,110.10,20.10,100.9,134.11,94.11,33.10,112.10,123.10,18.9,95.11,22.9,21.11,111.11,129.10,116.10,140.10,105.10,10.10,13.9,65.10,101.9,90.9,113.11,139.11,142.10,63.10,12.10,102.10,89.10,143.11,51.10,27.10,118.9,145.11,146.10,29.10,106.10,109.9,95.10,14.9,3.9,55.10,107.11,132.10,108.10,2.10,57.10,71.9,147.10,136.10,97.9,69.11,59.10,138.10,125.10,149.10,19.10,33.9,85.10,114.9,20.11,21.10,141.11,36.10,126.10,91.10,47.10,9.11,154.11,38.10,128.10,115.10,139.10,104.10,49.10,12.9,89.9,143.10,105.11,10.11,65.11,145.10,121.10,15.10,29.9,26.10,63.11,110.9,144.11,134.10,133.11,27.11,28.10,118.10,107.10,108.9,94.10,93.11,43.10,122.10,112.9,146.11,106.11 HTTP/1.1\r\nHost: 192.168.1.228\r\n\r\n'
2023-08-06 01:04:44.507 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.1.228: raw response: bytearray(b'{"characteristics":[{"aid":154,"iid":10,"value":true},{"aid":154,"iid":11,"value":100},{"aid":150,"iid":10,"valu.....

relevant device diag:

{
        "aid": 3,
        "services": [
          {
            "iid": 1,
            "type": "0000003E-0000-1000-8000-0026BB765291",
            "characteristics": [
              {
                "type": "00000023-0000-1000-8000-0026BB765291",
                "iid": 2,
                "perms": [
                  "pr"
                ],
                "format": "string",
                "value": "Remote switch 26",
                "description": "Name",
                "maxLen": 64
              },
              {
                "type": "00000020-0000-1000-8000-0026BB765291",
                "iid": 3,
                "perms": [
                  "pr"
                ],
                "format": "string",
                "value": "Legrand",
                "description": "Manufacturer",
                "maxLen": 64
              },
              {
                "type": "00000021-0000-1000-8000-0026BB765291",
                "iid": 4,
                "perms": [
                  "pr"
                ],
                "format": "string",
                "value": "Remote switch",
                "description": "Model",
                "maxLen": 64
              },
              {
                "type": "00000030-0000-1000-8000-0026BB765291",
                "iid": 5,
                "perms": [
                  "pr"
                ],
                "format": "string",
                "value": "**REDACTED**",
                "description": "Serial Number",
                "maxLen": 64
              },
              {
                "type": "00000014-0000-1000-8000-0026BB765291",
                "iid": 6,
                "perms": [
                  "pw"
                ],
                "format": "bool",
                "description": "Identify"
              },
              {
                "type": "00000052-0000-1000-8000-0026BB765291",
                "iid": 7,
                "perms": [
                  "pr"
                ],
                "format": "string",
                "value": "60.0.0",
                "description": "Firmware Revision",
                "maxLen": 64
              },
              {
                "type": "00000220-0000-1000-8000-0026BB765291",
                "iid": 17,
                "perms": [
                  "pr"
                ],
                "format": "data",
                "value": "+nvrOqq+MxE="
              }
            ]
          },
          {
            "iid": 8,
            "type": "00000096-0000-1000-8000-0026BB765291",
            "characteristics": [
              {
                "type": "00000079-0000-1000-8000-0026BB765291",
                "iid": 9,
                "perms": [
                  "pr",
                  "ev"
                ],
                "format": "uint8",
                "value": 0,
                "description": "Status Low Battery"
              },
              {
                "type": "00000068-0000-1000-8000-0026BB765291",
                "iid": 10,
                "perms": [
                  "pr",
                  "ev"
                ],
                "format": "uint8",
                "value": 100,
                "description": "Battery Level",
                "unit": "percentage",
                "minValue": 0,
                "maxValue": 100,
                "minStep": 1
              }
            ]
          },
          {
            "iid": 11,
            "type": "00000089-0000-1000-8000-0026BB765291",
            "characteristics": [
              {
                "type": "00000073-0000-1000-8000-0026BB765291",
                "iid": 12,
                "perms": [
                  "pr",
                  "ev"
                ],
                "format": "uint8",
                "value": 0,
                "description": "Programmable Switch Event",
                "minValue": 0,
                "maxValue": 0,
                "minStep": 1
              },
              {
                "type": "00000023-0000-1000-8000-0026BB765291",
                "iid": 13,
                "perms": [
                  "pr"
                ],
                "format": "string",
                "value": "Button 1",
                "description": "Name",
                "maxLen": 64
              },
              {
                "type": "000000CB-0000-1000-8000-0026BB765291",
                "iid": 14,
                "perms": [
                  "pr"
                ],
                "format": "uint8",
                "value": 1,
                "description": "Service Label Index",
                "minValue": 1,
                "maxValue": 255,
                "minStep": 1
              }
            ],
            "linked": [
              15
            ]
          },
          {
            "iid": 18,
            "type": "00000089-0000-1000-8000-0026BB765291",
            "characteristics": [
              {
                "type": "00000073-0000-1000-8000-0026BB765291",
                "iid": 19,
                "perms": [
                  "pr",
                  "ev"
                ],
                "format": "uint8",
                "value": 0,
                "description": "Programmable Switch Event",
                "minValue": 0,
                "maxValue": 0,
                "minStep": 1
              },
              {
                "type": "00000023-0000-1000-8000-0026BB765291",
                "iid": 20,
                "perms": [
                  "pr"
                ],
                "format": "string",
                "value": "Button 2",
                "description": "Name",
                "maxLen": 64
              },
              {
                "type": "000000CB-0000-1000-8000-0026BB765291",
                "iid": 21,
                "perms": [
                  "pr"
                ],
                "format": "uint8",
                "value": 2,
                "description": "Service Label Index",
                "minValue": 1,
                "maxValue": 255,
                "minStep": 1
              }
            ],
            "linked": [
              22
            ]
          },
          {
            "iid": 15,
            "type": "000000CC-0000-1000-8000-0026BB765291",
            "characteristics": [
              {
                "type": "000000CD-0000-1000-8000-0026BB765291",
                "iid": 16,
                "perms": [
                  "pr"
                ],
                "format": "uint8",
                "value": 1,
                "description": "Service Label Namespace"
              }
            ]
          },
          {
            "iid": 22,
            "type": "000000CC-0000-1000-8000-0026BB765291",
            "characteristics": [
              {
                "type": "000000CD-0000-1000-8000-0026BB765291",
                "iid": 23,
                "perms": [
                  "pr"
                ],
                "format": "uint8",
                "value": 1,
                "description": "Service Label Namespace"
              }
            ]
          }
        ]
      }
bdraco commented 1 year ago

We should block Programmable Switch Event from being queried. Its event only anyways

bdraco commented 1 year ago

@Vrobenmat great job on the analysis

Nice to get an issue report where I don't have to ask 20 questions.

Vrobenmat commented 1 year ago

Your welcome, and thanks for the fix! Saw there were quite some changes due to the event entities, figured a downgrade and test would be easiest with the kit right in front of me.