Improve retry logic for discovery, messaging (was: Handle empty responses) #38

acmay · 2020-04-10T23:09:59Z

I have a device outside with an RSSI of -78 that sometimes returns data and sometimes doesn't. There is also multiple wireless video feeds that are going on at the same time as well that probably don't help.

I did this to get past the first exception on the unpack of empty data but it still fails later on. Not sure the best spot to put some extra retry logic.

diff --git a/kasa/protocol.py b/kasa/protocol.py
index f29b4be..60368f0 100755
--- a/kasa/protocol.py
+++ b/kasa/protocol.py
@@ -57,6 +57,10 @@ class TPLinkSmartHomeProtocol:
             while True:
                 chunk = await reader.read(4096)
                 if length == -1:
+                    if len(chunk) < 4:
+                        _LOGGER.error("Request %s:%s Failed to get response",
+                                      host, request)
+                        break
                     length = struct.unpack(">I", chunk[0:4])[0]
                 buffer += chunk
                 if (length > 0 and len(buffer) >= length + 4) or not chunk:
@@ -66,7 +70,10 @@ class TPLinkSmartHomeProtocol:
                 writer.close()
                 await writer.wait_closed()
 
-        response = TPLinkSmartHomeProtocol.decrypt(buffer[4:])
+        if len(buffer) > 4:
+            response = TPLinkSmartHomeProtocol.decrypt(buffer[4:])
+        else:
+            response = ""
         _LOGGER.debug("< (%i) %s", len(response), response)
 
         return json.loads(response)

Here are the logs of a good and failed run.

acmay@mud:~/src/hass/python-kasa$ PYTHONPATH=`pwd` python3 kasa/cli.py --host 192.168.1.28 sysinfo
No --strip nor --bulb nor --plug given, discovering..
== System info ==
{'alias': 'TP-LINK_Smart Plug_2ECE',
 'child_num': 2,
 'children': [{'alias': 'Rope',
               'id': 'XXXX',
               'next_action': {'action': 1, 'schd_sec': 69240, 'type': 1},
               'on_time': 0,
               'state': 0},
              {'alias': 'Plug 2',
               'id': 'XXXX',
               'next_action': {'type': -1},
               'on_time': 0,
               'state': 0}],
 'deviceId': 'XXX',
 'feature': 'TIM',
 'hwId': 'XXXX',
 'hw_ver': '1.0',
 'latitude_i': XXXX,
 'led_off': 0,
 'longitude_i': XXXXX,
 'mac': 'XXXX',
 'mic_type': 'IOT.SMARTPLUGSWITCH',
 'model': 'KP400(US)',
 'ntc_state': 0,
 'oemId': 'XXXX',
 'rssi': -78,
 'status': 'new',
 'sw_ver': '1.0.10 Build 190716 Rel.095026',
 'updating': 0}
acmay@mud:~/src/hass/python-kasa$ PYTHONPATH=`pwd` python3 kasa/cli.py --host 192.168.1.28 sysinfo
No --strip nor --bulb nor --plug given, discovering..
ERROR:kasa.protocol:Request 192.168.1.28:{"system": {"get_sysinfo": null}, "emeter": {"get_realtime": null}, "smartlife.iot.dimmer": {"get_dimmer_parameters": null}, "smartlife.iot.common.emeter": {"get_realtime": null}, "smartlife.iot.smartbulb.lightingservice": {"get_light_state": null}} Failed to get response
Traceback (most recent call last):
  File "kasa/cli.py", line 391, in <module>
    cli()
  File "/home/acmay/.local/lib/python3.7/site-packages/click/core.py", line 829, in __call__
    return self.main(*args, **kwargs)
  File "/home/acmay/.local/lib/python3.7/site-packages/click/core.py", line 782, in main
    rv = self.invoke(ctx)
  File "/home/acmay/.local/lib/python3.7/site-packages/click/core.py", line 1256, in invoke
    Command.invoke(self, ctx)
  File "/home/acmay/.local/lib/python3.7/site-packages/click/core.py", line 1066, in invoke
    return ctx.invoke(self.callback, **ctx.params)
  File "/home/acmay/.local/lib/python3.7/site-packages/click/core.py", line 610, in invoke
    return callback(*args, **kwargs)
  File "/home/acmay/.local/lib/python3.7/site-packages/click/decorators.py", line 21, in new_func
    return f(get_current_context(), *args, **kwargs)
  File "kasa/cli.py", line 68, in cli
    dev = asyncio.run(Discover.discover_single(host))
  File "/usr/lib/python3.7/asyncio/runners.py", line 43, in run
    return loop.run_until_complete(main)
  File "/usr/lib/python3.7/asyncio/base_events.py", line 584, in run_until_complete
    return future.result()
  File "/home/acmay/src/hass/python-kasa/kasa/discover.py", line 176, in discover_single
    info = await protocol.query(host, Discover.DISCOVERY_QUERY)
  File "/home/acmay/src/hass/python-kasa/kasa/protocol.py", line 79, in query
    return json.loads(response)
  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)

The text was updated successfully, but these errors were encountered:

acmay · 2020-04-13T05:51:48Z

Doing a reboot command to the KP400 device looks to have cleared up this problem a lot for me. So adding this suggested recovery to the error message maybe the best thing to be done. Not sure if it is worth doing automatically on the error.

I do have wireshark packet captures of the errors and the KP400 does a TCP close of the connection quickly on the error case. I have no idea why. I can post the captures if it helps.
It almost seemed like the basic https://github.com/softScheck/tplink-smartplug tool worked better but it could also get the same error.

I had no luck getting a retry method going, but it maybe because I don't know the python async io methods well enough.

The other tool had a smaller payload that I was able to get in this lib with these changes as well, but it didn't help.

index f29b4be..e12aef0 100755
--- a/kasa/protocol.py
+++ b/kasa/protocol.py
@@ -38,7 +38,7 @@ class TPLinkSmartHomeProtocol:
         :return: response dict
         """
         if isinstance(request, dict):
-            request = json.dumps(request)
+            request = json.dumps(request, separators=(',', ':'))
 
         timeout = TPLinkSmartHomeProtocol.DEFAULT_TIMEOUT
         writer = None
diff --git a/kasa/smartdevice.py b/kasa/smartdevice.py
index 6117fe2..0c97a71 100755
--- a/kasa/smartdevice.py
+++ b/kasa/smartdevice.py
@@ -167,7 +167,10 @@ class SmartDevice:
         :rtype: dict
         :raises SmartDeviceException: if command was not executed correctly
         """
-        request: Dict[str, Any] = {target: {cmd: arg}}
+        if arg is None:
+            request: Dict[str, Any] = {target: {cmd: dict()}}
+        else:
+            request: Dict[str, Any] = {target: {cmd: arg}}
         if child_ids is not None:
             request = {"context": {"child_ids": child_ids}, target: {cmd: arg}}

rytilahti mentioned this issue Apr 10, 2020

HS107 Support #37

Closed

rytilahti added this to the Initial release milestone May 17, 2020

rytilahti added the enhancement New feature or request label May 17, 2020

rytilahti changed the title ~~Handle empty responses~~ Improve retry logic for discovery, messaging (was: Handle empty responses) May 17, 2020

rytilahti mentioned this issue May 24, 2020

Add retries to protocol queries #65

Merged

kirichkov closed this as completed in #65 May 27, 2020

rytilahti mentioned this issue Jul 28, 2020

Release 0.4.0.dev1 #93

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Uh oh!

Uh oh!

Improve retry logic for discovery, messaging (was: Handle empty responses) #38

Improve retry logic for discovery, messaging (was: Handle empty responses) #38

Uh oh!

Uh oh!

Improve retry logic for discovery, messaging (was: Handle empty responses) #38

Improve retry logic for discovery, messaging (was: Handle empty responses) #38

Comments

Uh oh!