GPIO test `test_gpio_interrupt` is failing for Xtensa targets

[SergioGasquez]

          By the way, as also @bjoernQ noticed, the GPIO test `test_gpio_interrupt` is failing for Xtensa targets (at least for S2 and S3) with: 

test tests::test_gpio_interrupt ... ERROR panicked at 'assertion failed: `(left == right)`'
diff < left / right >
<0
>9
└─ gpio::tests::test_gpio_interrupt @ tests/gpio.rs:182 
ERROR !! A panic occured in '/Users/sergio/.cargo/registry/src/index.crates.io-6f17d22bba15001f/defmt-0.3.6/src/lib.rs', at line 368, column 5:
└─ esp_backtrace::panic_handler @ /Users/sergio/.cargo/git/checkouts/esp-backtrace-eaa21176310f5c0a/edff83c/src/lib.rs:26  
ERROR explicit panic
└─ esp_backtrace::panic_handler @ /Users/sergio/.cargo/git/checkouts/esp-backtrace-eaa21176310f5c0a/edff83c/src/lib.rs:26  
ERROR Backtrace:
└─ esp_backtrace::panic_handler @ /Users/sergio/.cargo/git/checkouts/esp-backtrace-eaa21176310f5c0a/edff83c/src/lib.rs:26  
ERROR 0x4200488a
└─ esp_backtrace::panic_handler @ /Users/sergio/.cargo/git/checkouts/esp-backtrace-eaa21176310f5c0a/edff83c/src/lib.rs:26  
ERROR 0x4200487e
└─ esp_backtrace::panic_handler @ /Users/sergio/.cargo/git/checkouts/esp-backtrace-eaa21176310f5c0a/edff83c/src/lib.rs:26  
ERROR 0x42002d56
└─ esp_backtrace::panic_handler @ /Users/sergio/.cargo/git/checkouts/esp-backtrace-eaa21176310f5c0a/edff83c/src/lib.rs:26  
ERROR 0x4200256c
└─ esp_backtrace::panic_handler @ /Users/sergio/.cargo/git/checkouts/esp-backtrace-eaa21176310f5c0a/edff83c/src/lib.rs:26  
ERROR 0x42001f06
└─ esp_backtrace::panic_handler @ /Users/sergio/.cargo/git/checkouts/esp-backtrace-eaa21176310f5c0a/edff83c/src/lib.rs:26  
ERROR 0x4200132b
└─ esp_backtrace::panic_handler @ /Users/sergio/.cargo/git/checkouts/esp-backtrace-eaa21176310f5c0a/edff83c/src/lib.rs:26  
ERROR 0x420024fb
└─ esp_backtrace::panic_handler @ /Users/sergio/.cargo/git/checkouts/esp-backtrace-eaa21176310f5c0a/edff83c/src/lib.rs:26  
ERROR 0x42007df6
└─ esp_backtrace::panic_handler @ /Users/sergio/.cargo/git/checkouts/esp-backtrace-eaa21176310f5c0a/edff83c/src/lib.rs:26  
ERROR 0x40379261
└─ esp_backtrace::panic_handler @ /Users/sergio/.cargo/git/checkouts/esp-backtrace-eaa21176310f5c0a/edff83c/src/lib.rs:26  
ERROR 0x3ffffffd
└─ esp_backtrace::panic_handler @ /Users/sergio/.cargo/git/checkouts/esp-backtrace-eaa21176310f5c0a/edff83c/src/lib.rs:26  
Frame 0: syscall_readonly @ 0x420070d1 inline
       /Users/sergio/.cargo/registry/src/index.crates.io-6f17d22bba15001f/semihosting-0.1.7/src/sys/arm_compat/syscall/xtensa.rs:29:9
Frame 1: sys_exit_extended @ 0x00000000420070d1 inline
       /Users/sergio/.cargo/registry/src/index.crates.io-6f17d22bba15001f/semihosting-0.1.7/src/sys/arm_compat/mod.rs:197:9
Frame 2: exit @ 0x00000000420070c5 inline
       /Users/sergio/.cargo/registry/src/index.crates.io-6f17d22bba15001f/semihosting-0.1.7/src/sys/arm_compat/mod.rs:166:5
Frame 3: exit @ 0x00000000420070c5
       /Users/sergio/.cargo/registry/src/index.crates.io-6f17d22bba15001f/semihosting-0.1.7/src/process.rs:14:5
Frame 4: <unknown function @ 0x820070f4> @ 0x820070f4
FAILED

Originally posted by @SergioGasquez in #1412 (comment)

[SergioGasquez]

Did some investigation this morning, I couldn't find the root cause yet, but surprisingly, the following example, which is very similar to the test, works fine in S3:

//! GPIO interrupt

//% CHIPS: esp32 esp32c2 esp32c3 esp32c6 esp32h2 esp32s2 esp32s3
//% FEATURES: embassy embassy-time-timg0 embassy-executor-thread embassy-generic-timers

#![no_std]
#![no_main]

use core::cell::RefCell;

use critical_section::Mutex;
use esp_backtrace as _;
use esp_hal::{
    clock::ClockControl,
    delay::Delay,
    embassy,
    gpio::{Event, Input, PullDown, IO},
    peripherals::Peripherals,
    prelude::*,
    timer::TimerGroup,
};

static COUNTER: Mutex<RefCell<u32>> = Mutex::new(RefCell::new(0));
static INPUT_PIN: Mutex<RefCell<Option<esp_hal::gpio::Gpio2<Input<PullDown>>>>> =
    Mutex::new(RefCell::new(None));

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

    // Set GPIO2 as an output, and set its state high initially.
    let mut io = IO::new(peripherals.GPIO, peripherals.IO_MUX);
    io.set_interrupt_handler(interrupt_handler);

    let delay = Delay::new(&clocks);

    let timg0 = TimerGroup::new_async(peripherals.TIMG0, &clocks);
    embassy::init(&clocks, timg0);

    let mut io2 = io.pins.gpio2.into_pull_down_input();
    let mut io4 = io.pins.gpio4.into_push_pull_output();
    io4.set_low();

    critical_section::with(|cs| {
        *COUNTER.borrow_ref_mut(cs) = 0;
        io2.listen(Event::AnyEdge);
        INPUT_PIN.borrow_ref_mut(cs).replace(io2);
    });
    io4.set_high();
    delay.delay_millis(1);
    io4.set_low();
    delay.delay_millis(1);
    io4.set_high();
    delay.delay_millis(1);
    io4.set_low();
    delay.delay_millis(1);
    io4.set_high();
    delay.delay_millis(1);
    io4.set_low();
    delay.delay_millis(1);
    io4.set_high();
    delay.delay_millis(1);
    io4.set_low();
    delay.delay_millis(1);
    io4.set_high();
    delay.delay_millis(1);

    let count = critical_section::with(|cs| *COUNTER.borrow_ref(cs));
    assert_eq!(count, 9);
    esp_println::println!("Interrupts: {}", count);

    io2 = critical_section::with(|cs| INPUT_PIN.borrow_ref_mut(cs).take().unwrap());
    io2.unlisten();

    loop {
        delay.delay_millis(500);
    }
}

#[handler]
pub fn interrupt_handler() {
    critical_section::with(|cs| {
        use esp_hal::gpio::Pin;

        *COUNTER.borrow_ref_mut(cs) += 1;
        INPUT_PIN
            .borrow_ref_mut(cs)
            .as_mut() // we can't unwrap as the handler may get called for async operations
            .map(|pin| pin.clear_interrupt());
    });
}

[SergioGasquez]

While the following test, fails:

//! GPIO Test
//!
//! Folowing pins are used:
//! GPIO2
//! GPIO4

#![no_std]
#![no_main]

use core::cell::RefCell;

use critical_section::Mutex;
use defmt_rtt as _;
use esp_backtrace as _;
use esp_hal::{
    clock::ClockControl,
    delay::Delay,
    embassy,
    gpio::{Event, Input, PullDown, IO},
    peripherals::Peripherals,
    prelude::*,
    timer::TimerGroup,
};

static COUNTER: Mutex<RefCell<u32>> = Mutex::new(RefCell::new(0));
static INPUT_PIN: Mutex<RefCell<Option<esp_hal::gpio::Gpio2<Input<PullDown>>>>> =
    Mutex::new(RefCell::new(None));

#[cfg(test)]
#[embedded_test::tests(executor = esp_hal::embassy::executor::thread::Executor::new())]
mod tests {
    use defmt::assert_eq;

    use super::*;

    #[test]
    fn test_gpio_interrupt() {
        let peripherals = Peripherals::take();
        let system = peripherals.SYSTEM.split();
        let clocks = ClockControl::boot_defaults(system.clock_control).freeze();

        // Set GPIO2 as an output, and set its state high initially.
        let mut io = IO::new(peripherals.GPIO, peripherals.IO_MUX);
        io.set_interrupt_handler(interrupt_handler);

        let delay = Delay::new(&clocks);

        let timg0 = TimerGroup::new_async(peripherals.TIMG0, &clocks);
        embassy::init(&clocks, timg0);

        let mut io2 = io.pins.gpio2.into_pull_down_input();
        let mut io4 = io.pins.gpio4.into_push_pull_output();
        io4.set_low();

        critical_section::with(|cs| {
            *COUNTER.borrow_ref_mut(cs) = 0;
            io2.listen(Event::AnyEdge);
            INPUT_PIN.borrow_ref_mut(cs).replace(io2);
        });
        io4.set_high();
        delay.delay_millis(1);
        io4.set_low();
        delay.delay_millis(1);
        io4.set_high();
        delay.delay_millis(1);
        io4.set_low();
        delay.delay_millis(1);
        io4.set_high();
        delay.delay_millis(1);
        io4.set_low();
        delay.delay_millis(1);
        io4.set_high();
        delay.delay_millis(1);
        io4.set_low();
        delay.delay_millis(1);
        io4.set_high();
        delay.delay_millis(1);

        let count = critical_section::with(|cs| *COUNTER.borrow_ref(cs));
        assert_eq!(count, 9);

        io2 = critical_section::with(|cs| INPUT_PIN.borrow_ref_mut(cs).take().unwrap());
        io2.unlisten();
    }
}

#[handler]
pub fn interrupt_handler() {
    critical_section::with(|cs| {
        use esp_hal::gpio::Pin;

        *COUNTER.borrow_ref_mut(cs) += 1;
        INPUT_PIN
            .borrow_ref_mut(cs)
            .as_mut() // we can't unwrap as the handler may get called for async operations
            .map(|pin| pin.clear_interrupt());
    });
}

[SergioGasquez]

I've created a new branch with the test isolated and an example which does the same: https://github.com/SergioGasquez/esp-hal/tree/feat/xtensa-gpio-interrupt.
The example works fine while the test fails. Here is how to run both:

• Test: cargo xtask run-tests esp32s3 -t gpio_issue
• Example: cargo xtask run-example esp-hal esp32s3 gpio_issue

Remember to wire pin 2 and 4.

[bjoernQ]

Seems I found something. This reduced gpio.rs test seems to work for me most of the time:

//! GPIO Test
//!
//! Folowing pins are used:
//! GPIO2
//! GPIO4

#![no_std]
#![no_main]

use core::cell::RefCell;

use critical_section::Mutex;
use defmt_rtt as _;
use esp_backtrace as _;
use esp_hal::{
    clock::ClockControl,
    delay::Delay,
    embassy,
    gpio::{GpioPin, Input, Output, OutputPin, PullDown, PushPull, Unknown, IO},
    macros::handler,
    peripherals::Peripherals,
    system::SystemExt,
    timer::TimerGroup,
};

static COUNTER: Mutex<RefCell<u32>> = Mutex::new(RefCell::new(0));
static INPUT_PIN: Mutex<RefCell<Option<esp_hal::gpio::Gpio2<Input<PullDown>>>>> =
    Mutex::new(RefCell::new(None));

struct Context {
    io2: GpioPin<Input<PullDown>, 2>,
    io4: GpioPin<Output<PushPull>, 4>,
    delay: Delay,
}

impl Context {
    pub fn init() -> Self {
        let peripherals = Peripherals::take();
        let system = peripherals.SYSTEM.split();
        let clocks = ClockControl::boot_defaults(system.clock_control).freeze();

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

        let delay = Delay::new(&clocks);

        let timg0 = TimerGroup::new_async(peripherals.TIMG0, &clocks);
        embassy::init(&clocks, timg0);

        Context {
            io2: io.pins.gpio2.into_pull_down_input(),
            io4: io.pins.gpio4.into_push_pull_output(),
            delay,
        }
    }
}

#[handler(priority = esp_hal::interrupt::Priority::Priority2)]
pub fn interrupt_handler() {
    defmt::println!("interrupt");
    critical_section::with(|cs| {
        use esp_hal::gpio::Pin;

        *COUNTER.borrow_ref_mut(cs) += 1;
        INPUT_PIN
            .borrow_ref_mut(cs)
            .as_mut() // we can't unwrap as the handler may get called for async operations
            .map(|pin| pin.clear_interrupt());
    });
}

#[cfg(test)]
#[embedded_test::tests(executor = esp_hal::embassy::executor::thread::Executor::new())]
mod tests {
    use defmt::assert_eq;
    use embassy_time::{Duration, Timer};
    use esp_hal::gpio::{Event, Pin};
    use portable_atomic::{AtomicUsize, Ordering};

    use super::*;

    #[init]
    fn init() -> Context {
        unsafe {
            esp_hal::xtensa_lx::interrupt::enable_mask(
                esp_hal::xtensa_lx_rt::interrupt::CpuInterruptLevel::Level1.mask()
                    | esp_hal::xtensa_lx_rt::interrupt::CpuInterruptLevel::Level2.mask()
                    | esp_hal::xtensa_lx_rt::interrupt::CpuInterruptLevel::Level3.mask(),
            );
        }

        let mut ctx = Context::init();
        // make sure tests don't interfere with each other
        ctx.io4.set_low();
        ctx
    }

    #[test]
    fn test_gpio_interrupt(mut ctx: Context) {
        critical_section::with(|cs| {
            *COUNTER.borrow_ref_mut(cs) = 0;
            ctx.io2.listen(Event::AnyEdge);
            INPUT_PIN.borrow_ref_mut(cs).replace(ctx.io2);
        });
        ctx.io4.set_high();
        ctx.delay.delay_millis(1);
        ctx.io4.set_low();
        ctx.delay.delay_millis(1);
        ctx.io4.set_high();
        ctx.delay.delay_millis(1);
        ctx.io4.set_low();
        ctx.delay.delay_millis(1);
        ctx.io4.set_high();
        ctx.delay.delay_millis(1);
        ctx.io4.set_low();
        ctx.delay.delay_millis(1);
        ctx.io4.set_high();
        ctx.delay.delay_millis(1);
        ctx.io4.set_low();
        ctx.delay.delay_millis(1);
        ctx.io4.set_high();
        ctx.delay.delay_millis(1);

        let count = critical_section::with(|cs| *COUNTER.borrow_ref(cs));
        assert_eq!(count, 9);

        ctx.io2 = critical_section::with(|cs| INPUT_PIN.borrow_ref_mut(cs).take().unwrap());
        ctx.io2.unlisten();
    }
}

Seems like enabling the CPU interrupts was the missing piece.

Still, I wonder about a few things

• the handler priority doesn't seem to match what is needed for enable_mask always
• sometimes the counter is 10 not 9
• why don't we need it for running examples? Does embedded-test run different startup code?
• we use enable_mask here:

  esp-hal/esp-hal/src/interrupt/xtensa.rs

  Lines 344 to 346 in da3375b

  	xtensa_lx::interrupt::enable_mask(
  	xtensa_lx::interrupt::get_mask() | 1 << cpu_interrupt as u32,
  	);

  - so it shouldn't be needed to do it at all

[bjoernQ]

Ok I spend some time creating a "software-interrupts" test to see if it also runs into problems on S3 .... it does!

Next, I created a very simple example to be flashed via probe-rs (the exact version mentioned in the HIL-TEST readme).

#![no_std]
#![no_main]

use core::cell::RefCell;

use critical_section::Mutex;
use defmt_rtt as _;
use esp_backtrace as _;
use esp_hal::{
    clock::ClockControl,
    delay::Delay,
    peripherals::Peripherals,
    prelude::*,
    system::{SoftwareInterrupt, SystemControl},
};

static SWINT0: Mutex<RefCell<Option<SoftwareInterrupt<0>>>> = Mutex::new(RefCell::new(None));
static SWINT1: Mutex<RefCell<Option<SoftwareInterrupt<1>>>> = Mutex::new(RefCell::new(None));
static SWINT2: Mutex<RefCell<Option<SoftwareInterrupt<2>>>> = Mutex::new(RefCell::new(None));
static SWINT3: Mutex<RefCell<Option<SoftwareInterrupt<3>>>> = Mutex::new(RefCell::new(None));

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

    let mut sw_int = system.software_interrupt_control;
    critical_section::with(|cs| {
        sw_int
            .software_interrupt0
            .set_interrupt_handler(swint0_handler);
        SWINT0
            .borrow_ref_mut(cs)
            .replace(sw_int.software_interrupt0);

        sw_int
            .software_interrupt1
            .set_interrupt_handler(swint1_handler);
        SWINT1
            .borrow_ref_mut(cs)
            .replace(sw_int.software_interrupt1);

        sw_int
            .software_interrupt2
            .set_interrupt_handler(swint2_handler);
        SWINT2
            .borrow_ref_mut(cs)
            .replace(sw_int.software_interrupt2);

        sw_int
            .software_interrupt3
            .set_interrupt_handler(swint3_handler);
        SWINT3
            .borrow_ref_mut(cs)
            .replace(sw_int.software_interrupt3);
    });

    let delay = Delay::new(&clocks);
    let mut counter = 0;

    loop {
        delay.delay_millis(500);
        defmt::println!("Hello {}", counter);
        match counter {
            0 => critical_section::with(|cs| {
                SWINT0.borrow_ref(cs).as_ref().unwrap().raise();
            }),
            1 => critical_section::with(|cs| {
                SWINT1.borrow_ref(cs).as_ref().unwrap().raise();
            }),
            2 => critical_section::with(|cs| {
                SWINT2.borrow_ref(cs).as_ref().unwrap().raise();
            }),
            3 => {
                critical_section::with(|cs| {
                    SWINT3.borrow_ref(cs).as_ref().unwrap().raise();
                });
                counter = -1
            }
            _ => {}
        }
        counter += 1;
    }
}

#[handler]
fn swint0_handler() {
    defmt::println!("SW interrupt0");
    critical_section::with(|cs| {
        SWINT0.borrow_ref(cs).as_ref().unwrap().reset();
    });
}

#[handler]
fn swint1_handler() {
    defmt::println!("SW interrupt1");
    critical_section::with(|cs| {
        SWINT1.borrow_ref(cs).as_ref().unwrap().reset();
    });
}

#[handler]
fn swint2_handler() {
    defmt::println!("SW interrupt2");
    critical_section::with(|cs| {
        SWINT2.borrow_ref(cs).as_ref().unwrap().reset();
    });
}

#[handler]
fn swint3_handler() {
    defmt::println!("SW interrupt3");
    critical_section::with(|cs| {
        SWINT3.borrow_ref(cs).as_ref().unwrap().reset();
    });
}

I built it via cargo build --release and run it via probe-rs probe-rs run --chip=esp32s3 target\xtensa-esp32s3-none-elf\release\s3test

The result is surprising:

<lvl> Hello 0
└─ s3test::__xtensa_lx_rt_main @ src\main.rs:64
<lvl> SW interrupt0
└─ s3test::__esp_hal_internal_swint0_handler @ src\main.rs:89
<lvl> Hello 1
└─ s3test::__xtensa_lx_rt_main @ src\main.rs:64
<lvl> SW interrupt1
└─ s3test::__esp_hal_internal_swint1_handler @ src\main.rs:97
<lvl> Hello 2
└─ s3test::__xtensa_lx_rt_main @ src\main.rs:64
<lvl> SW interrupt2
└─ s3test::__esp_hal_internal_swint2_handler @ src\main.rs:105
<lvl> Hello 3
└─ s3test::__xtensa_lx_rt_main @ src\main.rs:64
<lvl> Hello 0
└─ s3test::__xtensa_lx_rt_main @ src\main.rs:64
<lvl> Hello 1
└─ s3test::__xtensa_lx_rt_main @ src\main.rs:64
<lvl> Hello 2
└─ s3test::__xtensa_lx_rt_main @ src\main.rs:64
<lvl> Hello 3
└─ s3test::__xtensa_lx_rt_main @ src\main.rs:64
<lvl> Hello 0
└─ s3test::__xtensa_lx_rt_main @ src\main.rs:64
<lvl> Hello 1
└─ s3test::__xtensa_lx_rt_main @ src\main.rs:64
<lvl> Hello 2
└─ s3test::__xtensa_lx_rt_main @ src\main.rs:64
<lvl> Hello 3
└─ s3test::__xtensa_lx_rt_main @ src\main.rs:64
<lvl> Hello 0
└─ s3test::__xtensa_lx_rt_main @ src\main.rs:64
<lvl> Hello 1
└─ s3test::__xtensa_lx_rt_main @ src\main.rs:64
<lvl> Hello 2
└─ s3test::__xtensa_lx_rt_main @ src\main.rs:64
<lvl> Hello 3
└─ s3test::__xtensa_lx_rt_main @ src\main.rs:64
<lvl> Hello 0
└─ s3test::__xtensa_lx_rt_main @ src\main.rs:64
<lvl> Hello 1
└─ s3test::__xtensa_lx_rt_main @ src\main.rs:64
<lvl> Hello 2
└─ s3test::__xtensa_lx_rt_main @ src\main.rs:64
<lvl> Hello 3
└─ s3test::__xtensa_lx_rt_main @ src\main.rs:64
<lvl> Hello 0
└─ s3test::__xtensa_lx_rt_main @ src\main.rs:64
<lvl> Hello 1
└─ s3test::__xtensa_lx_rt_main @ src\main.rs:64
<lvl> Hello 2
└─ s3test::__xtensa_lx_rt_main @ src\main.rs:64
<lvl> Hello 3
└─ s3test::__xtensa_lx_rt_main @ src\main.rs:64
<lvl> Hello 0
└─ s3test::__xtensa_lx_rt_main @ src\main.rs:64
<lvl> Hello 1
└─ s3test::__xtensa_lx_rt_main @ src\main.rs:64

Most of the time I cannot get any interrupt to trigger ... this was probably the best I could get.

[bjoernQ]

BTW on C6 everything works as expected!

[bjoernQ]

Adding code to blink an LED in the ISR shows it works when probe-rs is not attached - when it attaches the interrupts immediately stop working