probe-run

probe-run copied to clipboard

Hi Guys!

I am attempting to use probe-run to run my application on top of a custom bootloader.. It flashes successfully, and the application boots as expected. I don't expect to have defmt logging from both the bootloader and the application at the same time, as they are two different ELF files.

Looking at my application, i can verify that it looks to be built correctly:

➜  release git:(master) ✗ arm-none-eabi-nm -CSn output | head -n 30                                                                                                                                                                                                                                        [20/08/26|8:45:41]
00000000 00000001 N {:u32}
00000001 N _defmt_error_start
00000001 A "_defmt_version_ = 5a1047ba740398184fbe26b58fe504c0b918c6bb"
00000001 00000001 N panicked at {:str}:{:u32}:{:u32}
00000002 00000001 N Network init
00000003 00000001 N Failed to obtain time!
00000004 00000001 N Failed to obtain time!
00000005 00000001 N Abort error
00000006 00000001 N Failed to obtain ntp time!
00000007 00000001 N Buffer too small!!!
00000008 N _defmt_error_end
00000008 N _defmt_warn_start
00000008 00000001 N OTA Job removed!
00000009 00000001 N @#25 bytes(5709..5726)
00000009 N _defmt_info_start
00000009 N _defmt_warn_end
0000000a 00000001 N Copyright Mathias Koch 2020
0000000b 00000001 N Network initialized!
0000000c 00000001 N Time delta: {:?} ms
0000000d 00000001 N Re-attaching!
0000000e 00000001 N Re-registering & attaching!
0000000f N _defmt_debug_end
0000000f N _defmt_debug_start
0000000f N _defmt_info_end
0000000f N _defmt_trace_end
0000000f N _defmt_trace_start
08004404 00000004 R __RESET_VECTOR
08004408 00000038 R __EXCEPTIONS
08004408 R __reset_vector
08004440 R __eexceptions
...

And running RUST_LOG=info probe-run --chip STM32L475VGTx --defmt output flashes the device and ends up with:

[2020-08-26T06:42:31Z INFO  probe_run] flashed program
[2020-08-26T06:42:31Z INFO  probe_run] attached to core
DONE
resetting device
[2020-08-26T06:42:31Z INFO  probe_run] Could not attach because the target's RTT control block isn't initialized (yet). retrying
[2020-08-26T06:42:31Z INFO  probe_run] Successfully attached RTT

Then nothing more happens. I can verify that the application is running as expected, so only the logging is missing.. (built with default = ["defmt-default"])

Searching some more, it seems to be caused by this piece:

for try_index in 0..=NUM_RETRIES {
    rtt_res = Rtt::attach_region(sess.clone(), &ScanRegion::Exact(rtt_addr_res));
    match rtt_res {
        Ok(_) => {
            log::info!("Successfully attached RTT");
            break;
        }
        Err(probe_rs_rtt::Error::ControlBlockNotFound) => {
            if try_index < NUM_RETRIES {
                log::info!("Could not attach because the target's RTT control block isn't initialized (yet). retrying");
            } else {
                log::info!("Max number of RTT attach retries exceeded.");
                return Err(anyhow!(probe_rs_rtt::Error::ControlBlockNotFound));
            }
        }
        Err(e) => {
            return Err(anyhow!(e));
        }
    }
}

not delaying enough for the bootloader to jump to application before giving up on the RTT attachment.

A simple 1 second sleep between retries seems to fix my issue.

A simple 1 second sleep between retries seems to fix my issue.

Probably the rtt-target issue described in https://github.com/knurling-rs/probe-run/pull/25#issuecomment-677482231 .

The firmware that you are flashing with probe-run is using rtt-target or defmt-rtt?

It is using defmt-rtt

After reset the bootloader runs first and then it loads the "app". You are flashing the app with probe-run and the app is using defmt-rtt. If that's the case then it makes that you hit a timeout. The time spent in the bootloader is equivalent to adding a delay before r0::init_data initializes static variables (including RTT_BLOCK) in a normal cortex-m-rt application.

I think we can avoid the problem by having probe-run manually write RTT_BLOCK (it's just a few bytes in size) into RAM before resetting the device. That way probe-run will immediately find the RTT block and wait for the device to push data into it. With this approach the RTT_BLOCK will be initialized twice (once by probe-run and again by the device) but that shouldn't be an issue (it won't lost data because no data will be pushed into the RTT buffers between those two initializations).

After reset the bootloader runs first and then it loads the "app". You are flashing the app with probe-run and the app is using defmt-rtt. If that's the case then it makes that you hit a timeout. The time spent in the bootloader is equivalent to adding a delay before r0::init_data initializes static variables (including RTT_BLOCK) in a normal cortex-m-rt application.

That is exactly the case.

I think we can avoid the problem by having probe-run manually write RTT_BLOCK (it's just a few bytes in size) into RAM before resetting the device. That way probe-run will immediately find the RTT block and wait for the device to push data into it. With this approach the RTT_BLOCK will be initialized twice (once by probe-run and again by the device) but that shouldn't be an issue (it won't lost data because no data will be pushed into the RTT buffers between those two initializations).

I think that sounds like a very reasonable approach.

having probe-run manually write RTT_BLOCK (it's just a few bytes in size) into RAM before resetting the device

note: we can only do this with defmt-rtt because under that implementation RTT_BLOCK is const initialized so its initial value will be stored in the ELF file (program data)

implementation notes off the top of my head:

• the RTT_BLOCK variable is in the .data section (virtual address is in RAM)
• its initial value will be in Flash (its load address in in Flash)
• I believe if we use the object API to read a "raw" value from the .data section we'll get junk
• I think the initial values of sections like .data are stored in "program headers"; object should have an API to access the data stored there
• Would recommend looking into what cargo-flash / probe_rs::flash API does to flash the .data section

P.S. the variable is actually named _SEGGER_RTT, not RTT_BLOCK

Is there a reason for the RTT connection timeout? Couldn't we just continuously try to attach while in the main loop (with proper delays, to avoid using 100% CPU)? Potentially with some diagnostics to let the user know, of course.

Is there a reason for the RTT connection timeout?

iirc, the timeout is built into the probe_rs_rtt API; attach doesn't block forever

Couldn't we just continuously try to attach while in the main loop

maybe? but we need to handle the case where _SEGGER_RTT is present but the device hits exit before initializing the RTT. e.g.

// or without this whole `if` statement I guess
if cond_always_false() {
    init_rtt!();
}
// stuff
exit()

that should exit probe-run instead of blocking forever

Would it be possible to just add std::thread::sleep(std::time::Duration::from_secs(1)); in the rtt attach retry loop, until above is correctly tackled?

It would solve my issue of using probe-run currently, without really affecting anyone negatively?

@MathiasKoch is this still an issue with the crates.io version of defmt and/or probe-run v0.1.4?

I believe we now let the target run until it reaches main before looking for the RTT control block so that may help here.

Unfortunately still an issue, yes.

  (HOST) INFO  flashing program
  (HOST) INFO  success!
────────────────────────────────────────────────────────────────────────────────
  (HOST) ERROR Max number of RTT attach retries exceeded.
Error: RTT control block not found in target memory. Make sure RTT is initialized on the target.

Can confirm it still works in main branch with just a small delay in-between retry attempts

Were seeing this with the samd boards which have a uf2 bootloader fitted as well. Cargo embed works fine. When I wipe out the bootloader and adjust memory location probe run works again

This seems to be working for atsamd uf2 bootloader now.

$ probe-run --version
0.2.5 
supported defmt version: 0.2

@jacobrosenthal Thank you for reporting!

@MathiasKoch Could you please also check with the latest crates-io version of defmt and probe-run?

It is also working here.

The gold version would be the ability to get logs from both the bootloader & the application, but i am not sure that is worth the time or even possible.

I would love to have that feature as well, as especially in bootloaders, code size and thus use of defmt are of very high importance. The general setup works flawlessly for me, but log messages from the bootloader are not present. This is probably an issue for defmt though, having support for multiple binaries and properly handling an RTT Block which get's recreated mid-runtime.

RFC knurling-rs/defmt#652 has been submitted to address bootloader support