panic when using PinDriver.wait_for_low

[benhansen-io]

Bug description

panic when using PinDriver.wait_for_low (or wait_for_high) and allocating in near by code.

Looking at the code it appears I need to use a special waker? If so it should be documented (or I missed it)

Stack trace of PinDriver panic:

2025-01-06 07:27:46 0x403836c5: esp_system_abort at /home/ben/esp/esp-idf/components/esp_system/port/esp_system_chip.c:84
2025-01-06 07:27:46 0x4038b282: abort at /home/ben/esp/esp-idf/components/newlib/abort.c:38
2025-01-06 07:27:46 0x40377dbf: lock_acquire_generic at /home/ben/esp/esp-idf/components/newlib/locks.c:130
2025-01-06 07:27:46 0x40377efd: _lock_acquire_recursive at /home/ben/esp/esp-idf/components/newlib/locks.c:158
2025-01-06 07:27:46 0x420032c5: pthread_cond_signal at /home/ben/esp/esp-idf/components/pthread/pthread_cond_var.c:62
2025-01-06 07:27:46 0x4207c27f: parking::Inner::unpark at ??:?
2025-01-06 07:27:46 0x4207881b: alloc::task::raw_waker::wake at ??:?
2025-01-06 07:27:46 0x42083939: async_task::raw::RawTask<F,T,S,M>::wake at rust_ten_buttons.677112ee0055f3d8-cgu.00:?
2025-01-06 07:27:46 0x4200aaa4: esp_idf_hal::gpio::PinDriver<T,MODE>::handle_isr at ??:?
2025-01-06 07:27:46 0x4037bf31: gpio_isr_loop at /home/ben/esp/esp-idf/components/driver/gpio/gpio.c:463
2025-01-06 07:27:46 0x4037bfa6: gpio_intr_service at /home/ben/esp/esp-idf/components/driver/gpio/gpio.c:485
2025-01-06 07:27:46 0x40377c51: _xt_medint2 at /home/ben/esp/esp-idf/components/freertos/FreeRTOS-Kernel/portable/xtensa/xtensa_vectors.S:1329
2025-01-06 07:27:46 0x40380653: xt_utils_wait_for_intr at /home/ben/esp/esp-idf/components/xtensa/include/xt_utils.h:81
2025-01-06 07:27:46  (inlined by) esp_cpu_wait_for_intr at /home/ben/esp/esp-idf/components/esp_hw_support/cpu.c:111
2025-01-06 07:27:46 0x42004dca: esp_vApplicationIdleHook at /home/ben/esp/esp-idf/components/esp_system/freertos_hooks.c:59
2025-01-06 07:27:46 0x403849d1: prvIdleTask at /home/ben/esp/esp-idf/components/freertos/FreeRTOS-Kernel/tasks.c:4327 (discriminator 1)
2025-01-06 07:27:46 0x40386261: vPortTaskWrapper at /home/ben/esp/esp-idf/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:162

Another stack trace that occurs less frequently that might be helpful.

2025-01-06 07:32:48 Backtrace: 0x40375ee2:0x3fca17e0 0x403836c5:0x3fca1800 0x4038b282:0x3fca1820 0x40377dbf:0x3fca1890 0x40377efd:0x3fca18c0 0x4200328d:0x3fca18e0 0x4207a033:0x3fca1900 0x420765cf:0x3fca1930 0x420816ed:0x3fca1960 0x4200aa6c:0x3fca19d0 0x4037bf31:0x3fca19f0 0x4037bfa6:0x3fca1a10 0x40377c51:0x3fca1a30 0x40376945:0x3fceda60 0x40376983:0x3fceda80 0x40376dd0:0x3fcedaa0 0x4213d83f:0x3fcedac0 0x4213d9e0:0x3fcedae0 0x4213e7e9:0x3fcedb00 0x4206c7e6:0x3fcedb40 0x4200e7c6:0x3fcedb80 0x42087272:0x3fcedbc0 0x4201074f:0x3fcedc20 0x42011390:0x3fcedd30 0x42011a4c:0x3fcedd50 0x4202551f:0x3fcedd80 0x42003068:0x3fcedda0 0x40386261:0x3fceddc0
--- 2025-01-06 07:32:48 0x40375ee2: panic_abort at /home/ben/esp/esp-idf/components/esp_system/panic.c:452
2025-01-06 07:32:48 0x403836c5: esp_system_abort at /home/ben/esp/esp-idf/components/esp_system/port/esp_system_chip.c:84
2025-01-06 07:32:48 0x4038b282: abort at /home/ben/esp/esp-idf/components/newlib/abort.c:38
2025-01-06 07:32:48 0x40377dbf: lock_acquire_generic at /home/ben/esp/esp-idf/components/newlib/locks.c:130
2025-01-06 07:32:48 0x40377efd: _lock_acquire_recursive at /home/ben/esp/esp-idf/components/newlib/locks.c:158
2025-01-06 07:32:48 0x4200328d: pthread_cond_signal at /home/ben/esp/esp-idf/components/pthread/pthread_cond_var.c:62
2025-01-06 07:32:48 0x4207a033: parking::Inner::unpark at ??:?
2025-01-06 07:32:48 0x420765cf: alloc::task::raw_waker::wake at ??:?
2025-01-06 07:32:48 0x420816ed: async_task::raw::RawTask<F,T,S,M>::wake at rust_ten_buttons.677112ee0055f3d8-cgu.00:?
2025-01-06 07:32:48 0x4200aa6c: esp_idf_hal::gpio::PinDriver<T,MODE>::handle_isr at ??:?
2025-01-06 07:32:48 0x4037bf31: gpio_isr_loop at /home/ben/esp/esp-idf/components/driver/gpio/gpio.c:463
2025-01-06 07:32:48 0x4037bfa6: gpio_intr_service at /home/ben/esp/esp-idf/components/driver/gpio/gpio.c:485
2025-01-06 07:32:48 0x40377c51: _xt_medint2 at /home/ben/esp/esp-idf/components/freertos/FreeRTOS-Kernel/portable/xtensa/xtensa_vectors.S:1329
2025-01-06 07:32:48 0x40376945: heap_caps_malloc_base at /home/ben/esp/esp-idf/components/heap/heap_caps.c:172
2025-01-06 07:32:48 0x40376983: heap_caps_calloc_base at /home/ben/esp/esp-idf/components/heap/heap_caps.c:497
2025-01-06 07:32:48 0x40376dd0: heap_caps_calloc at /home/ben/esp/esp-idf/components/heap/heap_caps.c:506
2025-01-06 07:32:48 0x4213d83f: i2c_cmd_allocate at /home/ben/esp/esp-idf/components/driver/i2c/i2c.c:1188
2025-01-06 07:32:48 0x4213d9e0: i2c_cmd_link_append at /home/ben/esp/esp-idf/components/driver/i2c/i2c.c:1224
2025-01-06 07:32:48 0x4213e7e9: i2c_master_start at /home/ben/esp/esp-idf/components/driver/i2c/i2c.c:1241 (discriminator 2)
2025-01-06 07:32:48 0x4206c7e6: esp_idf_hal::i2c::I2cDriver::transaction at ??:?
2025-01-06 07:32:48 0x4200e7c6: <rust_ten_buttons::mutexed_i2c::MutexedI2c as embedded_hal::i2c::I2c>::transaction at ??:?
2025-01-06 07:32:48 0x42087272: mfrc522::Mfrc522<COMM,mfrc522::Initialized>::reqa at ??:?
2025-01-06 07:32:48 0x4201074f: rust_ten_buttons::rfid::rfid_listening_thread at ??:?
2025-01-06 07:32:48 0x42011390: std::sys_common::backtrace::__rust_begin_short_backtrace at rust_ten_buttons.677112ee0055f3d8-cgu.15:?
2025-01-06 07:32:48 0x42011a4c: core::ops::function::FnOnce::call_once{{vtable.shim}} at rust_ten_buttons.677112ee0055f3d8-cgu.15:?
2025-01-06 07:32:48 0x4202551f: std::sys::pal::unix::thread::Thread::new::thread_start at ??:?
2025-01-06 07:32:48 0x42003068: pthread_task_func at /home/ben/esp/esp-idf/components/pthread/pthread.c:196 (discriminator 15)
2025-01-06 07:32:48 0x40386261: vPortTaskWrapper at /home/ben/esp/esp-idf/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:162

• Would you like to work on a fix?

I can allocate a couple of hours to fix if the best fix is clear and reasonably straight forward.

To Reproduce

pub async fn monitor_irq(self, gpio: gpio::AnyIOPin) -> Result<(), EspError> {
    let mut pin = gpio::PinDriver::input(gpio)?;
    pin.set_pull(gpio::Pull::Up).unwrap();

    loop {
        pin.wait_for_low().await.unwrap();
        info!("AXP IRQ now low");

       // Application specific code that grabs a Mutex on an I2C peripheral and clears the status flags of the chip.


        pin.wait_for_high().await.unwrap();
        info!("AXP IRQ now high");
    }
}

Expected behavior

I should be able to await the state change without a panic.

Environment

• esp-idf-hal v0.45
• ESP-IDF: v5.1.2
• esp32s3
• Arch Linux

[ivmarkov]

These two lines look super-weird:

2025-01-06 07:27:46 0x42083939: async_task::raw::RawTask<F,T,S,M>::wake at rust_ten_buttons.677112ee0055f3d8-cgu.00:?
2025-01-06 07:27:46 0x4200aaa4: esp_idf_hal::gpio::PinDriver<T,MODE>::handle_isr at ??:?

... because it seems as if Waker::wake is called directly from an ISR context.
Did you - by any chance - enable the wake-from-isr feature?
It has a note "Only enable if you plan to use the edge-executor crate"

wake-from-isr is not what esp-idf-hal does by default, as it is dangerous and should only be used with async executors which are compatible with the wake-from-isr pattern (like edge-executor). One should only do that in very few niche cases where the lowest possible latency is absolutely necessary and the standard, safe pattern used by esp-idf-hal with ISRs (the ISR notifies a hidden high-prio thread/task which then calls Waker::wake so that you don't end up calling arbitrary async executor code from an ISR context which is very unsafe) is not giving you low enough latency.

But given that you seem to be modeling a button with the GPIO subsystem a "data ready" signal from the slow i2c system, I don't think you need very low latency anyway, so perhaps disable the wake-from-isr feature?

[benhansen-io]

Thanks for the help! Yes I did have wake-from-isr enabled, I must have enabled it a while ago when I started using edge-executor looking at another project. Removing it fixed the issue. Thanks again.