⚡ Improve TP-Link driver interaction

[rneswold]

The TP-Link driver "works", but it has a latency that I can't figure out.

I own 3 HS220 dimmers from Kasa. The DrMem driver can control them, but it can take up to 3 seconds for a change to occur. I believe it should be much quicker.

I based the design of the driver from information gleaned from tplink_smartplug.py and tplink-smarthome-commands.txt.

When the driver sends the command, it takes up to 3 seconds before a reply is received. What's confusing is that the Python script (mentioned above) almost always gets a reply in less than 10 ms! As of the latest commit, the DrMem driver sends the EXACT same request packet as the Python script, and yet it consistently gets a delayed response.

This is a tcpdump of the DrMem driver trying to turn on the LED indicator:

00:00:00.061574 IP drmemd.60336 > hs220.9999: Flags [P.], seq 74:114, ack 781, win 2920, length 40
        0x0000:  4500 0050 8efc 4000 4006 27d6 c0a8 0167  E..P..@.@.'....g
        0x0010:  c0a8 011e ebb0 270f 92ef 9b8d e968 b55e  ......'......h.^
        0x0020:  5018 0b68 c1c4 0000 0000 0024 d0f2 81f8  P..h.......$....
        0x0030:  8bff 9af7 d5ef 94b6 c5a0 d48b e782 e6b9  ................
        0x0040:  d6b0 d6f4 ceb5 97f8 9ef8 dae0 d1ac d1ac  ................
00:00:01.253542 IP hs220.9999 > drmemd.60336: Flags [.], ack 114, win 2807, length 0
        0x0000:  4500 0028 476b 0000 ff06 f08e c0a8 011e  E..(Gk..........
        0x0010:  c0a8 0167 270f ebb0 e968 b55e 92ef 9bb5  ...g'....h.^....
        0x0020:  5010 0af7 40db 0000 0000 0000 0000       P...@.........
00:00:00.655369 IP hs220.9999 > drmemd.60336: Flags [P.], seq 781:826, ack 114, win 2807, length 45
        0x0000:  4500 0055 476c 0000 ff06 f060 c0a8 011e  E..UGl.....`....
        0x0010:  c0a8 0167 270f ebb0 e968 b55e 92ef 9bb5  ...g'....h.^....
        0x0020:  5018 0af7 cb20 0000 0000 0029 d0f2 81f8  P..........)....
        0x0030:  8bff 9af7 d5ef 94b6 c5a0 d48b e782 e6b9  ................
        0x0040:  d6b0 d6f4 ceb5 97f2 80f2 adce a1c5 a082  ................
        0x0050:  b888 f588 f5                             .....

and this is the Python script:

00:00:00.000212 IP drmemd.61787 > hs220.9999: Flags [P.], seq 1:41, ack 1, win 33580, length 40
        0x0000:  4500 0050 0177 4000 4006 b55b c0a8 0167  E..P.w@.@..[...g
        0x0010:  c0a8 011e f15b 270f 31d1 5839 d9fe 5da2  .....['.1.X9..].
        0x0020:  5018 832c 4fee 0000 0000 0024 d0f2 81f8  P..,O......$....
        0x0030:  8bff 9af7 d5ef 94b6 c5a0 d48b e782 e6b9  ................
        0x0040:  d6b0 d6f4 ceb5 97f8 9ef8 dae0 d1ac d1ac  ................
00:00:00.006340 IP hs220.9999 > drmemd.61787: Flags [P.], seq 1:46, ack 41, win 2880, length 45
        0x0000:  4500 0055 c0eb 0000 ff06 76e1 c0a8 011e  E..U......v.....
        0x0010:  c0a8 0167 270f f15b d9fe 5da2 31d1 5861  ...g'..[..].1.Xa
        0x0020:  5018 0b40 d0c5 0000 0000 0029 d0f2 81f8  P..@.......)....
        0x0030:  8bff 9af7 d5ef 94b6 c5a0 d48b e782 e6b9  ................
        0x0040:  d6b0 d6f4 ceb5 97f2 80f2 adce a1c5 a082  ................
        0x0050:  b888 f588 f5                             .....

The TP-Link protocol uses a weak, XOR form of encryption so you can't read the JSON payload. However, you can see that the DrMem packet contents is the same as Python's. And you can see the replies are the same. It's just DrMem's interaction always has that middle reply from the dimmer that never gets sent when it's from Python.

Both, the Python script and DrMem, are running on the same machine -- so it's not an OS difference.

Right now, I need to work on other items in DrMem. This driver works -- even though it takes a awhile for it to perform a command. Maybe someone can see what I'm missing or come up with a test to make this work.

[rneswold]

I've tried several changes, none could make it respond faster. I've even seen the Python script experience the delays, so now I'm thinking the software in the dimmer is slow or just poorly written.

[rneswold]

The sequence numbers between the two are very different. This is because the driver first sends a "get info" command to the dimmer to get the current state. Getting the current state is usually a very fast operation.

[rneswold]

@Thomasdezeeuw, could this issue be caused by the mio, "short read" problems mentioned in this issue? This project uses tokio and I develop on NetBSD/aarch64, which uses kqueues. I'll do more testing with v1.39.1 to see if things have gotten better or not.

[Thomasdezeeuw]

It's hard to tell without knowing the code, but if you remove the following line: https://github.com/tokio-rs/tokio/blob/f8fe0ffb23c2279708cb5dada7c88defdae60845/tokio/src/io/poll_evented.rs#L210, you can test it

[rneswold]

I'll do more testing, but I tried to reproduce the problem that started this issue and I can't get it to delay as long as it did. I'm still seeing 200+ms delays, but not 3 seconds. So either the firmware was updated or the changes to tokio helped.

[rneswold]

Although these aren't speedy devices (we won't get them to update at 20Hz), the driver is working much better. The only differences are the changes made in tokio v1.39. I'll close this for now since it looks like it isn't the device or the driver that caused the problem.