defmt icon indicating copy to clipboard operation
defmt copied to clipboard

missing location info in backtrace frame when using `defmt::unwrap!`

Open japaric opened this issue 3 years ago • 4 comments

STR

Start from the app-template (defmt v0.2.0) and modify src/bin/hello.rs:

fn main() -> ! {
    defmt::unwrap!(cortex_m::Peripherals::take());
    defmt::unwrap!(cortex_m::Peripherals::take());

    app::exit()
}
$ cargo add cortex-m # 0.7.1
$ cargo rb hello
       0 ERROR panicked at 'unwrap failed: cortex_m :: Peripherals :: take()'
error: `Unwrap of a None option value`
└─ hello::__cortex_m_rt_main @ src/bin/hello.rs:9
stack backtrace:
   0: HardFaultTrampoline
      <exception entry>
   1: lib::inline::__udf
        at ./asm/inline.rs:171
   2: __udf
        at ./asm/lib.rs:49
   3: cortex_m::asm::udf
        at $REGISTRY/cortex-m-0.7.1/src/asm.rs:43
   4: _defmt_panic
        at src/lib.rs:14
   5: defmt::export::panic
        at $REGISTRY/defmt-0.2.0/src/export.rs:233
   6: hello::__cortex_m_rt_main
   7: main
        at src/bin/hello.rs:6
   8: ResetTrampoline
        at $REGISTRY/cortex-m-rt-0.6.13/src/lib.rs:547
   9: Reset
        at $REGISTRY/cortex-m-rt-0.6.13/src/lib.rs:550

Frame 6 is missing the location information.


In this other version of the program that frame does contain location info:

fn main() -> ! {
    defmt::unwrap!(None::<()>);

    app::exit()
}
$ cargo rb hello
       0 ERROR panicked at 'unwrap failed: None :: < () >'
error: `Unwrap of a None option value`
└─ hello::__cortex_m_rt_main @ src/bin/hello.rs:8
stack backtrace:
   0: HardFaultTrampoline
      <exception entry>
   1: lib::inline::__udf
        at ./asm/inline.rs:171
   2: __udf
        at ./asm/lib.rs:49
   3: cortex_m::asm::udf
        at $REGISTRY/cortex-m-0.7.1/src/asm.rs:43
   4: _defmt_panic
        at src/lib.rs:14
   5: defmt::export::panic
        at $REGISTRY/defmt-0.2.0/src/export.rs:233
   6: hello::__cortex_m_rt_main
        at src/bin/hello.rs:8
   7: main
        at src/bin/hello.rs:6
   8: ResetTrampoline
        at $REGISTRY/cortex-m-rt-0.6.13/src/lib.rs:547
   9: Reset
        at $REGISTRY/cortex-m-rt-0.6.13/src/lib.rs:550

japaric avatar Mar 04 '21 15:03 japaric

if I revert the dev profile to its defaults settings I do get full location info in the backtrace of the first program

       0 ERROR panicked at 'unwrap failed: cortex_m :: Peripherals :: take()'
error: `Unwrap of a None option value`
└─ hello::__cortex_m_rt_main @ src/bin/hello.rs:9
stack backtrace:
   0: HardFaultTrampoline
      <exception entry>
   1: lib::inline::__udf
        at ./asm/inline.rs:171
   2: __udf
        at ./asm/lib.rs:49
   3: cortex_m::asm::udf
        at $REGISTRY/cortex-m-0.7.1/src/asm.rs:43
   4: _defmt_panic
        at src/lib.rs:14
   5: defmt::export::panic
        at $REGISTRY/defmt-0.2.0/src/export.rs:233
   6: hello::__cortex_m_rt_main
        at src/bin/hello.rs:9
   7: main
        at src/bin/hello.rs:6
   8: ResetTrampoline
        at $REGISTRY/cortex-m-rt-0.6.13/src/lib.rs:547
   9: Reset
        at $REGISTRY/cortex-m-rt-0.6.13/src/lib.rs:550

japaric avatar Mar 04 '21 15:03 japaric

This is a problem with the opt-level, which is currently set to 3, which is the highest optimization. Lowering it to 1 fixes this bug, but I am not sure if it is desirable, since it also means we loose optimizations.

I will investigate why it does show the location info for the second example, but not the first.

Urhengulas avatar Dec 13 '21 12:12 Urhengulas

I've copied the implementation of cortex_m::Peripherals::take() to hello.rs, which resulted in the same behavior of not showing the location info. Next I reduced it as much as possible, but that it still doesn't show the location info, in order to find out what causes this behavior. This resulted in following code:

#![no_main]
#![no_std]

use krate as _; // global logger + panicking-behavior + memory layout

#[cortex_m_rt::entry]
fn main() -> ! {
    defmt::unwrap!(take());
    defmt::unwrap!(take());

    krate::exit();
}

static mut TAKEN: bool = false;

pub fn take() -> Option<()> {
    if unsafe { TAKEN } {
        None
    } else {
        unsafe { TAKEN = true };
        Some(())
    }
}
ERROR panicked at 'unwrap failed: take()'
error: `Unwrap of a None option value`
└─ hello::__cortex_m_rt_main @ src/bin/hello.rs:9
───────────────────────────────────────────────────────────
stack backtrace:
   0: HardFaultTrampoline
      <exception entry>
   1: lib::inline::__udf
        at ./asm/inline.rs:172:5
   2: __udf
        at ./asm/lib.rs:49:17
   3: cortex_m::asm::udf
        at $REGISTRY/cortex-m-0.7.3/src/asm.rs:43:5
   4: _defmt_panic
        at src/lib.rs:11:5
   5: hello::__cortex_m_rt_main
   6: main
        at src/bin/hello.rs:6:1
   7: Reset
(HOST) ERROR the program panicked

Observations

Meta

  • The desired location info is shown just below the error message in any scenario
    ERROR panicked at 'unwrap failed: take()'
    error: `Unwrap of a None option value`
    └─ hello::__cortex_m_rt_main @ src/bin/hello.rs:9
                                   ^^^^^^^^^^^^^^^^^^
                                   this location info
    

Things that do not make the location

  • changing the return type to Result<(), ()>

Things that make the location appearappear

  • making the function return None first
    pub fn take() -> Option<()> {
        if unsafe { TAKEN } {
            None
        } else {
            unsafe { TAKEN = true };
            None
        }
    }
    
  • replacing the static mut TAKEN: bool = false, with a &mut bool
    #[cortex_m_rt::entry]
    fn main() -> ! {
        let mut taken = false;
        defmt::unwrap!(take(&mut taken));
        defmt::unwrap!(take(&mut taken));
    
        krate::exit();
    }
    
    pub fn take(taken: &mut bool) -> Option<()> {
        if *taken {
            None
        } else {
            *taken = true;
            Some(())
        }
    }
    

Urhengulas avatar Dec 14 '21 16:12 Urhengulas

I've copied the implementation of cortex_m::Peripherals::take() to hello.rs

your version is going to be optimized quite differently because it does not contain a compiler barrier (+) so the compiler (or rather llvm) can re-order memory operations (I don't think that would happen in this case) or const-eval the logic and eliminate the static variable (this is more likely).

(+) core::atomic::compiler_fence(), a FFI call and the new asm! all behave like compiler barriers and interrupt::free uses one of those (depending on Cargo features)


in backtraces, locations are computed by the addr2line dependency. it could be that the PC (program counter) address we pass to it (after doing unwinding in probe-run) is wrong (thumb bit (bit 0) may need to be clear or set in that address). it could also be that __cortex_m_rt_main symbol is missing debug info or has the wrong address stored in the ELF though this pretty much only happens with symbols whose source is assembly rather than Rust.

I would suggest logging the PC address probe-run passes to addr2line for each frame and then manually using (separate program) addr2line on those PC addresses to see if addr2line can compute the location or not, and under what condition. You do need good and bad ELFs for this, as addr2line needs to read some metadata stored in the ELF file -- see how probe-run uses the library.


Meta The desired location info is shown just below the error message in any scenario

This is computed using a different code path. probe-run reads the DWARF info to get this location; the location is associated to static variable that the unwrap! expands to. addr2line does something different because it works with PC addresses though it also uses, likely different, DWARF info to do that.

japaric avatar Dec 15 '21 10:12 japaric