miot CLI works at most time, but sometime failed with ERROR user ack timeout.

[merdok]

  miot CLI works at most time, but sometime failed with `ERROR  user ack timeout`.

I execute 4 commands in one shot: turn off, get status, turn on, get status.
Compared with miot and miiocli, miiocli almost never failed, but miot almost failed at the third command every time.

miot send $GATEWAY_IP --token $GATEWAY_TOKEN set_properties "[{\"did\":\"$DEVICE_ID\",\"value\":false,\"siid\":2,\"piid\":1}]"
miot send $GATEWAY_IP --token $GATEWAY_TOKEN get_properties "[{\"did\":\"$DEVICE_ID\",\"siid\":2,\"piid\":1}]"
miot send $GATEWAY_IP --token $GATEWAY_TOKEN set_properties "[{\"did\":\"$DEVICE_ID\",\"value\":true,\"siid\":2,\"piid\":1}]"
miot send $GATEWAY_IP --token $GATEWAY_TOKEN get_properties "[{\"did\":\"$DEVICE_ID\",\"siid\":2,\"piid\":1}]"

# Output
 INFO  Connecting to device at  192.168.x.x
 INFO  Device found! Sending command: set_properties [{"did":"xxx","value":false,"siid":2,"piid":1}]
(Protocol) Call 192.168.x.x: set_properties - [{"did":"xxx","value":false,"siid":2,"piid":1}] - {"retries":1,"timeout":5000}
 SUCCESS  Response from device -> [{"did":"xxx","siid":2,"piid":1,"code":1,"ts":1665230823,"ret":0}]
 INFO  Connecting to device at  192.168.x.x
 INFO  Device found! Sending command: get_properties [{"did":"xxx","siid":2,"piid":1}]
(Protocol) Call 192.168.x.x: get_properties - [{"did":"xxx","siid":2,"piid":1}] - {"retries":1,"timeout":5000}
 SUCCESS  Response from device -> [{"did":"xxx","siid":2,"piid":1,"value":false,"code":0,"ts":1665230827,"ret":0}]
 INFO  Connecting to device at  192.168.x.x
 INFO  Device found! Sending command: set_properties [{"did":"xxx","value":true,"siid":2,"piid":1}]
(Protocol) Call 192.168.x.x: set_properties - [{"did":"xxx","value":true,"siid":2,"piid":1}] - {"retries":1,"timeout":5000}
 ERROR  user ack timeout
 INFO  Connecting to device at  192.168.x.x
 INFO  Device found! Sending command: get_properties [{"did":"xxx","siid":2,"piid":1}]
(Protocol) Call 192.168.x.x: get_properties - [{"did":"xxx","siid":2,"piid":1}] - {"retries":1,"timeout":5000}
 SUCCESS  Response from device -> [{"did":"xxx","siid":2,"piid":1,"value":false,"code":0,"ts":1665230831,"ret":0}]

And I switch the first and the third command, still failed at the third command.

Update:
I see miiocli's retry_count=3, timeout=5, so I add --retries 3 for miot, still failed.

Here's the data captured from wireshark:

miiocli:
--> {"id": 2, "method": "get_properties", "params": [{"did": "1044213155", "siid": 2, "piid": 1}]}
<-- {"id":2,"error":{"code":-9999,"message":"user ack timeout"},"exe_time":4004}
--> {"id": 3, "method": "get_properties", "params": [{"did": "1044213155", "siid": 2, "piid": 1}]}
<-- {"id":3,"result":[{"did":"1044213155","siid":2,"piid":1,"value":false,"code":0,"ts":1665232063,"ret":0}],"exe_time":12}

miot:
--> {"method":"set_properties","params":[{"did":"1044213155","value":true,"siid":2,"piid":1}],"id":1}
<-- {"id":1,"error":{"code":-9999,"message":"user ack timeout"},"exe_time":4005}

Seems miot retry not correctly working.

Originally posted by @0x5e in #348 (comment)

[merdok]

@0x5e
do you have any tips on how to cause the "user ack timeout"? I cannot trigger them on any of my devices, and having them to trigger would make it easier to debug this issue.

[0x5e]

@0x5e

do you have any tips on how to cause the "user ack timeout"? I cannot trigger them on any of my devices, and having them to trigger would make it easier to debug this issue.

If I send command to the mesh device too frequently, It will cause this error. For example, copy 4 commands together and paste to the shell, and enter, then usually failed at the third command...

[merdok]

The thing is that I do not have any mesh devices😅
So I need a reliable way to reproduce it without that.
Other then that, if you have coding knowledge and time, could you try to have a look? The code should be in the protocol file.

[0x5e]

OK, just give me some time to read the code, I will try.

[merdok]

thanks 👍