OTAWebUpdater speed upload

[rel1ct]

Hardware:

Board: ESP32 Dev Module
Core Installation/update date: 27/06/2018
IDE name: Arduino IDE
Flash Frequency: 80Mhz
Upload Speed: 921600

Description:

69.56 Kbit/s is normal? dial up??

Sketch:

#include "WiFi.h"
#include "WebServer.h"
#include "Update.h"
const char* ssid = "Update_Web";
const char* pass = "1234567890";
WebServer server(80);
char* serverIndex = "<form method='POST' action='/update' enctype='multipart/form-data'>"
                    "<input type='file' name='update'><br><br>"
                    "<input type='submit' value='Update'>"
                    "</form>";
unsigned long t_start,t_stop;
void setup(void) {
  Serial.begin(115200);
  Serial.println();
  Serial.println(ESP.getSdkVersion());
  WiFi.mode(WIFI_AP);
  WiFi.softAP(ssid, pass);
  server.on("/serverIndex", HTTP_GET, []() {
    server.sendHeader("Connection", "close");
    server.send(200, "text/html", serverIndex);
  });
  server.on("/update", HTTP_POST, []() {
    server.sendHeader("Connection", "close");
    server.send(200, "text/plain", (Update.hasError()) ? "FAIL" : "OK");
    delay(500);  // else server not be in time send "FAIL" or "OK"
    ESP.restart();
  }, []() {
    HTTPUpload& upload = server.upload();
    if (upload.status == UPLOAD_FILE_START) {
      t_start = millis();
      Serial.printf("Update: %s\n", upload.filename.c_str());
      if (!Update.begin(UPDATE_SIZE_UNKNOWN)) {
        Update.printError(Serial);
      }
    } else if (upload.status == UPLOAD_FILE_WRITE) {
      if (Update.write(upload.buf, upload.currentSize) != upload.currentSize) {
        Update.printError(Serial);
      }
    } else if (upload.status == UPLOAD_FILE_END) {
      if (Update.end(true)) {
        t_stop = millis();
        Serial.print("Time UPLOAD: "); Serial.print((t_stop - t_start) / 1000); Serial.println(" sec.");
        Serial.print("Speed UPLOAD: "); Serial.print((float(upload.totalSize / 1024)*8) / float((t_stop - t_start) / 1000)); Serial.println(" Kbit/s");
        Serial.printf("Update Success: %u bytes\nRebooting...\n", upload.totalSize);
      } else {
        Update.printError(Serial);
      }
    }
  });
  server.begin();
}
void loop(void) {
  server.handleClient();
}

Debug Messages:

.....
v3.2-dev-39-gaaf12390
Update: test1.ino.esp32.bin
Time UPLOAD: 82 sec.
Speed UPLOAD: 69.56 Kbit/s
Update Success: 730528 bytes
.....

Wireshark file esp32.pcapng

P.S.
especially for me-no-dev, please repeat your experiment at the last SDK.
library ESPAsyncWebServer

.....
v3.2-dev-39-gaaf12390
Update start: test2.ino.esp32.bin
Time UPLOAD: 10.82 sec.
Speed UPLOAD: 529.28 Kbit/s
Update Success: 733104 bytes
.....

old SDK

.....
v3.1-dev-661-gf586f5e6
Update start: test2.ino.esp32.bin
Time UPLOAD: 0.77 sec.
Speed UPLOAD: 6439.53 Kbit/s
Update Success: 634864 bytes
.....

[everslick]

HTTPUpload is painstakingly slow on ESP32. I get 10KB/s at max here.

[me-no-dev]

I can confirm this... rather strange
issue seem to be between raw LwIP and WiFiClient

here are my results:

AP

WebServer

Time UPLOAD: 1 sec.
Speed UPLOAD: 82.58 Kbit/s
Upload Success: 17806 bytes

AsyncWebServer

Time UPLOAD: 0 sec.
Speed UPLOAD: 741.92 Kbit/s
Upload Success: 17806 bytes

STA

WebServer

Time UPLOAD: 1 sec.
Speed UPLOAD: 82.77 Kbit/s
Upload Success: 17806 bytes

AsyncWebServer

Time UPLOAD: 0 sec.
Speed UPLOAD: 5087.43 Kbit/s
Upload Success: 17806 bytes

[me-no-dev]

btw those speeds do not include update. here is the sketch

#include "WiFi.h"
#include "WebServer.h"
#include "ESPAsyncWebServer.h"
const char* ssid = "Update_Web";
const char* pass = "1234567890";
WebServer server(80);
AsyncWebServer server1(81);
const char* serverIndex = "<form method='POST' action='/update' enctype='multipart/form-data'>"
                    "<input type='file' name='update'><br><br>"
                    "<input type='submit' value='Update'>"
                    "</form>";
unsigned long t_start,t_stop;

void setup(){
    WiFi.mode(WIFI_AP_STA);
    //WiFi.begin("your-ssid","your-pass");
    WiFi.softAP(ssid, pass);
    WiFi.setSleep(false);
    server.on("/update", HTTP_GET, []() {
      server.sendHeader("Connection", "close");
      server.send(200, "text/html", serverIndex);
    });
    server.on("/update", HTTP_POST, []() {
      server.sendHeader("Connection", "close");
      server.send(200, "text/html", serverIndex);
    }, []() {
      HTTPUpload& upload = server.upload();
      if (upload.status == UPLOAD_FILE_START) {
        t_start = millis();
        Serial.printf("Upload: %s\n", upload.filename.c_str());
      } else if (upload.status == UPLOAD_FILE_WRITE) {
        //do nothing
          Serial.printf("DATA: %u\n", upload.currentSize);
      } else if (upload.status == UPLOAD_FILE_END) {
          t_stop = millis();
          Serial.print("Time UPLOAD: "); Serial.print((t_stop - t_start) / 1000); Serial.println(" sec.");
          Serial.print("Speed UPLOAD: "); Serial.print(((float(upload.totalSize)*8) / float(t_stop - t_start))); Serial.println(" Kbit/s");
          Serial.printf("Upload Success: %u bytes\n", upload.totalSize);
      }
    });
    server.begin();

    // Simple Firmware Update Form
    server1.on("/update", HTTP_GET, [](AsyncWebServerRequest *request){
      request->send(200, "text/html", serverIndex);
    });
    server1.on("/update", HTTP_POST, [](AsyncWebServerRequest *request){
        request->send(200, "text/html", serverIndex);
    },[](AsyncWebServerRequest *request, String filename, size_t index, uint8_t *data, size_t len, bool final){
      if(!index){
          t_start = micros()/1000;
        Serial.printf("Upload Start: %s, %lu\n", filename.c_str(), micros()/1000);
      }
      Serial.printf("DATA: %u\n", len);
      if(final){
          t_stop = micros()/1000;
          Serial.print("Time UPLOAD: "); Serial.print((t_stop - t_start) / 1000); Serial.println(" sec.");
          Serial.print("Speed UPLOAD: "); Serial.print(((float((index+len))*8) / float(t_stop - t_start))); Serial.println(" Kbit/s");
          Serial.printf("Upload Success: %u bytes\n", index+len);
      }
    });
    server1.begin();
}

void loop(){
    server.handleClient();
}

[me-no-dev]

OK... I had a look a bit deeper. Seems that with POSIX sockets, the tcp window get's filled and takes more than it should to free some space. Here are two captures from normal WebServer and the Async one. You can spot that the Async one does better at controlling the throughput than the other one.

Normal WebServer

AsyncWebServer

[me-no-dev]

so... the regular web server reads byte by byte from the client. each read takes 84% of the time that it takes to process one byte. therefore we need a different approach towards reading data from the client in order to make the speed faster.

[me-no-dev]

OK, So this commit speeds up the server 8 times and reaches half a megabit per second.

[rel1ct]

Certainly not 8 times faster, but better than it was.

.....
v3.2-dev-39-gaaf12390
Update: test1.ino.esp32.bin
Time UPLOAD: 82 sec.
Speed UPLOAD: 69.56 Kbit/s
Update Success: 730528 bytes
.....

.....
v3.2-dev-39-gaaf12390
Update: test1.ino.esp32.bin
Time UPLOAD: 19.86 sec.
Speed UPLOAD: 273.27 Kbit/s
Update Success: 694736 bytes
.....

At v3.1-dev-661-gf586f5e6 the speed really increased 8 times!

[me-no-dev]

@rel1ct I measured without writing to flash, so just parsing the post (and discarding the data). I reached 550 Kbit/s from 70 something before. Surely when you add the time to write to flash, things change a bit.
Overall, netcon or posix socket implementation handle the client slightly different than what I do in Async. Window depletion and slower response is what I see as result. On pure POST parse speed, posix keeps the speed about constant, while Async reaches 15Mbit/s on ETH and 8Mbit/s on WiFi.

[rel1ct]

@me-no-dev
On SDK v3.1-dev-661-gf586f5e6 speed ~ 550 Kbit / s
On SDK v3.2-dev-39-gaaf12390 speed ~ 275 Kbit / s
What is the reason for such degradation?

v3.1-dev-661-gf586f5e6
Update: test1.ino.esp32.bin
Time UPLOAD: 8.54 sec.
Speed UPLOAD: 580.84 Kbit/s
Update Success: 634784 bytes

[me-no-dev]

honestly I have no idea. I looked through commits and all is normal. I do reach the speeds you mention, so maybe something in your env?

[rel1ct]

@me-no-dev

I do reach the speeds you mention, so maybe something in your env?

version github.com/espressif/arduino-esp32 from 16.04.2018 (mod. WiFiClient.h WiFiClient.cpp)

v3.1-dev-661-gf586f5e6
Update: test1.ino.esp32.bin
Time UPLOAD: 8.52 sec.
Speed UPLOAD: 581.80 Kbit/s
Update Success: 634784 bytes

version github.com/espressif/arduino-esp32 from 07.07.2018

v3.2-dev-39-gaaf12390
Update: test1.ino.esp32.bin
Time UPLOAD: 19.91 sec.
Speed UPLOAD: 272.66 Kbit/s
Update Success: 694768 bytes

version github.com/stickbreaker/arduino-esp32 from 02.07.2018 (mod. WiFiClient.h WiFiClient.cpp)

v3.1-dev-239-g1c3dd23f-dirty
Update: test1.ino.esp32.bin
Time UPLOAD: 8.09 sec.
Speed UPLOAD: 577.81 Kbit/s
Update Success: 598336 bytes

[me-no-dev]

I see nothing in Arduino that could cause this and I honestly do not see anything in LwIP that could either. The only other option is to be a change in the WiFi lib that is provided as blob to IDF. I went up and down commits both here and in IDF...

[me-no-dev]

@rel1ct btw are you testing using the same web server?

[me-no-dev]

@rel1ct can you test with the previous arduino version but without actually flashing? Like I am testing here:

double calcSpeed(unsigned long ms, size_t len){
    return (double)(len * 125) / (double)(ms * 16);
}
void startServer(){
    server.on("/update", HTTP_GET, []() {
      server.sendHeader("Connection", "close");
      server.send(200, "text/html", serverIndex);
    });
    server.on("/update", HTTP_POST, []() {
      server.sendHeader("Connection", "close");
      server.send(200, "text/html", serverIndex);
    }, []() {
      HTTPUpload& upload = server.upload();
      if (upload.status == UPLOAD_FILE_START) {
        t_start = millis();
        Serial.printf("Upload: %s\n", upload.filename.c_str());
      } else if (upload.status == UPLOAD_FILE_WRITE) {
        //do nothing
      } else if (upload.status == UPLOAD_FILE_END) {
          t_stop = millis();
          Serial.print("Time UPLOAD: "); Serial.print((t_stop - t_start) / 1000.0); Serial.println(" sec.");
          Serial.print("Speed UPLOAD: "); Serial.print(calcSpeed(t_stop - t_start, upload.totalSize)); Serial.println(" Kbit/s");
          Serial.printf("Upload Success: %u bytes\n", upload.totalSize);
      }
    });
    server.begin();
}

[rel1ct]

@me-no-dev

@rel1ct btw are you testing using the same web server?

Yes.

v3.1-dev-661-gf586f5e6
Upload: test1_1.ino.esp32.bin
Time UPLOAD: 8.04 sec.
Speed UPLOAD: 610.95 Kbit/s
Upload Success: 628736 bytes

v3.2-dev-39-gaaf12390
Upload: test1_1.ino.esp32.bin
Time UPLOAD: 9.68 sec.
Speed UPLOAD: 555.57 Kbit/s
Upload Success: 688512 bytes

With upload understood, thanks.

It turns out with old sdk the flashing occurs for 1 second, and on new SDK over 10 second?

Can close?