get_events fails for Tado Internet Bridge

[elmopl]

I am not sure if that is a known problem. I have just bought a Tado system and homekit module has worked like a charm to pair up with it and then to query accessories and control them.

$ python3 -m homekit.get_accessories -f test.homekit -a tado
1.1: >accessory-information<
  1.2: tado Internet Bridge ............ () >name< [pr]
  1.3: tado () >manufacturer< [pr]
  1.4: ............ () >serial-number< [pr]
  1.5: IB01 () >model< [pr]
  1.6: 60.6 () >firmware.revision< [pr]
  1.7:  () >identify< [pw]
1.8: >Unknown Service: E44673A0-247B-4360-8A76-DB9DA69C0100<
  1.9:  () >Unknown Characteristic E44673A0-247B-4360-8A76-DB9DA69C0101< [pw]
2.1: >accessory-information<
  2.2: tado Smart Radiator Thermostat ............ () >name< [pr]
  2.3: tado () >manufacturer< [pr]
  2.4: ............ () >serial-number< [pr]
  2.5: SRT01 () >model< [pr]
  2.6: 54.1 () >firmware.revision< [pr]
  2.7:  () >identify< [pw]
2.8: >Unknown Service: E44673A0-247B-4360-8A76-DB9DA69C0100<
  2.9:  () >Unknown Characteristic E44673A0-247B-4360-8A76-DB9DA69C0101< [pw]
2.10: >thermostat<
  2.11: tado Smart Radiator Thermostat ............ () >name< [pr]
  2.12: 1 () >heating-cooling.current< [pr,ev]
  2.13: 1 () >heating-cooling.target< [pr,pw,ev]
  2.14: 20.8 () >temperature.current< [pr,ev]
  2.15: 25 () >temperature.target< [pr,pw,ev]
  2.16: 0 () >temperature.units< [pr,pw,ev]
  2.17: 51 () >relative-humidity.current< [pr,ev]

Everything is working fine except for get_events. I was hoping I could avoid active polling temperatures and it seems homekit has get_events that should just keep on getting updated when new value comes in.

I have modified to see the payload that comes back and it seems empty:

2020-04-03 16:12:17,390 ip_implementation.py:0445 DEBUG session established
2020-04-03 16:12:17,391 secure_http.py:0073 DEBUG handle request: b'PUT /characteristics HTTP/1.1\r\nHost: 192.168.1.20:80\r\nContent-Type: application/hap+json\r\nContent-Length: 56\r\n\r\n{"characteristics": [{"aid": 2, "iid": 14, "ev": true}]}'
Session closed after receiving malformed response from device (bytearray(b''))
2020-04-03 16:12:17,411 get_events.py:0073 DEBUG Session closed after receiving malformed response from device (bytearray(b''))
Traceback (most recent call last):
  File "/usr/local/lib/python3.7/dist-packages/homekit/controller/ip_implementation.py", line 313, in get_events
    data = json.loads(body.decode())
  File "/usr/lib/python3.7/json/__init__.py", line 348, in loads
    return _default_decoder.decode(s)
  File "/usr/lib/python3.7/json/decoder.py", line 337, in decode
    obj, end = self.raw_decode(s, idx=_w(s, 0).end())
  File "/usr/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/dist-packages/homekit/get_events.py", line 68, in <module>
    results = pairing.get_events(characteristics, func, max_events=args.eventCount, max_seconds=args.secondsCount)
  File "/usr/local/lib/python3.7/dist-packages/homekit/controller/ip_implementation.py", line 317, in get_events
    raise AccessoryDisconnectedError(f"Session closed after receiving malformed response from device ({body})")
homekit.exceptions.AccessoryDisconnectedError: Session closed after receiving malformed response from device (bytearray(b''))

I couldn't find anyone with similar issue around and I don't have any other HomeKit devices to check if the issue is with Tado bridge or is there something I am doing wrong.

[Jc2k]

I have seen this with tado bridges, but same code works fine with many other devices. The empty string is actually the tado resetting the tcp connnection afaict.

We have previously had to change homekit_python to work around tado having a verrrry picky HomeKit implementation. It’s probably that the http message is subtly different to what a real iOS client sends.

[elmopl]

I guess this answers the question. As I am planning to push all my data to one mqtt queue, I guess I can just have a small script that polls state of things every minute or so and hide away that.

If there are any hints into what to look into in terms of protocol I might give it a shot to make it work (even if it's not going to get merged into main release having a working code locally would be useful if I can craft it).

[Jc2k]

I think we should try and understand what we are doing differently to iOS if we can. It might be as simple as sending “ev”: 1 instead of “ev”: True or tweaking one of the headers we send.

[jlusiardi]

hey @Jc2k this could be a thing for the debug proxy I've added lately to work on the IP Camera stuff. What do you think for debugging the tado get events with the proxy between an iPhone and a tado device? At least the question with the “ev”: 1 vs. “ev”: True from the phone to the accessory should be solvable...

Also, the spec in R1 and R2 say "ev": true.

[elmopl]

I tried "1" (as int) in json payload sent, but seems to have made no difference. The only Apple device I have access to is iPhone. Is there a way to make iPhone attempt to get events so I could peek at what it sends?

[jlusiardi]

@elmopl few questions:

• can you use the master from this git?
• can you please attach what the discover command prints?

Perhaps we can use the phone and the debug proxy to figure out what the phone sends to activate the events.

[Jc2k]

Sounds like a great opportunity to use the debug proxy!

To answer question about get events and iPhone - there isn’t a specific command, it will just always enable events if they are supported.

[elmopl]

$ PYTHONPATH=homekit_python/ python3 -m homekit.discover
Name: tado Internet Bridge XXXXXXXXXXXX._hap._tcp.local.
Url: http_impl://192.168.1.20:80
Configuration number (c#): 3
Feature Flags (ff): Supports HAP Pairing (Flag: 1)
Device ID (id): ab:cd:ef:gh:11:22
Model Name (md): tado Internet Bridge
Protocol Version (pv): 1.0
State Number (s#): 1
Status Flags (sf): Accessory has been paired. (Flag: 0)
Category Identifier (ci): Bridge (Id: 2)

[elmopl]

So I managed to get debug_proxy running, however I am not sure how to trigger "get_events" from iPhone "Home" app. Oddly enough "Home" app does not respect or acknowledge Tado's max temperature limitation.

However I can see commands being sent through the proxy.

[jlusiardi]

cool! My guess is, that the home app activates events as soon as it is started.

so I guess the best thing to do is:

1. close the home app
2. wait till nothing happens in the log of the proxy anymore
3. hit enter a few times to get a visual separation
4. start the app again
5. post everything after the visual separation (perhaps as gist)

(or just redirect directly into a file after restarting the proxy)

[elmopl]

2020-04-03 18:27:20,223 debug_proxy.py:0261 INFO %<------ finished creating proxy ------
2020-04-03 18:27:20,233 __init__.py:2297 ERROR Unknown error, possibly benign: KeyError('demoaccessory._hap._tcp.local.')
Traceback (most recent call last):
  File "/usr/local/lib/python3.7/dist-packages/zeroconf/__init__.py", line 2291, in unregister_service
    del self.services[info.name.lower()]
KeyError: 'demoaccessory._hap._tcp.local.'

Is that important? It doesn't seem to stop anything from working.

[elmopl]

And output from just opening the Home app after a long time of inactivity:

2020-04-03 18:28:15,873 accessoryserver.py:1219 INFO "POST /pair-verify HTTP/1.1" 200 -
2020-04-03 18:28:15,919 accessoryserver.py:1219 INFO "POST /pair-verify HTTP/1.1" 200 -
2020-04-03 18:28:15,936 accessoryserver.py:1219 INFO "GET /accessories HTTP/1.1" 200 -
2020-04-03 18:28:17,906 accessoryserver.py:1219 INFO "PUT /characteristics HTTP/1.1" 204 -
2020-04-03 18:28:17,954 debug_proxy.py:0132 INFO get value from 2.16 (type 00000036-0000-1000-8000-0026BB765291 / temperature.units):
0
2020-04-03 18:28:17,977 debug_proxy.py:0132 INFO get value from 2.14 (type 00000011-0000-1000-8000-0026BB765291 / temperature.current):
19.9
2020-04-03 18:28:18,000 debug_proxy.py:0132 INFO get value from 2.15 (type 00000035-0000-1000-8000-0026BB765291 / temperature.target):
25
2020-04-03 18:28:18,021 debug_proxy.py:0132 INFO get value from 2.12 (type 0000000F-0000-1000-8000-0026BB765291 / heating-cooling.current):
1
2020-04-03 18:28:18,036 debug_proxy.py:0132 INFO get value from 2.13 (type 00000033-0000-1000-8000-0026BB765291 / heating-cooling.target):
1
2020-04-03 18:28:18,036 accessoryserver.py:1219 INFO "GET /characteristics?id=2.16,2.14,2.15,2.12,2.13 HTTP/1.1" 200 -

[elmopl]

Also, I found this https://climespace.staging.mink-agency.com/storage/publications/pdf/xWdVNKrwE7NgZ6lhwdts6B22bJwo2GLfd314P5Qf.pdf

Not sure how reliable this is as a source for the homekit protocol, however it has this description (page 90):

If the characteristic supports notifications then the accessory must respond with a204 No ContentHTTPstatus code and an empty body.

So it sounds like Tado is responding as described.

edit: Actually it seems to be returning wrong code.

[Jc2k]

Would it be useful to repeat this with DEBUG_CRYPT (https://github.com/jlusiardi/homekit_python/blob/master/homekit/accessoryserver.py#L202) set your true to see the raw http from the iPhone?

[elmopl]

2020-04-03 18:54:36,796 accessoryserver.py:1219 INFO "POST /pair-verify HTTP/1.1" 200 -
2020-04-03 18:54:36,852 accessoryserver.py:1219 INFO "POST /pair-verify HTTP/1.1" 200 -
2020-04-03 18:54:36,864 accessoryserver.py:1219 INFO data >82< >b'1c60fa2856749909f7b1ecebd0b58d83438c53a2f4f1cb311d6dc7fcb11c8116ae9bc394d75ed6722d171407f31fa5891a684ed088ce6ac1c4b9e90915a49dd634f4fe70be1cf8aad00f1d07fad4a9a4e380'<
2020-04-03 18:54:36,872 accessoryserver.py:1219 INFO crypted request >bytearray(b'GET /accessories HTTP/1.1\r\nHost: DemoAccessory._hap._tcp.local\r\n\r\n')<
2020-04-03 18:54:36,874 accessoryserver.py:1219 INFO "GET /accessories HTTP/1.1" 200 -
2020-04-03 18:54:36,875 accessoryserver.py:1219 INFO response >b'HTTP/1.1 200 OK\r\nServer: BaseHTTP/0.6 Python/3.7.3\r\nDate: Fri, 03 Apr 2020 17:54:36 GMT\r\nContent-Type: application/hap+json\r\nContent-Length: 3136\r\n\r\n{"accessories": [{"aid": 1, "services": [{"iid": 1, "type": "0000003E-0000-1000-8000-0026BB765291", "characteristics": [{"type": "00000023-0000-1000-8000-0026BB765291", "iid": 2, "perms": ["pr"], "format": "string", "value": "tado Internet Bridge IB2740980992", "maxLen": 64}, {"type": "00000020-0000-1000-8000-0026BB765291", "iid": 3, "perms": ["pr"], "format": "string", "value": "tado", "maxLen": 64}, {"type": "00000030-0000-1000-8000-0026BB765291", "iid": 4, "perms": ["pr"], "format": "string", "value": "IB2740980992", "maxLen": 64}, {"type": "00000021-0000-1000-8000-0026BB765291", "iid": 5, "perms": ["pr"], "format": "string", "value": "IB01", "maxLen": 64}, {"type": "00000052-0000-1000-8000-0026BB765291", "iid": 6, "perms": ["pr"], "format": "string", "value": "60.6", "maxLen": 64}, {"type": "00000014-0000-1000-8000-0026BB765291", "iid": 7, "perms": ["pw"], "format": "bool"}]}, {"iid": 8, "type": "E44673A0-247B-4360-8A76-DB9DA69C0100", "characteristics": [{"type": "E44673A0-247B-4360-8A76-DB9DA69C0101", "iid": 9, "perms": ["pw"], "format": "string", "maxLen": 64}]}]}, {"aid": 2, "services": [{"iid": 1, "type": "0000003E-0000-1000-8000-0026BB765291", "characteristics": [{"type": "00000023-0000-1000-8000-0026BB765291", "iid": 2, "perms": ["pr"], "format": "string", "value": "tado Smart Radiator Thermostat VA2911374592", "maxLen": 64}, {"type": "00000020-0000-1000-8000-0026BB765291", "iid": 3, "perms": ["pr"], "format": "string", "value": "tado", "maxLen": 64}, {"type": "00000030-0000-1000-8000-0026BB765291", "iid": 4, "perms": ["pr"], "format": "string", "value": "VA2911374592", "maxLen": 64}, {"type": "00000021-0000-1000-8000-0026BB765291", "iid": 5, "perms": ["pr"], "format": "string", "value": "SRT01", "maxLen": 64}, {"type": "00000052-0000-1000-8000-0026BB765291", "iid": 6, "perms": ["pr"], "format": "string", "value": "54.1", "maxLen": 64}, {"type": "00000014-0000-1000-8000-0026BB765291", "iid": 7, "perms": ["pw"], "format": "bool"}]}, {"iid": 8, "type": "E44673A0-247B-4360-8A76-DB9DA69C0100", "characteristics": [{"type": "E44673A0-247B-4360-8A76-DB9DA69C0101", "iid": 9, "perms": ["pw"], "format": "string", "maxLen": 64}]}, {"iid": 10, "type": "0000004A-0000-1000-8000-0026BB765291", "characteristics": [{"type": "00000023-0000-1000-8000-0026BB765291", "iid": 11, "perms": ["pr"], "format": "string", "value": "tado Smart Radiator Thermostat VA2911374592", "maxLen": 64}, {"type": "0000000F-0000-1000-8000-0026BB765291", "iid": 12, "perms": ["pr", "ev"], "format": "uint8", "value": 1}, {"type": "00000033-0000-1000-8000-0026BB765291", "iid": 13, "perms": ["pr", "pw", "ev"], "format": "uint8", "value": 1}, {"type": "00000011-0000-1000-8000-0026BB765291", "iid": 14, "perms": ["pr", "ev"], "format": "float", "value": 21.1}, {"type": "00000035-0000-1000-8000-0026BB765291", "iid": 15, "perms": ["pr", "pw", "ev"], "format": "float", "value": 25}, {"type": "00000036-0000-1000-8000-0026BB765291", "iid": 16, "perms": ["pr", "pw", "ev"], "format": "uint8", "value": null}, {"type": "00000010-0000-1000-8000-0026BB765291", "iid": 17, "perms": ["pr", "ev"], "format": "float", "value": 51}]}]}]}'<
2020-04-03 18:54:36,876 accessoryserver.py:1219 INFO len(response) 3285
2020-04-03 18:54:36,876 accessoryserver.py:1219 INFO ==> BLOCK: len 1024
2020-04-03 18:54:36,904 accessoryserver.py:1219 INFO ==> BLOCK: len 1024
2020-04-03 18:54:36,926 accessoryserver.py:1219 INFO ==> BLOCK: len 1024
2020-04-03 18:54:36,948 accessoryserver.py:1219 INFO ==> BLOCK: len 213
2020-04-03 18:54:39,576 accessoryserver.py:1219 INFO data >338< >b'4d16fd67143e79da275dc5da46d7d6fa61209f665d60ce6e730a12658ab81d4251a2ae5fb8c87ac987f023bdc9ca34740eeb9eb2d741cdcc67ee108932aa4e47f355f2136ae3e1e209f79b5153025e6df68fc6d46bd2a20b1ae43b8338a348fe73d10960c07c3137caba04c7b433abd3662cdc42c1a209ef9e9ea02616da18b17e5377d1127686b8c132b200aba9193d59a6de4d0721297392c1737764dd246be3ec99ad2ad1be0f183c0841edd37a1e870a97dd8a8537ab7fc09aa16ce93ed46842d516d74a439c683e306d82718a00ed16f6ce91ea6ed4ee50622a201426d5261f4cabc403ae1191ccaf9498edcd897bb249fbd366e102838eaa9589e2692b9f412514e86ff28d8c62abbf9e75150dac056f0b20475d9fc212a0229810af8ef2aef69dbd862149e826b837088a77a691a002392f2ecf50a2d18fb1632b740d9320b776a378158a491368ba51ed29104e53'<
2020-04-03 18:54:39,598 accessoryserver.py:1219 INFO crypted request >bytearray(b'PUT /characteristics HTTP/1.1\r\nHost: DemoAccessory._hap._tcp.local\r\nContent-Length: 195\r\nContent-Type: application/hap+json\r\n\r\n{"characteristics":[{"aid":2,"iid":12,"ev":true},{"aid":2,"iid":13,"ev":true},{"aid":2,"iid":14,"ev":true},{"aid":2,"iid":15,"ev":true},{"aid":2,"iid":16,"ev":true},{"aid":2,"iid":17,"ev":true}]}')<
2020-04-03 18:54:39,599 accessoryserver.py:1219 INFO PUT /characteristics
2020-04-03 18:54:39,600 accessoryserver.py:1219 INFO body: b'{"characteristics":[{"aid":2,"iid":12,"ev":true},{"aid":2,"iid":13,"ev":true},{"aid":2,"iid":14,"ev":true},{"aid":2,"iid":15,"ev":true},{"aid":2,"iid":16,"ev":true},{"aid":2,"iid":17,"ev":true}]}'
2020-04-03 18:54:39,600 accessoryserver.py:1219 INFO set ev >2< >12< >True<
2020-04-03 18:54:39,600 accessoryserver.py:1219 INFO set ev >2< >13< >True<
2020-04-03 18:54:39,601 accessoryserver.py:1219 INFO set ev >2< >14< >True<
2020-04-03 18:54:39,601 accessoryserver.py:1219 INFO set ev >2< >15< >True<
2020-04-03 18:54:39,601 accessoryserver.py:1219 INFO set ev >2< >16< >True<
2020-04-03 18:54:39,601 accessoryserver.py:1219 INFO set ev >2< >17< >True<
2020-04-03 18:54:39,602 accessoryserver.py:1219 INFO "PUT /characteristics HTTP/1.1" 204 -
2020-04-03 18:54:39,602 accessoryserver.py:1219 INFO response >b'HTTP/1.1 204 No Content\r\nServer: BaseHTTP/0.6 Python/3.7.3\r\nDate: Fri, 03 Apr 2020 17:54:39 GMT\r\n\r\n'<
2020-04-03 18:54:39,603 accessoryserver.py:1219 INFO len(response) 99
2020-04-03 18:54:39,603 accessoryserver.py:1219 INFO ==> BLOCK: len 99
2020-04-03 18:54:39,734 accessoryserver.py:1219 INFO data >114< >b'c6ae915911b6407fb60a622c2d17888020dc888a79916576b1ec90f62955912855a2203a4b9d6281907e2308745c6b31c300162b220667cd02806d70afb7dcab727751799e1e1ccc7afb7743d1e27f0640ba477d5fcd114769dd642e75511036227f62aa4fffc8a4b681604df9f3ff86b0bf'<
2020-04-03 18:54:39,742 accessoryserver.py:1219 INFO crypted request >bytearray(b'GET /characteristics?id=2.14,2.15,2.12,2.16,2.13 HTTP/1.1\r\nHost: DemoAccessory._hap._tcp.local\r\n\r\n')<
2020-04-03 18:54:39,743 accessoryserver.py:1219 INFO GET /characteristics
2020-04-03 18:54:39,743 accessoryserver.py:1219 INFO query parameters: ids: ['2.14', '2.15', '2.12', '2.16', '2.13'], meta: False, perms: False, type: False, ev: False

[elmopl]

So changing (remove spaces from json):

331             data.append({'aid': aid, 'iid': iid, 'ev': True})
332         data = json.dumps({'characteristics': data})

to

331             data.append({'aid': aid, 'iid': iid, 'ev': True})
332         data = json.dumps({'characteristics': data}).replace(' ', '')

Makes get_events "hang". And changing the temperature I got event for it.

So it seems to be spaces it is fussy about.

[elmopl]

Better fix:

332         data = json.dumps({'characteristics': data}, separators=(',', ':'))

[Jc2k]

Wow. Well if the iPhone sends it without spaces and the tado relies on this then it sounds like something homekit_python should do too, though thats definitely not mentioned in the spec! :-p

[jlusiardi]

Ok, using separators=(',', ':') would be the way to go for me.

IMHO this is really not following the specs. The examples show nicely formatted json.

[jlusiardi]

@elmopl just to figure out if the device is also picking on writing characteristics, can you please try if this also fails (it should, because we write json to the tado):

PYTHONPATH=homekit_python/ python3 -m homekit.put_characteristic -f ${PAIRINGDATAFILE} -a ${ALIAS} -c 2.15 25

[jlusiardi]

closing since #182 was merged