False positive "call stack was corrupted" warning on 0.3

[jonas-schievink]

Describe the bug
I'm seeing a (HOST) WARN call stack was corrupted; unwinding could not be completed, even though unwinding seems to have worked fine and nothing happened that could have corrupted the stack.

To Reproduce
Steps to reproduce the behavior:

• Check out Add support for defmt 0.3 stm32-rs/bxcan#47
• cd testsuite; cargo test

Expected and observed behavior

Actual output:

    Finished test [unoptimized + debuginfo] target(s) in 0.01s
     Running tests/integration.rs (/home/jonas/dev/bxcan/target/thumbv7m-none-eabi/debug/deps/integration-7c7caa16bcb9d813)
(HOST) INFO  flashing program (16.20 KiB)
(HOST) INFO  success!
────────────────────────────────────────────────────────────────────────────────
(1/11) running `split_filters`...
└─ integration::tests::__defmt_test_entry @ tests/integration.rs:18
(2/11) running `basic_roundtrip`...
└─ integration::tests::__defmt_test_entry @ tests/integration.rs:43
(3/11) running `no_filters_no_frames`...
└─ integration::tests::__defmt_test_entry @ tests/integration.rs:58
(4/11) running `filter_mask32_std`...
└─ integration::tests::__defmt_test_entry @ tests/integration.rs:68
(5/11) running `filter_mask32_ext`...
└─ integration::tests::__defmt_test_entry @ tests/integration.rs:112
(6/11) running `filter_mask16`...
└─ integration::tests::__defmt_test_entry @ tests/integration.rs:153
(7/11) running `filter_list32_std`...
└─ integration::tests::__defmt_test_entry @ tests/integration.rs:193
(8/11) running `filter_list32_ext`...
└─ integration::tests::__defmt_test_entry @ tests/integration.rs:226
(9/11) running `dequeue_lower_priority_frame`...
└─ integration::tests::__defmt_test_entry @ tests/integration.rs:264
(10/11) running `enable_non_blocking`...
└─ integration::tests::__defmt_test_entry @ tests/integration.rs:317
(11/11) running `ext_roundtrip`...
└─ integration::tests::__defmt_test_entry @ tests/integration.rs:330
all tests passed!
└─ integration::tests::__defmt_test_entry @ tests/integration.rs:4
────────────────────────────────────────────────────────────────────────────────
stack backtrace:
   0: _ZN3lib6inline6__bkpt17h78c2a3232bb722b9E
        at ./asm/inline.rs:13:5
   1: __bkpt
        at ./asm/lib.rs:49:17
   2: _ZN10defmt_test6export4exit17h45e5ec6423f16273E
        at /home/jonas/.cargo/registry/src/github.com-1ecc6299db9ec823/defmt-test-0.3.0/src/export.rs:8:9
   3: main
        at tests/integration.rs:4:1
   4: Reset
(HOST) WARN  call stack was corrupted; unwinding could not be completed
(HOST) INFO  device halted without error
     Running tests/interrupts.rs (/home/jonas/dev/bxcan/target/thumbv7m-none-eabi/debug/deps/interrupts-fc17b8c8f4ece88b)
(HOST) INFO  flashing program (19.87 KiB)
(HOST) INFO  success!
────────────────────────────────────────────────────────────────────────────────
(1/6) running `tx_interrupt`...
└─ interrupts::tests::__defmt_test_entry @ tests/interrupts.rs:37
(2/6) running `rx_interrupt_message_pending`...
└─ interrupts::tests::__defmt_test_entry @ tests/interrupts.rs:71
(3/6) running `rx_interrupt_fifo_full`...
└─ interrupts::tests::__defmt_test_entry @ tests/interrupts.rs:105
(4/6) running `rx_interrupt_fifo_overrun`...
└─ interrupts::tests::__defmt_test_entry @ tests/interrupts.rs:145
(5/6) running `sce_interrupt_sleep`...
└─ interrupts::tests::__defmt_test_entry @ tests/interrupts.rs:195
(6/6) running `sce_interrupt_wakeup`...
└─ interrupts::tests::__defmt_test_entry @ tests/interrupts.rs:219
all tests passed!
└─ interrupts::tests::__defmt_test_entry @ tests/interrupts.rs:4
────────────────────────────────────────────────────────────────────────────────
stack backtrace:
   0: _ZN3lib6inline6__bkpt17h78c2a3232bb722b9E
        at ./asm/inline.rs:13:5
   1: __bkpt
        at ./asm/lib.rs:49:17
   2: _ZN10defmt_test6export4exit17h45e5ec6423f16273E
        at /home/jonas/.cargo/registry/src/github.com-1ecc6299db9ec823/defmt-test-0.3.0/src/export.rs:8:9
   3: main
        at tests/interrupts.rs:4:1
   4: Reset
(HOST) WARN  call stack was corrupted; unwinding could not be completed
(HOST) INFO  device halted without error

Expected output: the same, but without the warning.

[newAM]

I am also seeing this in the stm32wlxx-hal testsuite: https://github.com/stm32-rs/stm32wlxx-hal/runs/4208369937?check_suite_focus=true#step:6:33

I saw this infrequently with defmt 0.2 (difficult to reproduce, so I didn't file a bug report), but now it occurs every time with 0.3.

[jamesmunns]

I'm also hitting this on every run, along with #201.

james@archx1c6g-ovar ➜  emb-playground git:(main) ✗ DEFMT_LOG=info cargo rrb forth
   Compiling emb-playground v0.1.0 (/home/james/anachro/forth/emb-playground)
    Finished release [optimized + debuginfo] target(s) in 1.45s
     Running `probe-run --chip nRF52840_xxAA target/thumbv7em-none-eabihf/release/forth`
(HOST) INFO  flashing program (17.36 KiB)
(HOST) INFO  success!
────────────────────────────────────────────────────────────────────────────────
INFO  Hello!
└─ forth::__cortex_m_rt_main @ src/bin/forth.rs:11
INFO  lol: 10781266
└─ forth::__cortex_m_rt_main @ src/bin/forth.rs:30
────────────────────────────────────────────────────────────────────────────────
stack backtrace:
   0: _ZN3lib6inline6__bkpt17h78c2a3232bb722b9E
        at ./asm/inline.rs:13:5
   1: __bkpt
        at ./asm/lib.rs:49:17
   2: _ZN14emb_playground4exit17h99c2b316dcb70511E
        at src/lib.rs:18:5
   3: _ZN5forth18__cortex_m_rt_main17h8a5fd1dcc9faec7bE
        at src/bin/forth.rs:32:5
   4: main
        at src/bin/forth.rs:9:1
   5: Reset
(HOST) WARN  call stack was corrupted; unwinding could not be completed
(HOST) INFO  device halted without error

Running this application, with cargo rrb forth

[jonathanpallant]

A fix for this issue has gone into cortex-m-rt, but you won't see it until a) there's a new release (likely 0.7.1) or b) add a patch to Cargo.toml to use the git version.

[jonathanpallant]

https://crates.io/crates/cortex-m-rt/0.7.1 is now out.