Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

1.0.5 source code execution on ESP32 much slower than with 1.0.4 #4973

Closed
corrados opened this issue Mar 24, 2021 · 12 comments
Closed

1.0.5 source code execution on ESP32 much slower than with 1.0.4 #4973

corrados opened this issue Mar 24, 2021 · 12 comments
Labels
Status: Stale Issue is stale stage (outdated/stuck)

Comments

@corrados
Copy link

Hardware:

Board: ESP32 Dev Module
Core Installation version: 1.0.5
IDE name: Arduino IDE
Flash Frequency: 40Mhz
PSRAM enabled: no
Upload Speed: 115200
Computer OS: Windows 10

Description:

I am developing an open source edrum module (source code at Github: https://github.com/corrados/edrumulus) on my ESP32 dev module (NodeMCU with dual core ESP32). For that I need to sample from multiple ADC at a rate of 8 kHz and do some digital signal processing. I have worked with version 1.0.4 and could successfully process up to 7 channels. After upgrading to version 1.0.5, now I cannot even process just one single channel. So, the same source code executes much slower now.

Basically, I am using a "hw_timer_t" and check with "hw_timer_t" to get a constant sampling rate. Then I am using analogRead(), the MIDI-library and some floating point calculations.

@Gamelauncher
Copy link

Gamelauncher commented Apr 6, 2021

Having the same issue unfortunately.

Hardware:

Board: ESP32 Dev Module
Core Installation version: 1.0.5 & 1.0.6
IDE name: Arduino IDE
Flash Frequency: 40Mhz
PSRAM enabled: no
Upload Speed: 115200
Computer OS: Mac

Loaded Libs:
AsyncTcp
AsyncMqtt
ESPAsyncWebserver
UART driver for RS485 @ 9600
UART driver for RS232 @ 57600

There is huge difference after 1.0.4 where the slowdowns result in panics and corrupt heap. Been searching for ages for a solution as I thought it would be in one of the loaded libs. Reverting back to 1.0.4 makes a huge speed difference in for example mqtt sending, but also all the panics and crashes have disappeared. As soon I compile against 1.0.5 or 1.0.6, within 15 minutes it crashes again.

abort() was called at PC 0x40085c79 on core 0

ELF file SHA256: 0000000000000000

Backtrace: 0x400889dc:0x3ffe1440 0x40088c59:0x3ffe1460 0x40085c79:0x3ffe1480 0x40085da5:0x3ffe14b0 0x4010746f:0x3ffe14d0 0x40102b79:0x3ffe1790 0x40102a69:0x3ffe17e0 0x4008e0d5:0x3ffe1810 0x400863ba:0x3ffe1830 0x40085b71:0x3ffe1850 0x4000bec7:0x3ffe1870 0x401504c7:0x3ffe1890 0x4015054b:0x3ffe18b0 0x40150587:0x3ffe18d0 0x40152a87:0x3ffe18f0 0x4015fb9c:0x3ffe1910 0x40160a98:0x3ffe1930 0x401614fe:0x3ffe1950 0x4015a0cf:0x3ffe1970 0x4015e9c2:0x3ffe19a0 0x40149fd3:0x3ffe19c0 0x4008a8ba:0x3ffe19f0

Decoded:

0x400889dc: invoke_abort at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/esp32/panic.c line 156
0x40088c59: abort at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/esp32/panic.c line 171
0x40085c79: lock_acquire_generic at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/newlib/locks.c line 143
0x40085da5: _lock_acquire_recursive at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/newlib/locks.c line 171
0x4010746f: _vfiprintf_r at ../../../.././newlib/libc/stdio/vfprintf.c line 860
0x40102b79: fiprintf at ../../../.././newlib/libc/stdio/fiprintf.c line 50
0x40102a69: __assert_func at ../../../.././newlib/libc/stdlib/assert.c line 59
0x4008e0d5: multi_heap_free at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/heap/multi_heap_poisoning.c line 218
0x400863ba: heap_caps_free at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/heap/heap_caps.c line 268
0x40085b71: _free_r at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/newlib/syscalls.c line 42
0x401504c7: mem_free at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/lwip/lwip/src/core/mem.c line 176
0x4015054b: do_memp_free_pool at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/lwip/lwip/src/core/memp.c line 432
0x40150587: memp_free at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/lwip/lwip/src/core/memp.c line 489
0x40152a87: tcp_seg_free at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/lwip/lwip/src/core/tcp.c line 1410
0x4015fb9c: tcp_receive at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/lwip/lwip/src/core/tcp_in.c line 1192
0x40160a98: tcp_process at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/lwip/lwip/src/core/tcp_in.c line 878
0x401614fe: tcp_input at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/lwip/lwip/src/core/tcp_in.c line 372
0x4015a0cf: ip4_input at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/lwip/lwip/src/core/ipv4/ip4.c line 750
0x4015e9c2: ethernet_input at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/lwip/lwip/src/netif/ethernet.c line 184
0x40149fd3: tcpip_thread at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/lwip/lwip/src/api/tcpip.c line 135
0x4008a8ba: vPortTaskWrapper at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/freertos/port.c line 143```


@corrados
Copy link
Author

corrados commented Apr 6, 2021

For my project I found out that it is just the analogRead() function which is much slower in version 1.0.5 and also 1.0.6. As far as I understand, this is the corresponding change in the library: #3377.

As a workaround, I have written my own my_analogRead() function now.

@Gamelauncher
Copy link

I am not using analogRead, only 3 digital reads. It's hard to tell where it's coming from. I've just disabled ESPAsyncWebserver and that makes it run more stable, but if in turn I just disable AsyncMQTT, it also runs more stable. But running both will make it crash. I've patched all the libs with the fixes I could find and not able to pinpoint an exact cause. This problem has costed me 2 weeks already and I am glad with 1.0.4 it works perfect. When the project is finished, I'll try to revisit this and see where the hiccups are coming from.

@lbernstone
Copy link
Contributor

Please keep this on topic. The issue is about slowdowns from analogRead, not crashes (likely memory issues). OP has posted a workaround.

@martenjacobs
Copy link

For my project I found out that it is just the analogRead() function which is much slower in version 1.0.5 and also 1.0.6. As far as I understand, this is the corresponding change in the library: #3377.

As a workaround, I have written my own my_analogRead() function now.

Just FYI for people stumbling upon this issue: workaround code is here

@bxparks
Copy link
Contributor

bxparks commented Apr 18, 2021

I just observed the same when I upgraded from v1.0.4 to v1.0.6. The benchmarks for one of my libraries say that analogRead() became 2.5 - 3.5X slower (numbers below in microseconds, mostly due to one call to analogRead()):

$ git diff
 +---------------------------------------------------+
 | Button Event              | min/avg/max | samples |
 +---------------------------+-------------+---------+
...
-| LadderButtonConfig        |  21/ 24/ 76 | 2002    |
+| LadderButtonConfig        |  64/ 67/266 | 2002    |

Interestingly, the new analogRead() also consumes about 14kB more flash memory, but 400 bytes fewer static RAM:

$ git diff
 +--------------------------------------------------------------+
 | functionality                   |  flash/  ram |       delta |
 |---------------------------------+--------------+-------------|
-| Baseline                        | 206625/14564 |     0/    0 |
+| Baseline                        | 197914/13092 |     0/    0 |
...
-| LadderButtonConfig              | 211773/15452 |  5148/  888 |
+| LadderButtonConfig              | 216918/13504 | 19004/  412 |

Fortunately, I need a sampling rate of only about 200Hz, so I don't have any problems. But I can see why a sampling rate of 8kHz would no longer work. That would require analogRead() to be faster than 125 micros, which it cannot seem to do anymore.

@stale
Copy link

stale bot commented Jun 18, 2021

[STALE_SET] This issue has been automatically marked as stale because it has not had recent activity. It will be closed in 14 days if no further activity occurs. Thank you for your contributions.

@stale stale bot added the Status: Stale Issue is stale stage (outdated/stuck) label Jun 18, 2021
@stale
Copy link

stale bot commented Jul 11, 2021

[STALE_DEL] This stale issue has been automatically closed. Thank you for your contributions.

@stale stale bot closed this as completed Jul 11, 2021
@ch-fb
Copy link

ch-fb commented Aug 23, 2021

I have the same problem. 1.0.4 is fast. after upgrading, 1.0.5 and 1.0.6 super slow. I don't have analogRead in my loop(). In the meantime, has anybody figured out what causes the problem?

@hazowa
Copy link

hazowa commented Oct 7, 2021

The same problem, below a part of the sketch.
V1.04 shows 111KHz
V1.05 and V1.06 shows 17KHz

Please help!

#include <driver/adc.h>

#define data_buf_size 15000  
uint16_t data_buf[data_buf_size];    // Buffer for storing sensor data.
uint16_t data_buf_pointer_write=0; 
int samples = 10000;


void setup()
{
  Serial.begin(115200);
  adcAttachPin(35);   // 
  analogSetAttenuation(ADC_11db);
  analogSetClockDiv(1); 
  analogSetCycles(1);    // not available above V1.04
  analogReadResolution(12);
//  adc1_config_width(ADC_WIDTH_BIT_12);
//  adc1_config_channel_atten(ADC1_CHANNEL_0,ADC_ATTEN_DB_0);
}

void loop()
{
  data_buf_pointer_write=0; 
  samples = 1000;
  unsigned long start_time = micros();

  do    
  {
    data_buf[data_buf_pointer_write++] = analogRead(35);  
  } while (data_buf_pointer_write < samples);   
  unsigned long spent_time = micros() - start_time;
  Serial.println(String(1000000/(spent_time)) + "KHz"); // works because samples = 1000
  delay(1000);
}

@me-no-dev
Copy link
Member

We have started to use the ESP-IDF API for ADC. In 1.0.4 we had a custom driver.

@ch-fb
Copy link

ch-fb commented Oct 8, 2021 via email

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Status: Stale Issue is stale stage (outdated/stuck)
Projects
None yet
Development

No branches or pull requests

8 participants