esp-rs / esp-hal

no_std Hardware Abstraction Layers for ESP32 microcontrollers
https://docs.esp-rs.org/esp-hal/
Apache License 2.0
710 stars 195 forks source link

ESP32 _DoubleExceptionVector and __user_exception error #1198

Closed PhilippPolterauer closed 6 months ago

PhilippPolterauer commented 6 months ago

I am running into an issue when programming an ESP32-WROOM-D with rust.

I tried all the examples from https://github.com/esp-rs/esp-hal/tree/9a95c0aa880af7271f059797339bf890d2d59c64/esp32-hal, but all examples start with three exceptions, Besides that the examples seem to work normally, i just would like to understand what is going on and why this errors occurr.

esp@3e0ddb366c2d:/workspaces/esp32-rust$ cargo run
   Compiling noidf v0.1.0 (/workspaces/esp32-rust/no-idf)
    Finished dev [unoptimized + debuginfo] target(s) in 0.29s
     Running `espflash flash --monitor target/xtensa-esp32-none-elf/debug/main`
[2024-02-24T15:48:53Z INFO ] Serial port: '/dev/ttyUSB0'
[2024-02-24T15:48:53Z INFO ] Connecting...
[2024-02-24T15:48:53Z INFO ] Using flash stub
Chip type:         esp32 (revision v3.1)
Crystal frequency: 40 MHz
Flash size:        4MB
Features:          WiFi, BT, Dual Core, 240MHz, Coding Scheme None
MAC address:       e4:65:b8:77:6e:78
App/part. size:    186,064/4,128,768 bytes, 4.51%
[00:00:07] [========================================]      71/71      0x10000                                                                                                                                                                                                      [2024-02-24T15:49:02Z INFO ] Flashing has completed!
Commands:
    CTRL+R    Reset chip
    CTRL+C    Exit

ets Jul 29 2019 12:21:46

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:2
load:0x3fff0030,len:7104
load:0x40078000,len:15576
load:0x40080400,len:4
0x40080400 - _DoubleExceptionVector
    at ??:??
ho 8 tail 4 room 4
load:0x40080404,len:3876
0x40080404 - _DoubleExceptionVector
    at ??:??
entry 0x4008064c
0x4008064c - __user_exception
    at /home/esp/.cargo/registry/src/index.crates.io-6f17d22bba15001f/esp-backtrace-0.11.0/src/lib.rs:130
I (31) boot: ESP-IDF v5.1-beta1-378-gea5e0ff298-dirt 2nd stage bootloader
I (31) boot: compile time Jun  7 2023 07:48:23
I (33) boot: Multicore bootloader
I (37) boot: chip revision: v3.1
I (41) boot.esp32: SPI Speed      : 40MHz
I (46) boot.esp32: SPI Mode       : DIO
I (50) boot.esp32: SPI Flash Size : 4MB
I (55) boot: Enabling RNG early entropy source...
I (60) boot: Partition Table:
I (64) boot: ## Label            Usage          Type ST Offset   Length
I (71) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (79) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (86) boot:  2 factory          factory app      00 00 00010000 003f0000
I (94) boot: End of partition table
I (98) esp_image: segment 0: paddr=00010020 vaddr=3f400020 size=060c4h ( 24772) map
I (115) esp_image: segment 1: paddr=000160ec vaddr=3ff80000 size=00004h (     4) load
I (116) esp_image: segment 2: paddr=000160f8 vaddr=3ffb0000 size=00004h (     4) load
I (123) esp_image: segment 3: paddr=00016104 vaddr=40080000 size=0183ch (  6204) load
I (134) esp_image: segment 4: paddr=00017948 vaddr=00000000 size=086d0h ( 34512) 
I (152) esp_image: segment 5: paddr=00020020 vaddr=400d0020 size=1d68ch (120460) map
I (197) boot: Loaded app from partition at offset 0x10000
I (197) boot: Disabling RNG early entropy source...

The unclear errors are _DoubleExceptionVector and __user_exception.

I found a somewhat related issue at #1105

philipp@Philipp:/mnt/c/Users/phili$ espflash board-info
[2024-02-24T15:48:18Z INFO ] Serial port: '/dev/ttyUSB0'
[2024-02-24T15:48:18Z INFO ] Connecting...
[2024-02-24T15:48:18Z INFO ] Using flash stub
Chip type:         esp32 (revision v3.1)
Crystal frequency: 40 MHz
Flash size:        4MB
Features:          WiFi, BT, Dual Core, 240MHz, Coding Scheme None
MAC address:       e4:65:b8:77:6e:78
PhilippPolterauer commented 6 months ago

I found a second strange thing in the dual core example from https://github.com/esp-rs/esp-hal/blob/main/esp32-hal/examples/multicore.rs

//! This shows how to spawn a task on the second core.
//! The first core will print the value of a counter which is incremented by the
//! second core.

#![no_std]
#![no_main]

use core::cell::RefCell;

use critical_section::Mutex;
use esp32_hal::{
    clock::ClockControl,
    cpu_control::{CpuControl, Stack},
    peripherals::{Peripherals, TIMG1},
    prelude::*,
    timer::{Timer, Timer0, TimerGroup},
};
use esp_backtrace as _;
use esp_println::println;
use nb::block;

static mut APP_CORE_STACK: Stack<8192> = Stack::new();

#[entry]
fn main() -> ! {
    let peripherals = Peripherals::take();
    let system = peripherals.SYSTEM.split();
    let clocks = ClockControl::boot_defaults(system.clock_control).freeze();

    let timer_group0 = TimerGroup::new(peripherals.TIMG0, &clocks);
    let mut timer0 = timer_group0.timer0;

    let timer_group1 = TimerGroup::new(peripherals.TIMG1, &clocks);
    let mut timer1 = timer_group1.timer0;

    timer0.start(500u64.millis());
    timer1.start(500u64.millis());

    let counter = Mutex::new(RefCell::new(0));

    let mut cpu_control = CpuControl::new(system.cpu_control);
    let cpu1_fnctn = || {
        cpu1_task(&mut timer1, &counter);
    };
    let _guard = cpu_control
        .start_app_core(unsafe { &mut APP_CORE_STACK }, cpu1_fnctn)
        .unwrap();

    loop {
        block!(timer0.wait()).unwrap();
        let count = critical_section::with(|cs| *counter.borrow_ref(cs));
        println!("Hello World - Core 0! Counter is {}", count);
    }
}

fn cpu1_task(
    timer: &mut Timer<Timer0<TIMG1>>,
    counter: &critical_section::Mutex<RefCell<i32>>,
) -> ! {
    println!("Hello World - Core 1!");
    loop {
        block!(timer.wait()).unwrap();

        critical_section::with(|cs| {
            let new_val = counter.borrow_ref_mut(cs).wrapping_add(1);
            *counter.borrow_ref_mut(cs) = new_val;
        });
    }
}

it leads to the following output

esp@3e0ddb366c2d:/workspaces/esp32-rust$ cargo run --release
    Finished release [optimized + debuginfo] target(s) in 0.05s
     Running `espflash flash --monitor target/xtensa-esp32-none-elf/release/main`
[2024-02-24T16:01:48Z INFO ] Serial port: '/dev/ttyUSB0'
[2024-02-24T16:01:48Z INFO ] Connecting...
[2024-02-24T16:01:48Z INFO ] Using flash stub
Chip type:         esp32 (revision v3.1)
Crystal frequency: 40 MHz
Flash size:        4MB
Features:          WiFi, BT, Dual Core, 240MHz, Coding Scheme None
MAC address:       e4:65:b8:77:6e:78
App/part. size:    86,016/4,128,768 bytes, 2.08%
[2024-02-24T16:01:50Z INFO ] Flashing has completed!
Commands:
    CTRL+R    Reset chip
    CTRL+C    Exit

ets Jul 29 2019 12:21:46

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:2
load:0x3fff0030,len:7104
load:0x40078000,len:15576
load:0x40080400,len:4
0x40080400 - _DoubleExceptionVector
    at ??:??
ho 8 tail 4 room 4
load:0x40080404,len:3876
0x40080404 - _DoubleExceptionVector
    at ??:??
entry 0x4008064c
0x4008064c - esp_backtrace::arch::backtrace_internal
    at /home/esp/.cargo/registry/src/index.crates.io-6f17d22bba15001f/esp-backtrace-0.11.0/src/xtensa.rs:287
I (31) boot: ESP-IDF v5.1-beta1-378-gea5e0ff298-dirt 2nd stage bootloader
I (31) boot: compile time Jun  7 2023 07:48:23
I (33) boot: Multicore bootloader
I (37) boot: chip revision: v3.1
I (41) boot.esp32: SPI Speed      : 40MHz
I (46) boot.esp32: SPI Mode       : DIO
I (50) boot.esp32: SPI Flash Size : 4MB
I (55) boot: Enabling RNG early entropy source...
I (60) boot: Partition Table:
I (64) boot: ## Label            Usage          Type ST Offset   Length
I (71) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (79) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (86) boot:  2 factory          factory app      00 00 00010000 003f0000
I (94) boot: End of partition table
I (98) esp_image: segment 0: paddr=00010020 vaddr=3f400020 size=01ee4h (  7908) map
I (109) esp_image: segment 1: paddr=00011f0c vaddr=3ffb0000 size=00004h (     4) load
I (115) esp_image: segment 2: paddr=00011f18 vaddr=40080000 size=01aech (  6892) load
I (126) esp_image: segment 3: paddr=00013a0c vaddr=00000000 size=0c60ch ( 50700) 
I (150) esp_image: segment 4: paddr=00020020 vaddr=400d0020 size=04fb8h ( 20408) map
I (158) boot: Loaded app from partition at offset 0x10000
I (158) boot: Disabling RNG early entropy source...
Hello World - Core 1!
Hello World - Core 0! Counter is 0
Hello World - Core 0! Counter is 1
Hello World - Core 0! Counter is 2
Hello World - Core 0! Counter is 3
Hello World - Core 0! Counter is 4
Hello World - Core 0! Counter is 5

where only one of the two cores is actually increasing the counter.

I am not sure if this is really related or if i should raise a seperate issue.

bjoernQ commented 6 months ago

Thanks!

I see this looks confusing - actually what looks like exceptions are none.

load:0x40080400,len:4
0x40080400 - _DoubleExceptionVector
    at ??:??
ho 8 tail 4 room 4
load:0x40080404,len:3876
0x40080404 - _DoubleExceptionVector
    at ??:??
entry 0x4008064c
0x4008064c - __user_exception
    at /home/esp/.cargo/registry/src/index.crates.io-6f17d22bba15001f/esp-backtrace-0.11.0/src/lib.rs:130

This is output from the ROM bootloader - it's just output which might help when debugging problems. espflash tries to decode addresses and in this case fails and gives a somewhat scary output. At that point the Rust code isn't even running yet (we are before the 2nd stage bootloader)

For the second thing: Maybe the output of the example is bit confusing. Core 1 is counting and core 0 prints the current value. Core 1 only prints "Hello World" once. Any suggestions how to make the intention and the output of the example more obvious

MabezDev commented 6 months ago

Sorry for the confusion, as as @bjoernQ mentioned these are red herrings. We're trying to figure out a better way of handling this with espflash in https://github.com/esp-rs/espflash/issues/600.