Critical section causes unexpected behaviour in `--release` mode about avr-hal

[Patryk27]

Status: got it! -- llvm/llvm-project#85277

Once the fix is merged to LLVM, I should be able to push it to rustc within a couple of days.

[Patryk27]

Minimized:

#![no_std]
#![no_main]

use avr_device::interrupt;
use panic_halt as _;

#[arduino_hal::entry]
fn main() -> ! {
    let dp = arduino_hal::Peripherals::take().unwrap();
    let pins = arduino_hal::pins!(dp);
    let mut serial = arduino_hal::default_serial!(dp, pins, 57600);

    unsafe {
        interrupt::enable();
    }

    let irq = interrupt::disable_save();
    let counter = core::hint::black_box(123u64);

    _ = ufmt::uwriteln!(serial, "{}", counter);

    if irq.enabled() {
        _ = ufmt::uwriteln!(serial, "irq? 1");
    } else {
        _ = ufmt::uwriteln!(serial, "irq? 0");
    }

    loop {
        //
    }
}

As it is, it prints irq? 0 (which is wrong), but changing 123u64 to 123u32 brings back irq? 1, so it looks like the registers get mixed up somewhere, investigating 🔍

[Patryk27]

Alright, this one seems to be a proper bug in the LLVM codegen (i.e. doesn't seem to be related to the __udivdi3 etc. intrinsics this time 😄).

Minimized even more (by inlining stuff done by uwriteln!() etc.) - prints D, while it should print E:

#![no_std]
#![no_main]

use avr_device::interrupt;
use panic_halt as _;

#[arduino_hal::entry]
fn main() -> ! {
    unsafe {
        interrupt::enable();
    }

    let irq = interrupt::disable_save();
    let counter = core::hint::black_box(12u64); // at least a two-digit number is required to trigger the bug

    let mut buf = [0; 3];

    core::hint::black_box(fmt_num(&mut buf, counter));

    if irq.enabled() {
        report_irq_enabled();
    } else {
        report_irq_disabled();
    }

    loop {
        //
    }
}

fn fmt_num(buf: &mut [u8], mut n: u64) -> &[u8] { // corresponds to uxx!() from ufmt
    let mut i = 0;

    loop {
        unsafe {
            *buf.get_unchecked_mut(i) = (n % 10) as u8;
        }

        n /= 10;

        if n == 0 {
            break;
        } else {
            i += 1;
        }
    }

    if i > 2 { // branch not taken, but required for the bug to occur
        panic!("ayy");
    }

    buf
}

// separated from `main()` to make following the assembly easier
#[inline(never)]
fn report_irq_enabled() {
    let dp = arduino_hal::Peripherals::take().unwrap();
    let pins = arduino_hal::pins!(dp);
    let mut serial = arduino_hal::default_serial!(dp, pins, 57600);

    serial.write_byte(b'E');
    serial.write_byte(b'\n');
}

// ditto
#[inline(never)]
fn report_irq_disabled() {
    let dp = arduino_hal::Peripherals::take().unwrap();
    let pins = arduino_hal::pins!(dp);
    let mut serial = arduino_hal::default_serial!(dp, pins, 57600);

    serial.write_byte(b'D');
    serial.write_byte(b'\n');
}

If we inspect the assembly (e.g. by running avr-objdump or gdb on the *.elf file), we'll see four important places:

 202: 78 94        sei           // `interrupt::enable()`
 204: 8f b7        in r24, 0x3f  // `interrupt::disable_save()`, remembering previous irq state into `r24`
 206: 89 83        std Y+1, r24  // saves `irq` into memory, at address Y+1
 
 /* ... a couple of register-heavy calculations ...
   (hence `irq` gets moved from registers into the memory before) */

 26e: 49 81        ldd r20, Y+1  // loads `irq` back from the memory into register r20

 /* ... some other calculations, taken when the `loop` inside `fmt_num()`
        does a *second* round (or third, fourth etc.): */
 
 29a: 19 01        movw r2, r18
 29c: a4 01        movw r20, r8  // whoops, this clobbers r20!
 29e: b3 01        movw r22, r6

 /* ... back in `main()`, after `fmt_num()` completes:
    
    `if irq.enabled()`, checked assuming that `irq` is stored inside `r20`, but
    if the `loop` inside `fmt_num()` does a second round, it will clobber `r20`,
    making this check invalid! */

 312: 44 23        and r20, r20
 314: 1a f0        brmi .+6
 316: 0e 94 9c 00  call 0x138 ; `report_irq_disabled();`
 31a: 02 c0        rjmp .+4
 31c: 0e 94 53 00  call 0xa6 ; `report_irq_enabled();`
 320: ff cf        rjmp .-2

Tracking further 🔍

[Patryk27]

fyi, toolchain's already fixed (compiling with nightly-2024-03-22 produces a correct binary) 🙂

[gregoryholder]

Update: I was running cargo run --release (out of habit), running without the --release flag seems to fix it. Still strange...

[gregoryholder]

I've found a workaround by adding #[inline(never)] which works with the release build, as it seems the critical section closure gets optimized away into something else...

avr_device::interrupt::free(
    #[inline(never)]
    |_| {
        ufmt::uwriteln!(
            serial,
            "Counter: {}, interrupts enabled: {}",
            counter,
            int_en
        )
        .unwrap_infallible();
    },
);

[gregoryholder]

I'm suspecting this is a compilation / linker issue rather than crate-level issue.
If I change

[profile.release]
panic = "abort"
codegen-units = 1
debug = true
lto = true
opt-level = "s"

to

[profile.release]
panic = "abort"
codegen-units = 2 # anything > 1
debug = true
opt-level = "s"

my example works again.

Similarly, if I enable either overflow-checks or debug-assertions, it also works:

[profile.release]
panic = "abort"
codegen-units = 1
debug = true
lto = true
opt-level = "s"
overflow-checks = true  # enable either one (or both)
debug-assertions = true # enable either one (or both)

[Rahix]

Paging @Patryk27, maybe you know something here?

Otherwise we'll need to look at the generated assembly to find out where this is falling apart. My first guess would be that some u64 intrinsics are not working correctly...

[Patryk27]

Judging by the behavior, this does look like a codegen bug, but I don't recall anything that could cause it (in this case the intrinsics should be fine, but always worth to take a look there, considering the history 😄) - I'll also try to take a look during the week.

[Rahix]

Nice, then it's time to bump the compiler version again :)