Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

embassy-executor LoadProhibited exception when using a large task across two different cores in release profile on ESP32 #2704

Closed
manuelbaez opened this issue Mar 16, 2024 · 2 comments

Comments

@manuelbaez
Copy link

manuelbaez commented Mar 16, 2024

Hi, first I'd like to thank anyone who takes the time to read this, sorry about misspellings and any weird things I'm new to Rust and English is my second language :)

I'm trying to make a flight controller with an esp32 using embassy, I started with the esp idf std template but decided to move to no_std out of curiosity and maybe to get more performance and a lighter binary for the app.

I have my application sectioned into three main tasks at the moment:

  • A user input task
  • Telemetry/ debugging
  • Flight controller

I can run those three tasks just fine if I use only one core, but that introduces some unwanted spikes in the latency for the flight controller and I want it to be as performant as possible, so that's why I want to use the second core exclusively for that. But I'm facing the following issue when trying to use the second core for any of the tasks and also spawn the flight_controller simultaneously:

Exception occured 'LoadProhibited' Context PC=0x400dc1b8 PS=0x00060930 0x400dc1b8 - embassy_executor::raw::util::SyncUnsafeCell<T>::get at /mnt/disk-2/repos/embassy/embassy-executor/src/raw/util.rs:55 0x00060930 - ?? at ??:??

This only occurs when I try to spawn any of the tasks in the second core, it runs just fine when everything is in just one. At first, I thought it was the way I was sharing the user input data between the tasks, I'm using a struct of atomic values:

pub struct AtomicControllerInput {
   pub roll: AtomicI16,
   pub pitch: AtomicI16,
   pub yaw: AtomicI16,
   pub throttle: AtomicU8,
   pub kill_motors: AtomicBool,
   pub start: AtomicBool,
   pub calibrate_esc: AtomicBool,
   pub calibrate_sensors: AtomicBool,
}

impl AtomicControllerInput {
   pub const fn new() -> Self {
       AtomicControllerInput {
           roll: AtomicI16::new(0),
           pitch: AtomicI16::new(0),
           yaw: AtomicI16::new(0),
           throttle: AtomicU8::new(0),
           kill_motors: AtomicBool::new(false),
           start: AtomicBool::new(false),
           calibrate_esc: AtomicBool::new(false),
           calibrate_sensors: AtomicBool::new(false),
       }
   }
}

pub static SHARED_CONTROLLER_INPUT: AtomicControllerInput = AtomicControllerInput::new();\

So I removed that to test and the executor, where the flight controller is, kept crashing (also I use relaxed ordering, not sure if that's important), so I started to comment code to see at what point it crashes, and I found out it was crashing on an async function that used the I2C but interestingly when I made the function sync it stopped crashing at that point, but when I added some code back it started crashing again.

Then I saw in the docs about the task arena and I enabled the nightly feature, this Increased the amount of my code that I could put back into the function but still crashed at some point on some random arithmetic function, nothing that should cause problems. This is why I think this has something to do with the size of the task( call stack? or Future) since it seems to be trying to access memory out of bounds for the executor.

I decided to clone the embassy repo and tracked down the crash to this function call:

image

This is line 405 of the src/raw/mod.rs in the embassy-executor, but I'm at a loss here since I'm quite new to rust(I picked this project to start learning it) and I don't understand much of what's going on here, but I guess that wherever that poll_fn is getting assigned for that task it's assigning it a pointer that leads to some wrong memory address.

Important to note, This only happens in a release build, somehow debug builds are fine but the code runs 20 to 30x slower so that might be something worth mentioning, no idea why though.

This is the function that crashes in the executor.

Here is the full app code that's crashing.

This is what my main looks like when spawning to the second core:

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

#[main]
async fn main(spawner: Spawner) -> ! {
   // init_heap();
   let peripherals = Peripherals::take();
   let system = peripherals.SYSTEM.split();
   let clocks = ClockControl::max(system.clock_control).freeze();
   let clocks = CLOCKS.init(clocks);

   let timer = esp_hal::timer::TimerGroup::new(peripherals.TIMG0, clocks);
   embassy::init(clocks, timer);

   let mut cpu_control = CpuControl::new(system.cpu_control);

   // This line is for Wokwi only so that the console output is formatted correctly
   // print!("\x1b[20h");

   let io = IO::new(peripherals.GPIO, peripherals.IO_MUX);

   spawner.spawn(telemetry_task()).unwrap();

   spawner
       .spawn(controller_input_task(
           io.pins.gpio17,
           io.pins.gpio16,
           peripherals.UART2,
           clocks,
       ))
       .unwrap();

   let cpu1_fn = || {
       static APP_CORE_EXECUTOR: StaticCell<Executor> = StaticCell::new(); // I move this here to test, there's no difference
       let executor = APP_CORE_EXECUTOR.init(Executor::new());
       executor.run(|spawner| {
           spawner
               .spawn(flight_controller_task(
                   peripherals.I2C0,
                   io.pins.gpio21,
                   io.pins.gpio22,
                   peripherals.LEDC,
                   io.pins.gpio13.into_push_pull_output(),
                   io.pins.gpio12.into_push_pull_output(),
                   io.pins.gpio14.into_push_pull_output(),
                   io.pins.gpio27.into_push_pull_output(),
                   clocks,
               ))
               .unwrap();
       });
   };
   let _guard = cpu_control
       .start_app_core(unsafe { &mut APP_CORE_STACK }, cpu1_fn)
       .unwrap();

   let mut count = 0;
   loop {
       esp_println::println!("Main Task Count: {} ", count);
       count += 1;
       Timer::after_millis(u32::MAX as u64).await;
   }
}

This is the full console output when the app crashes:

[2024-03-16T18:43:24Z INFO ] Flashing has completed!
Commands:
	CTRL+R	Reset chip
	CTRL+C	Exit

������������������������

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
0x3fff0030 - _ZN12embassy_time13queue_generic5QUEUE17ha6ddcddb6f3e2583E
	at ??:??
load:0x40078000,len:15576
0x40078000 - _ZN12embassy_time13queue_generic5QUEUE17ha6ddcddb6f3e2583E
	at ??:??
load:0x40080400,len:4
0x40080400 - _DoubleExceptionVector
	at ??:??
ho 8 tail 4 room 4
load:0x40080404,len:3876
0x40080404 - _DoubleExceptionVector
	at ??:??
entry 0x4008064c
0x4008064c - esp_storage::chip_specific::esp_rom_spiflash_read::{{closure}}
	at ~/.cargo/registry/src/index.crates.io-6f17d22bba15001f/esp-storage-0.3.0/src/esp32.rs:127
I (30) boot: ESP-IDF v5.1-beta1-378-gea5e0ff298-dirt 2nd stage bootloader
I (30) boot: compile time Jun  7 2023 07:48:23
I (33) boot: Multicore bootloader
I (37) boot: chip revision: v1.0
I (41) boot.esp32: SPI Speed  	: 40MHz
I (45) boot.esp32: SPI Mode   	: DIO
I (50) boot.esp32: SPI Flash Size : 4MB
I (54) boot: Enabling RNG early entropy source...
I (60) boot: Partition Table:
I (63) boot: ## Label        	Usage      	Type ST Offset   Length
I (71) boot:  0 nvs          	WiFi data    	01 02 00009000 00006000
I (78) boot:  1 phy_init     	RF data      	01 01 0000f000 00001000
I (86) boot:  2 factory      	factory app  	00 00 00010000 003f0000
I (93) boot: End of partition table
I (97) esp_image: segment 0: paddr=00010020 vaddr=3f400020 size=02dach ( 11692) map
I (110) esp_image: segment 1: paddr=00012dd4 vaddr=3ffb0000 size=00018h (	24) load
I (114) esp_image: segment 2: paddr=00012df4 vaddr=40080000 size=02010h (  8208) load
I (126) esp_image: segment 3: paddr=00014e0c vaddr=00000000 size=0b20ch ( 45580)
I (147) esp_image: segment 4: paddr=00020020 vaddr=400d0020 size=0c9cch ( 51660) map
I (167) boot: Loaded app from partition at offset 0x10000
I (167) boot: Disabling RNG early entropy source...
Main Task Count: 0
Flash Capacity 4194304



Exception occured 'LoadProhibited'
Context
PC=0x400dc96c   	PS=0x00060930
0x400dc96c - embassy_executor::raw::util::SyncUnsafeCell<T>::get
	at /mnt/disk-2/repos/embassy/embassy-executor/src/raw/util.rs:55
0x00060930 - ??
	at ??:??
A0=0x800d3861   	A1=0x3ffb2300   	A2=0x3ffb2370   	A3=0x3ffb0020   	A4=0x3ffb2378
0x800d3861 - _ZN4core3ops8function6FnOnce9call_once17h16a8461cf8bbe284E.llvm.10835848324489580207
	at ??:??
0x3ffb2300 - _ZN23flight_controller_nostd14APP_CORE_STACK17he79d40bb23e68291E
	at ??:??
0x3ffb2370 - _ZN23flight_controller_nostd21____embassy_main_task28_$u7b$$u7b$closure$u7d$$u7d$28_$u7b$$u7b$closure$u7d$$u7d$17APP_CORE_EXECUTOR17heea9e4306717ebe5E
	at ??:??
0x3ffb0020 - _ZN23flight_controller_nostd7threads22flight_controller_task4POOL17hbaacbe7ba84f0f83E.llvm.461495821013083691
	at ??:??
0x3ffb2378 - _ZN23flight_controller_nostd21____embassy_main_task28_$u7b$$u7b$closure$u7d$$u7d$28_$u7b$$u7b$closure$u7d$$u7d$17APP_CORE_EXECUTOR17heea9e4306717ebe5E
	at ??:??
A5=0x00000001   	A6=0xfffffffd   	A7=0x00000001   	A8=0x800dc993   	A9=0x3ffb21f0
0x00000001 - <esp32::RMT as core::fmt::Debug>::fmt
	at ~/.cargo/registry/src/index.crates.io-6f17d22bba15001f/esp32-0.29.0/src/lib.rs:1531
0xfffffffd - _ZN4core3ops8function6FnOnce9call_once17h16a8461cf8bbe284E.llvm.10835848324489580207
	at ??:??
0x00000001 - <esp32::RMT as core::fmt::Debug>::fmt
	at ~/.cargo/registry/src/index.crates.io-6f17d22bba15001f/esp32-0.29.0/src/lib.rs:1531
0x800dc993 - _ZN4core3ops8function6FnOnce9call_once17h16a8461cf8bbe284E.llvm.10835848324489580207
	at ??:??
0x3ffb21f0 - _ZN23flight_controller_nostd14APP_CORE_STACK17he79d40bb23e68291E
	at ??:??
A10=0x00000001  	A11=0x3ffb0020  	A12=0x3ffb0044  	A13=0x3ffb003c  	A14=0x3ffb00fc
0x00000001 - <esp32::RMT as core::fmt::Debug>::fmt
	at ~/.cargo/registry/src/index.crates.io-6f17d22bba15001f/esp32-0.29.0/src/lib.rs:1531
0x3ffb0020 - _ZN23flight_controller_nostd7threads22flight_controller_task4POOL17hbaacbe7ba84f0f83E.llvm.461495821013083691
	at ??:??
0x3ffb0044 - _ZN23flight_controller_nostd7threads22flight_controller_task4POOL17hbaacbe7ba84f0f83E.llvm.461495821013083691
	at ??:??
0x3ffb003c - _ZN23flight_controller_nostd7threads22flight_controller_task4POOL17hbaacbe7ba84f0f83E.llvm.461495821013083691
	at ??:??
0x3ffb00fc - _ZN23flight_controller_nostd7threads22flight_controller_task4POOL17hbaacbe7ba84f0f83E.llvm.461495821013083691
	at ??:??
A15=0x00000000
0x00000000 - <esp32::RMT as core::fmt::Debug>::fmt
	at ~/.cargo/registry/src/index.crates.io-6f17d22bba15001f/esp32-0.29.0/src/lib.rs:1531
SAR=00000011
EXCCAUSE=0x0000001c EXCVADDR=0x00000005
0x0000001c - <esp32::RMT as core::fmt::Debug>::fmt
	at ~/.cargo/registry/src/index.crates.io-6f17d22bba15001f/esp32-0.29.0/src/lib.rs:1532
0x00000005 - <esp32::RMT as core::fmt::Debug>::fmt
	at ~/.cargo/registry/src/index.crates.io-6f17d22bba15001f/esp32-0.29.0/src/lib.rs:1531
LBEG=0x4000c2e0 	LEND=0x4000c2f6 	LCOUNT=0x00000000
0x4000c2e0 - _ZN12embassy_time13queue_generic5QUEUE17ha6ddcddb6f3e2583E
	at ??:??
0x4000c2f6 - _ZN12embassy_time13queue_generic5QUEUE17ha6ddcddb6f3e2583E
	at ??:??
0x00000000 - <esp32::RMT as core::fmt::Debug>::fmt
	at ~/.cargo/registry/src/index.crates.io-6f17d22bba15001f/esp32-0.29.0/src/lib.rs:1531
THREADPTR=0x00000000
0x00000000 - <esp32::RMT as core::fmt::Debug>::fmt
	at ~/.cargo/registry/src/index.crates.io-6f17d22bba15001f/esp32-0.29.0/src/lib.rs:1531
SCOMPARE1=0x00000100
0x00000100 - esp_hal::sha::Sha::finish
	at ??:??
BR=0x00000000
0x00000000 - <esp32::RMT as core::fmt::Debug>::fmt
	at ~/.cargo/registry/src/index.crates.io-6f17d22bba15001f/esp32-0.29.0/src/lib.rs:1531
ACCLO=0x00000000	ACCHI=0x00000000
0x00000000 - <esp32::RMT as core::fmt::Debug>::fmt
	at ~/.cargo/registry/src/index.crates.io-6f17d22bba15001f/esp32-0.29.0/src/lib.rs:1531
0x00000000 - <esp32::RMT as core::fmt::Debug>::fmt
	at ~/.cargo/registry/src/index.crates.io-6f17d22bba15001f/esp32-0.29.0/src/lib.rs:1531
M0=0x00000000   	M1=0x00000000   	M2=0x00000000   	M3=0x00000000
0x00000000 - <esp32::RMT as core::fmt::Debug>::fmt
	at ~/.cargo/registry/src/index.crates.io-6f17d22bba15001f/esp32-0.29.0/src/lib.rs:1531
0x00000000 - <esp32::RMT as core::fmt::Debug>::fmt
	at ~/.cargo/registry/src/index.crates.io-6f17d22bba15001f/esp32-0.29.0/src/lib.rs:1531
0x00000000 - <esp32::RMT as core::fmt::Debug>::fmt
	at ~/.cargo/registry/src/index.crates.io-6f17d22bba15001f/esp32-0.29.0/src/lib.rs:1531
0x00000000 - <esp32::RMT as core::fmt::Debug>::fmt
	at ~/.cargo/registry/src/index.crates.io-6f17d22bba15001f/esp32-0.29.0/src/lib.rs:1531
F64R_LO=0x00000000  F64R_HI=0x00000000  F64S=0x00000000
0x00000000 - <esp32::RMT as core::fmt::Debug>::fmt
	at ~/.cargo/registry/src/index.crates.io-6f17d22bba15001f/esp32-0.29.0/src/lib.rs:1531
0x00000000 - <esp32::RMT as core::fmt::Debug>::fmt
	at ~/.cargo/registry/src/index.crates.io-6f17d22bba15001f/esp32-0.29.0/src/lib.rs:1531
0x00000000 - <esp32::RMT as core::fmt::Debug>::fmt
	at ~/.cargo/registry/src/index.crates.io-6f17d22bba15001f/esp32-0.29.0/src/lib.rs:1531
FCR=0x00000000  	FSR=0x00000000
0x00000000 - <esp32::RMT as core::fmt::Debug>::fmt
	at ~/.cargo/registry/src/index.crates.io-6f17d22bba15001f/esp32-0.29.0/src/lib.rs:1531
0x00000000 - <esp32::RMT as core::fmt::Debug>::fmt
	at ~/.cargo/registry/src/index.crates.io-6f17d22bba15001f/esp32-0.29.0/src/lib.rs:1531
F0=0x00000000   	F1=0x00000000   	F2=0x00000000   	F3=0x00000000   	F4=0x00000000
0x00000000 - <esp32::RMT as core::fmt::Debug>::fmt
	at ~/.cargo/registry/src/index.crates.io-6f17d22bba15001f/esp32-0.29.0/src/lib.rs:1531
0x00000000 - <esp32::RMT as core::fmt::Debug>::fmt
	at ~/.cargo/registry/src/index.crates.io-6f17d22bba15001f/esp32-0.29.0/src/lib.rs:1531
0x00000000 - <esp32::RMT as core::fmt::Debug>::fmt
	at ~/.cargo/registry/src/index.crates.io-6f17d22bba15001f/esp32-0.29.0/src/lib.rs:1531
0x00000000 - <esp32::RMT as core::fmt::Debug>::fmt
	at ~/.cargo/registry/src/index.crates.io-6f17d22bba15001f/esp32-0.29.0/src/lib.rs:1531
0x00000000 - <esp32::RMT as core::fmt::Debug>::fmt
	at ~/.cargo/registry/src/index.crates.io-6f17d22bba15001f/esp32-0.29.0/src/lib.rs:1531
F5=0x00000000   	F6=0x00000000   	F7=0x00000000   	F8=0x00000000   	F9=0x00000000
0x00000000 - <esp32::RMT as core::fmt::Debug>::fmt
	at ~/.cargo/registry/src/index.crates.io-6f17d22bba15001f/esp32-0.29.0/src/lib.rs:1531
0x00000000 - <esp32::RMT as core::fmt::Debug>::fmt
	at ~/.cargo/registry/src/index.crates.io-6f17d22bba15001f/esp32-0.29.0/src/lib.rs:1531
0x00000000 - <esp32::RMT as core::fmt::Debug>::fmt
	at ~/.cargo/registry/src/index.crates.io-6f17d22bba15001f/esp32-0.29.0/src/lib.rs:1531
0x00000000 - <esp32::RMT as core::fmt::Debug>::fmt
	at ~/.cargo/registry/src/index.crates.io-6f17d22bba15001f/esp32-0.29.0/src/lib.rs:1531
0x00000000 - <esp32::RMT as core::fmt::Debug>::fmt
	at ~/.cargo/registry/src/index.crates.io-6f17d22bba15001f/esp32-0.29.0/src/lib.rs:1531
F10=0x00000000  	F11=0x00000000  	F12=0x00000000  	F13=0x00000000  	F14=0x00000000
0x00000000 - <esp32::RMT as core::fmt::Debug>::fmt
	at ~/.cargo/registry/src/index.crates.io-6f17d22bba15001f/esp32-0.29.0/src/lib.rs:1531
0x00000000 - <esp32::RMT as core::fmt::Debug>::fmt
	at ~/.cargo/registry/src/index.crates.io-6f17d22bba15001f/esp32-0.29.0/src/lib.rs:1531
0x00000000 - <esp32::RMT as core::fmt::Debug>::fmt
	at ~/.cargo/registry/src/index.crates.io-6f17d22bba15001f/esp32-0.29.0/src/lib.rs:1531
0x00000000 - <esp32::RMT as core::fmt::Debug>::fmt
	at ~/.cargo/registry/src/index.crates.io-6f17d22bba15001f/esp32-0.29.0/src/lib.rs:1531
0x00000000 - <esp32::RMT as core::fmt::Debug>::fmt
	at ~/.cargo/registry/src/index.crates.io-6f17d22bba15001f/esp32-0.29.0/src/lib.rs:1531
F15=0x00000000
0x00000000 - <esp32::RMT as core::fmt::Debug>::fmt
	at ~/.cargo/registry/src/index.crates.io-6f17d22bba15001f/esp32-0.29.0/src/lib.rs:1531

0x400d4a47
0x400d4a47 - _ZN7esp_hal3soc14implementation11cpu_control10CpuControl16start_core1_init17h8a56d85e6dac564bE.llvm.534746425162065537
	at ??:??
0x40000000
0x40000000 - _ZN12embassy_time13queue_generic5QUEUE17ha6ddcddb6f3e2583E
	at ??:??
0x40000740
0x40000740 - _ZN12embassy_time13queue_generic5QUEUE17ha6ddcddb6f3e2583E
	at ??:??
0x40000000
0x40000000 - _ZN12embassy_time13queue_generic5QUEUE17ha6ddcddb6f3e2583E
	at ??:??

Again thanks in advance for your time and any comments!

@manuelbaez manuelbaez changed the title embassy-executor LoadProhibited exception when using a large task across two different cores in release profile embassy-executor LoadProhibited exception when using a large task across two different cores in release profile on ESP32 Mar 16, 2024
@MabezDev
Copy link
Contributor

I can't see what esp-hal version your using, but ensure it includes esp-rs/esp-hal#1286 if you're using the second core at all. For the original ESP32, you will also want to have esp-rs/esp-hal#1289 included.

@manuelbaez
Copy link
Author

Hey, thanks for your answer! I pulled again from main and it seems to have fixed the issue, also it fixed the I2c frequency that was way off before. The I2c still crashes with AckCheckFailed when used in the second core and the SCL line locks forever, though for my use case, I can just run that task in core 0 as it works fine. I think I'll open an issue in the esp-hal about this later.

This is what I meant about the SCL line:
image

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants