search

espressif / openocd-esp32

OpenOCD branch with ESP32 JTAG support
Other
362 stars 132 forks source link

ESP32 - QIO flash configuration vs software breakpoints (OCD-940) #326

Open tipeter opened 6 months ago

tipeter commented 6 months ago

Development Kit

ESP32-DevkitC

Module or chip used

ESP32-WROOM-32

Debug Adapter

ESP-PROG

OpenOCD version

v0.12.0-esp32-20240318

Operating System

Windows 10

Using an IDE ?

Visual Studio Code, VisualGDB, custom configured Qt Creator 13

OpenOCD command line

openocd.exe -c "gdb_port 3333" -s C:/esp/tools/openocd-esp32/v0.12.0-esp32-20230921/openocd-esp32/share/openocd/scripts -f C:/esp/tools/openocd-esp32/v0.12.0-esp32-20240318/openocd-esp32/share/openocd/scripts/board/esp32-wrover-kit-1.8v.cfg

JTAG Clock Speed

default

ESP-IDF version

release/v5.2

Problem Description

Hello!

I use ESP-PROG JTAG programmer for ESP32-WROOM module and noticed an unusual phenomenon: If I set the module flash configuration to QIO, I cannot create a software breakpoint. In addition, several error messages appear when connecting OpenOCD in this case:

Warn : Failed to get flash maps (-6)!
Warn : Application image is invalid! Check configured binary flash offset 'appimage_offset'.
Warn : Failed to get flash mappings (-4)!

The two hardware breakpoints work perfectly, however, when creating a third - software - breakpoint, the following message appears:

Error: esp32.cpu0: Failed to get flash bank (-4)!
Error: [esp32.cpu0] can't add breakpoint: unknown reason
Error: No flash at address 0x400d540e

If I reset the flash configuration to DIO, everything is OK; and OpenOCD errors also disappear. By the way, the uploaded program works perfectly even with QIO mode, only debugging is problematic.

To reproduce the behavior I copied the base 'blink' project and switched the flash to QIO. Of course, I don't use the extra GPIOs used by QIO for anything.

The Init-commands are:

mon reset halt
maintenance flush register-cache
set remote hardware-breakpoint-limit 2
set remote hardware-watchpoint-limit 2
mon gdb_breakpoint_override hard
thb app_main
c

This is known normal behavior for QIO; or malfunction?

Many thanks!

Debug Logs

21:53:58: Starting C:\esp\tools\openocd-esp32\v0.12.0-esp32-20240318\openocd-esp32\bin\openocd.exe -c "gdb_port 3333" -s C:/esp/tools/openocd-esp32/v0.12.0-esp32-20230921/openocd-esp32/share/openocd/scripts -f C:/esp/tools/openocd-esp32/v0.12.0-esp32-20240318/openocd-esp32/share/openocd/scripts/board/esp32-wrover-kit-1.8v.cfg...
21:53:58: Debugging C:\esp\Projects\spi-dma-test\bld\ESP_IDF_ESP32-Debug\blink.elf ...
Open On-Chip Debugger v0.12.0-esp32-20240318 (2024-03-18-18:26)
Licensed under GNU GPL v2
For bug reports, read
    http://openocd.org/doc/doxygen/bugs.html
Info : auto-selecting first available session transport "jtag". To override use 'transport select <transport>'.
Info : Listening on port 6666 for tcl connections
Info : Listening on port 4444 for telnet connections
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.cpu0] Examination succeed
Info : [esp32.cpu1] Examination succeed
Info : starting gdb server for esp32.cpu0 on 3333
Info : Listening on port 3333 for gdb connections
Info : [esp32.cpu0] Debug controller was reset.
Info : [esp32.cpu0] Core was reset.
Info : [esp32.cpu1] Debug controller was reset.
Info : [esp32.cpu1] Core was reset.
Info : [esp32.cpu0] Target halted, PC=0x400845E6, debug_reason=00000000
Info : [esp32.cpu0] Reset cause (1) - (Power on reset)
Info : [esp32.cpu1] Target halted, PC=0x400845E6, debug_reason=00000000
Info : [esp32.cpu1] Reset cause (14) - (CPU1 reset by CPU0)
could not convert 'main' from the host encoding (CP1252) to UTF-32.
This normally should not happen, please file a bug report.Info : accepting 'gdb' connection on tcp/3333
Info : [esp32.cpu0] Target halted, PC=0x400845E6, debug_reason=00000000
Info : Set GDB target to 'esp32.cpu0'
Info : [esp32.cpu1] Target halted, PC=0x400845E6, debug_reason=00000000
Warn : No symbols for FreeRTOS!
Info : [esp32.cpu0] Target halted, PC=0x400BE65A, debug_reason=00000001
Warn : Failed to get flash maps (-6)!
Warn : Application image is invalid! Check configured binary flash offset 'appimage_offset'.
Warn : Failed to get flash mappings (-4)!
Info : [esp32.cpu0] Target halted, PC=0x400BE65A, debug_reason=00000001
Info : [esp32.cpu0] Target halted, PC=0x400BE65A, 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=0x400BE65A, debug_reason=00000001
Warn : Failed to get flash maps (-6)!
Warn : Application image is invalid! Check configured binary flash offset 'appimage_offset'.
Warn : Failed to get flash mappings (-4)!
Info : [esp32.cpu0] Target halted, PC=0x400BE65A, debug_reason=00000001
Info : Using flash bank 'esp32.cpu0.irom' size 0 KB
Info : [esp32.cpu0] Target halted, PC=0x400BE65A, debug_reason=00000001
Warn : Failed to get flash maps (-6)!
Warn : Application image is invalid! Check configured binary flash offset 'appimage_offset'.
Warn : Failed to get flash mappings (-4)!
Info : [esp32.cpu0] Target halted, PC=0x400BE65A, debug_reason=00000001
Info : Using flash bank 'esp32.cpu0.drom' size 0 KB
Info : New GDB Connection: 1, Target esp32.cpu0, state: halted
Warn : Prefer GDB command "target extended-remote :3333" instead of "target remote :3333"
Info : Detected FreeRTOS version: (10.5.1)
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)[esp32.cpu0] requesting target halt and executing a soft resetInfo : 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] requesting target halt and executing a soft reset
Info : [esp32.cpu0] Debug controller was reset.
[esp32.cpu0] Debug controller was reset.Info : [esp32.cpu0] Core 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=00000000Info : [esp32.cpu0] Reset cause (3) - (Software core reset)
[esp32.cpu0] Reset cause (3) - (Software core reset)Info : [esp32.cpu1] requesting target halt and executing a soft reset
[esp32.cpu1] requesting target halt and executing a soft resetInfo : [esp32.cpu0] Core was 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.
Info : [esp32.cpu1] Target halted, PC=0x40000400, debug_reason=00000000
Info : [esp32.cpu1] Reset cause (14) - (CPU1 reset by CPU0)
[esp32.cpu0] Target halted, PC=0x40000400, debug_reason=00000000[esp32.cpu1] Debug controller was reset.[esp32.cpu1] Core was reset.[esp32.cpu1] Target halted, PC=0x40000400, debug_reason=00000000[esp32.cpu1] Reset cause (14) - (CPU1 reset by CPU0)Info : [esp32.cpu0] Reset cause (3) - (Software core reset)
[esp32.cpu0] Reset cause (3) - (Software core reset)force hard breakpoints
force hard breakpointsInfo : [esp32.cpu0] Target halted, PC=0x400D53DF, debug_reason=00000001
[esp32.cpu0] Target halted, PC=0x400D53DF, debug_reason=00000001Info : Set GDB target to 'esp32.cpu0'
Set GDB target to 'esp32.cpu0'Info : [esp32.cpu1] Target halted, PC=0x400845E6, debug_reason=00000000
[esp32.cpu1] Target halted, PC=0x400845E6, debug_reason=00000000Info : Detected FreeRTOS version: (10.5.1)
Info : [esp32.cpu0] Target halted, PC=0x400845E6, debug_reason=00000000
[esp32.cpu0] Target halted, PC=0x400845E6, debug_reason=00000000Info : Set GDB target to 'esp32.cpu0'
Set GDB target to 'esp32.cpu0'Info : [esp32.cpu1] Target halted, PC=0x400845E6, debug_reason=00000000
[esp32.cpu1] Target halted, PC=0x400845E6, debug_reason=00000000Info : [esp32.cpu0] Target halted, PC=0x400D540B, debug_reason=00000001
[esp32.cpu0] Target halted, PC=0x400D540B, debug_reason=00000001Info : Set GDB target to 'esp32.cpu0'
Set GDB target to 'esp32.cpu0'Info : [esp32.cpu1] Target halted, PC=0x400845E6, debug_reason=00000000
[esp32.cpu1] Target halted, PC=0x400845E6, debug_reason=00000000Info : [esp32.cpu0] Target halted, PC=0x400D540E, debug_reason=00000001
[esp32.cpu0] Target halted, PC=0x400D540E, debug_reason=00000001Info : Set GDB target to 'esp32.cpu0'
Set GDB target to 'esp32.cpu0'Info : [esp32.cpu1] Target halted, PC=0x400845E6, debug_reason=00000000
[esp32.cpu1] Target halted, PC=0x400845E6, debug_reason=00000000Info : [esp32.cpu0] Target halted, PC=0x400D540B, debug_reason=00000001
[esp32.cpu0] Target halted, PC=0x400D540B, debug_reason=00000001Info : Set GDB target to 'esp32.cpu0'
Set GDB target to 'esp32.cpu0'Info : [esp32.cpu1] Target halted, PC=0x400845E6, debug_reason=00000000
[esp32.cpu1] Target halted, PC=0x400845E6, debug_reason=00000000Info : [esp32.cpu0] Target halted, PC=0x400D540E, debug_reason=00000001
[esp32.cpu0] Target halted, PC=0x400D540E, debug_reason=00000001Info : Set GDB target to 'esp32.cpu0'
Set GDB target to 'esp32.cpu0'Info : [esp32.cpu1] Target halted, PC=0x400845E6, debug_reason=00000000
[esp32.cpu1] Target halted, PC=0x400845E6, debug_reason=00000000Info : [esp32.cpu0] Target halted, PC=0x400D540B, debug_reason=00000001
[esp32.cpu0] Target halted, PC=0x400D540B, debug_reason=00000001Info : Set GDB target to 'esp32.cpu0'
Set GDB target to 'esp32.cpu0'Info : [esp32.cpu1] Target halted, PC=0x400845E6, debug_reason=00000000
[esp32.cpu1] Target halted, PC=0x400845E6, debug_reason=00000000Info : [esp32.cpu0] Target halted, PC=0x400D540E, debug_reason=00000001
[esp32.cpu0] Target halted, PC=0x400D540E, debug_reason=00000001Info : Set GDB target to 'esp32.cpu0'
Set GDB target to 'esp32.cpu0'Info : [esp32.cpu1] Target halted, PC=0x400845E6, debug_reason=00000000
[esp32.cpu1] Target halted, PC=0x400845E6, debug_reason=00000000Error: No flash at address 0x400d540e
Error: esp32.cpu0: Failed to get flash bank (-4)!
Error: [esp32.cpu0] can't add breakpoint: unknown reason
Error: No flash at address 0x400d540e
Error: esp32.cpu0: Failed to get flash bank (-4)!
Error: [esp32.cpu0] can't add breakpoint: unknown reason

Expected behavior

Ability to create software breakpoints as usual.

Screenshots

No response

erhankur commented 6 months ago

@tipeter Did you change your app image offset?

https://docs.espressif.com/projects/esp-idf/en/stable/esp32/api-guides/jtag-debugging/tips-and-quirks.html#flash-mappings-vs-sw-flash-breakpoints

And please check with the master branch. You can find windows artifact here

tipeter commented 6 months ago

No, I didn't change the appimage offset. A completely basic "blink" project. I flashed via usb serial with esp.py (I also tried jtag, nothing changed). There has also been a complete flash deletion. I tried the version you suggested, unfortunately the result is the same:


Open On-Chip Debugger v0.12.0-53d234ed (2024-05-02-20:04)
Licensed under GNU GPL v2
For bug reports, read
    http://openocd.org/doc/doxygen/bugs.html
Info : auto-selecting first available session transport "jtag". To override use 'transport select <transport>'.
Info : Listening on port 6666 for tcl connections
Info : Listening on port 4444 for telnet connections
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.cpu0] Examination succeed
Info : [esp32.cpu1] Examination succeed
Info : starting gdb server for esp32.cpu0 on 3333
Info : Listening on port 3333 for gdb connections
Info : [esp32.cpu0] Target halted, PC=0x400D5411, debug_reason=00000004
Info : [esp32.cpu0] Reset cause (3) - (Software core reset)
Info : Set GDB target to 'esp32.cpu0'
Info : [esp32.cpu1] Target halted, PC=0x400845E6, debug_reason=00000000
Info : [esp32.cpu1] Reset cause (14) - (CPU1 reset by CPU0)
could not convert 'main' from the host encoding (CP1252) to UTF-32.
This normally should not happen, please file a bug report.Info : accepting 'gdb' connection on tcp/3333
Warn : No symbols for FreeRTOS!
Info : [esp32.cpu0] Target halted, PC=0x400BE65A, debug_reason=00000001
Warn : Failed to get flash maps (-6)!
Warn : Application image is invalid! Check configured binary flash offset 'appimage_offset'.
Warn : Failed to get flash mappings (-4)!
Info : [esp32.cpu0] Target halted, PC=0x400BE65A, debug_reason=00000001
Info : [esp32.cpu0] Target halted, PC=0x400BE65A, 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=0x400BE65A, debug_reason=00000001
Warn : Failed to get flash maps (-6)!
Warn : Application image is invalid! Check configured binary flash offset 'appimage_offset'.
Warn : Failed to get flash mappings (-4)!
Info : [esp32.cpu0] Target halted, PC=0x400BE65A, debug_reason=00000001
Info : Using flash bank 'esp32.cpu0.irom' size 0 KB
Info : [esp32.cpu0] Target halted, PC=0x400BE65A, debug_reason=00000001
Warn : Failed to get flash maps (-6)!
Warn : Application image is invalid! Check configured binary flash offset 'appimage_offset'.
Warn : Failed to get flash mappings (-4)!
Info : [esp32.cpu0] Target halted, PC=0x400BE65A, debug_reason=00000001
Info : Using flash bank 'esp32.cpu0.drom' size 0 KB
Info : New GDB Connection: 1, Target esp32.cpu0, state: halted
Warn : Prefer GDB command "target extended-remote :3333" instead of "target remote :3333"
Info : Detected FreeRTOS version: (10.5.1)
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 resetInfo : [esp32.cpu0] Debug controller was reset.
[esp32.cpu0] Debug controller was reset.Info : [esp32.cpu0] Core 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=00000000Info : [esp32.cpu0] Reset cause (3) - (Software core reset)
[esp32.cpu0] Reset cause (3) - (Software core reset)Info : [esp32.cpu1] requesting target halt and executing a soft reset
[esp32.cpu1] requesting target halt and executing a soft resetInfo : [esp32.cpu0] Core was 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=00000000Info : [esp32.cpu1] Reset cause (14) - (CPU1 reset by CPU0)
[esp32.cpu1] Reset cause (14) - (CPU1 reset by CPU0)Info : [esp32.cpu0] Reset cause (3) - (Software core reset)
[esp32.cpu0] Reset cause (3) - (Software core reset)force hard breakpointsforce hard breakpoints
Info : [esp32.cpu0] Target halted, PC=0x400D53DF, debug_reason=00000001
[esp32.cpu0] Target halted, PC=0x400D53DF, debug_reason=00000001Info : Set GDB target to 'esp32.cpu0'
Set GDB target to 'esp32.cpu0'Info : [esp32.cpu1] Target halted, PC=0x400845E6, debug_reason=00000000
[esp32.cpu1] Target halted, PC=0x400845E6, debug_reason=00000000Info : Detected FreeRTOS version: (10.5.1)
Info : [esp32.cpu0] Target halted, PC=0x400845E6, debug_reason=00000000
[esp32.cpu0] Target halted, PC=0x400845E6, debug_reason=00000000Info : Set GDB target to 'esp32.cpu0'
Set GDB target to 'esp32.cpu0'Info : [esp32.cpu1] Target halted, PC=0x400845E6, debug_reason=00000000
[esp32.cpu1] Target halted, PC=0x400845E6, debug_reason=00000000Info : [esp32.cpu0] Target halted, PC=0x400D53E2, debug_reason=00000001
[esp32.cpu0] Target halted, PC=0x400D53E2, debug_reason=00000001Info : Set GDB target to 'esp32.cpu0'
Set GDB target to 'esp32.cpu0'Info : [esp32.cpu1] Target halted, PC=0x400845E6, debug_reason=00000000
[esp32.cpu1] Target halted, PC=0x400845E6, debug_reason=00000000Error: No flash at address 0x400d53e2
Error: esp32.cpu0: Failed to get flash bank (-4)!
Error: [esp32.cpu0] can't add breakpoint: unknown reason
Error: No flash at address 0x400d541e
Error: esp32.cpu0: Failed to get flash bank (-4)!
Error: [esp32.cpu0] can't add breakpoint: unknown reason
erhankur commented 6 months ago

Interesting, I tried blink + QIO config, and it works well.

Can you run OpenOCD like below and share the log.txt file? 

openocd.exe  -s C:/esp/tools/openocd-esp32/v0.12.0-esp32-20240318/openocd-esp32/share/openocd/scripts -f board/esp32-wrover-kit-3.3v.cfg -c "esp stub_log on" -d3 -l log.txt
tipeter commented 6 months ago

Hi!

I have attached the diary. Thank you very much for your help! openocd_log.zip

erhankur commented 6 months ago

Thanks. I will check it later today.

tipeter commented 6 months ago

It seems that there may be a hardware problem behind the strange behavior. I have two identical ESP32-DevkitC modules. At first I was able to set QIO mode on both, although the software breakpoint in QIO mode did not work with either. After several cross-tests, I came to the conclusion that the flash chip of one of the modules can no longer be switched to QIO mode by the bootloader. What is also interesting is that the module does not boot after a software breakpoint is unsuccessfully created in QIO mode, it complains about a checksum error. Apparently, due to the interrupted debugging, OpenOCD was unable to restore the contents of the flash. Another interesting thing is that the faultless ESP32 switches on to QIO mode after a fresh flash, but after unsuccessful debugging, it happened that it failed to set the QIO mode AND also referred to a checksum error.

I have attached the boot logos:

"Faulty" ESP32, unable to turn on QIO mode:

I (31) boot: ESP-IDF v5.2.1-485-g9b3ae86417 2nd stage bootloader
I (31) boot: compile time May  7 2024 09:53:52
I (32) boot: Multicore bootloader
I (37) boot: chip revision: v1.0
I (40) qio_mode: Enabling default flash chip QIO
E (46) qio_mode: Failed to set QIE bit, not enabling QIO mode
I (52) boot.esp32: SPI Speed      : 80MHz
I (57) boot.esp32: SPI Mode       : DIO
I (61) boot.esp32: SPI Flash Size : 4MB
I (66) boot: Enabling RNG early entropy source...
I (71) boot: Partition Table:
I (75) boot: ## Label            Usage          Type ST Offset   Length
I (82) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (90) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (97) boot:  2 factory          factory app      00 00 00010000 00100000
I (105) boot: End of partition table
I (109) esp_image: segment 0: paddr=00010020 vaddr=3f400020 size=09fech ( 40940) map
I (129) esp_image: segment 1: paddr=0001a014 vaddr=3ffb0000 size=02254h (  8788) load
I (132) esp_image: segment 2: paddr=0001c270 vaddr=40080000 size=03da8h ( 15784) load
I (142) esp_image: segment 3: paddr=00020020 vaddr=400d0020 size=147e4h ( 83940) map
I (169) esp_image: segment 4: paddr=0003480c vaddr=40083da8 size=089f4h ( 35316) load
I (187) boot: Loaded app from partition at offset 0x10000
I (187) boot: Disabling RNG early entropy source...
I (198) cpu_start: Multicore app
I (207) cpu_start: Pro cpu start user code
I (207) cpu_start: cpu freq: 240000000 Hz
I (207) cpu_start: Application information:
I (210) cpu_start: Project name:     blink
I (215) cpu_start: App version:      1
I (219) cpu_start: Compile time:     May  7 2024 09:53:52
I (225) cpu_start: ELF file SHA256:  b938a84dc...
I (231) cpu_start: ESP-IDF:          v5.2.1-485-g9b3ae86417
I (237) cpu_start: Min chip rev:     v0.0
I (242) cpu_start: Max chip rev:     v3.99 
I (246) cpu_start: Chip rev:         v1.0
I (251) heap_init: Initializing. RAM available for dynamic allocation:
I (258) heap_init: At 3FFAE6E0 len 00001920 (6 KiB): DRAM
I (264) heap_init: At 3FFB2B18 len 0002D4E8 (181 KiB): DRAM
I (271) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (277) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (283) heap_init: At 4008C79C len 00013864 (78 KiB): IRAM
I (290) spi_flash: detected chip: generic
I (294) spi_flash: flash io: qio

assert failed: do_core_init startup.c:334 (flash_ret == ESP_OK)

Backtrace: 0x400815ea:0x3ffe3a80 0x400857e9:0x3ffe3aa0 0x4008b21d:0x3ffe3ac0 0x400d18bd:0x3ffe3be0 0x400d1af9:0x3ffe3c00 0x4008131e:0x3ffe3c40 0x40079752:0x3ffe3c90 |<-CORRUPTED

Faultless ESP32 before debugging:

rst:0x1 (POWERON_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:1
load:0x3fff0030,len:7524
load:0x40078000,len:16528
ho 0 tail 12 room 4
load:0x40080400,len:4
load:0x40080404,len:4312
entry 0x4008065c
I (31) boot: ESP-IDF v5.2.1-485-g9b3ae86417 2nd stage bootloader
I (31) boot: compile time May  7 2024 09:53:52
I (32) boot: Multicore bootloader
I (36) boot: chip revision: v1.0
I (40) qio_mode: Enabling default flash chip QIO
I (45) boot.esp32: SPI Speed      : 80MHz
I (50) boot.esp32: SPI Mode       : QIO
I (54) boot.esp32: SPI Flash Size : 4MB
I (59) boot: Enabling RNG early entropy source...
I (64) boot: Partition Table:
I (68) boot: ## Label            Usage          Type ST Offset   Length
I (75) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (83) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (90) boot:  2 factory          factory app      00 00 00010000 00100000
I (98) boot: End of partition table
I (102) esp_image: segment 0: paddr=00010020 vaddr=3f400020 size=09fech ( 40940) map
I (121) esp_image: segment 1: paddr=0001a014 vaddr=3ffb0000 size=02254h (  8788) load
I (124) esp_image: segment 2: paddr=0001c270 vaddr=40080000 size=03da8h ( 15784) load
I (132) esp_image: segment 3: paddr=00020020 vaddr=400d0020 size=147e4h ( 83940) map
I (157) esp_image: segment 4: paddr=0003480c vaddr=40083da8 size=089f4h ( 35316) load
I (175) boot: Loaded app from partition at offset 0x10000
I (175) boot: Disabling RNG early entropy source...
I (186) cpu_start: Multicore app
I (194) cpu_start: Pro cpu start user code
I (194) cpu_start: cpu freq: 240000000 Hz
I (194) cpu_start: Application information:
I (197) cpu_start: Project name:     blink
I (202) cpu_start: App version:      1
I (207) cpu_start: Compile time:     May  7 2024 09:53:52
I (213) cpu_start: ELF file SHA256:  b938a84dc...
I (218) cpu_start: ESP-IDF:          v5.2.1-485-g9b3ae86417
I (224) cpu_start: Min chip rev:     v0.0
I (229) cpu_start: Max chip rev:     v3.99 
I (234) cpu_start: Chip rev:         v1.0
I (239) heap_init: Initializing. RAM available for dynamic allocation:
I (246) heap_init: At 3FFAE6E0 len 00001920 (6 KiB): DRAM
I (252) heap_init: At 3FFB2B18 len 0002D4E8 (181 KiB): DRAM
I (258) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (264) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (271) heap_init: At 4008C79C len 00013864 (78 KiB): IRAM
I (278) spi_flash: detected chip: generic
I (282) spi_flash: flash io: qio
I (286) main_task: Started on CPU0
I (296) main_task: Calling app_main()
I (296) example: Example configured to blink GPIO LED!
I (296) gpio: GPIO[2]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
I (306) example: Turning the LED OFF!
I (1306) example: Turning the LED ON!
I (2306) example: Turning the LED OFF!
I (3306) example: Turning the LED ON!

Faultless ESP32, after debugging and creating a software breakpoint:

rst:0x1 (POWERON_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:1
load:0x3fff0030,len:7524
load:0x40078000,len:16528
ho 0 tail 12 room 4
load:0x40080400,len:4
load:0x40080404,len:4312
entry 0x4008065c
I (30) boot: ESP-IDF v5.2.1-485-g9b3ae86417 2nd stage bootloader
I (31) boot: compile time May  7 2024 09:53:52
I (32) boot: Multicore bootloader
I (36) boot: chip revision: v1.0
I (40) qio_mode: Enabling default flash chip QIO
I (45) boot.esp32: SPI Speed      : 80MHz
I (50) boot.esp32: SPI Mode       : QIO
I (54) boot.esp32: SPI Flash Size : 4MB
I (59) boot: Enabling RNG early entropy source...
I (64) boot: Partition Table:
I (68) boot: ## Label            Usage          Type ST Offset   Length
I (75) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (83) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (90) boot:  2 factory          factory app      00 00 00010000 00100000
I (98) boot: End of partition table
I (102) esp_image: segment 0: paddr=00010020 vaddr=3f400020 size=09fech ( 40940) map
I (121) esp_image: segment 1: paddr=0001a014 vaddr=3ffb0000 size=02254h (  8788) load
I (124) esp_image: segment 2: paddr=0001c270 vaddr=40080000 size=03da8h ( 15784) load
I (132) esp_image: segment 3: paddr=00020020 vaddr=400d0020 size=147e4h ( 83940) map
I (157) esp_image: segment 4: paddr=0003480c vaddr=40083da8 size=089f4h ( 35316) load
E (168) esp_image: Checksum failed. Calculated 0xca read 0x5d
E (168) boot: Factory app partition is not bootable
E (169) boot: No bootable app partitions in the partition table
ets Jun  8 2016 00:22:57

rst:0x3 (SW_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:1
load:0x3fff0030,len:7524
load:0x40078000,len:16528
ho 0 tail 12 room 4
load:0x40080400,len:4
load:0x40080404,len:4312
entry 0x4008065c
I (60) boot: ESP-IDF v5.2.1-485-g9b3ae86417 2nd stage bootloader
I (60) boot: compile time May  7 2024 09:53:52
I (62) boot: Multicore bootloader
I (66) boot: chip revision: v1.0
I (70) qio_mode: Enabling default flash chip QIO
I (76) boot.esp32: SPI Speed      : 80MHz
I (80) boot.esp32: SPI Mode       : QIO
I (85) boot.esp32: SPI Flash Size : 4MB
I (89) boot: Enabling RNG early entropy source...
I (95) boot: Partition Table:
I (98) boot: ## Label            Usage          Type ST Offset   Length
I (106) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (113) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (121) boot:  2 factory          factory app      00 00 00010000 00100000
I (128) boot: End of partition table
I (133) esp_image: segment 0: paddr=00010020 vaddr=3f400020 size=09fech ( 40940) map
I (152) esp_image: segment 1: paddr=0001a014 vaddr=3ffb0000 size=02254h (  8788) load
I (154) esp_image: segment 2: paddr=0001c270 vaddr=40080000 size=03da8h ( 15784) load
I (163) esp_image: segment 3: paddr=00020020 vaddr=400d0020 size=147e4h ( 83940) map
I (188) esp_image: segment 4: paddr=0003480c vaddr=40083da8 size=089f4h ( 35316) load
E (199) esp_image: Checksum failed. Calculated 0xca read 0x5d
E (199) boot: Factory app partition is not bootable
E (200) boot: No bootable app partitions in the partition table
ets Jun  8 2016 00:22:57
erhankur commented 6 months ago

Yes, I can confirm there is a bug related to QIO mode. Breakpoint locations in flash are being replaced with either 0xFF or 0x00, causing the following instruction fetches to fail and leading to image corruption.

In the stub_flasher init maybe we should force to DIO mode and turn back to original mode, or properly init for every mode. I need to check that part. But it may take time.

tipeter commented 6 months ago

Thank you very much for your work!