tve / mqboard

Micro Framework for MicroPython Boards Managed via MQTT
MIT License
120 stars 18 forks source link

mqboard put needs to use flow-control #16

Open palmtreefrb opened 4 years ago

palmtreefrb commented 4 years ago

Any idea what might be happening here. Running /blinky/sync (venv) fredrick@fredrick-Studio-XPS-435MT:~/Development/micropython/mqboard/blinky$ ./sync.sh --server mqtt.xxxxxxx.com --port 8883 --tls --prefix aiotcomqtt Target directory /lib ok sntp.py ok sysinfo.py ok logging.py ok board.py ok mqtt.py ok mqrepl.py ok watchdog.py put shadiff ../mqtt_async/mqtt_async.py -> /lib/mqtt_async.py MQRepl protocol error put: message missing: 22 vs. 21 Aborted!

tve commented 4 years ago

The error states that message 21 got lost (it received message 22 when it expected 21). I have to admit I haven't seen that error triggered... mqboard doesn't use flow-control for put (only for ota), I wonder whether your MQTT server is configured to only buffer up to 20 messages per client or per topic... Is there a way you can check that? If that's the case, try to double the BUFLEN https://github.com/tve/mqboard/blob/master/mqboard/engine.py#L9, that will cut the number of messages in half...

palmtreefrb commented 4 years ago

Changed BUFLEN to 2400. Below is the output...

(venv) fredrick@fredrick-Studio-XPS-435MT:~/Development/micropython/mqboard/blinky$ ./sync --server mqtt.xxxxxx.com --port 8883 --tls --prefix aiotcomqtt --verbose --timeout 120 Target directory /lib Connecting to mqtt.xxxxxx.com:8883 Subscribing to aiotcomqtt/mqb/reply/out/syyIGwzl and aiotcomqtt/mqb/reply/err/syyIGwzl Pub aiotcomqtt/mqb/cmd/eval/syyIGwzl #0 last=True len=499 Received reply on topic 'aiotcomqtt/mqb/reply/out/syyIGwzl' with QoS 1 0.928kB in 1.427s -> 0.650kB/s ok sntp.py ok sysinfo.py ok logging.py ok board.py ok mqtt.py ok mqrepl.py ok watchdog.py put shadiff ./../mqtt_async/mqtt_async.py -> /lib/mqtt_async.py Subscribing to aiotcomqtt/mqb/reply/out/tEXJWKHS and aiotcomqtt/mqb/reply/err/tEXJWKHS Pub aiotcomqtt/mqb/cmd/put/tEXJWKHS//lib/mqtt_async.py #0 last=False len=2802 Pub aiotcomqtt/mqb/cmd/put/tEXJWKHS//lib/mqtt_async.py #1 last=False len=2802 Pub aiotcomqtt/mqb/cmd/put/tEXJWKHS//lib/mqtt_async.py #2 last=False len=2802 Pub aiotcomqtt/mqb/cmd/put/tEXJWKHS//lib/mqtt_async.py #3 last=False len=2802 Pub aiotcomqtt/mqb/cmd/put/tEXJWKHS//lib/mqtt_async.py #4 last=False len=2802 Pub aiotcomqtt/mqb/cmd/put/tEXJWKHS//lib/mqtt_async.py #5 last=False len=2802 Pub aiotcomqtt/mqb/cmd/put/tEXJWKHS//lib/mqtt_async.py #6 last=False len=2802 Pub aiotcomqtt/mqb/cmd/put/tEXJWKHS//lib/mqtt_async.py #7 last=False len=2802 Pub aiotcomqtt/mqb/cmd/put/tEXJWKHS//lib/mqtt_async.py #8 last=False len=2802 Pub aiotcomqtt/mqb/cmd/put/tEXJWKHS//lib/mqtt_async.py #9 last=False len=2802 Pub aiotcomqtt/mqb/cmd/put/tEXJWKHS//lib/mqtt_async.py #10 last=False len=2802 Pub aiotcomqtt/mqb/cmd/put/tEXJWKHS//lib/mqtt_async.py #11 last=False len=2802 Pub aiotcomqtt/mqb/cmd/put/tEXJWKHS//lib/mqtt_async.py #12 last=True len=2040 Received reply on topic 'aiotcomqtt/mqb/reply/out/tEXJWKHS' with QoS 1 34.830kB in 4.652s -> 7.487kB/s Target directory /src Subscribing to aiotcomqtt/mqb/reply/out/onaw5ZgQ and aiotcomqtt/mqb/reply/err/onaw5ZgQ Pub aiotcomqtt/mqb/cmd/eval/onaw5ZgQ #0 last=True len=499 Traceback (most recent call last): File "/safemode/mqrepl.py", line 313, in _msg_cb File "/safemode/mqrepl.py", line 192, in _do_eval File "", line 18, in File "", line 17, in _ls File "", line 14, in _ls_dir OSError: [Errno 2] ENOENT mkdir /src Subscribing to aiotcomqtt/mqb/reply/out/MngltQmr and aiotcomqtt/mqb/reply/err/MngltQmr Pub aiotcomqtt/mqb/cmd/eval/MngltQmr #0 last=True len=135 Received reply on topic 'aiotcomqtt/mqb/reply/out/MngltQmr' with QoS 1 0.132kB in 0.611s -> 0.216kB/s put missing ./blinky.py -> /src/blinky.py Subscribing to aiotcomqtt/mqb/reply/out/zCZ8r7gV and aiotcomqtt/mqb/reply/err/zCZ8r7gV Pub aiotcomqtt/mqb/cmd/put/zCZ8r7gV//src/blinky.py #0 last=True len=1692 Received reply on topic 'aiotcomqtt/mqb/reply/out/zCZ8r7gV' with QoS 1 1.654kB in 0.613s -> 2.698kB/s Target directory / Subscribing to aiotcomqtt/mqb/reply/out/KWc2q5u8 and aiotcomqtt/mqb/reply/err/KWc2q5u8 Pub aiotcomqtt/mqb/cmd/eval/KWc2q5u8 #0 last=True len=496 Received reply on topic 'aiotcomqtt/mqb/reply/out/KWc2q5u8' with QoS 1 0.537kB in 0.614s -> 0.875kB/s put missing ../board/main.py -> /main.py Subscribing to aiotcomqtt/mqb/reply/out/HPG0-ImY and aiotcomqtt/mqb/reply/err/HPG0-ImY Pub aiotcomqtt/mqb/cmd/put/HPG0-ImY//main.py #0 last=False len=2802 Pub aiotcomqtt/mqb/cmd/put/HPG0-ImY//main.py #1 last=True len=846 Received reply on topic 'aiotcomqtt/mqb/reply/out/HPG0-ImY' with QoS 1 3.564kB in 0.434s -> 8.207kB/s put missing ./board_config.py -> /board_config.py Subscribing to aiotcomqtt/mqb/reply/out/gjR3kdNb and aiotcomqtt/mqb/reply/err/gjR3kdNb Pub aiotcomqtt/mqb/cmd/put/gjR3kdNb//board_config.py #0 last=True len=2702 Received reply on topic 'aiotcomqtt/mqb/reply/out/gjR3kdNb' with QoS 1 2.641kB in 0.799s -> 3.304kB/s ok boot.py

palmtreefrb commented 4 years ago

Uggg, just now finding out that my ESP32-DevKitC WROOM-32D does not have a user LED only a 5v LED

tve commented 4 years ago

Looks good! So the amount of buffering at the broker level most likely was the issue. This means I need to implement flow-control, just like I do for OTA (which is a bit on the hacky end). Grrr...