Not able to connect to device after successfully pairing

[jc2k]

Not able to connect to device after successfully pairing

[Jc2k]

Use outside of home-assistant isn't really tested. There is a CLI tool, but I do most of my testing through a dev copy of home-assistant TBH.

Apparently you can do --log DEBUG, but I don't remember testing it.

For testing in HA you need to turn on debug logs in home assistant to see any useful logs. For homekit_controller you need logging for homeassistant.components.homekit_controller and aiohomekit set to DEBUG. Sorry I can't remember the syntax for this but it should be in the home assistant docs.

(There is some work going on upstream to let you enable these logs per integration from within the UI, might make it into Feb but i think Mar now unfortunately. Obviously doesn't help right now, but worth knowing going forwards).

When a pairing is successful it should create a pairing file on your machine with the encryption keys. It looks like that is ~/.local/share/aiohomekit/pairing.json (XDG_DATA_HOME). It looks like it will create the aiohomekit folder, but it might not make .local/share if its not already there.

The state you describe is probably that the device thinks its paired, and you can only have 1 pairing at a time, so it doesn't show up in homekit aware discovery tools and/or the device is crashing when we try to talk to it. Some of them have really crap JSON parsers and don't actually "parse" HTTP they just rely on the iOS format not changing. So it's possible we aren't matching byte for byte some obscure part of HAP. Last time it was the presence of spaces in the JSON between keys and values. Scandalous i know.

What device are we dealing with out of interest?

[jorgnyg]

@Jc2k The path you mentioned for the pairing.json set me in the right direction at least regarding the initial problem I faced. Figured out I had the file at wrong location, so the CLI commands like list-pairings and accessories now gives the expected response.

It now provides a state/value response, but the weird thing is that the response seems to always be data gathered at the point of the pairing phase. Running the watch command gives only fixed values even if values on the device itself has changed. It's like requesting information from the device at a fixed point in time. This also reflects the behaviour I observed in HA with the HomeKit Controller integration. In that case, restarting my HA instance (with the integration working correctly) would make the device sensor data read fixed values from the period before the restart.

My ultimate goal is to somehow control the device and not only read sensor data.
Will try to enable debug logs for both services, and report back if I find anything interesting. Thank you so far!

Here's information about the device

1.1: >accessory-information<
  1.2:  () >identify< [pw]
  1.3: Smartmi () >manufacturer< [pr]
  1.4: Smartmi Airpurifier P1 () >model< [pr]
  1.5: Smartmi Airpurifier P1 () >name< [pr]
  1.6: 100025123003BA () >serial-number< [pr]
  1.7: 1.0.7 () >firmware.revision< [pr]
1.8: >service<
  1.9: 1.1.0 () >version< [pr]
1.10: >air-purifier<
  1.11: 1 () >active< [pr,pw,ev]
  1.12: 2 () >air-purifier.state.current< [pr,ev]
  1.13: 1 () >air-purifier.state.target< [pr,pw,ev]
  1.14: 100.0 () >rotation.speed< [pr,pw,ev]
  1.15: air purifier () >name< [pr]
1.16: >air-quality<
  1.17: 0 () >air-quality< [pr,ev]
  1.18: 1.0 () >density.pm25< [pr,ev]
  1.19: air quality sensor () >name< [pr]
1.20: >filter-maintenance<
  1.21: 0 () >filter.change-indication< [pr,ev]
  1.22: 89.0 () >filter.life-level< [pr,ev]
  1.23: filter maintenance () >name< [pr]
1.24: >Unknown Service: 2E36328D-9B54-4884-B873-6AC8CD8D9241<
  1.25:  () >Unknown Characteristic 8AAD42A0-CEC9-4542-B49F-1DBF4BD6AA04< [pw]
  1.26: 0 () >Unknown Characteristic 87F14350-E02D-4D77-9A96-0B4658C805F5< [pr,ev]
  1.27: nedhywwbir5vbypd () >Unknown Characteristic 7645A55F-9CD9-492F-BFFE-C28D9963BDDE< [pr]
  1.28: 56025274e8db84270804 () >Unknown Characteristic E6608527-6537-41FB-A75F-823B2E96CC72< [pr]

[Jc2k]

So in Home Assistant there is currently a known bug where at start up the cached data from pairing time is inadvertently loaded into the state machine. It then proceeds to poll (and watch) and it does eventually update. I have close to 100 entities shared between 5 or so pairings and I don't see this stale data other than blips on graphs.

If polling is failing for you, and events aren't working for you, this would explain why you see stale data in Home Assistant.

The same is not true for aiohomekit itself. The output you pasted is generated directly from a /accessories HTTP request, so i'm a bit puzzled by why its stale - unless it really is what the device is returning. Some of these devices have incredibly broken HomeKit stacks, unable to generate valid JSON or parse valid JSON. So really no level of broken accessory would surprise me.

It's going to be hard to comment further without debug logs - so good luck getting them!

[Jc2k]

@jorgnyg Any luck getting the debug logs?

[jorgnyg]

@Jc2k I'm able to retrieve logs, but it's really hard to get anything valuable out of it. It never says the device is "unavailable", but stale data is often reported in. So based on logs everything is seemingly looking fine, except the values itself.

However, when adding the device in HA with HomeKit pin, it now says "Invalid flow specified". Closing the popup results in the device being added anyway. It also has a button entity called "Identify", which I've never seen before. This behaviour is very similar to this one https://community.home-assistant.io/t/hunter-simpleconnect-issue/391201

This is clearly a device with HomeKit poorly integrated..
Added logs from the pairing process.

Logs

2022-02-11 20:10:20 DEBUG (MainThread) [homeassistant.components.homekit_controller.config_flow] Discovered device Smartmi Airpurifier P1 (Smartmi Airpurifier P1 - 2B:B0:96:86:6E:15)
2022-02-11 20:10:21 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection] [140093955411104] Sending {"id": 46, "type": "result", "success": true, "result": [{"flow_id": "346605df193cbd5a83b6cc2fe14b6e9a", "handler": "homekit_controller", "context": {"source": "zeroconf", "unique_id": "2b:b0:96:86:6e:15", "title_placeholders": {"name": "Smartmi Airpurifier P1"}}, "step_id": "pair"}]}
2022-02-11 20:10:21 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection] [140093955411104] Received {'type': 'manifest/get', 'integration': 'homekit_controller', 'id': 48}
2022-02-11 20:10:21 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection] [140093955411104] Sending {"id": 48, "type": "result", "success": true, "result": {"domain": "homekit_controller", "name": "HomeKit Controller", "config_flow": true, "documentation": "https://www.home-assistant.io/integrations/homekit_controller", "requirements": ["aiohomekit==0.6.11"], "zeroconf": ["_hap._tcp.local."], "after_dependencies": ["zeroconf"], "codeowners": ["@Jc2k", "@bdraco"], "iot_class": "local_push", "is_built_in": true}}
2022-02-11 20:10:24 DEBUG (MainThread) [aiohomekit.controller.ip.connection] Starting reconnect loop to 192.168.0.148:80
2022-02-11 20:10:24 DEBUG (MainThread) [aiohomekit.controller.ip.connection] Attempting connection to 192.168.0.148:80
2022-02-11 20:10:25 DEBUG (MainThread) [aiohomekit.protocol.tlv] sending [
2022-02-11 20:10:25 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.0.148: raw request: b'POST /pair-setup HTTP/1.1\r\nHost: 192.168.0.148\r\nContent-Length: 6\r\nContent-Type: application/pairing+tlv8\r\n\r\n\x06\x01\x01\x00\x01\x00'
2022-02-11 20:10:25 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.0.148: raw response: bytearray(b'\x06\x01\x02\x03\xff_\xaa\xf1\xed\x18\xe1\xe6W\xf6;\xdcM\xc5\xa4}\'f\xeb#\x17\xb1\xfd0G\x11w\x9a\x81\xce\x82t\x83S\x97\xb4\xdf\xec]...)
2022-02-11 20:10:25 DEBUG (MainThread) [aiohomekit.protocol.tlv] receiving [
2022-02-11 20:10:32 DEBUG (MainThread) [aiohomekit.protocol.tlv] sending [
2022-02-11 20:10:32 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.0.148: raw request: b'POST /pair-setup HTTP/1.1\r\nHost: 192.168.0.148\r\nContent-Length: 457\r\nContent-Type: application/pairing+tlv8\r\n\r\n\x06\x01\x03\x03\xff\x11 \xfd\xcc\x86\x83C\xa8\xdf+\x04\xe5\xbdb\'\xa3y\xe41\xb7\xbc\xe4\xcaU\xc9\xf8\xae\x0c\xa7z4\xadd\x82\xfeTR$\x97l\x9b(\xe9\xe6\x11\x97BC\xad\xea\x17\xcd\x10Uq3\xacd\xecn\x7f\xbb\x861\xbd\xa25L\xfe8$5\xb9t4v\nF\xe5\xa4\tM\xaa\xf9\xf1&\xecm\xba|\r~\x8dh\xf4\xf2[\x81^|\xdb\xd2>\xd6\xedG$=^g\x8f2<\xa74\xf1\xf0\xfc\xf4|\xf6\xdd\xb3\rhC\x01\xff\xc0\x94\x9b|\xad\x1c\x1f\xf4q\x96\xa4\xe9\x99\xf5f\x1d\x89\xce\xc8$\xe8\x15\xaeIr\xb8S3\x8ei[z\xcb|f\xae\x1b\xb5\xbf\xf0\xd3O\x8d\xbb\r\xc6\xc1{\xa6\xb1\xa6\x8a\x1a\xd0\'\x18\x9f\x923\xaa_i\xd1a/\xde\x9dI\xdc\xdfs\x02\xa1\xe6b@2w\xfe\x0c.\xb5\xd9\x06Q\x8e\xfd\xfa\x0c\xc1\'\x9d\x87\x19\x8bl\x03j\xfdp\x8a\xcaH5Z8"\xc77\xc3\xc77\xc0\xa09Rs\xb0\xba2\x84Rtq5\xa6\xa4\x03\x81\x10N\x80\x9b\x93\x04\xc6jl\xc7\x83\xcd\xcd\xfc\xbao\x8fL\x86\xdf\xcc\xf1\xdb\x98\x1c{\x82)\x15\xb1\x89.\xa2\xf48\x7f\x89\x06\xda|\xfe\x83\x80\xc4PV\x81=\r\tQ\x8bF\xediT\x06\xe7+\xa2\xf9\xd2\xc9L\x1f\xf9\x1f\x0e\xeaN\x83\xbf\x94Y\xb0%\xb2OB)G\x10\xbb\x9d\x8al\x90\xbd\xb3\x08r\x88B\xda\xa87\xb4s\xf7=\xa1\x0e\x02\xb3\xe1\xaa\xef*<@\x92\xaaL,\xfa\xdd;\xe3\\<\xf0\x19\xd7+@i\xcbF\x8b\x04@A\xa7E\x85\x8al\x8b\x01\x88{.\xb6\xb4N\x13\xce\xfb\x8b\xb8\x10\x16\xb5A\xf7\xb0\xcc\xae\xda\xed\xaf2\xa5L\xa8\xc6xb\xe0_\xc5\xef\x98\x81\xbb\xe9\x0b\xc2P\xceP\xbd\xad\xa3\t97\xf3\xd5\xd9\x03\x8f\xf5WJ'
2022-02-11 20:10:32 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.0.148: raw response: bytearray(b'\x06\x01\x04\x04@\x99_c\x802c\xf3\x9e\xec\xd9\xcd<3q/\xdc\xb0#.\xffO\x98\x1b\xbbjz%1o\xa7\x08\\\x18m\xb5z\xf6\x8dA\xc4\x1a\x0eZ`H9U\x99*\xf4y\xb3\xf7m^8\xd1GK\x18v\xd1\x03\x1b')
2022-02-11 20:10:32 DEBUG (MainThread) [aiohomekit.protocol.tlv] receiving [
2022-02-11 20:10:32 DEBUG (MainThread) [aiohomekit.protocol.tlv] sending [
2022-02-11 20:10:32 DEBUG (MainThread) [aiohomekit.protocol.tlv] sending [
2022-02-11 20:10:32 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.0.148: raw request: b'POST /pair-setup HTTP/1.1\r\nHost: 192.168.0.148\r\nContent-Length: 159\r\nContent-Type: application/pairing+tlv8\r\n\r\n\x06\x01\x05\x05\x9a\xb2\xd7BW"`C[\xdaad\xa6A\xdf"A\x17\x8c\xdb\x08\x1a\\>n\xe4\xba\x1f\x9b\x03T*n\xc2\x97\xb3\xc8\xe8\x88\xcb\x16J\xf29R\xc1}\xb8X\xbc\xa5-\xaf\xfevqPma\x14\x12\x9a\xcd\xfe3A\xe7\xaf\x14\x08qr\x06\xeb/\\\xa3\xb2Qf\x08N\xa0\xee*\xf3\x8d\xdc*M\x19qZ\xe2\x9c\xe7,s\x94\xf6\x02K=\x08\xa2\xc9\xbe\xab&|\xf4\x03\x88S\xe9Z\x052\x87K/5\xd4\xe2!N\xbe8\xb7\xd8\xc6\xb8cK\x04H\xaeU9\xf8\xc4\x82\xae\xe5\xbd\xd9\x96\x16\xe9\xd9I\xdeO\xb6H'
2022-02-11 20:10:33 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.0.148: raw response: bytearray(b'\x06\x01\x06\x05\x872E\xc3\xf4\x89/\xbblakT_l\x1e|\x8e\x84\x9b^\x11\xeaYJL\xdfb\xc0P\x9f\x94\xae\x92cN\xfe\xc3\xc1m\xdc\x92\xb2\x9esM\xd4s\x1b68\xe1V\x1b\x9e~\x83\\\xe1uo;\x89/i\xda_W\x1e*bV"\xa3x:\x0c\x95\xd7(/\x1dnX\xf1\xc6\xeb2\xcf\xa3r&\xdaq\xf9\x8b\xf4\xecB\x01\xff\x03\xba \xe3\xc6\xb4xmiM\x98\x96}\x13c\x8b\x06a\xb9\x00-\x81\xa2\xecoF\xb1\xc2\xfcwJC]\xe8mH')
2022-02-11 20:10:33 DEBUG (MainThread) [aiohomekit.protocol.tlv] receiving [
2022-02-11 20:10:33 DEBUG (MainThread) [aiohomekit.protocol.tlv] receiving [
2022-02-11 20:10:33 DEBUG (MainThread) [aiohomekit.controller.ip.connection] Connection HomeKitConnection(host='192.168.0.148', port=80) lost.
2022-02-11 20:10:33 DEBUG (MainThread) [aiohomekit.controller.ip.connection] Starting reconnect loop to 192.168.0.148:80
2022-02-11 20:10:33 DEBUG (MainThread) [aiohomekit.controller.ip.connection] Attempting connection to 192.168.0.148:80
2022-02-11 20:10:33 DEBUG (MainThread) [aiohomekit.protocol.tlv] sending [
2022-02-11 20:10:33 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.0.148: raw request: b'POST /pair-verify HTTP/1.1\r\nHost: 192.168.0.148\r\nContent-Length: 37\r\nContent-Type: application/pairing+tlv8\r\n\r\n\x06\x01\x01\x03 \xa8?wBf\xb2\xbd\xd7\xcfk\xbb\xfez\\P\x0b,\x960\xd6#B\xa74\x99O/\x9dn\xce\xd6='
2022-02-11 20:10:33 DEBUG (MainThread) [homeassistant.components.homekit_controller.config_flow] Discovered device Smartmi Airpurifier P1 (Smartmi Airpurifier P1 - 2B:B0:96:86:6E:15)
2022-02-11 20:10:33 DEBUG (MainThread) [homeassistant.components.homekit_controller.config_flow] HomeKit device 2B:B0:96:86:6E:15 ignored as already paired
2022-02-11 20:10:33 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.0.148: raw response: bytearray(b'\x06\x01\x02\x03 \xc7\xf0\xdf\x9a\x9f\x07]\x85U\x8c=\xd7%m\x05\x0c\xb7\x14\x9ca%\xeaN!1\x05\xab\x07\xf1k\xcc\x11\x05e\xb3U\xe7d\x18>)C[\xd2\x01\xe2!Vm.\xc6\x88F\x8dY\xf8\xac=)\xdc\x13\xb2\xb4\xbby\xb0\xb2a\xb2\xde\xa2;\xc0gw\x83\xe2\x90\x06\x96\xd6\x85\xda\xb2\xb4Hz\x8c\x97D\x19\xcf^\x80e\x83[*\xfd\xdd\xc5\xcak\x13\xb4Vo~\x06\x12/\xa4\xf7\x85\xe8\xf5\xac@\x18g~\x0b\\\xfd#\xf2\xeb\xa2x\x05\x95\xd5\xfd\xd8\xe4')
2022-02-11 20:10:33 DEBUG (MainThread) [aiohomekit.protocol.tlv] receiving [
2022-02-11 20:10:33 DEBUG (MainThread) [aiohomekit.protocol.tlv] receiving [
2022-02-11 20:10:33 DEBUG (MainThread) [aiohomekit.protocol.tlv] sending [
2022-02-11 20:10:33 DEBUG (MainThread) [aiohomekit.protocol.tlv] sending [
2022-02-11 20:10:33 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.0.148: raw request: b'POST /pair-verify HTTP/1.1\r\nHost: 192.168.0.148\r\nContent-Length: 125\r\nContent-Type: application/pairing+tlv8\r\n\r\n\x06\x01\x03\x05x\x16\xd1\x9c\x97F\x03\t\xbb\xd1\xc0\x98\xbc\xf2\x9e.\xc6\x18\xbd\xf8\xe8\xea\xe1:h\xb8\x85\x8a\x84\xd3`\x81\xef\xc9\xb1y\xa3\x01\xf5\x10\x1e\x00\r\xa0\xc5\xcbK\x14\xec\xe0`\\\xee\\\xb2*\xdb\xc7\xfb\x90\xb3\x89j\xb5hoe\xc1\xee~\xd1c\xbe\xb3\xa8\x93\xd1\x03\xa2\xbf\x88<\xb8\x8b\xec\xe0"\xb4\xb8)\xd7\xa6\xa8g|\n\xe6\xd0\xcb=e\x03\xd2\xe9\xbc\xf8\x9e\xbf8\x12\x91\xd8\xfb~j\xe0\xba\xc5\xcd.\xf8'
2022-02-11 20:10:33 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.0.148: raw response: bytearray(b'\x06\x01\x04')
2022-02-11 20:10:33 DEBUG (MainThread) [aiohomekit.protocol.tlv] receiving [
2022-02-11 20:10:33 DEBUG (MainThread) [aiohomekit.controller.ip.connection] Secure connection to 192.168.0.148:80 established
2022-02-11 20:10:33 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.0.148: raw request: b'GET /accessories HTTP/1.1\r\nHost: 192.168.0.148\r\n\r\n'
2022-02-11 20:10:33 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.0.148: raw response: bytearray(b'{"accessories":[{"aid":1,"services":[{"iid":1,"type":"3E","characteristics":[{"iid":2,"type":"14","perms":["pw"],"ev":false,"format":"bool"},{"iid":3,"value":"Smartmi","type":"20","perms":["pr"],"ev":false,"format":"string"},{"iid":4,"value":"Smartmi Airpurifier P1","type":"21","perms":["pr"],"ev":false,"format":"string"},{"iid":5,"value":"Smartmi Airpurifier P1","type":"23","perms":["pr"],"ev":false,"format":"string"},{"iid":6,"value":"100025123003BA","type":"30","perms":["pr"],"ev":false,"format":"string"},{"iid":7,"value":"1.0.7","type":"52","perms":["pr"],"ev":false,"format":"string"}]},{"iid":8,"type":"A2","characteristics":[{"iid":9,"value":"1.1.0","type":"37","perms":["pr"],"ev":false,"format":"string"}]},{"iid":10,"type":"BB","linked":[16,20],"characteristics":[{"iid":11,"value":1,"type":"B0","perms":["pr","pw","ev"],"ev":false,"format":"uint8","minValue":0,"maxValue":1,"minStep":1},{"iid":12,"value":2,"type":"A9","perms":["pr","ev"],"ev":false,"format":"uint8","minValue":0,"maxValue":2,"minStep":1},{"iid":13,"value":1,"type":"A8","perms":["pr","pw","ev"],"ev":false,"format":"uint8","minValue":0,"maxValue":1,"minStep":1},{"iid":14,"value":100.00000,"type":"29","perms":["pr","pw","ev"],"ev":false,"format":"float","minValue":0.00000,"maxValue":100.00000,"minStep":1.00000,"unit":"percentage"},{"iid":15,"value":"air purifier","type":"23","perms":["pr"],"ev":false,"format":"string"}]},{"iid":16,"type":"8D","characteristics":[{"iid":17,"value":1,"type":"95","perms":["pr","ev"],"ev":false,"format":"uint8","minValue":0,"maxValue":5,"minStep":1},{"iid":18,"value":1.00000,"type":"C6","perms":["pr","ev"],"ev":false,"format":"float","minValue":0.00000,"maxValue":1000.00000},{"iid":19,"value":"air quality sensor","type":"23","perms":["pr"],"ev":false,"format":"string"}]},{"iid":20,"type":"BA","characteristics":[{"iid":21,"value":0,"type":"AC","perms":["pr","ev"],"ev":false,"format":"uint8","minValue":0,"maxValue":1,"minStep":1},{"iid":22,"value":86.00000,"type":"AB","perms":["pr","ev"],"ev":false,"format":"float","minValue":0.00000,"maxValue":100.00000,"minStep":1.00000},{"iid":23,"value":"filter maintenance","type":"23","perms":["pr"],"ev":false,"format":"string"}]},{"iid":24,"type":"2E36328D-9B54-4884-B873-6AC8CD8D9241","hidden":true,"characteristics":[{"iid":25,"type":"8AAD42A0-CEC9-4542-B49F-1DBF4BD6AA04","perms":["pw"],"ev":false,"format":"string"},{"iid":26,"value":0,"type":"87F14350-E02D-4D77-9A96-0B4658C805F5","perms":["pr","ev"],"ev":false,"format":"int"},{"iid":27,"value":"nedhywwbir5vbypd","type":"7645A55F-9CD9-492F-BFFE-C28D9963BDDE","perms":["pr"],"ev":false,"format":"string"},{"iid":28,"value":"56025274e8db84270804","type":"E6608527-6537-41FB-A75F-823B2E96CC72","perms":["pr"],"ev":false,"format":"string"}]}]}]}')
2022-02-11 20:10:33 INFO (MainThread) [homeassistant.setup] Setting up homekit_controller
2022-02-11 20:10:33 INFO (MainThread) [homeassistant.setup] Setup of domain homekit_controller took 0.0 seconds
2022-02-11 20:10:33 DEBUG (MainThread) [aiohomekit.controller.ip.connection] Starting reconnect loop to 192.168.0.148:80
2022-02-11 20:10:33 DEBUG (MainThread) [aiohomekit.controller.ip.connection] Attempting connection to 192.168.0.148:80
2022-02-11 20:10:33 DEBUG (MainThread) [aiohomekit.protocol.tlv] sending [
2022-02-11 20:10:33 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.0.148: raw request: b'POST /pair-verify HTTP/1.1\r\nHost: 192.168.0.148\r\nContent-Length: 37\r\nContent-Type: application/pairing+tlv8\r\n\r\n\x06\x01\x01\x03 a\xf5\xa9\xbb\x1c+\\\xd7\xa1"Y\xab\x08[*\x8a\x9e;A\xdf\xbcza\xb3\xa4\x05\'\x84\x11d\xf8\r'
2022-02-11 20:10:33 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.0.148: raw response: bytearray(b'\x06\x01\x02\x03 \xd5Q\x85\xadl\xb5\xe8\xdf=j_<\xf4\xb6Q\xf9v\xdc*\xef\x16\x0efC\xfe-\x0e\x01u\x14\xb0|\x05e\xf1\x00\xe5\xc8\x9d\x18Y\xfd(\x06Yd\xdd\xd4B\xa0\x96\x1e\x98\x8a\xdc\x94>\xbb\xf9\xe0\xfc\xea\x8d\xc4\xbf:n\xe0f\x93Z\x8cV\xcd\'jK\xa3\xdca\xa1\x0b\xda\x17\xd4\x1f\x17vu\x0cdH\xd1Z\xd7\x8a\xf3\xc7XjrS\xee\xa7\xf2\xa0\x14\x16\x85\xe4\x9c@EOk\x81\x94\x14\xea\xa6pN\xd1\xf1\x93\xe1\xfd\xed\x9a6I\x82"\xb8U')
2022-02-11 20:10:33 DEBUG (MainThread) [aiohomekit.protocol.tlv] receiving [
2022-02-11 20:10:33 DEBUG (MainThread) [aiohomekit.protocol.tlv] receiving [
2022-02-11 20:10:33 DEBUG (MainThread) [aiohomekit.protocol.tlv] sending [
2022-02-11 20:10:33 DEBUG (MainThread) [aiohomekit.protocol.tlv] sending [
2022-02-11 20:10:33 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.0.148: raw request: b'POST /pair-verify HTTP/1.1\r\nHost: 192.168.0.148\r\nContent-Length: 125\r\nContent-Type: application/pairing+tlv8\r\n\r\n\x06\x01\x03\x05x\xfb4\xbc\xd4b\x0f\x08AQ\x9e!\xa1\xa3C{\x9f\xd5\xecK^\xd5\xe5y\x7f\xab\xba&\xf0\xa1n~\x84$\xa3yx\xcb5\xf0\x8d\x0f\x05\xb1H\xf7`!\xbe\xeb\xb7\xf6\xde\x03\xce\xd0D\x02\xa4D\xc5\xa4\x84d\xc40+\xcc\xf8\xcd\xd3\xa9\xa1\x84\x8b\xbe;pe\xe6D\x89\xedp\xea\t\x8e\xe74\xd0\xf1\xf9\xe0\xe5\x84\xf6\xc7\xba\xd5\xcbV\xc3\xda\x06\xa9\x93\xce\xa2\x7f*\xf3\xd3{\x8c>\xf7hD!\xbc\xb6'
2022-02-11 20:10:33 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.0.148: raw response: bytearray(b'\x06\x01\x04')
2022-02-11 20:10:33 DEBUG (MainThread) [aiohomekit.protocol.tlv] receiving [
2022-02-11 20:10:33 DEBUG (MainThread) [aiohomekit.controller.ip.connection] Secure connection to 192.168.0.148:80 established
2022-02-11 20:10:33 DEBUG (MainThread) [homeassistant.components.homekit_controller.connection] Called async_set_available_state with True for 2B:B0:96:86:6E:15
2022-02-11 20:10:33 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.0.148: raw request: b'GET /accessories HTTP/1.1\r\nHost: 192.168.0.148\r\n\r\n'
2022-02-11 20:10:33 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.0.148: raw response: bytearray(b'{"accessories":[{"aid":1,"services":[{"iid":1,"type":"3E","characteristics":[{"iid":2,"type":"14","perms":["pw"],"ev":false,"format":"bool"},{"iid":3,"value":"Smartmi","type":"20","perms":["pr"],"ev":false,"format":"string"},{"iid":4,"value":"Smartmi Airpurifier P1","type":"21","perms":["pr"],"ev":false,"format":"string"},{"iid":5,"value":"Smartmi Airpurifier P1","type":"23","perms":["pr"],"ev":false,"format":"string"},{"iid":6,"value":"100025123003BA","type":"30","perms":["pr"],"ev":false,"format":"string"},{"iid":7,"value":"1.0.7","type":"52","perms":["pr"],"ev":false,"format":"string"}]},{"iid":8,"type":"A2","characteristics":[{"iid":9,"value":"1.1.0","type":"37","perms":["pr"],"ev":false,"format":"string"}]},{"iid":10,"type":"BB","linked":[16,20],"characteristics":[{"iid":11,"value":1,"type":"B0","perms":["pr","pw","ev"],"ev":false,"format":"uint8","minValue":0,"maxValue":1,"minStep":1},{"iid":12,"value":2,"type":"A9","perms":["pr","ev"],"ev":false,"format":"uint8","minValue":0,"maxValue":2,"minStep":1},{"iid":13,"value":1,"type":"A8","perms":["pr","pw","ev"],"ev":false,"format":"uint8","minValue":0,"maxValue":1,"minStep":1},{"iid":14,"value":100.00000,"type":"29","perms":["pr","pw","ev"],"ev":false,"format":"float","minValue":0.00000,"maxValue":100.00000,"minStep":1.00000,"unit":"percentage"},{"iid":15,"value":"air purifier","type":"23","perms":["pr"],"ev":false,"format":"string"}]},{"iid":16,"type":"8D","characteristics":[{"iid":17,"value":1,"type":"95","perms":["pr","ev"],"ev":false,"format":"uint8","minValue":0,"maxValue":5,"minStep":1},{"iid":18,"value":1.00000,"type":"C6","perms":["pr","ev"],"ev":false,"format":"float","minValue":0.00000,"maxValue":1000.00000},{"iid":19,"value":"air quality sensor","type":"23","perms":["pr"],"ev":false,"format":"string"}]},{"iid":20,"type":"BA","characteristics":[{"iid":21,"value":0,"type":"AC","perms":["pr","ev"],"ev":false,"format":"uint8","minValue":0,"maxValue":1,"minStep":1},{"iid":22,"value":86.00000,"type":"AB","perms":["pr","ev"],"ev":false,"format":"float","minValue":0.00000,"maxValue":100.00000,"minStep":1.00000},{"iid":23,"value":"filter maintenance","type":"23","perms":["pr"],"ev":false,"format":"string"}]},{"iid":24,"type":"2E36328D-9B54-4884-B873-6AC8CD8D9241","hidden":true,"characteristics":[{"iid":25,"type":"8AAD42A0-CEC9-4542-B49F-1DBF4BD6AA04","perms":["pw"],"ev":false,"format":"string"},{"iid":26,"value":0,"type":"87F14350-E02D-4D77-9A96-0B4658C805F5","perms":["pr","ev"],"ev":false,"format":"int"},{"iid":27,"value":"nedhywwbir5vbypd","type":"7645A55F-9CD9-492F-BFFE-C28D9963BDDE","perms":["pr"],"ev":false,"format":"string"},{"iid":28,"value":"56025274e8db84270804","type":"E6608527-6537-41FB-A75F-823B2E96CC72","perms":["pr"],"ev":false,"format":"string"}]}]}]}')
2022-02-11 20:10:33 DEBUG (MainThread) [homeassistant.components.homekit_controller.connection] Migrating device registry entries for pairing 2B:B0:96:86:6E:15
2022-02-11 20:10:33 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=homekit_controller>
2022-02-11 20:10:33 INFO (MainThread) [homeassistant.components.button] Setting up button.homekit_controller
2022-02-11 20:10:33 INFO (MainThread) [homeassistant.components.sensor] Setting up sensor.homekit_controller
2022-02-11 20:10:33 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection] [140093955411104] Sending {"id": 37, "type": "event", "event": {"event_type": "component_loaded", "data": {"component": "homekit_controller"}, "origin": "LOCAL", "time_fired": "2022-02-11T19:10:33.993590+00:00", "context": {"id": "c6103a6bb86e12686064cbb5b86c772d", "parent_id": null, "user_id": null}}}
2022-02-11 20:10:34 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection] [140093955411104] Sending {"id": 43, "type": "event", "event": {"event_type": "component_loaded", "data": {"component": "homekit_controller"}, "origin": "LOCAL", "time_fired": "2022-02-11T19:10:33.993590+00:00", "context": {"id": "c6103a6bb86e12686064cbb5b86c772d", "parent_id": null, "user_id": null}}}
2022-02-11 20:10:34 INFO (MainThread) [homeassistant.helpers.entity_registry] Registered new button.homekit_controller entity: button.smartmi_airpurifier_p1_identify
2022-02-11 20:10:34 INFO (MainThread) [homeassistant.helpers.entity_registry] Registered new sensor.homekit_controller entity: sensor.smartmi_airpurifier_p1_air_quality
2022-02-11 20:10:34 INFO (MainThread) [homeassistant.helpers.entity_registry] Registered new sensor.homekit_controller entity: sensor.smartmi_airpurifier_p1_pm2_5_density
2022-02-11 20:10:34 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.0.148: raw request: b'PUT /characteristics HTTP/1.1\r\nHost: 192.168.0.148\r\nContent-Length: 50\r\nContent-Type: application/hap+json\r\n\r\n{"characteristics":[{"aid":1,"iid":17,"ev":true}]}'
2022-02-11 20:10:34 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.0.148: raw response: bytearray(b'')
2022-02-11 20:10:34 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.0.148: raw request: b'PUT /characteristics HTTP/1.1\r\nHost: 192.168.0.148\r\nContent-Length: 50\r\nContent-Type: application/hap+json\r\n\r\n{"characteristics":[{"aid":1,"iid":18,"ev":true}]}'
2022-02-11 20:10:34 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.0.148: raw response: bytearray(b'')
2022-02-11 20:10:34 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.0.148: raw request: b'PUT /characteristics HTTP/1.1\r\nHost: 192.168.0.148\r\nContent-Length: 79\r\nContent-Type: application/hap+json\r\n\r\n{"characteristics":[{"aid":1,"iid":17,"ev":true},{"aid":1,"iid":18,"ev":true}]}'
2022-02-11 20:10:34 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.0.148: raw response: bytearray(b'')
2022-02-11 20:10:34 DEBUG (MainThread) [homeassistant.components.homekit_controller.connection] Starting HomeKit controller update: 2B:B0:96:86:6E:15
2022-02-11 20:10:34 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.0.148: raw request: b'GET /characteristics?id=1.17,1.18 HTTP/1.1\r\nHost: 192.168.0.148\r\n\r\n'
2022-02-11 20:10:34 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.0.148: raw response: bytearray(b'{"characteristics":[{"aid":1,"iid":17,"value":1},{"aid":1,"iid":18,"value":1.00000}]}')
2022-02-11 20:10:34 DEBUG (MainThread) [homeassistant.components.homekit_controller.connection] Called async_set_available_state with True for 2B:B0:96:86:6E:15
2022-02-11 20:10:34 DEBUG (MainThread) [homeassistant.components.homekit_controller.connection] Finished HomeKit controller update: 2B:B0:96:86:6E:15
2022-02-11 20:10:34 DEBUG (MainThread) [homeassistant.helpers.translation] Cache miss for en: sensor.homekit_controller, button.homekit_controller
2022-02-11 20:10:34 DEBUG (SyncWorker_5) [homeassistant.util.json] JSON file not found: /usr/src/homeassistant/homeassistant/components/homekit_controller/translations/sensor.en.json
2022-02-11 20:10:34 DEBUG (SyncWorker_5) [homeassistant.util.json] JSON file not found: /usr/src/homeassistant/homeassistant/components/homekit_controller/translations/button.en.json
2022-02-11 20:10:43 DEBUG (SyncWorker_3) [homeassistant.helpers.storage] Writing data for homekit_controller-entity-map to /config/.storage/homekit_controller-entity-map
2022-02-11 20:10:47 DEBUG (MainThread) [zeroconf] Received from '::ffff:192.168.0.139':5353 [socket 17 (('::', 5353, 0, 0))]: <DNSIncoming:{id=0, flags=0, truncated=False, n_q=6, n_ans=0, n_auth=0, n_add=1, questions=[ptr[question,QU,in,lb._dns-sd._udp.local.], ptr[question,QU,in,_companion-link._tcp.local.], ptr[question,QU,in,_homekit._tcp.local.], ptr[question,QU,in,_hap._tcp.local.], ptr[question,QU,in,_hap._udp.local.], ptr[question,QU,in,_sleep-proxy._udp.local.]], answers=[]}> (151 bytes) as [b'\x00\x00\x00\x00\x00\x06\x00\x00\x00\x00\x00\x01\x02lb\x07_dns-sd\x04_udp\x05local\x00\x00\x0c\x80\x01\x0f_companion-link\x04_tcp\xc0\x1c\x00\x0c\x80\x01\x08_homekit\xc07\x00\x0c\x80\x01\x04_hap\xc07\x00\x0c\x80\x01\x04_hap\xc0\x17\x00\x0c\x80\x01\x0c_sleep-proxy\xc0\x17\x00\x0c\x80\x01\x00\x00)\x05\xa0\x00\x00\x11\x94\x00\x12\x00\x04\x00\x0e\x00\x1a\x16\x87j\xb2ZT\xbeH\xd9\x8dN\xcf']
2022-02-11 20:11:33 DEBUG (MainThread) [homeassistant.components.homekit_controller.connection] Starting HomeKit controller update: 2B:B0:96:86:6E:15
2022-02-11 20:11:33 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.0.148: raw request: b'GET /characteristics?id=1.17,1.18 HTTP/1.1\r\nHost: 192.168.0.148\r\n\r\n'
2022-02-11 20:11:34 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.0.148: raw response: bytearray(b'{"characteristics":[{"aid":1,"iid":17,"value":1},{"aid":1,"iid":18,"value":1.00000}]}')
2022-02-11 20:11:34 DEBUG (MainThread) [homeassistant.components.homekit_controller.connection] Called async_set_available_state with True for 2B:B0:96:86:6E:15
2022-02-11 20:11:34 DEBUG (MainThread) [homeassistant.components.homekit_controller.connection] Finished HomeKit controller update: 2B:B0:96:86:6E:15
2022-02-11 20:11:51 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection] [140093955411104] Sending {"id": 66, "type": "result", "success": true, "result": {"area_id": null, "config_entry_id": "a9e032c427d75c85c14c412bfcc15600", "device_id": "fb912d0638c012669481722b0fd3e7a6", "disabled_by": null, "entity_category": "diagnostic", "entity_id": "button.smartmi_airpurifier_p1_identify", "icon": null, "name": null, "platform": "homekit_controller", "capabilities": null, "device_class": null, "original_device_class": null, "original_icon": null, "original_name": "Smartmi Airpurifier P1 Identify", "unique_id": "homekit-100025123003BA-aid:1-sid:1-cid:2"}}
2022-02-11 20:11:59 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection] [140093955411104] Sending {"id": 67, "type": "result", "success": true, "result": {"area_id": null, "config_entry_id": "a9e032c427d75c85c14c412bfcc15600", "device_id": "fb912d0638c012669481722b0fd3e7a6", "disabled_by": null, "entity_category": "diagnostic", "entity_id": "button.smartmi_airpurifier_p1_identify", "icon": null, "name": null, "platform": "homekit_controller", "capabilities": null, "device_class": null, "original_device_class": null, "original_icon": null, "original_name": "Smartmi Airpurifier P1 Identify", "unique_id": "homekit-100025123003BA-aid:1-sid:1-cid:2"}}
2022-02-11 20:12:33 DEBUG (MainThread) [homeassistant.components.homekit_controller.connection] Starting HomeKit controller update: 2B:B0:96:86:6E:15
2022-02-11 20:12:33 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.0.148: raw request: b'GET /characteristics?id=1.17,1.18 HTTP/1.1\r\nHost: 192.168.0.148\r\n\r\n'
2022-02-11 20:12:34 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.0.148: raw response: bytearray(b'{"characteristics":[{"aid":1,"iid":17,"value":1},{"aid":1,"iid":18,"value":1.00000}]}')
2022-02-11 20:12:34 DEBUG (MainThread) [homeassistant.components.homekit_controller.connection] Called async_set_available_state with True for 2B:B0:96:86:6E:15
2022-02-11 20:12:34 DEBUG (MainThread) [homeassistant.components.homekit_controller.connection] Finished HomeKit controller update: 2B:B0:96:86:6E:15

[Jc2k]

The identify button is a new feature. It's so you can tell which one is which when you have a lot of them. The device should flash a status light, beep or make itself known somehow. It's also useful to debug the connectivity.

Oh my phone but I'll look at the logs as soon as I can.

[jorgnyg]

@Jc2k Ah understand. No worries.
Now I was able to connect without the error, but after a restart or integration reload I typically get logs like this, even though the values are wrong.

2022-02-11 20:55:24 DEBUG (MainThread) [aiohomekit.controller.ip.connection] 192.168.0.148: raw response: bytearray(b'{"characteristics":[{"aid":1,"iid":17,"value":1},{"aid":1,"iid":18,"value":1.00000}]}')
2022-02-11 20:55:24 DEBUG (MainThread) [homeassistant.components.homekit_controller.connection] Called async_set_available_state with True for 2B:B0:96:86:6E:15
2022-02-11 20:55:24 DEBUG (MainThread) [homeassistant.components.homekit_controller.connection] Finished HomeKit controller update: 2B:B0:96:86:6E:15

[Jc2k]

So to me those logs look absolutely fine. That is the raw JSON body your device is sending us (after stripping the encryption), before i process them. Thats why they are reported as a bytearray(b'...'), they haven't even been parsed yet.

So if you are saying "1" and "1.00000" are wrong, then unfortunately its the device at fault and there is nothing I can do...

[jorgnyg]

@Jc2k Okay, thank you for your time and clarifying this! Will close this now:)