Xtensa: Something goes wrong when inside an exception handler and trying to use RTT + probe-rs

[bjoernQ]

Discovered in #2061

When using DEFMT + RTT + probe-rs the exception handler isn't able to produce any output. I get a message like WARN probe_rs::util::rtt::client: RTT control block corrupted (write pointer is 1006700828 while buffer size is 1024 for up channel 0 (defmt)), re-attaching as soon as the exception handler is trying to write to RTT. Tested at least on ESP32-S3 - most probably it's like that on all the Xtensas (needs to get checked)

This might have worked before

This works fine on RISC-V (tested on ESP32-C6)

[bjoernQ]

Ok maybe it's not a real issue but just "bad luck" on my side.

This is the code triggering the problem for me

#![no_std]
#![no_main]

use defmt_rtt as _;
use esp_backtrace as _;

use esp_hal::{
    clock::ClockControl,
    delay::Delay,
    interrupt::{self},
    peripherals::{Interrupt, Peripherals, TIMG0},
    prelude::*,
    system::SystemControl,
    timer::timg::{Timer, Timer0, TimerGroup},
};

use core::cell::RefCell;
use critical_section::Mutex;

static TIMER0: Mutex<RefCell<Option<Timer<Timer0<TIMG0>, esp_hal::Blocking>>>> =
    Mutex::new(RefCell::new(None));

#[entry]
fn main() -> ! {
    let peripherals = Peripherals::take();
    let system = SystemControl::new(peripherals.SYSTEM);

    let clocks = ClockControl::max(system.clock_control).freeze();
    let delay = Delay::new(&clocks);

    let timg0 = TimerGroup::new(peripherals.TIMG0, &clocks);
    let timer0 = timg0.timer0;
    timer0.set_interrupt_handler(tg0_t0_level);

    interrupt::enable(
        Interrupt::TG0_T0_LEVEL,
        esp_hal::interrupt::Priority::Priority1,
    )
    .unwrap();
    timer0.load_value(500u64.millis()).unwrap();
    timer0.start();
    timer0.listen();

    critical_section::with(|cs| {
        TIMER0.borrow_ref_mut(cs).replace(timer0);
    });

    loop {
        defmt::info!("staying alive");
        delay.delay_millis(500);
    }
}

#[handler]
fn tg0_t0_level() {
    let x = (esp_hal::time::current_time()
        .duration_since_epoch()
        .to_millis() as f32
        / 2f32) as u32;

    defmt::info!("x = {}", x);

    critical_section::with(|cs| {
        let mut timer0 = TIMER0.borrow_ref_mut(cs);
        let timer0 = timer0.as_mut().unwrap();

        timer0.clear_interrupt();
        timer0.load_value(500u64.millis()).unwrap();
        timer0.start();
    });
}

However this does work as expected (i.e. showing the output of esp-backtrace)

#![no_std]
#![no_main]

use defmt_rtt as _;
use esp_backtrace as _;

use esp_hal::{
    clock::ClockControl,
    delay::Delay,
    interrupt::{self},
    peripherals::{Interrupt, Peripherals, TIMG0},
    prelude::*,
    system::SystemControl,
    timer::timg::{Timer, Timer0, TimerGroup},
};

use core::cell::RefCell;
use critical_section::Mutex;

static TIMER0: Mutex<RefCell<Option<Timer<Timer0<TIMG0>, esp_hal::Blocking>>>> =
    Mutex::new(RefCell::new(None));

#[entry]
fn main() -> ! {
    let peripherals = Peripherals::take();
    let system = SystemControl::new(peripherals.SYSTEM);

    let clocks = ClockControl::max(system.clock_control).freeze();
    let delay = Delay::new(&clocks);

    let timg0 = TimerGroup::new(peripherals.TIMG0, &clocks);
    let timer0 = timg0.timer0;
    timer0.set_interrupt_handler(tg0_t0_level);

    interrupt::enable(
        Interrupt::TG0_T0_LEVEL,
        esp_hal::interrupt::Priority::Priority1,
    )
    .unwrap();
    timer0.load_value(500u64.millis()).unwrap();
    timer0.start();
    timer0.listen();

    critical_section::with(|cs| {
        TIMER0.borrow_ref_mut(cs).replace(timer0);
    });

    loop {
        defmt::info!("staying alive");
        delay.delay_millis(500);
    }
}

#[handler]
fn tg0_t0_level() {
    let x = (esp_hal::time::current_time()
        .duration_since_epoch()
        .to_millis() as f32
        / 2f32) as u32;

    unsafe {
        static mut FOO: u32 = 0u32;
        core::ptr::addr_of_mut!(FOO).write_volatile(x);
    }

    critical_section::with(|cs| {
        let mut timer0 = TIMER0.borrow_ref_mut(cs);
        let timer0 = timer0.as_mut().unwrap();

        timer0.clear_interrupt();
        timer0.load_value(500u64.millis()).unwrap();
        timer0.start();
    });
}

[bugadani]

@bjoernQ please include your Cargo.toml, too, the features may be interesting for repro.

[bjoernQ]

Sure - just forgot that 😄

[package]
name = "cp0"
version = "0.1.0"
edition = "2021"

[dependencies]
esp-backtrace = { version = "0.14.0", default-features = false, features = [
    "esp32s3",
    "exception-handler",
    "panic-handler",
    "defmt",
]}

esp-hal = { version = "0.20.1", features = [
    "esp32s3",
] }
defmt            = "0.3.8"
defmt-rtt = "0.4.1"

critical-section = "1.1.3"

[profile.dev]
# Rust debug is too slow.
# For debug builds always builds with some optimization
opt-level = "s"

[profile.release]
codegen-units = 1        # LLVM can perform better optimizations using a single thread
debug = 2
debug-assertions = false
incremental = false
lto = 'fat'
opt-level = 's'
overflow-checks = false

[patch.crates-io]
esp-hal = { path = "/projects/esp/esp-hal/esp-hal" }
esp-backtrace = { path = "/projects/esp/esp-hal/esp-backtrace" }
esp-println = { path = "/projects/esp/esp-hal/esp-println" }
xtensa-lx-rt = { path = "/projects/esp/esp-hal/xtensa-lx-rt" }

[MabezDev]

I suppose we should transfer this to probe-rs, unless there is something specific in the hal that's messing things up?

[bugadani]

We may, but it's unclear where the issue is and I have a suspicion who'll take this up so it probably doesn't matter where this issue lives :)