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
71.08k stars 29.74k forks source link

Unable to connect Tado bridge as HomeKit climate device #16971

Closed luukdobber closed 5 years ago

luukdobber commented 5 years ago

Home Assistant release with the issue: 0.79.0

Last working Home Assistant release (if known):

Operating environment (Hass.io/Docker/Windows/etc.): Hass.io

Component/platform: https://www.home-assistant.io/components/climate.homekit_controller/

Description of problem: I am trying to add my Tado bridge to Home Assistant using the homekit_controller component. This would allow me to have offline control for my heating instead of using the tado API. Home Assistant throws an error when I try to pair the bridge in the UI. This is what I did:

  1. Reset HomeKit on the tado bridge so it's not connected to my iPad anymore. The devices disappeared from the Home app, so this seems to have worked.
  2. Add HomeKit discovery to my configuration.yaml and restart HA.
  3. Click "configure" on the "tado Internet Bridge" item in the UI.
  4. Enter the HomeKit code from the sticker on the bridge and click submit.

After a while the dialog closes end the stacktrace mentioned below appeared in the logs.

Problem-relevant configuration.yaml entries and (fill out even if it seems unimportant):

discovery:
  enable:
    - homekit

Traceback (if applicable):

Error executing service <ServiceCall configurator.configure (c:53514ee038d142deafe498967e874b70): configure_id=1825889744-2, fields=code=<<HomeKit code from sticker on device>>
Traceback (most recent call last):
  File "/usr/local/lib/python3.6/site-packages/homeassistant/core.py", line 1177, in _event_to_service_call
    await service_handler.func(service_call)
  File "/usr/local/lib/python3.6/site-packages/homeassistant/components/configurator.py", line 224, in async_handle_service_call
    call.data.get(ATTR_FIELDS, {}))
  File "/usr/local/lib/python3.6/concurrent/futures/thread.py", line 56, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/local/lib/python3.6/site-packages/homeassistant/components/homekit_controller/__init__.py", line 146, in device_config_callback
    pairing_id)
  File "/usr/local/lib/python3.6/site-packages/homekit/protocol.py", line 69, in perform_pair_setup
    connection.request('POST', '/pair-setup', request_tlv, headers)
  File "/usr/local/lib/python3.6/http/client.py", line 1239, in request
    self._send_request(method, url, body, headers, encode_chunked)
  File "/usr/local/lib/python3.6/http/client.py", line 1250, in _send_request
    self.putrequest(method, url, **skips)
  File "/usr/local/lib/python3.6/http/client.py", line 1108, in putrequest
    raise CannotSendRequest(self.__state)
http.client.CannotSendRequest: Request-sent

Additional information:

Jc2k commented 5 years ago

The changes to fix merging are now on homekit_python master branch and should be in the next tag. No ETA for that at present.

The changes to fix operation_list have past code review and should land on HA master when CI passes.

23040 and #22995 still need review but hopefully not far behind.

Will have a think how best to test the changes - maybe I can spin up a fork of the container or something.

Jc2k commented 5 years ago

@cf00 Missed it when replying yesterday but RE:

The json I sent was from the bridge paired in the venv outside homeassistant. How can I run homekit.get_accessories with the bridge paired in homeassistant? What would be the parameters for the -f and -a arguments?

The JSON file is in your configuration folder. E.g. if you have /config/configuration.yaml then you also have /config/.homekit/pairings.json (or, if i have misremembered, pairing.json).

The value for -a is the homekit id as it appears in homekit.discover (the code that looks like a mac address).

cf00 commented 5 years ago

I tried this now but the output seems to be identical, with the "temperature.target" element showing the correct values.

I also managed to upgrade to the dev build (0.92.0-dev) via docker and (after upgrading the python homekit library) I can pair it and my devices show up. The operation_list attribute is now set correctly, but it still has target_temperature: null. And there is no humidity.

Since the dev build seems to break my hue sensor custom component, I went back to 0.91.3 and paired the bridge again. Not sure if it's relevant, but while my devices showed up almost immediately after pairing on the dev build, this time none showed up at first. After a restart, a few appeared, and only after two more restarts all of them are now available again.

Jc2k commented 5 years ago

Humidity PR still not merged so this is expected.

With operation_list set did the UI for that at least work?

get_accessories CLI uses a slightly different mechanism than HA to get values (it’s too inefficient for minutely pollings). So we could try the get_characteristic cli tool (which is what ha is doing) and see if that works, otherwise I’m going to have to litter the code with debug prints.

I think I saw a PR for the Hue sensors - they might be getting native support. That might be what caused that problem.

The delay for entities showing is known. Config entries work will help to a degree. Some of it is entities aren’t loaded until first discovery scan finished after as much as 30s. Config entries will remove that delay. Then there are some oddities about entities propagating to UI. This can sometimes be fixed with browser refreshes. Again config entries probably fix this.

cf00 commented 5 years ago

With operation_list set did the UI for that at least work?

Yes.

get_accessories CLI uses a slightly different mechanism than HA to get values (it’s too inefficient for minutely pollings). So we could try the get_characteristic cli tool (which is what ha is doing) and see if that works, otherwise I’m going to have to litter the code with debug prints.

Not sure if I figured it out correctly but here is the output from get_characteristic. 3.15 should be the target temperature for a device.

# python -m homekit.get_characteristic -f /config/.homekit/pairing.json -a 83:a9:5d:9c:43:f0 -c 3.15 --log DEBUG
2019-04-16 11:11:01,755 ip_implementation.py:0399 DEBUG init session
2019-04-16 11:11:01,804 tlv.py:0134 DEBUG sending [
  6: (1 bytes) 0x01
  3: (32 bytes) b'0\xfel\x97\x8a\x18\xdd\xe3\x8a\\\xe7<U\xc8\x10Pumpx\x8dK{\xa9\x14\xd0\x0f\x17\x1e\xeb\xc9F'
]

2019-04-16 11:11:01,804 tlv.py:0117 DEBUG receiving [
  6: (1 bytes) 0x01
  3: (32 bytes) 0x30fe6c978a18dde38a5ce73c55c81050756d70788d4b7ba914d00f171eebc946
]

2019-04-16 11:11:01,804 __init__.py:0075 DEBUG write message: [
  6: (1 bytes) 0x01
  3: (32 bytes) 0x30fe6c978a18dde38a5ce73c55c81050756d70788d4b7ba914d00f171eebc946
]

2019-04-16 11:11:01,849 tlv.py:0117 DEBUG receiving [
  6: (1 bytes) 0x02
  3: (32 bytes) 0x31c87814876ad371ccc7bc9b7433627320a3ac3c55608986345f82fe2670be50
  5: (101 bytes) 0x12ab1f6c5ebe11a19d14caa66d482460a0b048fb235dbf3a988702d17a573c009b060f918126cb0d9d89e08ce3fa7adee493535cb99e833ae6f60e23fe8628de96c2edea7984d0472d7b06002db87291605585a9e53b2fc85cfd1335b9be1fd46aab0db03b
]

2019-04-16 11:11:01,850 __init__.py:0082 DEBUG response: [
  6: (1 bytes) 0x02
  3: (32 bytes) 0x31c87814876ad371ccc7bc9b7433627320a3ac3c55608986345f82fe2670be50
  5: (101 bytes) 0x12ab1f6c5ebe11a19d14caa66d482460a0b048fb235dbf3a988702d17a573c009b060f918126cb0d9d89e08ce3fa7adee493535cb99e833ae6f60e23fe8628de96c2edea7984d0472d7b06002db87291605585a9e53b2fc85cfd1335b9be1fd46aab0db03b
]

2019-04-16 11:11:01,853 tlv.py:0117 DEBUG receiving [
  1: (17 bytes) 0x38333a61393a35643a39633a34333a6630
  10: (64 bytes) 0xb66c004253b091d956a863251446447078597fd526d42396178e6e15f4da2926be691e0396c13e1c0f5d9fe1822f97adc251b2c6ab6a5333be69b744f7418502
]

2019-04-16 11:11:01,858 tlv.py:0134 DEBUG sending [
  1: (36 bytes) b'9259a111-23a4-46ca-95b7-2d50476e5459'
  10: (64 bytes) b'\x97\x88V\xcdT\xb1\xb6\xc8r\x86\xe65s\xa9\x05\x13\xb5XI\xa7\xc9>\xc0C\xb3Q2+\x9b\x00A\xe1O\xe8\x9fz\x7f`\xbc\x11\xaa@\xfbc\xc4\x15V\xac]K\xb6\x85k\x8b\xae\x10\xdf\xff\x81:Ku\xce\t'
]

2019-04-16 11:11:01,861 tlv.py:0134 DEBUG sending [
  6: (1 bytes) 0x03
  5: (120 bytes) 0xdc3f8e769e9dcf1adf675156b44e2a2356295f64d6bd8aaca351aa97d02e925dc0bccc3d732c5faa5f27b54dca09d23e6442f6e0c6eec4d04c47a5f756b5cee42b980eb063a25c25b9d8e94d180adbe039624caf450028412df6fa8dc7235ce7edad68e39f82b62e02b4d155eb7fb5f65b868538746c6719
]

2019-04-16 11:11:01,861 tlv.py:0117 DEBUG receiving [
  6: (1 bytes) 0x03
  5: (120 bytes) 0xdc3f8e769e9dcf1adf675156b44e2a2356295f64d6bd8aaca351aa97d02e925dc0bccc3d732c5faa5f27b54dca09d23e6442f6e0c6eec4d04c47a5f756b5cee42b980eb063a25c25b9d8e94d180adbe039624caf450028412df6fa8dc7235ce7edad68e39f82b62e02b4d155eb7fb5f65b868538746c6719
]

2019-04-16 11:11:01,861 __init__.py:0075 DEBUG write message: [
  6: (1 bytes) 0x03
  5: (120 bytes) 0xdc3f8e769e9dcf1adf675156b44e2a2356295f64d6bd8aaca351aa97d02e925dc0bccc3d732c5faa5f27b54dca09d23e6442f6e0c6eec4d04c47a5f756b5cee42b980eb063a25c25b9d8e94d180adbe039624caf450028412df6fa8dc7235ce7edad68e39f82b62e02b4d155eb7fb5f65b868538746c6719
]

2019-04-16 11:11:01,942 tlv.py:0117 DEBUG receiving [
  6: (1 bytes) 0x04
]

2019-04-16 11:11:01,943 __init__.py:0082 DEBUG response: [
  6: (1 bytes) 0x04
]

2019-04-16 11:11:01,944 ip_implementation.py:0426 DEBUG session established
Session closed after receiving malformed response from device
2019-04-16 11:11:01,968 get_characteristic.py:0071 DEBUG Session closed after receiving malformed response from device
Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/homekit/controller/ip_implementation.py", line 199, in get_characteristics
    data = json.loads(response.read().decode())['characteristics']
  File "/usr/local/lib/python3.7/json/__init__.py", line 348, in loads
    return _default_decoder.decode(s)
  File "/usr/local/lib/python3.7/json/decoder.py", line 337, in decode
    obj, end = self.raw_decode(s, idx=_w(s, 0).end())
  File "/usr/local/lib/python3.7/json/decoder.py", line 355, in raw_decode
    raise JSONDecodeError("Expecting value", s, err.value) from None
json.decoder.JSONDecodeError: Expecting value: line 1 column 1 (char 0)

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/homekit/get_characteristic.py", line 68, in <module>
    include_type=args.type, include_events=args.events)
  File "/usr/local/lib/python3.7/site-packages/homekit/controller/ip_implementation.py", line 203, in get_characteristics
    raise AccessoryDisconnectedError("Session closed after receiving malformed response from device")
homekit.exceptions.AccessoryDisconnectedError: Session closed after receiving malformed response from device

However, if I do the same command for characteristic 3.14 (current temperature), I get the same (?) error, even though homeassistant seems to be able to retrieve that value.

# python -m homekit.get_characteristic -f /config/.homekit/pairing.json -a 83:a9:5d:9c:43:f0 -c 3.14 --log DEBUG
2019-04-16 11:16:59,678 ip_implementation.py:0399 DEBUG init session
2019-04-16 11:16:59,723 tlv.py:0134 DEBUG sending [
  6: (1 bytes) 0x01
  3: (32 bytes) b'\x8b\xa8YS\x05\x02\xf7\xda\xd7\xc2t\x05\x06ez)\x17`\xac\x12\x8fY\xdc\xc7\x9b\xea\x0f\xd7\xc5\xfa D'
]

2019-04-16 11:16:59,724 tlv.py:0117 DEBUG receiving [
  6: (1 bytes) 0x01
  3: (32 bytes) 0x8ba859530502f7dad7c2740506657a291760ac128f59dcc79bea0fd7c5fa2044
]

2019-04-16 11:16:59,724 __init__.py:0075 DEBUG write message: [
  6: (1 bytes) 0x01
  3: (32 bytes) 0x8ba859530502f7dad7c2740506657a291760ac128f59dcc79bea0fd7c5fa2044
]

2019-04-16 11:16:59,770 tlv.py:0117 DEBUG receiving [
  6: (1 bytes) 0x02
  3: (32 bytes) 0x6d38b86633cc99c364f2309e4d79f8395033547125486c9f27cf63dc226fbe72
  5: (101 bytes) 0x717c6910bcc1853c9f8be1fe7353f1e860b23707205ef8dc64b173b3a8fbc76c4e1c86b313220356b9e13c065eb326186e888e9c6e89e1ff1b66de09886dd27ccc17e461664153195fc82a369eab386d9d7443236aabda4276a4b70b8e7ca097e1f0137e2f
]

2019-04-16 11:16:59,770 __init__.py:0082 DEBUG response: [
  6: (1 bytes) 0x02
  3: (32 bytes) 0x6d38b86633cc99c364f2309e4d79f8395033547125486c9f27cf63dc226fbe72
  5: (101 bytes) 0x717c6910bcc1853c9f8be1fe7353f1e860b23707205ef8dc64b173b3a8fbc76c4e1c86b313220356b9e13c065eb326186e888e9c6e89e1ff1b66de09886dd27ccc17e461664153195fc82a369eab386d9d7443236aabda4276a4b70b8e7ca097e1f0137e2f
]

2019-04-16 11:16:59,773 tlv.py:0117 DEBUG receiving [
  1: (17 bytes) 0x38333a61393a35643a39633a34333a6630
  10: (64 bytes) 0xb80a10382a534bb8eb18430de821da2f97cb204c1703931895b7f203b93719bdce842e16cf6d868ffe6d7d37ead7f06c81bff75ca0a3a839e6bb1a13de52690c
]

2019-04-16 11:16:59,778 tlv.py:0134 DEBUG sending [
  1: (36 bytes) b'9259a111-23a4-46ca-95b7-2d50476e5459'
  10: (64 bytes) b';\x86\x8d\xfb\xbf=\xcd\xc8\x901\x0cs\x88\x18\x15/\x18\xaa\xdfh`1\x1d\x16\x88\xf1\x1d7n\xef\xbf\x12]%:\xdf\x06.\xd8r\xe8\xb1\x0c\x9b\xd7\xd16\xb6\xc9Q\xcd\xa3\xb5\xa3\x10\xa0\x9f\xb3\xf3\x83\xa2q\x15\x06'
]

2019-04-16 11:16:59,780 tlv.py:0134 DEBUG sending [
  6: (1 bytes) 0x03
  5: (120 bytes) 0x76ed3d90c49f463f982aed37502ee3c82f3ad8f720365a85967c5e0dded1d5aac82105781a7a9ea21d640d616f9b11d00733637421650988ace4430996dd2cbfcfcd09305daa7722f3c3e811cd803f0ba4dc8be3a44496cf744261c7595bab1eccdf891505623aaba98995e8e93db47cd941d6e8c17b7210
]

2019-04-16 11:16:59,780 tlv.py:0117 DEBUG receiving [
  6: (1 bytes) 0x03
  5: (120 bytes) 0x76ed3d90c49f463f982aed37502ee3c82f3ad8f720365a85967c5e0dded1d5aac82105781a7a9ea21d640d616f9b11d00733637421650988ace4430996dd2cbfcfcd09305daa7722f3c3e811cd803f0ba4dc8be3a44496cf744261c7595bab1eccdf891505623aaba98995e8e93db47cd941d6e8c17b7210
]

2019-04-16 11:16:59,780 __init__.py:0075 DEBUG write message: [
  6: (1 bytes) 0x03
  5: (120 bytes) 0x76ed3d90c49f463f982aed37502ee3c82f3ad8f720365a85967c5e0dded1d5aac82105781a7a9ea21d640d616f9b11d00733637421650988ace4430996dd2cbfcfcd09305daa7722f3c3e811cd803f0ba4dc8be3a44496cf744261c7595bab1eccdf891505623aaba98995e8e93db47cd941d6e8c17b7210
]

2019-04-16 11:16:59,863 tlv.py:0117 DEBUG receiving [
  6: (1 bytes) 0x04
]

2019-04-16 11:16:59,863 __init__.py:0082 DEBUG response: [
  6: (1 bytes) 0x04
]

2019-04-16 11:16:59,864 ip_implementation.py:0426 DEBUG session established
Session closed after receiving malformed response from device
2019-04-16 11:16:59,888 get_characteristic.py:0071 DEBUG Session closed after receiving malformed response from device
Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/homekit/controller/ip_implementation.py", line 199, in get_characteristics
    data = json.loads(response.read().decode())['characteristics']
  File "/usr/local/lib/python3.7/json/__init__.py", line 348, in loads
    return _default_decoder.decode(s)
  File "/usr/local/lib/python3.7/json/decoder.py", line 337, in decode
    obj, end = self.raw_decode(s, idx=_w(s, 0).end())
  File "/usr/local/lib/python3.7/json/decoder.py", line 355, in raw_decode
    raise JSONDecodeError("Expecting value", s, err.value) from None
json.decoder.JSONDecodeError: Expecting value: line 1 column 1 (char 0)

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/homekit/get_characteristic.py", line 68, in <module>
    include_type=args.type, include_events=args.events)
  File "/usr/local/lib/python3.7/site-packages/homekit/controller/ip_implementation.py", line 203, in get_characteristics
    raise AccessoryDisconnectedError("Session closed after receiving malformed response from device")
homekit.exceptions.AccessoryDisconnectedError: Session closed after receiving malformed response from device
cf00 commented 5 years ago

The delay for entities showing is known. Config entries work will help to a degree. Some of it is entities aren’t loaded until first discovery scan finished after as much as 30s. Config entries will remove that delay.

Where and how can I set config entries?

Jc2k commented 5 years ago

That's the internal name for the integrations list in homeassistant (where Hue appears). You can't yet use them for homekit accessories - it's in a branch i'm working on. It's more or less done, i've just got to get it reviewed and merged. It's a large change so breaking it up for review is taking a while though.

Jc2k commented 5 years ago

If you can, could you edit the file /usr/local/lib/python3.7/site-packages/homekit/controller/ip_implementation.py and edit line 199.

Right now it should look like:

    data = json.loads(response.read().decode())['characteristics']

Would be helpful to see the output if you change it to:

    response_bytes = response.read().decode()
    print(response_bytes)
    data = json.loads(response_bytes)['characteristics']
cf00 commented 5 years ago

Ok. After the change:

# python -m homekit.get_characteristic -f /config/.homekit/pairing.json -a 83:a9:5d:9c:43:f0 -c 3.15 --log DEBUG
2019-04-16 11:49:56,993 ip_implementation.py:0401 DEBUG init session
2019-04-16 11:49:57,050 tlv.py:0134 DEBUG sending [
  6: (1 bytes) 0x01
  3: (32 bytes) b'\xa7\xf6d\xc2b\xfe\xfd\xef;\x81\x19H\xc4\xba\x9b\xec\xf0P\x11\xd3\x9aj\xd3\xceE\xef\x94\x9b\xc9+\xde '
]

2019-04-16 11:49:57,050 tlv.py:0117 DEBUG receiving [
  6: (1 bytes) 0x01
  3: (32 bytes) 0xa7f664c262fefdef3b811948c4ba9becf05011d39a6ad3ce45ef949bc92bde20
]

2019-04-16 11:49:57,050 __init__.py:0075 DEBUG write message: [
  6: (1 bytes) 0x01
  3: (32 bytes) 0xa7f664c262fefdef3b811948c4ba9becf05011d39a6ad3ce45ef949bc92bde20
]

2019-04-16 11:49:57,097 tlv.py:0117 DEBUG receiving [
  6: (1 bytes) 0x02
  3: (32 bytes) 0x9f5f77aed0f79f2dcbbe0b6ecf535b90f4e7c5b08adbbc4f037dac7aaf323637
  5: (101 bytes) 0xcbf0193696a870ddb4e177c28d571f46c5cf390021221ca9ed2f1636917b7fd44d19da99dced1f9d9142da3b3d97ee38ce6bbfce598daf290ac014d20fd715ba2c3e258b783f27fb7153ea16567fd47a08c6195efb4c7e0750bec2376b2fc517b6abc90eb0
]

2019-04-16 11:49:57,098 __init__.py:0082 DEBUG response: [
  6: (1 bytes) 0x02
  3: (32 bytes) 0x9f5f77aed0f79f2dcbbe0b6ecf535b90f4e7c5b08adbbc4f037dac7aaf323637
  5: (101 bytes) 0xcbf0193696a870ddb4e177c28d571f46c5cf390021221ca9ed2f1636917b7fd44d19da99dced1f9d9142da3b3d97ee38ce6bbfce598daf290ac014d20fd715ba2c3e258b783f27fb7153ea16567fd47a08c6195efb4c7e0750bec2376b2fc517b6abc90eb0
]

2019-04-16 11:49:57,101 tlv.py:0117 DEBUG receiving [
  1: (17 bytes) 0x38333a61393a35643a39633a34333a6630
  10: (64 bytes) 0xf234bdb9c0f1ae77ea95628cd6870237779618cf7af5bddf4204575f98e35f0ff8045e9e721edae957bed4ca95626ed0220f9ba45c44a254916ec2e6f272f60c
]

2019-04-16 11:49:57,106 tlv.py:0134 DEBUG sending [
  1: (36 bytes) b'9259a111-23a4-46ca-95b7-2d50476e5459'
  10: (64 bytes) b'\xe5A\x1b/\xb9\x05\xc5\xd5\xee\xce\x11G\x0c\x10\xbe\xeeV\x18\xaa\x85\xbb\xf2$\xfe\x11\xdc\x14\x11\xe2\n`ELY\xe5!\x12\x1d\x8d\xfeD\xff\xf7\xc3"\x98\t\xfcBi\xd2x}\xb8<\x18\xad\xba\x1926\xd8\x1e\x00'
]

2019-04-16 11:49:57,109 tlv.py:0134 DEBUG sending [
  6: (1 bytes) 0x03
  5: (120 bytes) 0x33f4f2dcf38852b043b3724a56fb58623c1e65f58bbdf0e4e8fdf77b7e3428d1eae6d96116259a84a11d4a33f342c3fca4b20e95cf248d4bd96b145d08227cc56b66d3c7dfa7a02c37749e5c0d20ac420a7f3aa3814aea644c130edbe19dee85a6b0d14685609fd3163c52db03a1fd7f6de5b98313ba790c
]

2019-04-16 11:49:57,109 tlv.py:0117 DEBUG receiving [
  6: (1 bytes) 0x03
  5: (120 bytes) 0x33f4f2dcf38852b043b3724a56fb58623c1e65f58bbdf0e4e8fdf77b7e3428d1eae6d96116259a84a11d4a33f342c3fca4b20e95cf248d4bd96b145d08227cc56b66d3c7dfa7a02c37749e5c0d20ac420a7f3aa3814aea644c130edbe19dee85a6b0d14685609fd3163c52db03a1fd7f6de5b98313ba790c
]

2019-04-16 11:49:57,109 __init__.py:0075 DEBUG write message: [
  6: (1 bytes) 0x03
  5: (120 bytes) 0x33f4f2dcf38852b043b3724a56fb58623c1e65f58bbdf0e4e8fdf77b7e3428d1eae6d96116259a84a11d4a33f342c3fca4b20e95cf248d4bd96b145d08227cc56b66d3c7dfa7a02c37749e5c0d20ac420a7f3aa3814aea644c130edbe19dee85a6b0d14685609fd3163c52db03a1fd7f6de5b98313ba790c
]

2019-04-16 11:49:57,191 tlv.py:0117 DEBUG receiving [
  6: (1 bytes) 0x04
]

2019-04-16 11:49:57,191 __init__.py:0082 DEBUG response: [
  6: (1 bytes) 0x04
]

2019-04-16 11:49:57,192 ip_implementation.py:0428 DEBUG session established

Session closed after receiving malformed response from device
2019-04-16 11:49:57,217 get_characteristic.py:0071 DEBUG Session closed after receiving malformed response from device
Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/homekit/controller/ip_implementation.py", line 201, in get_characteristics
    data = json.loads(response_bytes)['characteristics']
  File "/usr/local/lib/python3.7/json/__init__.py", line 348, in loads
    return _default_decoder.decode(s)
  File "/usr/local/lib/python3.7/json/decoder.py", line 337, in decode
    obj, end = self.raw_decode(s, idx=_w(s, 0).end())
  File "/usr/local/lib/python3.7/json/decoder.py", line 355, in raw_decode
    raise JSONDecodeError("Expecting value", s, err.value) from None
json.decoder.JSONDecodeError: Expecting value: line 1 column 1 (char 0)

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/homekit/get_characteristic.py", line 68, in <module>
    include_type=args.type, include_events=args.events)
  File "/usr/local/lib/python3.7/site-packages/homekit/controller/ip_implementation.py", line 205, in get_characteristics
    raise AccessoryDisconnectedError("Session closed after receiving malformed response from device")
homekit.exceptions.AccessoryDisconnectedError: Session closed after receiving malformed response from device
Jc2k commented 5 years ago

.. it didn't print anything did it? Probably means its returned nothing, which smells like it doesn't like the HTTP request that is being sent.

You are right that it's weird that some of these are working in HA and not on the CLI. Near where you made the last change there is a bunch of code like this:

        if include_meta:
            url += '&meta=1'
        else:
            url += '&meta=0'
        if include_perms:
            url += '&perms=1'
        else:
            url += '&perms=0'
        if include_type:
            url += '&type=1'
        else:
            url += '&type=0'
        if include_events:
            url += '&ev=1'
        else:
            url += '&ev=0'

I noticed my iPhone never sends the =0 variants, so maybe the tado doesn't like that we do? So just delete that entire block of code and try again?

cf00 commented 5 years ago

That's it! The CLI returns the value and it also shows up in homeassistant and the UI works.

Jc2k commented 5 years ago

OK, let's try a more correct version that I can slap in a PR:

        if include_meta:
            url += '&meta=1'
        if include_perms:
            url += '&perms=1'
        if include_type:
            url += '&type=1'
        if include_events:
            url += '&ev=1'
cf00 commented 5 years ago

It's still working, both in the CLI and in ha.

Jc2k commented 5 years ago

Cool, i'll get a PR upstream for that.

Jc2k commented 5 years ago

All my outstanding HA fixes have landed on dev, including humidity support. If you run dev and the master branch of homekit_python the tado should work. If someone can try that it would be a big help.

jimz011 commented 5 years ago

I am so sorry, I said I’d help but have been sick the last few days. I am finally feeling a bit better. So I might try this later.

So I need HA dev? And how do I get the master branch of homekit_python?

I run this in a python venv. I know how to get the dev version of HA. But have no idea how to get the master branch of homekit_python.

Jc2k commented 5 years ago

Hi @jimz011 - glad that you are feeling better!

Yes, you need HA dev. The PR's landed in the past few hours.

For homekit_python - you should be able to do pip install https://github.com/jlusiardi/homekit_python/archive/master.zip in your venv. The only gotcha is if you already have homekit_python in your config/deps folder. I think that one might trump the system/venv one, so delete it if you do.

jimz011 commented 5 years ago

Ok I will try that. Dev or beta branch for HA? As I see your fixes are mentioned in the changes (on the beta page).

homekit_controller: Support cover stop (@Jc2k - #23046) (homekit_controller docs) Fix handling of homekit_controler zeroconf c# changes (@Jc2k - #22995) (homekit_controller docs) Support fetching/setting humidity of HomeKit controller thermostats (@Jc2k - #23040) (homekit_controller docs)

The beta has been pushed out 2 hours ago. So I am guessing that the beta might be up to date with your PR’s. But I will figure it out. I will post an answer when I have it working.

Jc2k commented 5 years ago

Hmm if its in beta im surprised because they only just hit dev! But looks like they are indeed on the rc branch too.

jimz011 commented 5 years ago

Haha, I just edited my post to say rc was pushed out 2 hours ago :P, which is fine seeing I always run rc versions of HA (and work around the broken stuff in the meantime).

jimz011 commented 5 years ago

Just one more question do you think I would need to update homekit_python? Or might it just work with the rc branch? I don’t see homekit_python mentioned. Though an update to HAP-Python 2.5.0 is mentioned.

Jc2k commented 5 years ago

Yeah you need lastest homekit_python master, will not pair without it. The fixes on HA are for after the pairing and security networking are working.

Normal workflow:

So obviously there is nothing to 'see' on the HA side yet.

cf00 commented 5 years ago

I can confirm that everything seems to work on 0.92.0b0 with the updated homekit_python. Target temperature, humidity and operation_list are all there; the UI works. I did not test pairing as it was still paired from the previous version (but I assume that should work too).

(Any idea why this release is not loading the custom component? My hue sensors still don't work .. I didn't find any change which would explain that. I know it's completely off topic here, but any pointer would be appreciated)

Jc2k commented 5 years ago

Not sure about your hue sensor problem, sorry.

cf00 commented 5 years ago

Thanks anyway.

I really appreciate your help and the effort you put into getting this to work. You are doing an outstanding job.

jimz011 commented 5 years ago

So I have tried to install the rc, which is running fine (after some hiccups) I also installed the homekit python package. However my situation is the same. When I enter the homekit code in the configurator nothing happens. (You will see a loading wheel for a few sec). It won’t accept any code for me. I even tried some random letters, but nothing appears to be happening (nothing in logs/console either). When I press to submit the code nothing happens in the console either.

Pretty tired now, so gonna check back in tomorrow.

Edit: couldn't stand it and tried the dev version as well. Still no effect. It is like the configurator just doesn't do anything at all. (I did manage to pair my koogeek switches though, so you might think that the configurator should be working).

Jc2k commented 5 years ago

@jimz011 ok when you are back we can try and verify the homekit installation worked. The behaviour you are getting sounds like the new version isn’t installed right.

jimz011 commented 5 years ago

Update: I have tried pairing it via the cmd line as per your instructions earlier. When I try to pair it it will say: remote connection closed by the other end. (Haven’t used debug yet, as I was tired yesterday)

I might try it on a clean install tonight. The crazy thing is that it used to work a few HA updates ago (I mean the pairing part). It would throw some errors in the console. However it just does nothing at the moment.

Jc2k commented 5 years ago

@cf00 i noticed that Hue sensors are now supported on master - see https://github.com/home-assistant/home-assistant/commit/474ac8b09ee369916061bf1991f7f8956612a0fe. It got cherry picked into 0.92 so should be in next release.

@jimz011 right now we have a few options about why its working for others and not you:

As you said before, theres nothing weird about your install so right now they are my best guesses.

Based on the code history i'm not sure how pairing could have ever worked. The bug has existed in homekit_python at least a year ago, and it's not that kind of change you could accidentally undo so i suspect it never worked. Best guess is it was a firmware update that broke it and made HTTP parsing much stricter.

Please try:

$ python3 -m venv homekit_test

$ source homekit_test/bin/activate

$ pip install --no-cache --upgrade https://github.com/jlusiardi/homekit_python/archive/master.zip

$ python -m homekit.init_controller_storage -f test.json

$ python -m homekit.discover
Name: DemoAccessory._hap._tcp.local.
Url: http_impl://192.168.1.254:8085
Configuration number (c#): 67
Feature Flags (ff): No support for HAP Pairing (Flag: 0)
Device ID (id): ff:f0:00:00:00:00
Model Name (md): DemoAccessory
Protocol Version (pv): 1.0
State Number (s#): 1
Status Flags (sf): Accessory has not been paired with any controllers. (Flag: 1)
Category Identifier (ci): Lightbulb (Id: 5)

$ python -m homekit.pair -f test.json -p 031-45-154 -a test -d ff:f0:00:00:00:00 --log DEBUG
<snip>
2019-04-12 21:31:38,505 ip_implementation.py:0426 DEBUG session established
Pairing for "test" was established.

Make sure you use that exact pip install incantation. The first version of these instructions use a release. That tag/release will not work.

If that fails please also do:

$ python -c "print(__import__('homekit').__file__)"

$ pwd

So I can check its finding the right homekit.

The first command will print something like

/private/tmp/homekit_test/lib/python3.7/site-packages/homekit/__init__.py

Copy the path into this command, replacing homekit/__init__.py with homekit/protocol/__init__.py.

$ cat /private/tmp/homekit_test/lib/python3.7/site-packages/homekit/protocol/__init__.py | grep skip
        connection.putrequest('POST', '/pair-setup', skip_accept_encoding=True)
        connection.putrequest('POST', '/pair-verify', skip_accept_encoding=True)
jimz011 commented 5 years ago

Ok I will give that a try, my firmware is version is the same (50.6).

cf00 commented 5 years ago

If it helps, I always used the following command to update homekit_python for my HA (docker) installation whenever I switched to a different HA release during testing:

pip install --upgrade git+git://github.com/jlusiardi/homekit_python.git@master

It seems to have worked every time (disclaimer: this is just the result of trial and error, and I don't really know what it does and if this is the right/recommended way).

@Jc2k,, thanks for the hint re hue sensor. I already figured out why the custom component didn't work; I should have RTFM, it is literally the first sentence in the beta release notes.

jimz011 commented 5 years ago

@cf00 thanks that did it for me, pairing now seems to work in the test environment (via cmd line) and HA seems to be doing something when I enter the code now. Unfortunately I am not home so there is no way to reset the paired bridge for me remotely. Will post my results later on.

Btw, did I mention that you guys are really helpful, doing a massively great job and very friendly? Well I did now :P

Jc2k commented 5 years ago

@jimz011 you'll make us blush 😆

You can potentially remote unpair with the homekit cli, btw.

From docs:

python -m homekit.unpair -f ${PAIRINGDATAFILE} -a ${ALIAS} [--log ${LOGLEVEL}]

So if following my instructions from before then:

python -m homekit.unpair -f test.json -a test --log DEBUG

I don't think we've tried this on a tado yet so would be good to test it.

jimz011 commented 5 years ago

Seems to have worked, tried to copy the debug but almost impossible to do on a phone using rdp :P.

I have managed to unpair the device, and now it paired up with Home Assistant just fine. Entities are showing up in Home Assistant now. Haven’t tested if they actually work.

If you’d like I can post the logs later on when I have a proper pc.

Thanks a lot!

jimz011 commented 5 years ago

One more thing, I see it only creates a single entity as opposed to the tado component (which uses the unofficial API).

I think this is intended as there are only 2 operation modes as well (which is great as there is the heat operation mode, which the tado component lacks).

The tado component creates like 6 entities per device. That is why I ask.

jimz011 commented 5 years ago

I managed to get the log copied :P

2019-04-18 12:53:56,224 tlv.py:0134 DEBUG sending [ 6: (1 bytes) 0x01 0: (1 bytes) 0x04 1: (36 bytes) b'd9097764-8c21-4303-9790-8eb2ed64d913' ]

2019-04-18 12:53:56,225 ip_implementation.py:0391 DEBUG init session 2019-04-18 12:53:56,346 tlv.py:0134 DEBUG sending [ 6: (1 bytes) 0x01 3: (32 bytes) b'=\x1b\xad\xca\x9f>q>uc\xe7\xae\x9e\x8a\xc7"k\xa2\xcb\xd3+Z\t\x14\xbc\xefz\xcc4\x9e\xf3J' ]

2019-04-18 12:53:56,347 tlv.py:0117 DEBUG receiving [ 6: (1 bytes) 0x01 3: (32 bytes) 0x3d1badca9f3e713e7563e7ae9e8ac7226ba2cbd32b5a0914bcef7acc349ef34a ]

2019-04-18 12:53:56,348 init.py:0075 DEBUG write message: [ 6: (1 bytes) 0x01 3: (32 bytes) 0x3d1badca9f3e713e7563e7ae9e8ac7226ba2cbd32b5a0914bcef7acc349ef34a ]

2019-04-18 12:53:56,396 tlv.py:0117 DEBUG receiving [ 6: (1 bytes) 0x02 3: (32 bytes) 0x8d4ea0d8077f5e52e015d90810f96021f751bbd1fd59698d0d5f047bcc99677e 5: (101 bytes) 0xd0a06e3c7057de061740e0526646e61285baea4c25f5ebf9ec5eef869ecb055dbb42437e30f43a16cfd35c64546bea22d7e001a3a9c232af599b26da936d2036280086856e13182211b8caace2025c3e42381e95069625aafd27601f07cec81772088f9e52 ]

2019-04-18 12:53:56,396 init.py:0082 DEBUG response: [ 6: (1 bytes) 0x02 3: (32 bytes) 0x8d4ea0d8077f5e52e015d90810f96021f751bbd1fd59698d0d5f047bcc99677e 5: (101 bytes) 0xd0a06e3c7057de061740e0526646e61285baea4c25f5ebf9ec5eef869ecb055dbb42437e30f43a16cfd35c64546bea22d7e001a3a9c232af599b26da936d2036280086856e13182211b8caace2025c3e42381e95069625aafd27601f07cec81772088f9e52 ]

2019-04-18 12:53:56,401 tlv.py:0117 DEBUG receiving [ 1: (17 bytes) 0x38633a63373a36383a34313a61633a6135 10: (64 bytes) 0x3616baad5b007998e06cb0b04f1cdc795bc85cd32a5ac6eeaefc528dc07deba439322b480d6d468766b775a3f2b4e58c0ace14abc7bf4ddeed2fa7d0fbfdb10b ]

2019-04-18 12:53:56,413 tlv.py:0134 DEBUG sending [ 1: (36 bytes) b'd9097764-8c21-4303-9790-8eb2ed64d913' 10: (64 bytes) b'6\x8e\x16A\x822\xe4\xec\x0e\xc5Q98:d\xf7\xee b\xc1\xefS\x1c$X"i>\xfa\xb6[\x10\x9c>n\xfek!}T^&\x95n\xf3\x98\xdf\xe0\xb3H\x1d\x8cl\x13K\x06\xbbm\xc7i\x13\x8e\xb4\x02' ]

2019-04-18 12:53:56,418 tlv.py:0134 DEBUG sending [ 6: (1 bytes) 0x03 5: (120 bytes) 0x3a2f8027f6f52e6f6269f1abbc5bf5aa08ac5d8335ef4bcf265591cc3a191d4ffc11a79ddd63b43700d91883e24e3422e06c0e7a5fc0bf87963d5ed20218f5de392573d6653e0f0f5d44d4aaff08a52e2a48fdd480c4624904f244a362edcd46c829aec826e78ecc40610fcb48decb09be95ac7dee49a427 ]

2019-04-18 12:53:56,418 tlv.py:0117 DEBUG receiving [ 6: (1 bytes) 0x03 5: (120 bytes) 0x3a2f8027f6f52e6f6269f1abbc5bf5aa08ac5d8335ef4bcf265591cc3a191d4ffc11a79ddd63b43700d91883e24e3422e06c0e7a5fc0bf87963d5ed20218f5de392573d6653e0f0f5d44d4aaff08a52e2a48fdd480c4624904f244a362edcd46c829aec826e78ecc40610fcb48decb09be95ac7dee49a427 ]

2019-04-18 12:53:56,418 init.py:0075 DEBUG write message: [ 6: (1 bytes) 0x03 5: (120 bytes) 0x3a2f8027f6f52e6f6269f1abbc5bf5aa08ac5d8335ef4bcf265591cc3a191d4ffc11a79ddd63b43700d91883e24e3422e06c0e7a5fc0bf87963d5ed20218f5de392573d6653e0f0f5d44d4aaff08a52e2a48fdd480c4624904f244a362edcd46c829aec826e78ecc40610fcb48decb09be95ac7dee49a427 ]

2019-04-18 12:53:56,497 tlv.py:0117 DEBUG receiving [ 6: (1 bytes) 0x04 ]

2019-04-18 12:53:56,497 init.py:0082 DEBUG response: [ 6: (1 bytes) 0x04 ]

2019-04-18 12:53:56,497 ip_implementation.py:0418 DEBUG session established 2019-04-18 12:53:56,882 tlv.py:0117 DEBUG receiving [ 6: (1 bytes) 0x02 ]

2019-04-18 12:53:56,882 controller.py:0529 DEBUG response data: [[6, bytearray(b'\x02')]] Pairing for "test" was removed.

Jc2k commented 5 years ago

If the unpair worked I don't need the logs.

Jc2k commented 5 years ago

Oh gods haha well done

jimz011 commented 5 years ago

Ah k, well I posted it anyways (srry about that). Anyways is it correct that there is only one entity created per device?

Edit: nvm was a stupid question, as it mimics the entities presented in homekit (which is one per device).

Jc2k commented 5 years ago

GH tip: If you surround your logs / tracebacks with ``` at the start and the end it uses a monospace font and is a bit easier to read.

Hard to say if i understand your question correctly as I don't have a tado. Let's say you had a thermostat and a radiator valve. I'd expect 2 entities. If you just have a thermostat and no radiator valves, i'd expect 1 entity. I'd expect these entities to be climate entities. They would have temperature readouts and you could set target temperatures and operation modes. They would potentially have humidity readouts and target humidity (entity will auto configure based on capabilities reported by the device).

If you can describe more about the 6 entities I can maybe elaborate on how that maps to homekit.

Some devices have batteries, these will be supported at some point and will probably be seperate entities. But I haven't wired up the battery service yet.

jimz011 commented 5 years ago

Ah yeah sorry about the monospace, seems to be different than the one on the home assistant forums (or its just me and not getting the right symbols on my phone, I have tried it in the past though).

What I meant was is that the Tado component (which currently is the only way to add Tado to HA) creates multiple entities per device. E.g.

Per device these entities will be created by the tado component. It uses the unofficial Tado API (which is just the official tado webinterface). I have to mention that most of these extra entities are completely useless to me as most of that info also resides in the climate entity.

I figured that this solution will only create a single entity per device as that is exactly what homekit would do (when I pair it to my phone).

But as I mentioned it was a stupid question to begin with. It all seems to work now, will try some integrations later on but man this is great work!

jimz011 commented 5 years ago

@cf00 sorry bit off topic. You said dev branch broke your custom components? Add the following file to your custom components (assuming you have already renamed all the components to the new format e.g. hue/light.py instead of light/hue.py).

__init__.py

Add this file to each folder (the file can be empty). Custom components should now work again. (I have tested this on rc as well but it isn’t working as it will throw errors). So for now it only works on dev branch.

cf00 commented 5 years ago

@jimz011 thanks. I had it already figured out. Had to add also DOMAIN = 'huesensor' to __init__.py but I guess with https://github.com/home-assistant/home-assistant/pull/23177 this shouldn't be necessary any more.

Everything is working for me now on 0.92.0b0 thanks to the great support from @Jc2k.

jimz011 commented 5 years ago

Ah yeah, in my case all but a few custom components were failing because of it. However I can’t seem to get it to work on rc (it throws me errors on rc when adding that file, and without it they won’t load at all).

Anyways once again thanks to all of you.

Jc2k commented 5 years ago

If either of you are able to easily try branches (sorry I'm not sure how this works with Docker images) then it would be a great help to me if you could try this one:

https://github.com/Jc2k/home-assistant/tree/homekit_pairing_entity_maps

It shouldn't have any noticeable changes (everything should work exactly as it does now), but its an important piece of prep for my config entries PR. It would be good to know it doesn't break anything.

(This will still require you to manually install homekit_python from git).

Jc2k commented 5 years ago

(This is now on dev upstream if that's easier to test, and even though it's merged 'd still appreciate if you can confirm whether it works for you).

cf00 commented 5 years ago

I failed miserably trying to update from github, but a new dev docker image was published just now, so I assume that would include your changes?

Anyway, I updated and am now on 0.93.0.dev0. So far everything seems normal and nothing seems to be broken. Anything in particular I should test or look at?

Jc2k commented 5 years ago

So in your config directory there should be a .storage directory - can you check if there is a homekit_controller-entity-map file? If that doesn't exist then my commit hasn't made it into the docker image yet (or my code is utterly broken).

cf00 commented 5 years ago

Ok, in the meantime two new dev docker images have been published and it now includes your changes. Must have missed it by a few seconds previously, but by now I am an expert in updating docker images :-)

So, the homekit_controller-entity-map is there and seems to contain the info for my tado devices. Everything still seems to work, nothing unusual in the UI or in the logs/console.

Jc2k commented 5 years ago

Excellent news - thank you very much for helping me test that.