PlatformIO Community

ESP-PROG debug fails in PIO with all boards, LIBUSB_ERROR_PIPE

I am having an issue debugging ESP32 wrover based boards using the esp-prog and PIO. In all cases, running debug fails with the following errors after running for a minute and successfully reading and writing:

Error: ftdi device did not return all data: 0, expected 12
Error: error while flushing MPSSE queue: -4
Error: libusb_handle_events() failed with LIBUSB_ERROR_PIPE

I haven’t been able to find anything similar searching the forums. This happens no matter what code I use (including Blink), and no matter what board I use. I have tried:

  1. Changing ESP32 Wrover boards, tried both Lolin D32 Pro and a custom board
  2. Changing the adapter speed to 200Khz, 2Mhz, 5Mhz, 10Mhz, and 20Mhz
  3. Powering the ESP boards via the esp-prog at 5v or 3.3v
  4. Powering the ESP boards via USB

PIO ini:

platform = espressif32
board = esp-wrover-kit
framework = arduino

build_flags =
-w
-DBOARD_HAS_PSRAM
-mfix-esp32-psram-cache-issue

src_build_flags =
-Wall
board_build.f_cpu = 240000000L
board_build.f_flash = 80000000L

monitor_speed = 115200

debug_tool = esp-prog
debug_init_break = tbreak setup

Full log:

--------------------------------------------------------------------------------
Verbose mode can be enabled via `-v, --verbose` option
CONFIGURATION: https://docs.platformio.org/page/boards/espressif32/esp-wrover-kit.html
PLATFORM: Espressif 32 1.12.2 > Espressif ESP-WROVER-KIT
HARDWARE: ESP32 240MHz, 320KB RAM, 4MB Flash
DEBUG: Current (esp-prog) On-board (ftdi) External (esp-prog, iot-bus-jtag, jlink, minimodule, olimex-arm-usb-ocd, olimex-arm-usb-ocd-h, olimex-arm-usb-tiny-h, olimex-jtag-tiny, tumpa)
PACKAGES:
 - framework-arduinoespressif32 3.10004.200129 (1.0.4)
 - tool-esptoolpy 1.20600.0 (2.6.0)
 - toolchain-xtensa32 2.50200.80 (5.2.0)
LDF: Library Dependency Finder -> http://bit.ly/configure-pio-ldf
LDF Modes: Finder ~ chain, Compatibility ~ soft
Found 29 compatible libraries
Scanning dependencies...
Dependency Graph
Building in debug mode
Retrieving maximum program size .pio/build/esp-wrover-kit/firmware.elf
Checking size .pio/build/esp-wrover-kit/firmware.elf
Advanced Memory Usage is available via "PlatformIO Home > Project Inspect"
RAM:   [=         ]  13.6% (used 44440 bytes from 327680 bytes)
Flash: [=======   ]  65.8% (used 862398 bytes from 1310720 bytes)
========================= [SUCCESS] Took 3.57 seconds =========================
Reading symbols from /Users/.../Documents/.../.pio/build/esp-wrover-kit/firmware.elf...
done.
PlatformIO Unified Debugger -> http://bit.ly/pio-debug
PlatformIO: debug_tool = esp-prog
PlatformIO: Initializing remote target...
Open On-Chip Debugger  v0.10.0-esp32-20190708 (2019-07-08-11:04)
Licensed under GNU GPL v2
For bug reports, read
	http://openocd.org/doc/doxygen/bugs.html
none separate
adapter speed: 10000 kHz
Info : Configured 2 cores
esp32 interrupt mask on
Info : tcl server disabled
Info : telnet server disabled
Info : ftdi: if you experience problems at higher adapter clocks, try the command "ftdi_tdo_sample_edge falling"
Info : clock speed 10000 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: Debug controller 0 was reset (pwrstat=0x5F, after clear 0x0F).
Info : esp32: Core 0 was reset (pwrstat=0x5F, after clear 0x0F).
Info : esp32: Debug controller 1 was reset (pwrstat=0x5F, after clear 0x0F).
Info : esp32: Core 1 was reset (pwrstat=0x5F, after clear 0x0F).
Info : Detected debug stubs @ 3ffc2efc on core0 of target 'esp32'
Info : accepting 'gdb' connection from pipe
Error: No symbols for FreeRTOS
Info : Target halted. PRO_CPU: PC=0x4014F472 (active)    APP_CPU: PC=0x400D747E
Info : Target halted. PRO_CPU: PC=0x400916EE (active)    APP_CPU: PC=0x400D747E
Info : Flash mapping 0: 0x10020 -> 0x3f400020, 198 KB
Info : Flash mapping 1: 0x50018 -> 0x400d0018, 513 KB
Info : Target halted. PRO_CPU: PC=0x400916EE (active)    APP_CPU: PC=0x400D747E
Info : Auto-detected flash size 8192 KB
Info : Using flash size 8192 KB
Info : Target halted. PRO_CPU: PC=0x400916EE (active)    APP_CPU: PC=0x400D747E
Info : Flash mapping 0: 0x10020 -> 0x3f400020, 198 KB
Info : Flash mapping 1: 0x50018 -> 0x400d0018, 513 KB
Info : Using flash size 516 KB
Info : Target halted. PRO_CPU: PC=0x400916EE (active)    APP_CPU: PC=0x400D747E
Info : Flash mapping 0: 0x10020 -> 0x3f400020, 198 KB
Info : Flash mapping 1: 0x50018 -> 0x400d0018, 513 KB
Info : Using flash size 200 KB
0x4014f472 in pm_rx_beacon_process ()
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: Debug controller 0 was reset (pwrstat=0x5F, after clear 0x0F).
Info : esp32: Core 0 was reset (pwrstat=0x5F, after clear 0x0F).
esp32: Debug controller 0 was reset (pwrstat=0x5F, after clear 0x0F).
esp32: Core 0 was reset (pwrstat=0x5F, after clear 0x0F).
Info : Target halted. PRO_CPU: PC=0x5000004B (active)    APP_CPU: PC=0x00000000
Target halted. PRO_CPU: PC=0x5000004B (active)    APP_CPU: PC=0x00000000
Info : esp32: Core 0 was reset (pwrstat=0x1F, after clear 0x0F).
Info : esp32: Debug controller 1 was reset (pwrstat=0x5F, after clear 0x0F).
Info : esp32: Core 1 was reset (pwrstat=0x5F, after clear 0x0F).
esp32: Core 0 was reset (pwrstat=0x1F, after clear 0x0F).
esp32: Debug controller 1 was reset (pwrstat=0x5F, after clear 0x0F).
esp32: Core 1 was reset (pwrstat=0x5F, after clear 0x0F).
Info : Target halted. PRO_CPU: PC=0x40000400 (active)    APP_CPU: PC=0x40000400
Target halted. PRO_CPU: PC=0x40000400 (active)    APP_CPU: PC=0x40000400
** Programming Started **
** Programming Started **
auto erase enabled
auto erase enabled
Info : Target halted. PRO_CPU: PC=0x400916EE (active)    APP_CPU: PC=0x40000400
Target halted. PRO_CPU: PC=0x400916EE (active)    APP_CPU: PC=0x40000400
Info : Target halted. PRO_CPU: PC=0x400916EE (active)    APP_CPU: PC=0x40000400
Target halted. PRO_CPU: PC=0x400916EE (active)    APP_CPU: PC=0x40000400
wrote 16384 bytes from file /Users/nick/.platformio/packages/framework-arduinoespressif32/tools/sdk/bin/bootloader_dio_80m.bin in 0.860183s (18.601 KiB/s)
wrote 16384 bytes from file /Users/nick/.platformio/packages/framework-arduinoespressif32/tools/sdk/bin/bootloader_dio_80m.bin in 0.860183s (18.601 KiB/s)
** Programming Finished **
** Programming Finished **
** Verify Started **
** Verify Started **
Info : Target halted. PRO_CPU: PC=0x400916EE (active)    APP_CPU: PC=0x40000400
Target halted. PRO_CPU: PC=0x400916EE (active)    APP_CPU: PC=0x40000400
read 15856 bytes from file /Users/nick/.platformio/packages/framework-arduinoespressif32/tools/sdk/bin/bootloader_dio_80m.bin and flash bank 0 at offset 0x00001000 in 0.326285s (47.457 KiB/s)
contents match
read 15856 bytes from file /Users/nick/.platformio/packages/framework-arduinoespressif32/tools/sdk/bin/bootloader_dio_80m.bin and flash bank 0 at offset 0x00001000 in 0.326285s (47.457 KiB/s)
contents match
** Verified OK **
** Verified OK **
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: Debug controller 0 was reset (pwrstat=0x5F, after clear 0x0F).
Info : esp32: Core 0 was reset (pwrstat=0x5F, after clear 0x0F).
esp32: Debug controller 0 was reset (pwrstat=0x5F, after clear 0x0F).
esp32: Core 0 was reset (pwrstat=0x5F, after clear 0x0F).
Info : Target halted. PRO_CPU: PC=0x5000004B (active)    APP_CPU: PC=0x00000000
Target halted. PRO_CPU: PC=0x5000004B (active)    APP_CPU: PC=0x00000000
Info : esp32: Core 0 was reset (pwrstat=0x1F, after clear 0x0F).
Info : esp32: Debug controller 1 was reset (pwrstat=0x5F, after clear 0x0F).
Info : esp32: Core 1 was reset (pwrstat=0x5F, after clear 0x0F).
esp32: Core 0 was reset (pwrstat=0x1F, after clear 0x0F).
esp32: Debug controller 1 was reset (pwrstat=0x5F, after clear 0x0F).
esp32: Core 1 was reset (pwrstat=0x5F, after clear 0x0F).
Info : Target halted. PRO_CPU: PC=0x40000400 (active)    APP_CPU: PC=0x40000400
Target halted. PRO_CPU: PC=0x40000400 (active)    APP_CPU: PC=0x40000400
** Programming Started **
** Programming Started **
auto erase enabled
auto erase enabled
Info : Target halted. PRO_CPU: PC=0x400916EE (active)    APP_CPU: PC=0x40000400
Target halted. PRO_CPU: PC=0x400916EE (active)    APP_CPU: PC=0x40000400
Info : Target halted. PRO_CPU: PC=0x400916EE (active)    APP_CPU: PC=0x40000400
Target halted. PRO_CPU: PC=0x400916EE (active)    APP_CPU: PC=0x40000400
wrote 4096 bytes from file /Users/nick/Documents/ESPLED/Arduino/ESP32_Artnet/.pio/build/esp-wrover-kit/partitions.bin in 0.659934s (6.061 KiB/s)
wrote 4096 bytes from file /Users/nick/Documents/ESPLED/Arduino/ESP32_Artnet/.pio/build/esp-wrover-kit/partitions.bin in 0.659934s (6.061 KiB/s)
** Programming Finished **
** Programming Finished **
** Verify Started **
** Verify Started **
Info : Target halted. PRO_CPU: PC=0x400916EE (active)    APP_CPU: PC=0x40000400
Target halted. PRO_CPU: PC=0x400916EE (active)    APP_CPU: PC=0x40000400
read 3072 bytes from file /Users/nick/Documents/ESPLED/Arduino/ESP32_Artnet/.pio/build/esp-wrover-kit/partitions.bin and flash bank 0 at offset 0x00008000 in 0.290918s (10.312 KiB/s)
contents match
read 3072 bytes from file /Users/nick/Documents/ESPLED/Arduino/ESP32_Artnet/.pio/build/esp-wrover-kit/partitions.bin and flash bank 0 at offset 0x00008000 in 0.290918s (10.312 KiB/s)
contents match
** Verified OK **
** Verified OK **
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: Debug controller 0 was reset (pwrstat=0x5F, after clear 0x0F).
Info : esp32: Core 0 was reset (pwrstat=0x5F, after clear 0x0F).
esp32: Debug controller 0 was reset (pwrstat=0x5F, after clear 0x0F).
esp32: Core 0 was reset (pwrstat=0x5F, after clear 0x0F).
Info : Target halted. PRO_CPU: PC=0x5000004B (active)    APP_CPU: PC=0x00000000
Target halted. PRO_CPU: PC=0x5000004B (active)    APP_CPU: PC=0x00000000
Info : esp32: Core 0 was reset (pwrstat=0x1F, after clear 0x0F).
Info : esp32: Debug controller 1 was reset (pwrstat=0x5F, after clear 0x0F).
Info : esp32: Core 1 was reset (pwrstat=0x5F, after clear 0x0F).
esp32: Core 0 was reset (pwrstat=0x1F, after clear 0x0F).
esp32: Debug controller 1 was reset (pwrstat=0x5F, after clear 0x0F).
esp32: Core 1 was reset (pwrstat=0x5F, after clear 0x0F).
Info : Target halted. PRO_CPU: PC=0x40000400 (active)    APP_CPU: PC=0x40000400
Target halted. PRO_CPU: PC=0x40000400 (active)    APP_CPU: PC=0x40000400
** Programming Started **
** Programming Started **
auto erase enabled
auto erase enabled
Info : Target halted. PRO_CPU: PC=0x400916EE (active)    APP_CPU: PC=0x40000400
Target halted. PRO_CPU: PC=0x400916EE (active)    APP_CPU: PC=0x40000400
Info : Target halted. PRO_CPU: PC=0x400916EE (active)    APP_CPU: PC=0x40000400
Target halted. PRO_CPU: PC=0x400916EE (active)    APP_CPU: PC=0x40000400
wrote 8192 bytes from file /Users/nick/.platformio/packages/framework-arduinoespressif32/tools/partitions/boot_app0.bin in 0.727178s (11.001 KiB/s)
wrote 8192 bytes from file /Users/nick/.platformio/packages/framework-arduinoespressif32/tools/partitions/boot_app0.bin in 0.727178s (11.001 KiB/s)
** Programming Finished **
** Programming Finished **
** Verify Started **
** Verify Started **
Info : Target halted. PRO_CPU: PC=0x400916EE (active)    APP_CPU: PC=0x40000400
Target halted. PRO_CPU: PC=0x400916EE (active)    APP_CPU: PC=0x40000400
read 8192 bytes from file /Users/nick/.platformio/packages/framework-arduinoespressif32/tools/partitions/boot_app0.bin and flash bank 0 at offset 0x0000e000 in 0.299664s (26.697 KiB/s)
contents match
read 8192 bytes from file /Users/nick/.platformio/packages/framework-arduinoespressif32/tools/partitions/boot_app0.bin and flash bank 0 at offset 0x0000e000 in 0.299664s (26.697 KiB/s)
contents match
** Verified OK **
** Verified OK **
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: Debug controller 0 was reset (pwrstat=0x5F, after clear 0x0F).
Info : esp32: Core 0 was reset (pwrstat=0x5F, after clear 0x0F).
esp32: Debug controller 0 was reset (pwrstat=0x5F, after clear 0x0F).
esp32: Core 0 was reset (pwrstat=0x5F, after clear 0x0F).
Info : Target halted. PRO_CPU: PC=0x5000004B (active)    APP_CPU: PC=0x00000000
Target halted. PRO_CPU: PC=0x5000004B (active)    APP_CPU: PC=0x00000000
Info : esp32: Core 0 was reset (pwrstat=0x1F, after clear 0x0F).
Info : esp32: Debug controller 1 was reset (pwrstat=0x5F, after clear 0x0F).
Info : esp32: Core 1 was reset (pwrstat=0x5F, after clear 0x0F).
esp32: Core 0 was reset (pwrstat=0x1F, after clear 0x0F).
esp32: Debug controller 1 was reset (pwrstat=0x5F, after clear 0x0F).
esp32: Core 1 was reset (pwrstat=0x5F, after clear 0x0F).
Info : Target halted. PRO_CPU: PC=0x40000400 (active)    APP_CPU: PC=0x40000400
Target halted. PRO_CPU: PC=0x40000400 (active)    APP_CPU: PC=0x40000400
** Programming Started **
** Programming Started **
auto erase enabled
auto erase enabled
Error: ftdi device did not return all data: 0, expected 12
ftdi device did not return all data: 0, expected 12
Error: error while flushing MPSSE queue: -4
error while flushing MPSSE queue: -4
Error: libusb_handle_events() failed with LIBUSB_ERROR_PIPE
libusb_handle_events() failed with LIBUSB_ERROR_PIPE
.pioinit:15: Error in sourced command file:

Googling "ftdi device did not return all data: 0" returns a grand total 3 results – none of which are concluding to an accepted answer.

I’d say “lower clock” or “power all boards with a good external power supply” but you’ve tried that already…

You may try something exotic like changing the OS / running Linux in a VM and see if the behaviour changes. Otherwise I’d recommend asking the openocd devs directly at https://sourceforge.net/p/openocd/tickets/ for this seemly exotic / rarely encountered error.

Thanks @maxgerhardt, will do.

Going to spin up a Linux VM later and will confirm if that works or not. I’m starting to wonder if it’s a hardware issue with the ESP-PROG itself.

@maxgerhardt the same setup works flawlessly on Ubuntu 20…so looks to be a driver issue on my end in MacOS. I’ll troubleshoot later and update this thread.

Good that you’ve narrowed down the error. Could be that proprietary FTDI drivers are outdated or too new, or Apple provided ones are bad, maybe.