embassy
embassy copied to clipboard
Add support for `rtos-trace` behind a feature flag
This allows SystemView to be used to profile the behavior of the user's application.
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 isCOMP_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 theRtosTraceApplicationCallbacks
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 nameRtosTraceApplicationCallbacks
, thertos-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.
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.
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
.
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?)
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.
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.
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:)
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 theCargo.toml
. (Yes, I know we already had thenightly
feature, but adding features to choose betweendefmt/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.
Thanks! Looking forward to try this 😸
bors r+