espressif / arduino-esp32

Arduino core for the ESP32
GNU Lesser General Public License v2.1
13.72k stars 7.43k forks source link

WebServer.handleClient() longer time execution on ESP32-C3 compares to ESP8266 (930 us vs 10us) #7708

Open Owiec94 opened 1 year ago

Owiec94 commented 1 year ago

Board

ESP32-C3

Device Description

ESP32-C3 DevKitM-1

Hardware Configuration

GPIO 19 as a test for Logic Analyzer software

Version

latest master (checkout manually)

IDE Name

PlatformIO

Operating System

Windows 10 x64

Flash frequency

mode:DOUT, clock div:1

PSRAM enabled

yes

Upload speed

ota

Description

Im using WebServer.handleClient() to manage GET commands with parameters in URL. This function on ESP32 takes 90 times longer compares to ESP8266. My method of testing: image with Logic analyzer.

platform = espressif32 board = esp32-c3-devkitm-1

test with few handlers (webServer.on("/setParams"......): 933us esp32-c3_full

test without any handlers, just webServer.init(): 933us esp32-c3_no_handlers

platform = espressif8266 board = esp07 test with few handlers: 11.88us esp8266-full

test without any handlers, just init: esp8266-no_handlers 11.88us

ESP32-C3 needs 933us compares to 11us on ESP8266 which is 90x timer slower than older chips. In my solution time is critical and I had to slow down other peripherals (to prevent overflow buffers), which affects essential on performance.

Sketch


void esp_get_hardware_info(void);
WebServer server(80);
void setup() 
{   
    Serial.begin(115200);
    WiFi.mode(WIFI_MODE_STA);
    IPAddress ip(192,168,1,116);
    IPAddress gw(192,168,1,1);
    IPAddress subnet(255,255,255,0);
    WiFi.config(ip, gw, subnet);
    WiFi.begin("ssid", "pw");

    while(WiFi.status() != WL_CONNECTED)
    {
        delay(500);
    }

    localIP = WiFi.localIP();
    WiFi.setAutoReconnect(true);
    WiFi.setTxPower(WIFI_POWER_19_5dBm);

    server.on(PSTR("/info"), esp_get_hardware_info);
    server.begin();

    pinMode(19, OUTPUT);
    digitalWrite(19,LOW);
}

void loop() 
{

    digitalWrite(19, HIGH);  
    server.handleClient();                               
    digitalWrite(19, LOW);                              

}

void esp_get_hardware_info(void)
{
    esp_chip_info_t chip_info;
    esp_chip_info(&chip_info);

    Serial.println("Hardware info");
    Serial.printf("%d cores Wifi %s%s\n", chip_info.cores, (chip_info.features & CHIP_FEATURE_BT) ? "/BT" : "",
    (chip_info.features & CHIP_FEATURE_BLE) ? "/BLE" : "");
    Serial.printf("Silicon revision: %d\n", chip_info.revision);
    Serial.printf("%dMB %s flash\n", spi_flash_get_chip_size()/(1024*1024), (chip_info.features & CHIP_FEATURE_EMB_FLASH) ? "embeded" : "external");

    //get chip id
    String chipId = String((uint32_t)ESP.getEfuseMac(), HEX);
    chipId.toUpperCase();

    Serial.printf("Chip id: %s\n", chipId.c_str());
}

platformio.ini
[env:esp32dev]
platform = espressif32
board = esp32-c3-devkitm-1
board_build.flash_mode = dout
board_build.f_cpu = 160000000L
board_build.filesystem = littlefs
board_build.mcu = esp32c3
board_build.variant = esp32c3
framework = arduino

Debug Message

-

Other Steps to Reproduce

This long time execution doesnt matter if WiFi is connected or not, also doesnt matter if we called before webServer.init() or not.

Both chips are clocked 160MHz.

I have checked existing issues, online documentation and the Troubleshooting Guide

SuGlider commented 1 year ago

@Owiec94 - Would you mind posting an example Sketch that demonstrates this issue? It would help us to analyse it.

Owiec94 commented 1 year ago

@Owiec94 - Would you mind posting an example Sketch that demonstrates this issue? It would help us to analyse it.

Sure, I've pasted basic code in 1st post (without my stuff) which still generating long time execution - tested before paste here. If You need any additional info feel free to write, I'll do my best. Hope that helps quickly optimize that function. Thank You

Owiec94 commented 1 year ago

@SuGlider any chances to fix it? Should I provide any info to help solve that problem?

SuGlider commented 1 year ago

Yes, I'll work on it soon, in a couple of weeks.

scottchiefbaker commented 1 year ago

I ran in to this same issue and posted an easily recreatable (is that a word) example on Reddit. This issue affects ALL ESP32 boards so the title may need to be updated.

With WebServer.h in it's current form it is impossible to get your main loop() to run more than 1000 times per second. This is extremely limiting for most applications.

Board handleClient() on handleClient() off
ESP8266 118156/s 142672/s
ESP32 1001/s 37409/s
ESP32-S2 994/s 289981/s

The issue only crops up when handleClient() is called. I believe the issue is the delay(1) that's inside of handleClient() here.

Whoever implemented this planned for this, because it can be disabled with server.enableDelay(false). This is an undocumented feature, and really hard to track down. Having delay inside of handleClient() should not be the default, because most people will not expect that adding a web server to their project will drop performance so much.

scottchiefbaker commented 1 year ago

Attached is the script I use to test this: blink-web.ino.gz.

FWIW while simply adding server.enableDelay(false) does improve performance significantly, the performance level is still significantly lower than ESP8266WebServer.h.

Board Iterations Percent of ESP8266
ESP8266 118156 100%
ESP32 32293 27.3%
ESP32-S2 57370 48.5%

Step 1 should be removing that arbitrary delay (or making enableDelay(true) the default). Step 2 should be to dive deeper in to WebServer.h to figure out why it's so much slower than ESP8266WebServer.h even with more powerful ESP32 hardware.

Owiec94 commented 1 year ago

Sorry for late response, temporary workaround is to call server.enableDelay(false); and call webserver.handle() every 1ms using timer. Now on ESP32-C3 we have 20us executing time - much much better but not perfect.

lbernstone commented 1 year ago

I'm the person that implemented enableDelay. The reasoning there was that the vast majority of examples on the net do not put any sort of delay in the loop. This causes loop to block any other activity in spawned threads, and so there were lots of issues that would come up about that, which is difficult to track down and fatal. I knew this could slow down the process if you have a lot of other processing in the loop (hence enableDelay), but in reality, a delay of 10 ms is fairly trivial, and handling over 1000 transactions per second is not behavior that should be encouraged.

scottchiefbaker commented 1 year ago

The issue as I see it is that a person could have a project that has a working requirement of 20kHz, they add in WebServer.h and now their project is limited to 1kHz. There is little to no explanation about this limitation, nor is it on par with other webserver libraries. ESP8266WebServer.h has an effective speed of 116kHz and the ESPAsyncWebServer.h has speed in the 175kHz range.

Wouldn't it make more sense to yield() than delay(1)? That would free up resources for the other spawned threads without limiting loop speed.

artes14 commented 1 year ago

The issue as I see it is that a person could have a project that has a working requirement of 20kHz, they add in WebServer.h and now their project is limited to 1kHz. There is little to no explanation about this limitation, nor is it on par with other webserver libraries. ESP8266WebServer.h has an effective speed of 116kHz and the ESPAsyncWebServer.h has speed in the 175kHz range.

Wouldn't it make more sense to yield() than delay(1)? That would free up resources for the other spawned threads without limiting loop speed.

https://github.com/espressif/arduino-esp32/blob/0260cd66a3438ae09811f6cd16efd51944004af4/libraries/WebServer/src/WebServer.cpp#L350-L352

there is something like a yield() here, as there is a delay(1) in the same function