Unable to debug with external SPIRAM / JTAG (OCD-434) #120
Description
Hello,
I can't debug when CONFIG_ESP32_SPIRAM_SUPPORT is set. As you can see on the log below, I never reach the first breakpoint located in app_main. There is no more log after the bootloader stage.
I debug without problem when CONFIG_ESP32_SPIRAM_SUPPORT is not set.
Setup
- ESP-IDF v4.1
- ESP32-WROVER-IE (FLASH 16MB)
- ESP-PROG JTAG
- openocd v0.10.0-esp32-20200709
OpenOCD
$ openocd.exe -f board/esp32-wrover-kit-1.8v.cfg
Open On-Chip Debugger v0.10.0-esp32-20200709 (2020-07-09-08:54)
Licensed under GNU GPL v2
For bug reports, read
http://openocd.org/doc/doxygen/bugs.html
Info : Configured 2 cores
Info : Listening on port 6666 for tcl connections
Info : Listening on port 4444 for telnet connections
Error: libusb_open() failed with LIBUSB_ERROR_NOT_SUPPORTED
Info : clock speed 5000 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 : Target halted. CPU0: PC=0x400D755B (active)
Info : Target halted. CPU1: PC=0x00000000
Info : Listening on port 3333 for gdb connections
Info : accepting 'gdb' connection on tcp/3333
Error: No symbols for FreeRTOS
Info : cpu0: Target halted, PC=0x40091856, debug_reason=00000001
Info : Flash mapping 0: 0x10020 -> 0x3f400020, 139 KB
Info : Flash mapping 1: 0x40020 -> 0x400d0020, 698 KB
Info : cpu0: Target halted, PC=0x40091856, debug_reason=00000001
Info : Auto-detected flash bank 'esp32.flash' size 16384 KB
Info : Using flash bank 'esp32.flash' size 16384 KB
Info : cpu0: Target halted, PC=0x40091856, debug_reason=00000001
Info : Flash mapping 0: 0x10020 -> 0x3f400020, 139 KB
Info : Flash mapping 1: 0x40020 -> 0x400d0020, 698 KB
Info : Using flash bank 'esp32.irom' size 700 KB
Info : cpu0: Target halted, PC=0x40091856, debug_reason=00000001
Info : Flash mapping 0: 0x10020 -> 0x3f400020, 139 KB
Info : Flash mapping 1: 0x40020 -> 0x400d0020, 698 KB
Info : Using flash bank 'esp32.drom' size 140 KB
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 : cpu0: Debug controller 0 was reset.
Info : cpu0: Core 0 was reset.
Info : cpu0: Target halted, PC=0x500000CF, debug_reason=00000000
Info : esp32: Core 0 was reset.
Info : esp32: Debug controller 1 was reset.
Info : esp32: Core 1 was reset.
Info : Target halted. CPU0: PC=0x40000400 (active)
Info : Target halted. CPU1: PC=0x40000400
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 : cpu0: Debug controller 0 was reset.
Info : cpu0: Core 0 was reset.
Info : cpu0: Target halted, PC=0x500000CF, debug_reason=00000000
Info : esp32: Core 0 was reset.
Info : esp32: Debug controller 1 was reset.
Info : esp32: Core 1 was reset.
Info : Target halted. CPU0: PC=0x40000400 (active)
Info : Target halted. CPU1: PC=0x40000400
** Programming Started **
Info : cpu0: Target halted, PC=0x40091856, debug_reason=00000001
Info : cpu0: Target halted, PC=0x40091856, debug_reason=00000001
** Programming Finished **
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 : cpu0: Debug controller 0 was reset.
Info : cpu0: Core 0 was reset.
Info : cpu0: Target halted, PC=0x500000CF, debug_reason=00000000
Info : esp32: Core 0 was reset.
Info : esp32: Debug controller 1 was reset.
Info : esp32: Core 1 was reset.
Info : Target halted. CPU0: PC=0x40000400 (active)
Info : Target halted. CPU1: PC=0x40000400
** Programming Started **
Info : cpu0: Target halted, PC=0x40091856, debug_reason=00000001
Info : cpu0: Target halted, PC=0x40091856, debug_reason=00000001
** Programming Finished **
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 : cpu0: Debug controller 0 was reset.
Info : cpu0: Core 0 was reset.
Info : cpu0: Target halted, PC=0x500000CF, debug_reason=00000000
Info : esp32: Core 0 was reset.
Info : esp32: Debug controller 1 was reset.
Info : esp32: Core 1 was reset.
Info : Target halted. CPU0: PC=0x40000400 (active)
Info : Target halted. CPU1: PC=0x40000400
** Programming Started **
Info : cpu0: Target halted, PC=0x40091856, debug_reason=00000001
Info : cpu0: Target halted, PC=0x40091856, debug_reason=00000001
** Programming Finished **
Error: Error2 reading FreeRTOS thread name.
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 : cpu0: Debug controller 0 was reset.
Info : cpu0: Core 0 was reset.
Info : cpu0: Target halted, PC=0x500000CF, debug_reason=00000000
Info : esp32: Core 0 was reset.
Info : esp32: Debug controller 1 was reset.
Info : esp32: Core 1 was reset.
Info : Target halted. CPU0: PC=0x40000400 (active)
Info : Target halted. CPU1: PC=0x40000400
Info : Target halted. CPU0: PC=0x400D755B (active)
Info : Target halted. CPU1: PC=0x40000400
Error: Error2 reading FreeRTOS thread name.GDB
$ xtensa-esp32-elf-gdb.exe -x gdbinit build/my-app.elf
GNU gdb (crosstool-NG esp-2020r2) 8.1.0.20180627-git
Copyright (C) 2018 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law. Type "show copying"
and "show warranty" for details.
This GDB was configured as "--host=x86_64-host_w64-mingw32 --target=xtensa-esp32-elf".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
<http://www.gnu.org/software/gdb/documentation/>.
For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from build/my-app.elf...done.
gdbinit: No such file or directory.
(gdb) target remote :3333
Remote debugging using :3333
Reset ESP with halt command
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)
cpu0: Debug controller 0 was reset.
cpu0: Core 0 was reset.
cpu0: Target halted, PC=0x500000CF, debug_reason=00000000
esp32: Core 0 was reset.
esp32: Debug controller 1 was reset.
esp32: Core 1 was reset.
Target halted. CPU0: PC=0x40000400 (active)
Target halted. CPU1: PC=0x40000400
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)
cpu0: Debug controller 0 was reset.
cpu0: Core 0 was reset.
cpu0: Target halted, PC=0x500000CF, debug_reason=00000000
esp32: Core 0 was reset.
esp32: Debug controller 1 was reset.
esp32: Core 1 was reset.
Target halted. CPU0: PC=0x40000400 (active)
Target halted. CPU1: PC=0x40000400
** Programming Started **
cpu0: Target halted, PC=0x40091856, debug_reason=00000001
cpu0: Target halted, PC=0x40091856, debug_reason=00000001
** Programming Finished **
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)
cpu0: Debug controller 0 was reset.
cpu0: Core 0 was reset.
cpu0: Target halted, PC=0x500000CF, debug_reason=00000000
esp32: Core 0 was reset.
esp32: Debug controller 1 was reset.
esp32: Core 1 was reset.
Target halted. CPU0: PC=0x40000400 (active)
Target halted. CPU1: PC=0x40000400
** Programming Started **
cpu0: Target halted, PC=0x40091856, debug_reason=00000001
cpu0: Target halted, PC=0x40091856, debug_reason=00000001
** Programming Finished **
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)
cpu0: Debug controller 0 was reset.
cpu0: Core 0 was reset.
cpu0: Target halted, PC=0x500000CF, debug_reason=00000000
esp32: Core 0 was reset.
esp32: Debug controller 1 was reset.
esp32: Core 1 was reset.
Target halted. CPU0: PC=0x40000400 (active)
Target halted. CPU1: PC=0x40000400
** Programming Started **
cpu0: Target halted, PC=0x40091856, debug_reason=00000001
cpu0: Target halted, PC=0x40091856, debug_reason=00000001
** Programming Finished **
Hardware assisted breakpoint 1 at 0x400d755b: file ../main/main.c, line 6.
0x40000400 in ?? ()
(gdb) set remote hardware-watchpoint-limit 2
(gdb) mon reset halt
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)
cpu0: Debug controller 0 was reset.
cpu0: Core 0 was reset.
cpu0: Target halted, PC=0x500000CF, debug_reason=00000000
esp32: Core 0 was reset.
esp32: Debug controller 1 was reset.
esp32: Core 1 was reset.
Target halted. CPU0: PC=0x40000400 (active)
Target halted. CPU1: PC=0x40000400
(gdb) flushregs
Register cache flushed.
(gdb) thb app_main
Note: breakpoint 1 also set at pc 0x400d755b.
Hardware assisted breakpoint 2 at 0x400d755b: file ../main/main.c, line 6.
(gdb) c
Continuing.
Target halted. CPU0: PC=0x400D755B (active)
Target halted. CPU1: PC=0x40000400
[Switching to Thread 1073413532]Serial output
ets Jul 29 2019 12:21:46
rst:0x3 (SW_RESET),boot:0x12 (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:2
load:0x3fff0030,len:4
load:0x3fff0034,len:9136
ho 0 tail 12 room 4
load:0x40078000,len:14728
ho 0 tail 12 room 4
load:0x40080400,len:4476
entry 0x400806c4
I (32) boot: ESP-IDF v4.1 2nd stage bootloader
I (32) boot: compile time 19:13:47
D (33) bootloader_flash: mmu set block paddr=0x00000000 (was 0xffffffff)
I (38) boot: chip revision: 3
I (42) boot_comm: chip revision: 3, min. bootloader chip revision: 0
D (49) boot.esp32: magic e9
D (52) boot.esp32: segments 04
D (55) boot.esp32: spi_mode 02
D (58) boot.esp32: spi_speed 00
D (61) boot.esp32: spi_size 04
I (64) boot.esp32: SPI Speed : 40MHz
I (69) boot.esp32: SPI Mode : DIO
I (74) boot.esp32: SPI Flash Size : 16MB
D (78) boot: Enabling RTCWDT(9000 ms)
I (82) boot: Enabling RNG early entropy source...
D (87) bootloader_flash: mmu set paddr=00000000 count=1 size=c00 src_addr=8000 src_addr_aligned=0
D (96) boot: mapped partition table 0x8000 at 0x3f408000
D (102) flash_parts: partition table verified, 6 entries
I (107) boot: Partition Table:
I (111) boot: ## Label Usage Type ST Offset Length
D (118) boot: load partition table entry 0x3f408000
D (123) boot: type=1 subtype=2
I (126) boot: 0 nvs WiFi data 01 02 00009000 00006000
D (134) boot: load partition table entry 0x3f408020
D (139) boot: type=1 subtype=1
I (142) boot: 1 phy_init RF data 01 01 0000f000 00001000
D (149) boot: load partition table entry 0x3f408040
D (154) boot: type=0 subtype=0
I (157) boot: 2 factory factory app 00 00 00010000 00100000
D (165) boot: load partition table entry 0x3f408060
D (170) boot: type=1 subtype=82
I (173) boot: 3 www Unknown data 01 82 00110000 00400000
D (181) boot: load partition table entry 0x3f408080
D (186) boot: type=1 subtype=82
I (189) boot: 4 storage Unknown data 01 82 00510000 00020000
I (196) boot: End of partition table
D (201) boot: Trying partition index -1 offs 0x10000 size 0x100000
D (207) esp_image: reading image header @ 0x10000
D (212) bootloader_flash: mmu set block paddr=0x00010000 (was 0xffffffff)
D (219) esp_image: image header: 0xe9 0x06 0x02 0x04 4008136c
I (224) boot_comm: chip revision: 3, min. application chip revision: 0
I (232) esp_image: segment 0: paddr=0x00010020 vaddr=0x3f400020 size=0x22d7c (142716) map
D (240) esp_image: free data page_count 0x00000032
D (245) bootloader_flash: mmu set paddr=00010000 count=3 size=22d7c src_addr=10020 src_addr_aligned=10000
D (317) bootloader_flash: mmu set block paddr=0x00030000 (was 0xffffffff)
I (317) esp_image: segment 1: paddr=0x00032da4 vaddr=0x3ffb0000 size=0x035c4 ( 13764) load
D (321) esp_image: free data page_count 0x00000032
D (326) bootloader_flash: mmu set paddr=00030000 count=1 size=35c4 src_addr=32da4 src_addr_aligned=30000
D (342) bootloader_flash: mmu set block paddr=0x00030000 (was 0xffffffff)
I (343) esp_image: segment 2: paddr=0x00036370 vaddr=0x40080000 size=0x00404 ( 1028) load
D (352) esp_image: free data page_count 0x00000032
D (357) bootloader_flash: mmu set paddr=00030000 count=1 size=404 src_addr=36370 src_addr_aligned=30000
D (367) bootloader_flash: mmu set block paddr=0x00030000 (was 0xffffffff)
I (373) esp_image: segment 3: paddr=0x0003677c vaddr=0x40080404 size=0x0989c ( 39068) load
D (382) esp_image: free data page_count 0x00000032
D (387) bootloader_flash: mmu set paddr=00030000 count=2 size=989c src_addr=3677c src_addr_aligned=30000
D (415) bootloader_flash: mmu set block paddr=0x00040000 (was 0xffffffff)
I (415) esp_image: segment 4: paddr=0x00040020 vaddr=0x400d0020 size=0xaeabc (715452) map
D (420) esp_image: free data page_count 0x00000032
D (425) bootloader_flash: mmu set paddr=00040000 count=11 size=aeabc src_addr=40020 src_addr_aligned=40000
D (744) bootloader_flash: mmu set block paddr=0x000e0000 (was 0xffffffff)
I (744) esp_image: segment 5: paddr=0x000eeae4 vaddr=0x40089ca0 size=0x0f628 ( 63016) load
D (749) esp_image: free data page_count 0x00000032
D (753) bootloader_flash: mmu set paddr=000e0000 count=2 size=f628 src_addr=eeae4 src_addr_aligned=e0000
D (794) bootloader_flash: mmu set paddr=000f0000 count=1 size=20 src_addr=fe0ec src_addr_aligned=f0000
I (808) boot: Loaded app from partition at offset 0x10000
I (808) boot: Disabling RNG early entropy source...
D (808) boot: Mapping segment 0 as DROM
D (812) boot: Mapping segment 4 as IROM
D (816) boot: calling set_cache_and_start_app
D (820) boot: configure drom and irom and start
D (825) boot: start: 0x4008136c
I (828) psram: This chip is ESP32-D0WD
I (833) spiram: Found 64MBit SPI RAM device
I (838) spiram: SPI RAM mode: flash 40m sram 40m
I (843) spiram: PSRAM initialized, cache is in normal (1-core) mode.
I (850) cpu_start: Pro cpu up.
I (854) cpu_start: Application information:
I (858) cpu_start: Project name: my-app
I (864) cpu_start: App version: 30eda54-dirty
I (870) cpu_start: Compile time: Sep 28 2020 19:08:59
I (876) cpu_start: ELF file SHA256: cac28c16f92daf46...
I (882) cpu_start: ESP-IDF: v4.1
I (887) cpu_start: Single core mode
I (1790) spiram: SPI SRAM memory test OK
I (1790) heap_init: Initializing. RAM available for dynamic allocation:
I (1791) heap_init: At 3FFAE6E0 len 00001920 (6 KiB): DRAM
I (1797) heap_init: At 3FFBCA68 len 00023598 (141 KiB): DRAM
I (1803) heap_init: At 3FFE0440 len 0001FBC0 (126 KiB): D/IRAM
I (1810) heap_init: At 40078000 len 00008000 (32 KiB): IRAM
I (1816) heap_init: At 400992C8 len 00006D38 (27 KiB): IRAM
I (1822) cpu_start: Pro cpu start user code
I (1827) spiram: Adding pool of 4096K of external SPI memory to heap allocator
I (1848) spi_flash: detected chip: gd
I (1848) spi_flash: flash io: dio
I (1848) cpu_start: Starting scheduler on PRO CPU.
I (1851) spiram: Reserving pool of 32K of internal memory for DMA/internal allocationsAny idea?
Thanks