Upload reports that it's successful but board isn't running application

drrmcguire119 · July 28, 2020, 4:24pm

I recently upgraded PlatformIO to version 4.4.0a7. I have a custom PCB that is using a ESP32-D2WD chip. I am programming this device via JTAG using the ESP-PROG board.

Before upgrading I was able to program my board this way with no issue (I unfortunately did not mark down the version of platformIO I was running before the upgrade), but now I am unable to. I’ve tried all the solutions I’ve been able to find on the forums (everything from checking my settings.json file, changing upload_rates, and ensuring that there is no spaces in my build path) with no luck.

My current platformIO.ini file is:

[env:esp32dev]
platform = espressif32
board = esp32dev
framework = espidf 
monitor_speed = 115200
debug_tool = esp-prog
upload_protocol = esp-prog
upload_speed = 9600
upload_port = COM[45]
build_flags = 
    -DCORE_DEBUG_LEVEL=0
board_build.embed_txtfiles = 
    src/hddr.html

The output of running upload in verbose mode is:

Terminal will be reused by tasks, press any key to close it.

> Executing task: C:\Users\dylan.mcguire\.platformio\penv\Scripts\platformio.exe run --verbose --target upload <

Processing esp32dev (platform: espressif32; board: esp32dev; framework: espidf; monitor_speed: 115200; debug_tool: esp-prog; upload_protocol: esp-prog; upload_speed: 9600; upload_port: COM[45]; build_flags: -DCORE_DEBUG_LEVEL=0; board_build.embed_txtfiles:
src/hddr.html)
--------------------------------------------------------------------------------------------------------------------------------------------------
CONFIGURATION: https://docs.platformio.org/page/boards/espressif32/esp32dev.html
PLATFORM: Espressif 32 1.12.4 > Espressif ESP32 Dev Module
HARDWARE: ESP32 240MHz, 320KB RAM, 4MB Flash
DEBUG: Current (esp-prog) 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-espidf 3.40001.200521 (4.0.1)
 - tool-cmake 3.16.4
 - tool-esptoolpy 1.20600.0 (2.6.0)
 - tool-idf 1.0.1
 - tool-mconf 1.4060000.20190628 (406.0.0)
 - tool-mkspiffs 2.230.0 (2.30)
 - tool-ninja 1.9.0
 - tool-openocd-esp32 1.1000.20190708 (10.0)
 - toolchain-esp32ulp 1.22851.190618 (2.28.51)
 - toolchain-xtensa32 2.80200.200226 (8.2.0)
Reading CMake configuration...
LDF: Library Dependency Finder -> http://bit.ly/configure-pio-ldf
LDF Modes: Finder ~ chain, Compatibility ~ soft
Found 0 compatible libraries
Scanning dependencies...
No dependencies
Building in release mode
<lambda>(["checkprogsize"], [".pio\build\esp32dev\firmware.elf"])
MethodWrapper(["checkprogsize"], [".pio\build\esp32dev\firmware.elf"])
Advanced Memory Usage is available via "PlatformIO Home > Project Inspect"
RAM:   [===       ]  28.8% (used 94408 bytes from 327680 bytes)
Flash: [========  ]  76.9% (used 806234 bytes from 1048576 bytes)
.pio\build\esp32dev\firmware.elf  :

section                                                size         addr

.rtc.text                                                 0   1074528256

.rtc.dummy                                                0   1073217536

.rtc.force_fast                                           0   1073217536

.rtc_noinit                                               0   1342177280

.rtc.force_slow                                           0   1342177280

.iram0.vectors                                         1024   1074266112

.iram0.text                                           94269   1074267136

.dram0.data                                           68960   1073414144

.noinit                                                   0   1073483104

.dram0.bss                                            25448   1073483104

.flash.rodata                                        124676   1061158944

.flash.text                                          517305   1074593816

.debug_frame                                          87912            0

.debug_info                                         3096463            0

.debug_abbrev                                        258819            0

.debug_loc                                           703478            0

.debug_aranges                                        34024            0

.debug_ranges                                         39416            0

.debug_line                                         1639246            0

.debug_str                                           269434            0

.comment                                                217            0

.xtensa.info                                             56            0

.xt.prop._ZTISt9exception                                12            0

.xt.prop._ZTISt9bad_alloc                                12            0

.xt.prop._ZTVN10__cxxabiv117__class_type_infoE           12            0

.xt.prop._ZTVN10__cxxabiv120__si_class_type_infoE        12            0

Total                                               6960795
<lambda>(["upload"], [".pio\build\esp32dev\firmware.bin"])
AVAILABLE: esp-prog, espota, esptool, iot-bus-jtag, jlink, minimodule, olimex-arm-usb-ocd, olimex-arm-usb-ocd-h, olimex-arm-usb-tiny-h, olimex-jtag-tiny, tumpa
CURRENT: upload_protocol = esp-prog
openocd -d2 -s C:/Users/dylan.mcguire/.platformio/packages/tool-openocd-esp32/share/openocd/scripts -f interface/ftdi/esp32_devkitj_v1.cfg -f board/esp-wroom-32.cfg -c "program_esp32 {{.pio\build\esp32dev\firmware.bin}} 0x10000 verify" -c "program_esp32 {{C:\Users\dylan.mcguire\Desktop\mHDDR-ESP32v4\mHDDR-ESP32v4\.pio\build\esp32dev/bootloader.bin}} 0x1000 verify" -c "program_esp32 {{C:\Users\dylan.mcguire\Desktop\mHDDR-ESP32v4\mHDDR-ESP32v4\.pio\build\esp32dev/partitions.bin}} 0x8000 verify" -c "reset run; shutdown"
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
debug_level: 2
none separate
adapter speed: 20000 kHz
Info : Configured 2 cores
esp32 interrupt mask on
Info : ftdi: if you experience problems at higher adapter clocks, try the command "ftdi_tdo_sample_edge falling"
Info : clock speed 20000 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 : Listening on port 3333 for gdb connections
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 : Target halted. PRO_CPU: PC=0x4000AE2F (active)    APP_CPU: PC=0x00000000 
Info : esp32: Debug controller 0 was reset (pwrstat=0x5F, after clear 0x0F).
Info : esp32: Core 0 was reset (pwrstat=0x5F, after clear 0x0F).
Info : 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).
Info : Target halted. PRO_CPU: PC=0x40000400 (active)    APP_CPU: PC=0x40000400 
** Programming Started **
auto erase enabled
Info : Target halted. PRO_CPU: PC=0x400916EE (active)    APP_CPU: PC=0x40000400 
Info : Flash mapping 0: 0x10020 -> 0x3f400020, 121 KB
Info : Flash mapping 1: 0x30018 -> 0x400d0018, 505 KB
Info : Target halted. PRO_CPU: PC=0x400916EE (active)    APP_CPU: PC=0x40000400 
Info : Auto-detected flash size 2048 KB
Info : Using flash size 2048 KB
Info : Target halted. PRO_CPU: PC=0x400916EE (active)    APP_CPU: PC=0x40000400 
Info : Target halted. PRO_CPU: PC=0x400916EE (active)    APP_CPU: PC=0x40000400 
wrote 806912 bytes from file .pio\build\esp32dev\firmware.bin in 5.046980s (156.133 KiB/s)
** Programming Finished **
** Verify Started **
Info : Target halted. PRO_CPU: PC=0x400916EE (active)    APP_CPU: PC=0x40000400 
read 806352 bytes from file .pio\build\esp32dev\firmware.bin and flash bank 0 at offset 0x00010000 in 2.947397s (267.169 KiB/s)
contents match
** 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)
Info : esp32: Debug controller 0 was reset (pwrstat=0x5F, after clear 0x0F).
Info : esp32: Core 0 was reset (pwrstat=0x5F, after clear 0x0F).
Info : 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).
Info : Target halted. PRO_CPU: PC=0x40000400 (active)    APP_CPU: PC=0x40000400 
** Programming Started **
auto erase enabled
Info : Target halted. PRO_CPU: PC=0x400916EE (active)    APP_CPU: PC=0x40000400 
Info : Target halted. PRO_CPU: PC=0x400916EE (active)    APP_CPU: PC=0x40000400 
wrote 28672 bytes from file C:\Users\dylan.mcguire\Desktop\mHDDR-ESP32v4\mHDDR-ESP32v4\.pio\build\esp32dev/bootloader.bin in 0.894635s (31.298 KiB/s)
** Programming Finished **
** Verify Started **
Info : Target halted. PRO_CPU: PC=0x400916EE (active)    APP_CPU: PC=0x40000400 
read 25552 bytes from file C:\Users\dylan.mcguire\Desktop\mHDDR-ESP32v4\mHDDR-ESP32v4\.pio\build\esp32dev/bootloader.bin and flash bank 0 at offset 0x00001000 in 0.335586s (74.357 KiB/s)
contents match
** 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)
Info : esp32: Debug controller 0 was reset (pwrstat=0x5F, after clear 0x0F).
Info : esp32: Core 0 was reset (pwrstat=0x5F, after clear 0x0F).
Info : 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).
Info : Target halted. PRO_CPU: PC=0x40000400 (active)    APP_CPU: PC=0x40000400 
** Programming Started **
auto erase enabled
Info : Target halted. PRO_CPU: PC=0x400916EE (active)    APP_CPU: PC=0x40000400 
Info : Target halted. PRO_CPU: PC=0x400916EE (active)    APP_CPU: PC=0x40000400 
wrote 4096 bytes from file C:\Users\dylan.mcguire\Desktop\mHDDR-ESP32v4\mHDDR-ESP32v4\.pio\build\esp32dev/partitions.bin in 0.562370s (7.113 KiB/s)
** Programming Finished **
** Verify Started **
Info : Target halted. PRO_CPU: PC=0x400916EE (active)    APP_CPU: PC=0x40000400 
read 3072 bytes from file C:\Users\dylan.mcguire\Desktop\mHDDR-ESP32v4\mHDDR-ESP32v4\.pio\build\esp32dev/partitions.bin and flash bank 0 at offset 0x00008000 in 0.261884s (11.455 KiB/s)
contents match
** 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)
Info : esp32: Debug controller 0 was reset (pwrstat=0x5F, after clear 0x0F).
Info : esp32: Core 0 was reset (pwrstat=0x5F, after clear 0x0F).
Info : 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).
shutdown command invoked
Warn : Flash driver of esp32.flash does not support free_driver_priv()
Warn : Flash driver of irom does not support free_driver_priv()
Warn : Flash driver of drom does not support free_driver_priv()
========================================================== [SUCCESS] Took 23.40 seconds ==========================================================

Terminal will be reused by tasks, press any key to close it.

I have always received the three warnings about free_driver_priv() even when I uploaded the code and it ran successfully.

Thank you in advance for any/all help!

maxgerhardt · July 28, 2020, 4:27pm

The logs show that the upload was indeed succesful via JTAG.

So you have a problem that the firmware is not executed correctly on the ESP32 after the update? What symptomps does it have? Does a simple Blinky still work?

drrmcguire119 · July 28, 2020, 4:34pm

Correct, since the update the code is seemingly not running at all on the board.

The board has no LED’s (not my choice), but a simple version of my code that should just turn on WiFi is not running. I’m able to check this a) it’s SSID is not being broadcast as my laptop + phone cannot see it and b) the current draw (when powered from a bench supply) is minimal.

It should be noted that I have a DEVKITC, that I used for development while the board was being designed. I am able to program this without issue and the simple version of my code runs just fine.

maxgerhardt · July 28, 2020, 4:51pm

Hm well the DevkitC uses a “ESP32-WROOM-32” module with an underlying ESP32-D0WDQ6 chip (source, source)

The basic specs for this chip should be according to the datasheet

grafik
grafik
Here are some things to try:

test GPIO toggling firmware on any pins which are accessible or at least probable on the board with a multimeter
since you can already upload via JTAG you can also debug via JTAG. See if the firmware starts up at all in the ESP-IDF boot code, whether it reaches your app_main() etc.
double checking or adapting the JTAG upload paramaters (freq, voltage, …). Since you do board = esp32dev you must look at the esp-wroom-32.cfg file in your C:\<user>\.platformio\packages\tool-openocd-esp32\share\openocd\scripts\board folder
Uploading via the UART bootloader instead of JTAG – maybe the UART bootloader auto-detects the correct settings like flash voltage (1.8V), flash size (2MB), flash frequency (40MHz) etc better than a JTAG upload with hardcoded settings. For that just remove the upload_tool = esp-prog and use a USB-UART adapter connected to the UART of the ESP32 and put it in bootloader mode (GPIO0 low + reset press)
if you installed PlatformIO via Python-pip from the CLI, you can always pip uninstall platformio and pip install 'platformio==version' with the given versions if that’s what has caused problems.
rolling back used ESP-IDF versions if that was also updated during your update. Use platform = espressif32@version with versions from https://github.com/platformio/platform-espressif32/releases for the specific ESP-IDF version you want.

drrmcguire119 · July 28, 2020, 6:26pm

Tried a couple of these things.

since you can already upload via JTAG you can also debug via JTAG. See if the firmware starts up at all in the ESP-IDF boot code, whether it reaches your app_main() etc.

Seems to blow past my breakpoint at app_main (that’s the breakpoint at line 104 it mentions). It seems like it might pause for all of a millisecond before continuing to run.

** 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

Hardware assisted breakpoint 1 at 0x400d4d74: file src\HDDR_Main.c, line 104.

PlatformIO: Initialization completed

PlatformIO: Resume the execution to `debug_init_break = thb app_main`

PlatformIO: More configuration options -> http://bit.ly/pio-debug

Note: automatically using hardware breakpoints for read-only addresses.

Info : Target halted. PRO_CPU: PC=0x40007A48 (active) APP_CPU: PC=0x400076E2

Target halted. PRO_CPU: PC=0x40007A48 (active) APP_CPU: PC=0x400076E2

If I pause the debugger it will stop and give me some seemingly random addresses. Was able to get the following error by trying stepping over a few times (it never takes me in the code to where it is paused).

Program
 received signal SIGINT, Interrupt.
0x40007a48 in ?? ()
Info : Target halted. PRO_CPU: PC=0x400093EA (active)    APP_CPU: PC=0x400076E2 
Target halted. PRO_CPU: PC=0x400093EA (active)    APP_CPU: PC=0x400076E2 

    Program
     received signal SIGINT, Interrupt.
    0x400093ea in ?? ()
    Error: esp32: Failed to read insn (-4)!
    Error: esp32: Failed to add SW BP!
    Error: can't add breakpoint: resource not available
    Warning:
    Cannot insert breakpoint 0.
    Cannot access memory at address 0x400093f4

    0x40009394 in ?? ()
    Not implemented stop reason (assuming exception): undefined
    Info : Target halted. PRO_CPU: PC=0x400093E0 (active)    APP_CPU: PC=0x400076DD 
    Target halted. PRO_CPU: PC=0x400093E0 (active)    APP_CPU: PC=0x400076DD

double checking or adapting the JTAG upload paramaters (freq, voltage, …). Since you do board = esp32dev you must look at the esp-wroom-32.cfg file in your C:\<user>\.platformio\packages\tool-openocd-esp32\share\openocd\scripts\board folder

So after you mentioned that I remembered having done that before but just to be safe I went and checked that file. It was not set to use flash 1.8v, I’m wondering if upgrading platformIO reset this file? Anyways, I changed this before I ran the debugger code above.

Lastly, I changed my sdkconfig to use 2MB instead of 16MB I had it set to. I had changed it to 16MB because I was looking at the specs page for the part which says it has a 16MB flash …

maxgerhardt · July 28, 2020, 6:33pm

No the graph says 16Mb with is 16Megabit so 16/8 = 2 Megabyte

Hm I guess you should try UART upload if JTAG upload and debugger stopping puts you seemlingly random addresses with no stack trace / call trace

Yeah there are limitations for only 2 breakpoints max which needs special care (https://docs.espressif.com/projects/esp-idf/en/latest/esp32/api-guides/jtag-debugging/tips-and-quirks.html#breakpoints-and-watchpoints-available)

drrmcguire119 · July 28, 2020, 6:51pm

No the graph says 16Mb with is 16Mega bit so 16/8 = 2 Megabyte

Dangit I can’t believe I missed that! Very silly.

Anyways I did notice once last thing. When it’s programming the board during debug I noticed that there’s two errors that show up (see below). I’m not sure if I should pay attention to these or not since it eventually continues on and says it programmed successfully …

Errors are:

No symbols for FreeRTOS and Too large number of threads 1693293521! (I promise I don’t have 1693293521 threads in my code)

adapter speed: 20000 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 20000 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 : accepting 'gdb' connection from pipe

Error: No symbols for FreeRTOS

Info : Target halted. PRO_CPU: PC=0x40009409 (active) APP_CPU: PC=0x00000000

Info : Target halted. PRO_CPU: PC=0x400916EE (active) APP_CPU: PC=0x00000000

Info : Flash mapping 0: 0x10020 -> 0x3f400020, 121 KB

Info : Flash mapping 1: 0x30018 -> 0x400d0018, 505 KB

Info : Target halted. PRO_CPU: PC=0x400916EE (active) APP_CPU: PC=0x00000000

Info : Auto-detected flash size 2048 KB

Info : Using flash size 2048 KB

Info : Target halted. PRO_CPU: PC=0x400916EE (active) APP_CPU: PC=0x00000000

Info : Flash mapping 0: 0x10020 -> 0x3f400020, 121 KB

Info : Flash mapping 1: 0x30018 -> 0x400d0018, 505 KB

Info : Using flash size 508 KB

Info : Target halted. PRO_CPU: PC=0x400916EE (active) APP_CPU: PC=0x00000000

Info : Flash mapping 0: 0x10020 -> 0x3f400020, 121 KB

Info : Flash mapping 1: 0x30018 -> 0x400d0018, 505 KB

Info : Using flash size 124 KB

0x40009409 in ?? ()

Error: Too large number of threads 1693293521!