Add support for `rtos-trace` behind a feature flag

[quentinmit]

trafficstars

This allows SystemView to be used to profile the behavior of the user's application.

[quentinmit]

What if we created a set of generic tracing macros in src/trace.rs which expands to rtos-trace stuff when rtos-trace configuration is specified? The general idea is that we can add other tracing mechanisms in the same place without having to instrument the executor for each mechanism.

Otherwise looks good!

My understanding is that the rtos-trace crate is already trying to be those generic macros. Do we really want to diverge the ecosystem like that? (You have to add the systemview-target crate if you want to get SystemView tracing; the rtos-trace crate uses similar linking tricks to defmt/log/etc. to swap in implementations.) There's also the embedded_profiling crate but it doesn't seem to have a sufficient API surface for tracing an entire system.

That all said, there's a few minor problems that I'd love to resolve:

• We don't have task names because that's just not part of the executor API. Ideally we'd call trace::task_send_info with the name of each task. Since all of the task names are present in the symbol table, I'm wondering if we can play nasty build script tricks to bake the symbol names of the tasks into the binary.
• There's currently a typo in rtos-trace that makes it require nightly (an extra type is specified where it's not needed); we might want to wait for https://gitlab.com/bern-rtos/tools/rtos-trace/-/merge_requests/1 to be merged and released to fix that typo.
• SystemView docs recommend not tracing high-frequency ISRs. On my nrf52840 I'm seeing a ton of invocations of ISR 19 (COMP), which is maybe part of timekeeping? (The docs say interrupt 19 is COMP_LPCOMP, but AFAIK my code isn't touching the comparator.) This implementation doesn't provide any way to disable tracing for high-frequency ISRs.
• The crate reads the DWT.CYCCNT register to timestamp each event, but in order for this to be usable the user has to provide an implementation of the RtosTraceApplicationCallbacks trait that reports the system's clock frequency. I tried and couldn't find any generic interface for that, so I ended up just hard-coding the frequency in my application... (and with the name RtosTraceApplicationCallbacks, the rtos-trace crate doesn't envision the RTOS providing that anyway). Not sure there's anything Embassy can do about this but it's a pain point.

I think this is probably worth merging without fixing those, but I wanted to mention them. I guess I could add a working example that shows how to use tracing.

[lulf]

I didn't realize it was just a front-end, sorry!

I guess what confused me was the feature flags needed to use it, whereas with the logging macros the feature flag is hidden in fmt.rs.

[chemicstry]

This is really interesting! I was thinking about something like this for quite some time, but didn't know about rtos-trace.

Regarding task names, I think this could be implemented in embassy_executor::task macro without build script hacking. Although this wouldn't support anything dynamic like boxed futures (I don't think they are supported in the executor yet anyway).

An unrelated question: Is there anything in rust ecosystem to view these systemview events except the proprietary Segger tool? It would be really cool if it worked with probe-run.

[quentinmit]

This is really interesting! I was thinking about something like this for quite some time, but didn't know about rtos-trace.

Regarding task names, I think this could be implemented in embassy_executor::task macro without build script hacking. Although this wouldn't support anything dynamic like boxed futures (I don't think they are supported in the executor yet anyway).

I don't think would cover other use cases, either, like ector actors since it directly constructs Task objects.

An unrelated question: Is there anything in rust ecosystem to view these systemview events except the proprietary Segger tool? It would be really cool if it worked with probe-run.

It looks like defmt has an open issue for this: https://github.com/knurling-rs/defmt/issues/520

You could presumably write an rtos-trace backend that uses defmt once defmt gains support for tracing. (Though is it safe to call defmt from an interrupt context?)

[FrozenDroid]

We don't have task names because that's just not part of the executor API. Ideally we'd call trace::task_send_info with the name of each task. Since all of the task names are present in the symbol table, I'm wondering if we can play nasty build script tricks to bake the symbol names of the tasks into the binary.

Since Task::new() is const, maybe we could gather a list of all the task type_name's. I don't know how we will associate the Task type names at runtime though. Maybe we need a task_id only for tracing purposes.

[quentinmit]

I added an example for testing this feature. Unfortunately @FrozenDroid's PR doesn't seem to work out of the box; I'm trying to debug it now.

[Dirbaio]

Could you add a new examples/nrf-rtos-trace example project instead? The examples lose "teaching value" really quickly if there's so much complex feature stuff going on in the Cargo.toml. (Yes, I know we already had the nightly feature, but adding features to choose between defmt/log is way worse :sweat_smile:)

[quentinmit]

Could you add a new examples/nrf-rtos-trace example project instead? The examples lose "teaching value" really quickly if there's so much complex feature stuff going on in the Cargo.toml. (Yes, I know we already had the nightly feature, but adding features to choose between defmt/log is way worse 😅)

Fair enough. I think it was also kind of useful to have the examples of using log in an embedded context, though.

[lulf]

Thanks! Looking forward to try this 😸

bors r+

[bors[bot]]

Build succeeded:

• all