Feature exceptions

[arjanmels]

• Added higher level interrupt handling
• Added example for exception/interrupt handling.

This requires pull requests: https://github.com/esp-rs/xtensa-lx6-rt/pull/12 and https://github.com/esp-rs/esp32/pull/31.

(And builds on previous pull requests in this repo, better to merge them first: #16, #22)

[arjanmels]

I consider this complete and ready for merge now.

[MabezDev]

Hi @arjanmels I've tried flashing some examples but I'm getting cycled reboots with this log:

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:2
load:0x3fff0048,len:12
ho 0 tail 12 room 4
load:0x3fff0054,len:4800
load:0x40078000,len:17448
load:0x4007c428,len:4840
entry 0x4007c6a0
␛[0;31mE (69) esp_image: image at 0x10000 segment count 21 exceeds max 16␛[0m
␛[0;31mE (69) boot: Factory app partition is not bootable␛[0m
␛[0;31mE (70) boot: No bootable app partitions in the partition table␛[0m
ets Jun  8 2016 00:22:57

I haven't touched the partitions.csv, but here it anyway:

# Partition table
# Name,   Type, SubType, Offset,  Size, Flags
factory,  app,  factory, 0x10000, 0x3f0000,

Any ideas?

[arjanmels]

It looks like bootloader and partitions.csv are flashed correctly as it tries to load image from 0x10000.

Can you inspect (and perhaps share the output of the flash script)?

Maybe the flash speed is too high. I use 921600 by default. Try to reduce it to 115200.

[MabezDev]

It appeared to flash okay at the baud, but here is the output from 115200 baud:

Verify bootloader and partition table... modified

Flashing... 0x1000 target/bootloader.bin 0x8000 target/partitions.bin 0x10000 target/xtensa-esp32-none-elf/debug/examples/exception.bin

Connecting.....
Chip is ESP32D0WDQ6 (revision 1)
Features: WiFi, BT, Dual Core, 240MHz, VRef calibration in efuse, Coding Scheme None
MAC: 3c:71:bf:9d:0d:f8
Auto-detected Flash size: 4MB
Compressed 27200 bytes to 16152...
Wrote 27200 bytes (16152 compressed) at 0x00001000 in 1.4 seconds (effective 153.0 kbit/s)...
Hash of data verified.
Compressed 3072 bytes to 69...
Wrote 3072 bytes (69 compressed) at 0x00008000 in 0.0 seconds (effective 2443.9 kbit/s)...
Hash of data verified.
Compressed 218288 bytes to 57175...
Wrote 218288 bytes (57175 compressed) at 0x00010000 in 5.0 seconds (effective 346.2 kbit/s)...
Hash of data verified.

Hard resetting via RTS pin...

Succesfully build and flashed application

Seems like it properly flashes the bootloader, partition table and application, but I'm still met with:

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:2
load:0x3fff0048,len:12
ho 0 tail 12 room 4
load:0x3fff0054,len:4800
load:0x40078000,len:17448
load:0x4007c428,len:4840
entry 0x4007c6a0
␛[0;31mE (69) esp_image: image at 0x10000 segment count 21 exceeds max 16␛[0m
␛[0;31mE (69) boot: Factory app partition is not bootable␛[0m
␛[0;31mE (70) boot: No bootable app partitions in the partition table␛[0m
ets Jun  8 2016 00:22:57

Maybe my esptool is outdated.

Edit: It was the esptool on my system, updated to v2.8 and it now works :)

[MabezDev]

Hmm more issues... I mean fun!

rst:0x10 (RTCWDT_RTC_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:2
load:0x3fff0048,len:12
ho 0 tail 12 room 4
load:0x3fff0054,len:4800
load:0x40078000,len:17448
load:0x4007c428,len:4840
entry 0x4007c6a0
Fatal exception (0): IllegalInstruction
epc1=0x400d12c4, epc2=0x00000000, epc3=0x00000000, excvaddr=0x00000000, depc=0x00000000

seems like the offending instruction is andb. From the asm dump:

400d12c4:   020000          andb    b0, b0, b0

Full dump dump.zip

Hard to tell if this is a llvm codegen issue, or something else. Any ideas?

This has been built using https://github.com/MabezDev/rust-xtensa/commit/70a8b479b51543d4c51e2a3f12bdc6c213794b9a

[arjanmels]

I just also built afresh from: https://github.com/MabezDev/rust-xtensa/commit/70a8b479b51543d4c51e2a3f12bdc6c213794b9a (which works fine BTW, thank you very much!)

I uploaded prebuilt binary files to: Pre-built bin files

I also created the dump file: dump_AM.S The content is quite different: my file has mangled names, yours has nice name with rust paths.

I am using the 8.2.0 xtensa gcc toolchain. Could that make a difference?

Do you have any extra/special cargo config settings? (perhaps check with find . -path ".*/.cargo/config" in your homedir)

My active ones:

[target.xtensa-esp32-none-elf]
runner = "xtensa-esp32-elf-gdb -q -x xtensa.gdb"

[build]
rustflags = [
  "-C", "link-arg=-nostartfiles",
  "-C", "link-arg=-Wl,-Tlink.x",

]
target = "xtensa-esp32-none-elf"

and

paths = ["rust/xtensa-lx6-rt", "rust/esp32"]

[MabezDev]

I'm currently using 8.1.0 toolchain, I'll upgrade and try it shortly. FYI you asm dump link points a commit from the fork?

I used xtensa-esp32-elf-objdump -C -D target/xtensa-esp32-none-elf/debug/examples/exception > dump.S to disassemble. The -C flag demangles the symbols.

My .config looks like:

[target.xtensa-esp32-none-elf]
runner = "xtensa-esp32-elf-gdb -q -x xtensa.gdb"

[build]
rustflags = [
  "-C", "link-arg=-nostartfiles",
  "-C", "link-arg=-Wl,-Tlink.x",
]
target = "xtensa-esp32-none-elf"

The only modifications I've made locally to this branch are to depend on the newly release crates:

xtensa-lx6-rt = "0.1.0"
esp32 = "0.4.0"

[arjanmels]

No my asm dump was from my current working version. I didn't know the -C flag.

I redid the build with the updated dependencies (commit 7b45f7a): dump_AM.S.

Still lots of differences. Not sure why at all.

[MabezDev]

So I've upgraded to 8.2.0 toolchain, which made no difference.

entry 0x4007c6a0
Fatal exception (0): IllegalInstruction
epc1=0x400d9aa3, epc2=0x00000000, epc3=0x00000000, excvaddr=0x00000000, depc=0x00000000

My reset handler asm:

400d9aa0 <ESP32Reset>:
400d9aa0:   005136          entry   a1, 40
400d9aa3:   018d        mov.n   a8, a1
400d9aa5:   db9ba1          l32r    a10, 400d0914 <_stext+0x8f4>
400d9aa8:   db9cb1          l32r    a11, 400d0918 <_stext+0x8f8>
400d9aab:   db9c81          l32r    a8, 400d091c <_stext+0x8fc>
400d9aae:   0008e0          callx8  a8
400d9ab1:   ffffc6          j   400d9ab4 <ESP32Reset+0x14>
400d9ab4:   db9ba1          l32r    a10, 400d0920 <_stext+0x900>
400d9ab7:   db9bb1          l32r    a11, 400d0924 <_stext+0x904>
400d9aba:   db9881          l32r    a8, 400d091c <_stext+0x8fc>
400d9abd:   0008e0          callx8  a8
400d9ac0:   ffffc6          j   400d9ac3 <ESP32Reset+0x23>
400d9ac3:   db9981          l32r    a8, 400d0928 <_stext+0x908>
400d9ac6:   0008e0          callx8  a8
400d9ac9:   ffffc6          j   400d9acc <ESP32Reset+0x2c>
400d9acc:   db9881          l32r    a8, 400d092c <_stext+0x90c>
400d9acf:   0189        s32i.n  a8, a1, 0
400d9ad1:   00a002          movi    a0, 0
400d9ad4:   201880          or  a1, a8, a8
400d9ad7:   ffffc6          j   400d9ada <ESP32Reset+0x3a>
400d9ada:   db9581          l32r    a8, 400d0930 <_stext+0x910>
400d9add:   0008e0          callx8  a8
400d9ae0:   004f10          break   15, 1

400d9aa3: 018d mov.n a8, a1 seems to be the offending line this time, which makes me thing that it's not actually an illegal instruction, but perhaps some alignment issue maybe? This is further backed up by the fact our reset handlers are identical instruction-wise, only addresses are different.

[arjanmels]

That's an interesting find and indeed alignment is important for data from the iram.

Now the question is why the alignment is different. Must be todo with the linker.

Did you recompile llvm/rust after upgrading the toolchain (maybe still using older linker)?

[MabezDev]

Hmm I am getting more and more confused right now. I replaced my exceptions.bin with the ones you provided earlier, making sure the flash script would use that, and not build over it, and I am still getting the error.

rst:0x10 (RTCWDT_RTC_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:2
load:0x3fff0048,len:12
ho 0 tail 12 room 4
load:0x3fff0054,len:4800
load:0x40078000,len:17448
load:0x4007c428,len:4840
entry 0x4007c6a0
Fatal exception (0): IllegalInstruction
epc1=0x400db5d4, epc2=0x00000000, epc3=0x00000000, excvaddr=0x00000000, depc=0x00000000

Maybe this a board specific thing? The output from esptool when flashing is as follows:

Connecting.....
Chip is ESP32D0WDQ6 (revision 1)
Features: WiFi, BT, Dual Core, 240MHz, VRef calibration in efuse, Coding Scheme None
Crystal is 40MHz
MAC: 3c:71:bf:9d:0d:f8
Auto-detected Flash size: 4MB

[MabezDev]

Okay so I dug out another esp32, a rev 0 this time:

Connecting....
Chip is ESP32D0WDQ6 (revision 0)
Features: WiFi, BT, Dual Core, Coding Scheme None
Crystal is 40MHz

And it works! Which is progress, now to figure out why it wasn't working on the rev....

[MabezDev]

Final findings before I head to bed: https://docs.espressif.com/projects/esp-idf/en/latest/esp32/api-guides/fatal-errors.html#illegalinstruction seems like it might not be able to pull the instructions from flash.

[arjanmels]

After some thought I might understand why the asm is different: Rust stores some file paths for the panic messages. (You can check by using -s option for objdump.) (Although these messages end up in the rodata segment not the rwtext segment, but some reference might be different.)

I tried on 2 different boards (Espressif WRover devkit: ESP32D0WDQ5, 40MHz xtal, rev 1 and cheap unbranded board with 0.93 OLED: ESP32D0WDQ6, 26MHz xtal, rev 1). I don't seem to have rev0 boards at hand.

Is perhaps flash mode marginal (DIO, 40MHz?). (Can be changed in flash script via FLASH_MODE and FLASH_SPEED variables.)

You can run the entire program from RAM, by changing the default features in Cargo.toml to:

[features]
default=["external_ram", "mem","all_in_ram"]

In addition you can stop using the 2nd stage bootloader by changing USE_BOOTLOADER in the flash script to 0.

[MabezDev]

You can run the entire program from RAM, by changing the default features in Cargo.toml to: [features] default=["external_ram", "mem","all_in_ram"] In addition you can stop using the 2nd stage bootloader by changing USE_BOOTLOADER in the flash script to 0.

Running the program in RAM does indeed work. I've tried setting the speed to 20m, and tried all 4 modes but it still doesn't work unfortunately.

[arjanmels]

Very strange, so the flash does work properly (as the RAM is loaded from flash at startup) and it does work properly on another device.

Can you send me your .bin images, so I can try it on a couple of device on my end?

[MabezDev]

Very strange, so the flash does work properly (as the RAM is loaded from flash at startup) and it does work properly on another device.

Indeed, very strange. Here are my bins.

exceptions.zip

[MabezDev]

So I think I've tracked it down to xtensa_lx6_rt::set_stack_pointer(&mut _stack_end_cpu0); some how one of my boards, sp gets set to zero after this line, and the first instruction using the stack hangs the board. Commenting this line out gets it working on both boards (obviously with less stack than planned).

Here is my memory.x (no modifications, but just incase):

/* This memory map assumes the flash cache is on; 
   the blocks used are excluded from the various memory ranges 

   see: https://github.com/espressif/esp-idf/blob/master/components/soc/src/esp32/soc_memory_layout.c
   for details
   */

/* override entry point */
ENTRY(ESP32Reset)

/* reserved at the start of DRAM for e.g. teh BT stack */
RESERVE_DRAM = 0;

/* reserved at the start of the RTC memories for use by the ULP processor */
RESERVE_RTC_FAST = 0;
RESERVE_RTC_SLOW = 0;

/* define stack size for both cores */
STACK_SIZE = 8k;

/* Specify main memory areas */
MEMORY
{
  reserved_cache_seg     : ORIGIN = 0x40070000, len = 64k /* SRAM0; reserved for usage as flash cache*/
  vectors_seg ( RX )     : ORIGIN = 0x40080000, len =  1k /* SRAM0 */
  iram_seg ( RX )        : ORIGIN = 0x40080400, len = 128k-0x400 /* SRAM0 */

  reserved_for_rom_seg   : ORIGIN = 0x3FFAE000, len = 8k /* SRAM2; reserved for usage by the ROM */
  dram_seg ( RW )        : ORIGIN = 0x3FFB0000 + RESERVE_DRAM, len = 176k - RESERVE_DRAM /* SRAM2+1; first 64kB used by BT if enable */
  reserved_for_boot_seg  : ORIGIN = 0x3FFDC200, len = 144k /* SRAM1; reserved for static ROM usage; can be used for heap */

  /* external flash 
     The 0x20 offset is a convenience for the app binary image generation.
     Flash cache has 64KB pages. The .bin file which is flashed to the chip
     has a 0x18 byte file header, and each segment has a 0x08 byte segment
     header. Setting this offset makes it simple to meet the flash cache MMU's
     constraint that (paddr % 64KB == vaddr % 64KB).)
  */
  irom_seg ( RX )        : ORIGIN = 0x400D0020, len = 3M - 0x20
  drom_seg ( R )         : ORIGIN = 0x3F400020, len = 4M - 0x20

  /* RTC fast memory (executable). Persists over deep sleep. Only for core 0 (PRO_CPU) */
  rtc_fast_iram_seg(RWX) : ORIGIN = 0x400C0000, len = 8k

  /* RTC fast memory (same block as above), viewed from data bus. Only for core 0 (PRO_CPU) */
  rtc_fast_dram_seg(RW)  : ORIGIN = 0x3FF80000 + RESERVE_RTC_FAST, len = 8k - RESERVE_RTC_FAST

  /* RTC slow memory (data accessible). Persists over deep sleep. */
  rtc_slow_seg(RW)       : ORIGIN = 0x50000000 + RESERVE_RTC_SLOW, len = 8k - RESERVE_RTC_SLOW

  /* external memory, including data and text, 
     4MB is the maximum, if external psram is bigger, paging is required */
  psram_seg(RWX)         : ORIGIN = 0x3F800000, len = 4M
}

/* map generic regions to output sections */
INCLUDE "alias.x"

/* esp32 specific regions */
SECTIONS {
  .rwtext :
  {
   . = ALIGN(4);
    *(.rwtext.literal .rwtext .rwtext.literal.* .rwtext.*)
  } > iram_seg AT > RODATA

  .rtc_fast.text : {
   . = ALIGN(4);
    *(.rtc_fast.literal .rtc_fast.text .rtc_fast.literal.* .rtc_fast.text.*)
  } > rtc_fast_iram_seg AT > RODATA

  /*
    This section is required to skip rtc.text area because rtc_iram_seg and
    rtc_data_seg are reflect the same address space on different buses.
  */
  .rtc_fast.dummy (NOLOAD) :
  {
    _rtc_dummy_start = ABSOLUTE(.); /* needed to make section proper size */
    . = SIZEOF(.rtc_fast.text);
    _rtc_dummy_end = ABSOLUTE(.); /* needed to make section proper size */
  } > rtc_fast_dram_seg

  .rtc_fast.data :
  {
    _rtc_fast_data_start = ABSOLUTE(.);
    . = ALIGN(4);
    *(.rtc_fast.data .rtc_fast.data.*)
    _rtc_fast_data_end = ABSOLUTE(.);
  } > rtc_fast_dram_seg AT > RODATA

 .rtc_fast.bss (NOLOAD) :
  {
    _rtc_fast_bss_start = ABSOLUTE(.);
    . = ALIGN(4);
    *(.rtc_fast.bss .rtc_fast.bss.*)
    _rtc_fast_bss_end = ABSOLUTE(.);
  } > rtc_fast_dram_seg

 .rtc_fast.noinit (NOLOAD) :
  {
    . = ALIGN(4);
    *(.rtc_fast.noinit .rtc_fast.noinit.*)
  } > rtc_fast_dram_seg

 .rtc_slow.text : {
   . = ALIGN(4);
    *(.rtc_slow.literal .rtc_slow.text .rtc_slow.literal.* .rtc_slow.text.*)
  } > rtc_slow_seg AT > RODATA

  .rtc_slow.data :
  {
    _rtc_slow_data_start = ABSOLUTE(.);
    . = ALIGN(4);
    *(.rtc_slow.data .rtc_slow.data.*)
    _rtc_slow_data_end = ABSOLUTE(.);
  } > rtc_slow_seg AT > RODATA

 .rtc_slow.bss (NOLOAD) :
  {
    _rtc_slow_bss_start = ABSOLUTE(.);
    . = ALIGN(4);
    *(.rtc_slow.bss .rtc_slow.bss.*)
    _rtc_slow_bss_end = ABSOLUTE(.);
  } > rtc_slow_seg

 .rtc_slow.noinit (NOLOAD) :
  {
    . = ALIGN(4);
    *(.rtc_slow.noinit .rtc_slow.noinit.*)
  } > rtc_slow_seg

 .external.data :
  {
    _external_data_start = ABSOLUTE(.);
    . = ALIGN(4);
    *(.external.data .external.data.*)
    _external_data_end = ABSOLUTE(.);
  } > psram_seg AT > RODATA

 .external.bss (NOLOAD) :
  {
    _external_bss_start = ABSOLUTE(.);
    . = ALIGN(4);
    *(.external.bss .external.bss.*)
    _external_bss_end = ABSOLUTE(.);
  } > psram_seg

 .external.noinit (NOLOAD) :
  {
    . = ALIGN(4);
    *(.external.noinit .external.noinit.*)
  } > psram_seg

  /* must be last segment using psram_seg */
  .external_heap_start (NOLOAD) :
  {
    . = ALIGN (4);
    _external_heap_start = ABSOLUTE(.);
  } > psram_seg

}

_external_ram_start = ABSOLUTE(ORIGIN(psram_seg));
_external_ram_end = ABSOLUTE(ORIGIN(psram_seg)+LENGTH(psram_seg));

_heap_end = ABSOLUTE(ORIGIN(dram_seg))+LENGTH(dram_seg)+LENGTH(reserved_for_boot_seg) - 2*STACK_SIZE;
_text_heap_end = ABSOLUTE(ORIGIN(iram_seg)+LENGTH(iram_seg));
_external_heap_end = ABSOLUTE(ORIGIN(psram_seg)+LENGTH(psram_seg));

_stack_start_cpu1 = _heap_end;
_stack_end_cpu1 = _stack_start_cpu1 + STACK_SIZE;
_stack_start_cpu0 = _stack_end_cpu1;
_stack_end_cpu0 = _stack_start_cpu0 + STACK_SIZE;

EXTERN(DefaultHandler);
INCLUDE "device.x"

[arjanmels]

Interesting find on the SP. I'll give your bins a try on some of my boards (but will be later in the week I am afraid). Also will check how esp-idf handles setting stack (although that is quite complex as it goes together with task switching).

[arjanmels]

I tried your bin files on 8 different devices (1xEspressif Wrover devkit 4.1, 2xM5Stick-C, 2 different TTGO and 1 no brand, 2x Adafruit Huzzah esp32, variation of wroom modules, direct soldered, 26M and 40MHz xtal. All rev1 silicon). I cannot reproduce illegal instruction on any of them.

My tentative conclusion is that you have a unit with a subtle defect...

[MabezDev]

I does indeed look that way, very very strange behavior. I might see if I have an identical board kicking about.

[MabezDev]

So I actually found an identical board and works! Not going to lie, that is the first time I've had an intermittent hardware failure like that happen to me, and I've been playing with these things for years!

Apologies for that! I guess I can now get to actually reviewing this ;)

[arjanmels]

Not worries, debugging is part of the fun. Glad we found out.

[arjanmels]

@MabezDev Thanks for the review. Will work on the proposed changes.

BTW how do you want to go about merging. This PR includes #16 and #22. Do you just want to merge this one (and then close the others), or do you want to merge them one by one?

[MabezDev]

BTW how do you want to go about merging. This PR includes #16 and #22. Do you just want to merge this one (and then close the others), or do you want to merge them one by one?

By reviewing this PR , I've looked through all the others at the same time, so I think I'll just merge this one. As it stands this looks great! Thank you very much for all your hard work :)