rytilahti / python-miio

Python library & console tool for controlling Xiaomi smart appliances
https://python-miio.readthedocs.io
GNU General Public License v3.0
3.75k stars 561 forks source link

Qingping Air Monitor firmware update breaks request - Root Cause Identified #1489

Closed HikerScott closed 2 years ago

HikerScott commented 2 years ago

When my Qingping Air Monitor received an update this morning, it changed it's token (which was annoying) but, even worse, the request for status no longer works.

Info request return:

/data/data/com.termux/files/usr/bin/miiocli -o json_pretty airqualitymonitor --token <bigLongTokenRedacted> --ip 192.168.1.66 info {
  "life": 3808,
  "model": "cgllc.airmonitor.s1", "token": "<bigLongTokenRedacted>", "ipflag": 1,
  "miio_ver": "0.0.9", "mac": "<macRedacted>",
  "fw_ver": "4.1.8_9999", "hw_ver": "Linux", "miio_client_ver": "4.1.8",
  "VmPeak": 48704,
  "VmRSS": 920, "MemFree": 99544, "ap": {
    "ssid": "<ssidRedacted>",
    "bssid": "<alsoRedacted>", "rssi": "-17", "freq": 2462
  }, "netif": {
    "localIp": "192.168.1.66", "mask": "255.255.255.0",
    "gw": "192.168.1.254" }, "miio_times": [
    3808,
    12,
    0,
    3794
  ]
}

Status request return:

/data/data/com.termux/files/usr/bin/miiocli airqualitymonitor --token 774e65686f387773307151696c50324d --ip 192.168.1.66 status Traceback (most recent call last):
  File "/data/data/com.termux/files/usr/bin/miiocli", line 8, in <module>
    sys.exit(create_cli()) File "/data/data/com.termux/files/usr/lib/python3.10/site-packages/miio/cli.py", line 66, in create_cli
    return cli(auto_envvar_prefix="MIIO")
  File "/data/data/com.termux/files/usr/lib/python3.10/site-packages/miio/click_common.py", line 51, in __call__
    return self.main(*args, **kwargs)
  File "/data/data/com.termux/files/usr/lib/python3.10/site-packages/click/core.py", line 1055, in main
    rv = self.invoke(ctx)
  File "/data/data/com.termux/files/usr/lib/python3.10/site-packages/click/core.py", line 1657, in invoke
    return _process_result(sub_ctx.command.invoke(sub_ctx)) File "/data/data/com.termux/files/usr/lib/python3.10/site-packages/click/core.py", line 1657, in invoke
    return _process_result(sub_ctx.command.invoke(sub_ctx))
  File "/data/data/com.termux/files/usr/lib/python3.10/site-packages/click/core.py", line 1404, in invoke
    return ctx.invoke(self.callback, **ctx.params)
  File "/data/data/com.termux/files/usr/lib/python3.10/site-packages/click/core.py", line 760, in invoke
    return __callback(*args, **kwargs)
  File "/data/data/com.termux/files/usr/lib/python3.10/site-packages/miio/click_common.py", line 305, in wrap
    kwargs["result"] = func(*args, **kwargs)
  File "/data/data/com.termux/files/usr/lib/python3.10/site-packages/click/decorators.py", line 84, in new_func
    return ctx.invoke(f, obj, *args, **kwargs)
  File "/data/data/com.termux/files/usr/lib/python3.10/site-packages/click/core.py", line 760, in invoke
    return __callback(*args, **kwargs)
  File "/data/data/com.termux/files/usr/lib/python3.10/site-packages/miio/click_common.py", line 270, in command_callback
    return miio_command.call(miio_device, *args, **kwargs)
  File "/data/data/com.termux/files/usr/lib/python3.10/site-packages/miio/click_common.py", line 217, in call
    return method(*args, **kwargs)
  File "/data/data/com.termux/files/usr/lib/python3.10/site-packages/miio/click_common.py", line 184, in _wrap
    return func(self, *args, **kwargs)
  File "/data/data/com.termux/files/usr/lib/python3.10/site-packages/miio/airqualitymonitor.py", line 197, in status
    return AirQualityMonitorStatus(defaultdict(lambda: None, values))
ValueError: dictionary update sequence element #0 has length 1; 2 is required
rytilahti commented 2 years ago

Please add --debug to your status requests and you will see what type of response the device send to you, that might or might not help.

Are any of the commands working?

HikerScott commented 2 years ago

Really appreciate you getting back so quickly! Lots of different things happening here. One is that the token keeps changing. :(

The info command, as shown in the first box above, works.

Here's the debug of a non-working status command -- you'll see you get back the none of the requested information, just an acknowledgement that the request was "ok" and the exe time:

/data/data/com.termux/files/usr/bin/miiocli --debug airqualitymonitor --token <tokenChangingOftenSucks> --ip 192.168.1.66 status
INFO:miio.cli:Debug mode active DEBUG:miio.click_common:Unknown model, trying autodetection. None None
DEBUG:miio.miioprotocol:Got a response: Container: data = Container: data = b'' (total 0)
        value = b'' (total 0) offset1 = 32
        offset2 = 32 length = 0 header = Container:
        data = b'!1\x00 \x00\x00\x00\x00\x0fZ\x15\x18\x00\x00\x02-' (total 16) value = Container: length = 32
            unknown = 0
            device_id = unhexlify('0f5a1518') ts = 1970-01-01 00:09:17 offset1 = 0
        offset2 = 16 length = 16
    checksum = b'\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff' (total 16)
DEBUG:miio.miioprotocol:Discovered 0f5a1518 with ts: 1970-01-01 00:09:17, token: b'ffffffffffffffffffffffffffffffff'
DEBUG:miio.miioprotocol:[192.168.1.66:54321](http://192.168.1.66:54321/) >>: {'id': 1, 'method': 'miIO.info', 'params': []}
DEBUG:miio.miioprotocol:[192.168.1.66:54321](http://192.168.1.66:54321/) (ts: 1970-01-01 00:09:17, id: 1) << {'id': 1, 'result': {'life': 557, 'model': 'cgllc.airmonitor.s1', 'token': '<tokenChangingOftenSucks>', 'ipflag': 1, 'miio_ver': '0.0.9', 'mac': '<redacted>', 'fw_ver': '4.1.8_9999', 'hw_ver': 'Linux', 'miio_client_ver': '4.1.8', 'VmPeak': 48704, 'VmRSS': 756, 'MemFree': 83948, 'ap': {'ssid': '<redacted>', 'bssid': '<redacted>', 'rssi': '-52', 'freq': 2462}, 'netif': {'localIp': '192.168.1.66', 'mask': '255.255.255.0', 'gw': '192.168.1.254'}, 'miio_times': [557, 0, 0, 555]}, 'exe_time': 7}
DEBUG:miio.device:Detected model cgllc.airmonitor.s1
DEBUG:miio.miioprotocol:[192.168.1.66:54321](http://192.168.1.66:54321/) >>: {'id': 2, 'method': 'get_prop', 'params': ['battery', 'co2', 'humidity', 'pm25', 'temperature', 'tvoc']}
DEBUG:miio.miioprotocol:[192.168.1.66:54321](http://192.168.1.66:54321/) (ts: 1970-01-01 00:09:18, id: 2) << {'id': 2, 'result': 'ok', 'exe_time': 46}
DEBUG:miio.airqualitymonitor:Count (6) of requested properties does not match the count (2) of received values.
Traceback (most recent call last):
  File "/data/data/com.termux/files/usr/bin/miiocli", line 8, in <module>
    sys.exit(create_cli())
  File "/data/data/com.termux/files/usr/lib/python3.10/site-packages/miio/cli.py", line 66, in create_cli
    return cli(auto_envvar_prefix="MIIO")
  File "/data/data/com.termux/files/usr/lib/python3.10/site-packages/miio/click_common.py", line 51, in __call__
    return self.main(*args, **kwargs)
  File "/data/data/com.termux/files/usr/lib/python3.10/site-packages/click/core.py", line 1055, in main
    rv = self.invoke(ctx)
  File "/data/data/com.termux/files/usr/lib/python3.10/site-packages/click/core.py", line 1657, in invoke
    return _process_result(sub_ctx.command.invoke(sub_ctx))
  File "/data/data/com.termux/files/usr/lib/python3.10/site-packages/click/core.py", line 1657, in invoke
    return _process_result(sub_ctx.command.invoke(sub_ctx))
  File "/data/data/com.termux/files/usr/lib/python3.10/site-packages/click/core.py", line 1404, in invoke
    return ctx.invoke(self.callback, **ctx.params)
  File "/data/data/com.termux/files/usr/lib/python3.10/site-packages/click/core.py", line 760, in invoke
    return __callback(*args, **kwargs)
  File "/data/data/com.termux/files/usr/lib/python3.10/site-packages/miio/click_common.py", line 305, in wrap
    kwargs["result"] = func(*args, **kwargs)
  File "/data/data/com.termux/files/usr/lib/python3.10/site-packages/click/decorators.py", line 84, in new_func
    return ctx.invoke(f, obj, *args, **kwargs)
  File "/data/data/com.termux/files/usr/lib/python3.10/site-packages/click/core.py", line 760, in invoke
    return __callback(*args, **kwargs)
  File "/data/data/com.termux/files/usr/lib/python3.10/site-packages/miio/click_common.py", line 270, in command_callback
    return miio_command.call(miio_device, *args, **kwargs)
  File "/data/data/com.termux/files/usr/lib/python3.10/site-packages/miio/click_common.py", line 217, in call
    return method(*args, **kwargs)
  File "/data/data/com.termux/files/usr/lib/python3.10/site-packages/miio/click_common.py", line 184, in _wrap
    return func(self, *args, **kwargs)
  File "/data/data/com.termux/files/usr/lib/python3.10/site-packages/miio/airqualitymonitor.py", line 197, in status
    return AirQualityMonitorStatus(defaultdict(lambda: None, values))
ValueError: dictionary update sequence element #0 has length 1; 2 is required
~ $ |

So I went into developer mode on the box itself and restarted the client in debug mode. Here's what I see:

2022:08:12:06:43:23.929 [D] otu: [192.168.1.65:56724] talking, len=144
2022:08:12:06:43:23.930 [D] otu: local rpc packet.
2022:08:12:06:43:23.931 [D] otu: {"id": 2, "method": "get_prop", "params": ["battery", "co2", "humidity", "pm25", "temperature", "tvoc"]}.
2022:08:12:06:43:23.942 [D] ot: get_prop[id=2] is a ext method
2022:08:12:06:43:23.942 [D] miio_ot: ext rpc recvd
2022:08:12:06:43:23.943 [I] miio_instance: miio_ext_rpc_hook_default called
2022:08:12:06:43:23.943 [I] miio_instance: ext rpc [id=2]
2022:08:12:06:43:23.944 [D] miio_client_func: method_local_broadcast_msg(), {"id": 2, "method": "get_prop", "params": ["battery", "co2", "humidity", "pm25", "temperature", "tvoc"]}
2022:08:12:06:43:23.944 [D] miio_client_func: 7, msg: {"id": 2, "method": "get_prop", "params": ["battery", "co2", "humidity", "pm25", "temperature", "tvoc"]},  len:104
2022:08:12:06:43:23.945 [D] D0: timer@b49007e8 = 777ms, time_elapsed = 25ms
2022:08:12:06:43:23.973 [D] miio_client_func: ot_agent_recv_handler(): fd:7, recv_len:22 bytes, total_len:22 bytes, total_msg:{"id":2,"result":"ok"}
2022:08:12:06:43:23.974 [D] miio_client_func: ot_agent_recv_handler_one(): fd:7, msg:{"id":2,"result":"ok"} length:22 bytes
2022:08:12:06:43:23.974 [D] miio_client_func: handle_command_ack_msg: {"id":2,"result":"ok"}
2022:08:12:06:43:23.974 [I] miio_client_func: Up-ack msg, id:2, fd:7, len=22
2022:08:12:06:43:23.974 [D] ot: ot_down_rpc_delegate_ack_handle(), 506, malloc_len: 94, pload_len: 22
2022:08:12:06:43:23.974 [D] miio_client_func: left_len: 0, left_buf:
2022:08:12:06:43:23.975 [D] miio_client_func: ot_agent_recv_handler(): fd:7, recv_len:-1 bytes, total_len:-1 bytes, total_msg:
2022:08:12:06:43:23.976 [D] ot: ot_down_rpc_delegate_finish(), 419, id: 2, timestamp: 0, tick: 0, pload_len: 22
2022:08:12:06:43:23.976 [D] otu: otu_down_rpc_delegate_ack(), 329, ack: {"id":2,"result":"ok","exe_time":34}, len: 36

So that's not great. One hint may be the cloud receiving it's subscription... their method doesn't seem to be "get_prop" but "props". Dunno if that will help:

2022:08:12:06:59:28.539 [D] miio_client_func: ot_agent_recv_handler(): fd:10, recv_len:444 bytes, total_len:444 bytes, total_msg:{"id":423,"method":"props","params":{"battery":100,"battery_state":"charging","co2":"1277","co2_duration":0,"co2_state":"sampling","co2_timestamp":1660258768,"humidity":"53.3","humidity_state":"sampling","pm25":"8","pm25_state":"sampling","pm25_timestamp":1660258768,"temperature":"22.0","temperature_state":"sampling","temperature_unit":"c","tvoc":"869","tvoc_duration":0,"tvoc_state":"sampling","tvoc_timestamp":1660258767,"tvoc_unit":"ppb"}}
2022:08:12:06:59:28.539 [D] miio_client_func: ot_agent_recv_handler_one(): fd:10, msg:{"id":423,"method":"props","params":{"battery":100,"battery_state":"charging","co2":"1277","co2_duration":0,"co2_state":"sampling","co2_timestamp":1660258768,"humidity":"53.3","humidity_state":"sampling","pm25":"8","pm25_state":"sampling","pm25_timestamp":1660258768,"temperature":"22.0","temperature_state":"sampling","temperature_unit":"c","tvoc":"869","tvoc_duration":0,"tvoc_state":"sampling","tvoc_timestamp":1660258767,"tvoc_unit":"ppb"}} length:444 bytes
2022:08:12:06:59:28.539 [D] miio_client_rpc: call={"id":423,"method":"props","params":{"battery":100,"battery_state":"charging","co2":"1277","co2_duration":0,"co2_state":"sampling","co2_timestamp":1660258768,"humidity":"53.3","humidity_state":"sampling","pm25":"8","pm25_state":"sampling","pm25_timestamp":1660258768,"temperature":"22.0","temperature_state":"sampling","temperature_unit":"c","tvoc":"869","tvoc_duration":0,"tvoc_state":"sampling","tvoc_timestamp":1660258767,"tvoc_unit":"ppb"}}
2022:08:12:06:59:28.540 [D] ots: ots_up_rpc_delegate_out_cb(), 292, {"id":423,"method":"props","params":{"battery":100,"battery_state":"charging","co2":"1277","co2_duration":0,"co2_state":"sampling","co2_timestamp":1660258768,"humidity":"53.3","humidity_state":"sampling","pm25":"8","pm25_state":"sampling","pm25_timestamp":1660258768,"temperature":"22.0","temperature_state":"sampling","temperature_unit":"c","tvoc":"869","tvoc_duration":0,"tvoc_state":"sampling","tvoc_timestamp":1660258767,"tvoc_unit":"ppb"}}
2022:08:12:06:59:33.462 [D] miio_client_func: ot_agent_recv_handler(): fd:10, recv_len:114 bytes, total_len:114 bytes, total_msg:{"id":425,"method":"props","params":{"co2":"1277","humidity":"53.3","pm25":"8","temperature":"22.0","tvoc":"865"}}
2022:08:12:06:59:33.463 [D] miio_client_func: ot_agent_recv_handler_one(): fd:10, msg:{"id":425,"method":"props","params":{"co2":"1277","humidity":"53.3","pm25":"8","temperature":"22.0","tvoc":"865"}} length:114 bytes
2022:08:12:06:59:33.463 [D] miio_client_rpc: call={"id":425,"method":"props","params":{"co2":"1277","humidity":"53.3","pm25":"8","temperature":"22.0","tvoc":"865"}}

I'm at my limit for looking into things... After figuring out how to get the real data, the other issue will be about how I handle the token changing often (haven't figured out how often yet).

HikerScott commented 2 years ago

ROOT CAUSE IDENTIFIED

Stumbled across the test_properties function. With this new release, "battery" is not a valid property. Inclusion of "battery" in the state request causes a result of "ok" with no valid data. If you remove "battery" from your list properties, all other data values are properly returned. There are other properties which one would expect were valid that cause the same problem.

Invalid properties which will cause a get_prop to fail: battery co2_duration co2_timestamp pm25_timestamp temperature_state temperature_unit tvoc_duration tvoc_timestamp

Valid properties: co2 co2_state humidity humidity_state pm25 pm25_state temperature tvoc tvoc_state tvoc_unit

Solution Don't request "battery" with it's other params, at least for this version of firmware. I have not determined if there is another param listed that will return the battery, though I have tried battery_level, batterylevel, battery_life, batterylife, battery_charge and batterycharge and none of them work.

Ulitmately, if we can find a way to get battery that would be ideal, but if we can't to maintain backwards compatibility, it may be worthwhile not requesting "battery" from the unit but returning an invalid value (eg. 0, 999) to the operator and making a note in documentation somewhere... or change to have a "state_v4" and let "state" return invalid, or have a whole new product type "airqualitymonitor_v4". I'll leave that up to whoever is kind enough to fix this, and will send all my love their way.

pkmcnc commented 2 years ago

any fixes so far? please

sstu commented 2 years ago

2022.8.6 not fixed

HikerScott commented 2 years ago

2022.8.6 not fixed

Indeed, the root cause was identified 5 days after that release and they haven't got the bugs out of the time machines yet. :)

I'm keeping my fingers crossed that some developer will be kind enough to code a fix -- I'm not that developer though, unfortunately.

In the meantime, if you're desperate, you can use test_properties with debug mode on to get the info you need... However it will be in a big huge debug string and you'll need to scan for it.

WeslyG commented 2 years ago

I made an attempt to understand what happened to the "battery" property, and decided to look at the plugin in the mihome application, (main.bundle is a javascript file, so there are no big problems there) I downloaded the latest version of the plugin 35, and looked at the get_prop requests (yes, they are sent through the cloud, judging by the code), however, there is still a battery field there, which obviously receives a response from the server.

Now I'm trying to track which request comes over the network to the device itself, from xiaomi servers. Perhaps this will give an answer where the battery property has moved to.

A simple solution is to exclude the battery property for firmware version > 4, and I think it's not so difficult to write code for this (I'll try).

However, the right solution, in my opinion, is to understand how xiaomi receives data now. And it seems that this is still possible, if you remember the skills of hacking networks)

syssi commented 2 years ago

@WeslyG Could you try to compare the order of the property list (of the get_prop) command (react app vs. python-miio)? Sometimes the device firmware expects a fixed order. May be the issue can be solved by re-ordering the property list of the python-miio request.

WeslyG commented 2 years ago

https://gist.github.com/WeslyG/7e0c8179d4fb9aa7b9443c757b19dcdd#file-gistfile1-txt-L272

If you're interested, I downloaded the original plugin Bundle, and here's a link to this line. But it doesn't change anything much.

I captured the traffic, but as expected, there is no interaction with the local 54321 port, this is the usual encrypted tcp with which airmonitor communicates with xiaomi servers. Nothing new(

WeslyG commented 2 years ago

@syssi I wrote a simple test to check whether rearranging the parameter locations will help to get battery data. I used a utility that generates all possible permutations of parameters, and fed its result into a test that checks the location. I added a parameter to the status method, which I pass on to the device request.

import itertools
from miio import AirQualityMonitor

values = ["battery", "co2", "humidity", "pm25", "temperature", "tvoc"]

all_possible_options = itertools.permutations(values)

device = AirQualityMonitor(ip="192.168.1.1", token="TOKENHERE")

for i in list(all_possible_options):
    print('================')
    print(i)
    print(device.status(i))
    print('================')

run as

python myTest.py > file.txt

And nothing, all values are false, the answer is just "Ok" to each of the requests.

WeslyG commented 2 years ago

I wrote an implementation that removes the battery field for the 4th firmware version, it seems that this is the only thing we can do now. I hope it will be accepted quickly.

HikerScott commented 2 years ago

Quick note that the device upgraded to 4.1.8_0256 yesterday and continues to not report battery.

Many thanks to @WeslyG for coding what will be the eventual fix. Looking forward to @rytilahti's next release including the change!