Intermittent GDB problems with PIO 6.1.1 under Windows

mtron47 · September 12, 2023, 9:52am

Hi all

Trying to debug a new ESP32 project using proprietary hardware and esp-prog I could not start a GDB-session. After numerous trials and failures I reverted to this very basic scenario, but still no success: I created a new Arduino project using an ESP-Wrover-Kit V4.1. This is platformio.ini:

[env:esp-wrover-kit]
platform = espressif32
board = esp-wrover-kit
framework = arduino
debug_init_break = tbreak setup
debug_speed = 500

and this is the Arduino code, straight from PIO:

#include <Arduino.h>

// put function declarations here:
int myFunction(int, int);

void setup() {
  // put your setup code here, to run once:
  int result = myFunction(2, 3);
}

void loop() {
  // put your main code here, to run repeatedly:
}

// put function definitions here:
int myFunction(int x, int y) {
  return x + y;
}

Then I hit F5. Compilation in debug mode alsways works without errors, then GDB comes up. Sometimes execution stops at the entry of setup(), as expected. But mostly I get this on the Debug Console:

undefinedC:\Users\Peter\.platformio\packages\toolchain-xtensa-esp32\bin\xtensa-esp32-elf-gdb.exe: warning: Couldn't determine a path for the index cache directory.
Reading symbols from D:\Peter\Documents\PlatformIO\Projects\dbg-Doodle\.pio\build\esp-wrover-kit\firmware.elf...
PlatformIO Unified Debugger -> https://bit.ly/pio-debug
PlatformIO: debug_tool = ftdi
PlatformIO: Initializing remote target...
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
adapter speed: 20000 kHz

WARNING: boards/esp32-wrover.cfg is deprecated, and may be removed in a future release.
         If your board is ESP32-WROVER-KIT, use board/esp32-wrover-kit-1.8v.cfg instead.
adapter speed: 500 kHz

Info : tcl server disabled
Info : telnet server disabled
Error: libusb_open() failed with LIBUSB_ERROR_NOT_SUPPORTED
Info : clock speed 500 kHz
Info : JTAG 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)
Info : [esp32.cpu0] Target halted, PC=0x4000C341, debug_reason=00000000
Info : [esp32.cpu1] Target halted, PC=0x40000400, debug_reason=00000000
Info : starting gdb server for esp32.cpu0 on pipe
Info : accepting 'gdb' connection from pipe
Warn : No symbols for FreeRTOS!
Info : [esp32.cpu0] Target halted, PC=0x40092612, debug_reason=00000001
Info : Set GDB target to 'esp32.cpu0'
Info : Flash mapping 0: 0x10020 -> 0x3f400020, 103 KB
Info : Flash mapping 1: 0x30020 -> 0x400d0020, 543 KB
Info : [esp32.cpu0] Target halted, PC=0x40092612, debug_reason=00000001
Info : Auto-detected flash bank 'esp32.cpu0.flash' size 4096 KB
Info : Using flash bank 'esp32.cpu0.flash' size 4096 KB
Info : [esp32.cpu0] Target halted, PC=0x40092612, debug_reason=00000001
Info : Flash mapping 0: 0x10020 -> 0x3f400020, 103 KB
Info : Flash mapping 1: 0x30020 -> 0x400d0020, 543 KB
Info : Using flash bank 'esp32.cpu0.irom' size 544 KB
Info : [esp32.cpu0] Target halted, PC=0x40092612, debug_reason=00000001
Info : Flash mapping 0: 0x10020 -> 0x3f400020, 103 KB
Info : Flash mapping 1: 0x30020 -> 0x400d0020, 543 KB
Info : Using flash bank 'esp32.cpu0.drom' size 104 KB
Info : New GDB Connection: 1, Target esp32.cpu0, state: halted
Warn : negative reply, retrying
0x4000c341 in ?? ()
Info : JTAG 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)
JTAG tap: esp32.cpu0 tap/device found: 0x120034e5 (mfg: 0x272 (Tensilica), part: 0x2003, ver: 0x1)
JTAG tap: esp32.cpu1 tap/device found: 0x120034e5 (mfg: 0x272 (Tensilica), part: 0x2003, ver: 0x1)
Info : [esp32.cpu0] requesting target halt and executing a soft reset
[esp32.cpu0] requesting target halt and executing a soft reset
Info : [esp32.cpu0] Debug controller was reset.
Info : [esp32.cpu0] Core was reset.
[esp32.cpu0] Debug controller was reset.
[esp32.cpu0] Core was reset.
Info : [esp32.cpu0] Target halted, PC=0x500000CF, debug_reason=00000000
[esp32.cpu0] Target halted, PC=0x500000CF, debug_reason=00000000
Info : [esp32.cpu1] requesting target halt and executing a soft reset
Info : [esp32.cpu0] Core was reset.
[esp32.cpu1] requesting target halt and executing a soft reset
[esp32.cpu0] Core was reset.
Info : [esp32.cpu0] Target halted, PC=0x40000400, debug_reason=00000000
Info : [esp32.cpu1] Debug controller was reset.
Info : [esp32.cpu1] Core was reset.
[esp32.cpu0] Target halted, PC=0x40000400, debug_reason=00000000
[esp32.cpu1] Debug controller was reset.
[esp32.cpu1] Core was reset.
Info : [esp32.cpu1] Target halted, PC=0x40000400, debug_reason=00000000
[esp32.cpu1] Target halted, PC=0x40000400, debug_reason=00000000
Info : [esp32.cpu0] Target halted, PC=0x40092612, debug_reason=00000001
[esp32.cpu0] Target halted, PC=0x40092612, debug_reason=00000001
Info : Flash mapping 0: 0x10020 -> 0x3f400020, 103 KB
Info : Flash mapping 1: 0x30020 -> 0x400d0020, 543 KB
Flash mapping 0: 0x10020 -> 0x3f400020, 103 KB
Flash mapping 1: 0x30020 -> 0x400d0020, 543 KB
Info : [esp32.cpu0] Target halted, PC=0x40092612, debug_reason=00000001
[esp32.cpu0] Target halted, PC=0x40092612, debug_reason=00000001
Info : Auto-detected flash bank 'esp32.cpu1.flash' size 4096 KB
Info : Using flash bank 'esp32.cpu1.flash' size 4096 KB
** Programming Started **
Auto-detected flash bank 'esp32.cpu1.flash' size 4096 KB
Using flash bank 'esp32.cpu1.flash' size 4096 KB
** Programming Started **
Error: timed out while waiting for target halted
timed out while waiting for target halted
Info : [esp32.cpu0] Target halted, PC=0x4000C341, debug_reason=00000000
Error: xtensa_wait_algorithm: not halted 0, pc 0x4000c341, ps 0x60025
Error: Failed to wait algorithm (-302)!
Error: Algorithm run failed (-302)!
[esp32.cpu0] Target halted, PC=0x4000C341, debug_reason=00000000
xtensa_wait_algorithm: not halted 0, pc 0x4000c341, ps 0x60025
Failed to wait algorithm (-302)!
Algorithm run failed (-302)!
Error: Target is already running an algorithm
Error: Failed to start algorithm (-4)!
Info : PROF: Erased 20480 bytes in 767.782 ms
Target is already running an algorithm
Failed to start algorithm (-4)!
PROF: Erased 20480 bytes in 767.782 ms
Error: Target is already running an algorithm
Error: Failed to start algorithm (-4)!
Info : PROF: Wrote 20480 bytes in 777.328 ms (data transfer time included)
Target is already running an algorithm
Failed to start algorithm (-4)!
PROF: Wrote 20480 bytes in 777.328 ms (data transfer time included)
** Programming Finished in 44632 ms **
** Verify Started **
** Programming Finished in 44632 ms **
** Verify Started **
Error: Target is already running an algorithm
Error: Failed to start algorithm (-4)!
Info : PROF: Flash verified in 777.196 ms
Error: **** Verification failure! ****
Error: target_hash fcef9e...000
Error: file_hash: a1108e...9dcd9c
Target is already running an algorithm
Failed to start algorithm (-4)!
PROF: Flash verified in 777.196 ms
**** Verification failure! ****
target_hash fcef9e...000
file_hash: a1108e...9dcd9c
** Verify Failed **
.pioinit:12: Error in sourced command file:
Protocol error with Rcmd

What algorithm is the target alredy running?
And why is there a verification failure? I tried to alleviate communication problems by reducing the debug speed to 500 kHz.
And what can I do to avoid this: WARNING: boards/esp32-wrover.cfg is deprecated, and may be removed in a future release.
If your board is ESP32-WROVER-KIT, use board/esp32-wrover-kit-1.8v.cfg instead.
Thank you for your help!

mtron47 · September 23, 2023, 8:22am

This is a follow-up on my post above. What I forgot to mention is that the drivers used to communicate with esp-prog over USB were always WinUSB (v6.1.7500.16385) for Interface 0 = JTAG and the Standard FTDIBUS (v2.12.36.4) for Interface 1 = Serial.

These are the things I did when a debugging session didn.t want to come up:

Reinstalling the driver for Interface 0 → This never did any good.
Unplugging / re-plugging the USB cable → This helped sometimes
Cleaning the project, then Run / Start Debugging (F5) When that didn’t help →
Terminate PlatformIO, then restart it. When that didn’t help →
Unplug the USB cable, restart Windows, plug in the USB cable, verify that the correct (WinUSB) driver is active for Interface 0, start PlatformIO, Run → Start Debugging (F5) → That mostly worked, but it is very time consuming.
And by the way: There are two USB sockets on the front of my PC. The left one “works” as described above, but the right one does not. (That is for debugging. For all other purposes it works flawlessly.) So I stick to the left one.

Now, is my problem solved? Yes, as I can debug my project. And no because it may become tedious and overly time-consuming and I don’t really know what I am doing i.e. I don’t understand what is happening behind the scenes in the maze of PlatformIO-scripts - I don’t like that.