Open vdm97 opened 2 years ago
Body was too long...
there is a good debugging doc in the esp-idf vscode extension repo, if you haven't found it.
Hi there, i think i got the same problem
I already posted at the ESP32.com forum: https://www.esp32.com/viewtopic.php?f=14&t=30217
Hi there, i think i got the same problem
I already posted at the ESP32.com forum: https://www.esp32.com/viewtopic.php?f=14&t=30217
Hi, the specific error code is different (yours is esp_algorithm.c:225 algorithm_run(): Failed to wait algorithm (-302)!
, mine is esp_algorithm.c:203 algorithm_run(): Failed to start algorithm (-4)!
) but the general error image is very similar indeed. The error appears when we add extra code and the error breaks JTAG.
there is a good debugging doc in the esp-idf vscode extension repo, if you haven't found it.
I investigated the error with more detailed debug output, but i lack the neccessary JTAG/OpenOCD knowledge to find a solution. I added the debug output of ESP-IDFv5.0-beta1 for someone who has the neccessary knowledge.
PS: Should i post this error in the ESP32-OpenOCD repo?
here is the doc I was referring to:
https://github.com/espressif/vscode-esp-idf-extension/blob/master/docs/DEBUGGING.md
here is the doc I was referring to:
https://github.com/espressif/vscode-esp-idf-extension/blob/master/docs/DEBUGGING.md
Thank you for the link but i do not get how this should help me. The error is not present when Bluetooth is deactivated and only appears when i activate Bluetooth so i do not think that it is a VSCode ESP IDF extension / OpenOCD misconficuration. I could be wrong of course..
I have some new information regarding this issue. While adding the BLE functionality i noticed, that my heap gets really full. Therefore i spent some time freeing up space. Yesterday i updated to ESP-IDF v4.4.3 and noticed that my flashing problem does not occur anymore. After some testing i found out that it was not the new version of ESP-IDF that fixed the problem but instead freeing up the heap. I attached the output of heap_caps_print_heap_info(MALLOC_CAP_8BIT)
for both cases.
If find the fix really strange and think that freeing up the heap is not the real fix but i cannot think of any other change i did to the code which might cause the issue/fix. Therefore i am not sure if i should close this issue.
Yesterday I encountered a similar JTAG problem.
Does anyone else think it might be related to the CONFIG_BOOTLOADER_APP_ROLLBACK_ENABLE=y
setting? Given that I also removed the Bluetooth settings, I suppose it could also be a memory issue?
I'm not sure I've ever encountered a low memory issue causing JTAG programming problems. Is there a device RAM overhead for JTAG programming and/or single-step debugging?
@vdm97 I'd be interested in seeing your sdkconfig
settings if possible.
Hi @gojimmypi,
my sdkconfig is posted above:
Body was too long... sdkconfig
PS: I do not use the CONFIG_BOOTLOADER_APP_ROLLBACK_ENABLE
setting.
Today i encountered this error again. After updating from IDF version 4.4.3 to version 5.0.2 my IRAM usage was at 92.7 % and i could not flash my ESP32-WROOM-32 a second time anymore. So i started to search for a solution and found this issue but updating OpenOCD to the newest release did not help. Therefore i removed the last configurable piece of code from the IRAM (CONFIG_LWIP_IRAM_OPTIMIZATION) which reduced the IRAM usage to 82.2 %. After a manual flash via serial flashing i could flash again with the ESP-IDF VS Code Extension like before. So unfortunately the error is still present...
Thanks for your investigations. You mentioned the heap size... could it possibly be related to written flash size? (I'm a total beginner, so I'm just brainstorming here.)
I'm seeing similar -- my procedure is to switch to a smaller project and do a non-debug upload. Then I can go back to the "large" project and do a debug upload and it works, but only one time. Then the board is "broken" for debugging until I repeat the procedure.
I posted at the PIO forum with some more details: https://community.platformio.org/t/interesting-results-re-chronic-esp-prog-problems/37168
Relevant quote:
You have to switch to a “small” project, and you have to do a non-debug upload to fix it. Trying to do a non-debug upload of the “large” project will not fix it. Trying to do a debug upload of a “small” project will not work, and will not fix it.
My “large” project uses about 79% of the flash. Successful debug logs show that it’s uploading 1044480 bytes. Again, this only works one time, then it is “broken” until the procedure above is followed.
A “small” project can be debugged over and over without issue.
It's interesting to me that your flash usage is right around where mine is... I've been incrementally building this project, and it just started to fail, so if in fact there is a firm threshold of image size that triggers the issue, I would expect it to be near the size I'm currently failing at (1044480.)
Sorry, I just saw this long-time-opened issue.
OpenOCD uses the IRAM memory 0x3FFE0000
to 0x3FFF8000
for the working area meaning that it is a region in the SRAM for the stub flasher code and data.
https://github.com/espressif/openocd-esp32/blob/master/tcl/target/esp32.cfg#L32
This region is in use by OpenOCD, when you want to flash applications or use flash breakpoints. Before running the flasher stub, OpenOCD will read this region, save it, run the flasher stub application, and restore it.
As I understand, when your application IRAM usage is high, you can not update your application from the JTAG. Correct?
I can try to create a test app, to reproduce the issue by allocating a high chunk of memory from the heap. Or maybe someone can do it by simulating the application memory usage? Also, are any other settings needed to see the failure?
I am sorry to hear that this issue is called a 'chronic' in the community. I will do my best to find a solution.
Thanks! I have been working this morning to narrow things down. Unfortunately I am a beginner and barely know C or microcontrollers (e.g. I barely understand what IRAM even is) but I will help if I can!
Here is what I found today (doing this on an ESP32-DevKitC-VIE which uses WROVER):
Suspecting that the issue was written flash size, I made a program that #include's "bigfile.h" where bigfile is like this:
const long arrsize = 260000;
const int bigarray[260000] = {
0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
...
0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, };
(they are ints and I mistakenly assigned bytes, but I assume that's irrelevant)
And main.cpp was:
#include <Arduino.h>
#include <bigfile.cpp>
void setup()
{
Serial.begin(115200);
while (!Serial) delay(10);
srand(time(NULL));
Serial.println(bigarray[rand()%arrsize]);
}
void loop() {;}
...even though flash was 99.5% used, this debugged fine.
So instead I used a python script to generate ../include/bigfile.cpp which is like this:
#pragma GCC push_options
#pragma GCC optimize("O0")
static volatile int i = 0;
void func0(int newv);
void func0(int newv) { volatile int a = 0; a += 1; i = a; }
void func1(int newv);
void func1(int newv) { volatile int a = 0; a += 1; i = a; func0(a); }
void func2(int newv);
void func2(int newv) { volatile int a = 0; a += 1; i = a; func1(a); }
void func3(int newv);
void func3(int newv) { volatile int a = 0; a += 1; i = a; func2(a); }
...
void func124(int newv) { volatile int a = 0; a += 1; i = a; func123(a); }
#pragma GCC pop_options
And main is like this:
#include <Arduino.h>
#include <bigfile.cpp>
void setup()
{
Serial.begin(115200);
while (!Serial) delay(10);
func124(0);
}
void loop() {;}
I'm a clueless beginner so I'm obviously just trying anything I can to prevent the code from being optimized away. No idea if any of this is smart.
If I generate bigfile.cpp with 124 functions (and main calls func123(0)) then it works: I can debug multiple times in a row.
If I generate bigfile.cpp with 125 functions (and main calls func124(0)) then I can debug the first time but it doesn't debug properly: e.g. it stops at setup() and I hit F5 and it stops at some random other place for no apparent reason. Then when I stop debugging and try to F5 again, it does not work, etc. In other words, it's the same pattern as described: I have to flash in non-debug mode, and I must do so with a smaller-sized program (e.g. regenerate bigfile.cpp with 124 or less functions). Then it will work again.
Apologies if everything in this comment is a waste of time; I just wanted to share in case it is useful. Maybe the way I am nesting function calls in the test code is bound to cause problems and this is a different issue. At any rate, if there is anything else I can do to assist let me know!
Here are debug console outputs: goodflash_at_124 is the one that worked repeatedly; goodflash_but_bad_session_at_125.txt is where it seemed to flash OK but debugging was unpredictable/broken. badflash_at_125 is the subsequent attempt to flash which just hangs. The specific errors and pattern of failure are a little different from my real project, but I guess that would be expected if this is a case of the process overwriting openocd memory accidentally or something.
I am facing this issue in an esp32 running the hci_uart example with version esp-idf 5.2.1 (https://github.com/espressif/esp-idf/tree/v5.2.1/examples/bluetooth/hci/controller_hci_uart_esp32).
Is there any way I can help debug this issue?
Thanks
@antoniovazquezblanco using the latest OpenOCD release can you get the stub flasher logs and attach ocd-log.txt here?
openocd -f board/esp32-wrover-kit-3.3v.cfg -c "esp stub_log on" -d3 -locd-log.txt
If you are willing to dive deep into the stub codes, you can follow the steps to get more debug logs. https://github.com/espressif/openocd-esp32/blob/master/contrib/loaders/flash/espressif/README.md
And can you write your steps to reproduce the issue? I did a quick test with the HCI example and didn't see an error.
The error is intermitent for me. It sometimes happens, sometimes not. I am able to debug with a cppdbg
configuration around 30% of the times. Totally unable to debug with espidf
config.
Take into account that the command was only run once and that it may not show the usual behaviour. The executed command for my board:
openocd.exe -f interface/jlink.cfg -f target/esp32.cfg -c "esp stub_log on" -d3 -l "ocd-log.txt"
The obtained log: ocd-log.txt
Your tools are not up to date. Can you run install.bat and download latest idf tool set. OpenOCD release will be v0.12.0-esp32-20240318
And afaik, speed matters with a jlink probe. Try to lower the frequency;
-f interface/jlink.cfg -c "adapter speed 5000" -f target/esp32.cfg -c "esp stub_log on" -d3 -l "ocd-log.txt"
You are right, VSCode + espidf
adapter not stable enough. We are working on a new adapter integration. You can give a try. https://github.com/espressif/vscode-esp-idf-extension/pull/1131
For the cppdbg configuration, I use below launch.json. Its OK.
{
"name": "ESP-IDF debug(cppdbg)",
"type": "cppdbg",
"request": "launch",
"program": "${config:esp_idf_app_elf_path}",
"args": [],
"cwd": "${workspaceFolder}",
"externalConsole": false,
"MIMode": "gdb",
"useExtendedRemote": true,
"miDebuggerPath": "${config:esp_idf_app_gdb}",
"debugServerPath": "${config:esp_idf_openocd_path}/openocd",
"windows" : {
"miDebuggerPath": "${config:esp_idf_app_gdb}.exe",
"debugServerPath": "${config:esp_idf_openocd_path}\\openocd.exe",
},
"miDebuggerServerAddress": ":3333",
"debugServerArgs": "${config:esp_idf_openocd_config}",
"filterStderr": true,
"filterStdout": false,
"launchCompleteCommand": "None",
"setupCommands": [
{ "text": "set remotetimeout 10" },
],
"postRemoteConnectCommands": [
{ "text": "mon reset halt" },
{ "text": "maintenance flush register-cache"},
],
"stopAtConnect": false,
"logging": {
"exceptions": true,
"engineLogging": false,
"moduleLoad": false,
"programOutput": false,
"trace": true,
"traceResponse": true
},
},
So, Please update your OpenOCD and share the logs again.
I've been away for a while now. I had little to no time for this but this has not failed in the couple of tests I did since I've updated to the latest version and added the -c "adapter speed 5000"
option. Adapter speed option seems crucial for correct operation. I will get back to this thread after I find some time to properly test this.
Thanks
I have the same problem with a ESP32-S3-WROOM using the USB-Jtag interface. Espressif IDE 3 with IDF 5.2.2 but also tried the latest stable IDF 5.3.1. The result is the same. i tried changing many parameters without any change. I tried also with the hello world example project but openocd does not work.
I confirm what user chconnor has written. His solution saves my project debug. :) Such situation happens with IDF 5.2.2 ESP32S3.
@pawel6843 We made significant size optimizations in the stub code itself. I’m curious, what is your OpenOCD version?
And is there a test applicaton to share with us? I can not still reproduce this error and unfortunately can't help.
The OpenOCD version I have been using is Open On-Chip Debugger v0.12.0-esp32-20240318 (2024-03-18-18:26). I do not have time right now to even read this whole thread. I just wanted to signal that there seems to be a problem that prevents debugging at all - until somone finds out chconnor's solution. And it is even then still seriously annoying that with big projects we need to load programs twice and switch. Because it was ok hmm before adding Bluetooth Mesh. And even if I would have time, I would have to prepare some another project for it, as I does not feel like I could share this, as it is for my employer.
Answers checklist.
IDF version.
v4.4.2, v5.0-beta1, v5.0.2
Operating System used.
Windows
How did you build your project?
VS Code IDE
If you are using Windows, please specify command line type.
PowerShell
What is the expected behavior?
A successful flash via OpenOCD/JTAG.
What is the actual behavior?
My company uses a custom board where the ESP32-WROOM-32 with 16MB flash (ESP32) is used as a WiFi chip. For that purpose it works very well, so thank you very much for providing the chip and the good tools! We use the VS Code ESP extension in conjunction with the ESP-Prog Board (JTAG) which works (most of the time) quite good. Furthermore the ESP32 is connected to a STM32 and UART is used for communication. The STM32 can also be used as a last hope to flash the ESP32.
Now about the problem. We wanted to expand the usage of the ESP32 by adding Bluetooth Low Energy (BLE) functionality. For that we activated Bluetooth in the menuconfig and selected the NimBLE stack. This did not work with the error described below. After some searching we found this ticket with a similar error in the OpenOCD log and updated our ESP-IDF from v4.4.1 to v4.4.2 and then to v5.0-beta1 (After realising that the fix is not part of v4.4.2.). After this BLE worked fine on its own and with WiFi coexistence but the WiFi stopped working with timeout issues (SPIFFS could not be served). To fix the issue we tried different task priorities for WiFi and BLE and varying BLE window and interval settings but without success. In the end we opened the menuconfig and changed the BLE stack to Bluedroid. With this stack BLE and WiFi works in coexistence but our initial error appeared again. The OpenOCD log where the error appears is attached below.
We do not know what the real cause of the error is but it appears on ESP-IDF v4.4.1 and v4.4.2 when we activate Bluetooth and select the NimBLE or Bluedroid stack. After we switched to ESP-IDF v5.0-beta1 the error only appears when we select the Bluedroid stack but does not appear when we select the NimBLE stack (We are ignoring the NimBLE/WiFi coexistence error/misconfiguration? here.). To fit a BLE stack on the ESP we had to deactivate all three WiFi IRAM optimizations, so maybe this plays a role in the error. Furthermore the IRAM and DRAM of the ESP32 is quite full so maybe this plays also a role.
Interestingly the ESP32 can always be flashed with the same binary (BLE enabled with Bluedroid stack) when the STM32 is used for serial flashing and the code is working fine if we look at the monitor and connect via WiFi/BLE but the same binary can only be be flashed the first time when OpenOCD/JTAG is used for flashing. On the second flashing the error in OpenOCD/JTAG appears, so BLE/Bluedroid code has to be present on the ESP32 for the error to appear.
All help is appreciated and we are happy to provide more information if needed.
Steps to reproduce.
I cannot provide our closed source firmware of the ESP32 and building an example is not easy because we have a lot of parts and i am not really sure where the error is coming from. I will take the time to do that if it will not be possible to get help otherwise.
Build or installation Logs.
Image size
``` Total sizes: Used static DRAM: 90236 bytes ( 34344 remain, 72.4% used) .data size: 23316 bytes .bss size: 66920 bytes Used static IRAM: 121086 bytes ( 9986 remain, 92.4% used) .text size: 120059 bytes .vectors size: 1027 bytes Used Flash size : 1407143 bytes .text : 1126587 bytes .rodata : 280300 bytes Total image size: 1551545 bytes (.bin may be padded larger) ```
OpenOCD (The VS Code extension is responsible for the strange formatting...)
``` [OpenOCD] Open On-Chip Debugger v0.11.0-esp32-20220706 (2022-07-06-15:48) Licensed under GNU GPL v2 For bug reports, read http://openocd.org/doc/doxygen/bugs.html [OpenOCD] debug_level: 2 [OpenOCD] adapter speed: 20000 kHz [OpenOCD] Info : Listening on port 6666 for tcl connections [OpenOCD] Info : Listening on port 4444 for telnet connections [OpenOCD] Info : ftdi: if[OpenOCD] you experience problems at higher adapter clocks, try the command "ftdi tdo_sample_edge falling" Info : clock speed 20000 kHz [OpenOCD] Info : JT[OpenOCD] AG tap: esp32.cpu0 tap/device found: 0x120034e5 (mfg: 0x272 (Tensilica), part: 0x2003, ver: 0x1) Info : JTAG tap: esp32.cpu1 tap/device found: 0x120034e5 (mfg: 0x272 (Tensilica), part: 0x2003, ver: 0x1) [OpenOCD] Info : [esp32.cpu0] [OpenOCD] Target halted, PC=0x40000400, debug_reason=00000000 [OpenOCD] Info : [esp32.cpu1] Target halted, PC=0x40000400, debug_reason=00000000 [OpenOCD] Info : start[OpenOCD] ing gdb server for esp32.cpu0 on 3333 Info : Listening on port 3333 for gdb connections [OpenOCD] Info : accepting 'tcl' connection on tcp/6666 Info : dropped 'tcl' connection [OpenOCD] Info : accepting 'tcl' connection on tcp/6666 [OpenOCD] Flashing c:/svn/P[OpenOCD] _ARM_xx/ESP32/build/bootloader/bootloader.bin at 0x1000 [OpenOCD] Info : JTAG tap: esp32.cpu0 tap/device found: 0x120034e[OpenOCD] 5 (mfg: 0x272 (Tensilica), part: 0x2003, ver: 0x1) Info : JTAG tap: esp32.cpu1 tap/device found: 0x120034e5 (mfg: 0x272 (Tensilica), part: 0x2003, ver: 0x1) [OpenOCD] Info : [esp32.cpu0] requesting target halt and executing a soft reset [OpenOCD] Info : [esp32.cpu0] Deb[OpenOCD] ug controller was reset. [OpenOCD] Info : [esp3[OpenOCD] 2.cpu0] Core was reset. [OpenOCD] Info : [esp32.cpu0] Targ[OpenOCD] et halted, PC=0x500000CF, debug_reason=00000000 [OpenOCD] Info : Set GDB target to 'es[OpenOCD] p32.cpu0' [OpenOCD] Info : [esp32.cpu1] [OpenOCD] requesting target halt and executing a soft reset [OpenOCD] Info : [esp32.cpu0] Core was reset. [OpenOCD] Info : [esp32.cpu0] Target[OpenOCD] halted, PC=0x40000400, debug_reason=00000000 [OpenOCD] Info : [[OpenOCD] esp32.cpu1] Debug controller was reset. [OpenOCD] Info : [es[OpenOCD] p32.cpu1] Core was reset. [OpenOCD] Info : [es[OpenOCD] p32.cpu1] Target halted, PC=0x40000400, debug_reason=00000000 [OpenOCD] Info : [esp32.cpu[OpenOCD] 0] Target halted, PC=0x40092612, debug_reason=00000001 [OpenOCD] Info : Flash mapping 0: 0x10020 -> 0x3f400020, 266 [OpenOCD] KB Info : Flash mapping 1: 0x60020 -> 0x400d0020, 1105 KB [OpenOCD] Info : [esp3[OpenOCD] 2.cpu0] Target halted, PC=0x40092612, debug_reason=00000001 [OpenOCD] Info : Auto-[OpenOCD] detected flash bank 'esp32.cpu0.flash' size 16384 KB Info : Using flash bank 'esp32.cpu0.flash' size 16384 KB [OpenOCD] Info : [esp3[OpenOCD] 2.cpu0] Target halted, PC=0x40092612, debug_reason=00000001 [OpenOCD] Info : Flash mapping 0: 0x10020 -> 0x3f40002[OpenOCD] 0, 266 KB Info : Flash mapping 1: 0x60020 -> 0x400d0020, 1105 KB [OpenOCD] Info : [esp32.cpu[OpenOCD] 0] Target halted, PC=0x40092612, debug_reason=00000001 [OpenOCD] Info : Auto-detected flash bank 'esp32.cpu1.flash' size 16384 KB Info : Using[OpenOCD] flash bank 'esp32.cpu1.flash' size 16384 KB [OpenOCD] ** Progr[OpenOCD] amming Started ** [OpenOCD] ❌ Error: timed out [OpenOCD] while waiting for target halted [OpenOCD] Info : [esp32.cpu0] Target halted, PC[OpenOCD] =0x40082343, debug_reason=00000000 [OpenOCD] ❌ Error: xtensa_wait_algorithm: not halted [OpenOCD] ❌ 0, pc 0x40082343, ps 0x60423 Error: Failed to wait algorithm (-302)! Error: Algorithm run failed (-302)! [OpenOCD] ❌ Error: Ta[OpenOCD] ❌ rget is already running an algorithm Error: Failed to start algorithm (-4)! [OpenOCD] Info : PROF: Erased [OpenOCD] 28672 bytes in 66.962 ms [OpenOCD] Err[OpenOCD] ❌ or: Target is already running an algorithm Error: Failed to start algorithm (-4)! [OpenOCD] Info : PROF: Wrote 286[OpenOCD] 72 bytes in 73.221 ms (data transfer time included) [OpenOCD] ** Program[OpenOCD] ming Finished in 40669 ms ** [OpenOCD] ** Verify[OpenOCD] Started ** [OpenOCD] ❌ Error: Target [OpenOCD] ❌ is already running an algorithm Error: Failed to start algorithm (-4)! [OpenOCD] Info : PROF: Flash verified in 70[OpenOCD] ❌ .972 ms Error: **** Verification failure! **** Error: target_hash 000...000 Error: file_hash: 0d6ef...722da1 [OpenOCD] ** Flashing[OpenOCD] Failed ** -1 ```
More Information.
No response