Unexpected disconnect and throughput slowdown during OTA Update on ESP32

[Stephen Cooper]

Hi all

I'v attempting to get a project working on an ESP32 performing OTA Updates. The binary is uploaded to the ESP via Bluetooth using BTStack.

The reliability and throughput of this upload is all over the place however. About 1 in 5 updates attempts result in success. The throughput of the packets being sent keeps slowing down too, about 10-12 packets are sent consecutively then there is a pause of a second or two then more packets are sent. This pause grows over the course of the update usually resulting in a disconnect during the upgrade process.

I have a custom built web app performing the update using WebBluetooth and tried a few different approaches. Initially i had the characteristic set to `WRITE` in the .gatt and the webapp would just recursively send packets after each promise resolves.

I though maybe the UI is overloading and sending packets faster than the ESP can handle so i changed the architecture to have the characteristic configure for `WRITE_WITHOUT_RESPONSE | NOTIFY` and make the ESP send a notification out after each packet was processed. The Web app would then only send the next packet once it received this notification.

Sadly this did not solve the issue.

I can code around it in the web app by re-connecting and resending failed packets but i feel there is something fundamental im doing wrong or have configured wrong.

The code for the webapp and ESP can be found here: https://github.com/ste2425/BluePad32OTADemo

The bit specifically where the ESP receives data and does the OTA is here: 
https://github.com/ste2425/BluePad32OTADemo/blob/main/ESP32/Controller/ble.ino#L127

Any assistance on how to debug this, or even if anyone can see anything obvious would be great. Im used to much higher level languages and environments (.net core, NodeJs etc) so debugging this issue is proving challenging.

Thanks

[Stephen Cooper]

So Iv'e figured out how to enable HCI Dumps.

Noticed some interesting patterns but sadly i have no idea what the hex values mean.

Sadly i cleared the log by accident however i can reproduce and save to file the logs if they are actually of use. 

I can see data in the log which match the behaviour of the pauses in-between packets being uploaded.

Blue appear to be packets being uploaded, earlier in the log i can see multiple of these happening a second. Then there are pauses in the middle (red) which can last a good number of seconds) then packets being sent continues.

Included the bit where the disconnect happens for reference 

[Matthias Ringwald]

Hi Stephen

You've OTA involves quite some layers. You report slow throughput, disconnects and pauses in-between.

My suggestion would be to go back to our examples and verify that they work and then start to add functionality step by step.

As ground truth, please run gatt_streamer_server and le_streamer_client on two ESP32. You should get around 80 kB/s throughput if I remember correctly (full-duplex, DLE, 1M-PHY).
You can then replace one or both ESP32 with a process running on your desktop PC and a Bluetooth Controller - see port/libusb and port/windows-winusb

In this test, all data is thrown away. As you're working on OTA, I can imagine that the part that stores data in flash might cause delays, so I'd add that last.

For fast data transfer on LE, you can use the GATT Write Without Response. As you probably can send the data faster than you can store them in flash, I would suggest to send the number of received packets in a Notification to allow the sender to implement some kind of window-based flow control. (e.g. max 20 packets will be unacknowledged).

If you store the HCI log into a text file, you can use tool/create_packet_log.py to convert it to a .pklg file which can be opened with the Wireshark tool.

Best
Matthias

> On 11 Sep 2023, at 15:24, Stephen Cooper <Ste.c...@live.co.uk> wrote:
>
> So Iv'e figured out how to enable HCI Dumps.
>
> Noticed some interesting patterns but sadly i have no idea what the hex values mean.
>
> Sadly i cleared the log by accident however i can reproduce and save to file the logs if they are actually of use.
>
> I can see data in the log which match the behaviour of the pauses in-between packets being uploaded.
> Blue appear to be packets being uploaded, earlier in the log i can see multiple of these happening a second. Then there are pauses in the middle (red) which can last a good number of seconds) then packets being sent continues.
>

> <log.png>
>
> Included the bit where the disconnect happens for reference <log2.png>

>
>
> On Friday, 8 September 2023 at 12:36:00 UTC+1 Stephen Cooper wrote:
> Hi all
>
> I'v attempting to get a project working on an ESP32 performing OTA Updates. The binary is uploaded to the ESP via Bluetooth using BTStack.
>
> The reliability and throughput of this upload is all over the place however. About 1 in 5 updates attempts result in success. The throughput of the packets being sent keeps slowing down too, about 10-12 packets are sent consecutively then there is a pause of a second or two then more packets are sent. This pause grows over the course of the update usually resulting in a disconnect during the upgrade process.
>
> I have a custom built web app performing the update using WebBluetooth and tried a few different approaches. Initially i had the characteristic set to `WRITE` in the .gatt and the webapp would just recursively send packets after each promise resolves.
>
> I though maybe the UI is overloading and sending packets faster than the ESP can handle so i changed the architecture to have the characteristic configure for `WRITE_WITHOUT_RESPONSE | NOTIFY` and make the ESP send a notification out after each packet was processed. The Web app would then only send the next packet once it received this notification.
>
> Sadly this did not solve the issue.
>
> I can code around it in the web app by re-connecting and resending failed packets but i feel there is something fundamental im doing wrong or have configured wrong.
>
> The code for the webapp and ESP can be found here: https://github.com/ste2425/BluePad32OTADemo
>
> The bit specifically where the ESP receives data and does the OTA is here:
> https://github.com/ste2425/BluePad32OTADemo/blob/main/ESP32/Controller/ble.ino#L127
>
> Any assistance on how to debug this, or even if anyone can see anything obvious would be great. Im used to much higher level languages and environments (.net core, NodeJs etc) so debugging this issue is proving challenging.
>
> Thanks
>

> --
> You received this message because you are subscribed to the Google Groups "btstack-dev" group.
> To unsubscribe from this group and stop receiving emails from it, send an email to btstack-dev...@googlegroups.com.
> To view this discussion on the web visit https://groups.google.com/d/msgid/btstack-dev/6ab18bea-b9f1-418e-8389-492a1ff8e1ebn%40googlegroups.com.
> <log.png><log2.png>