tracing: fix recursive register_callsite deadlock
#2634
Merged
Conversation
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
hawkw
changed the title
register_callsite callsregister_callsite deadlock
hawkw
added a commit
to tosc-rs/mnemos
that referenced
this pull request
Jun 24, 2023
Currently, the `tracing` collector in the Allwinner D1 platform impl is hardcoded to the DEBUG level. This is unfortunate, as it means that we will always do the work of collecting and formatting DEBUG traces, even when no one is listening on the UART tracing port. It would be more efficient if we only formatted traces when a `crowtty` instance has subscribed to the UART tracing port. Additionally, because trace metadata is sent when the callsite is initially registered, a `crowtty` instance that attaches after the board has started running may miss some trace metadata. Finally, there is no way to change the trace level on the fly, as it's hard-coded in the kernel. This branch changes the `mnemos-trace-proto` wire protocol to include a host to target message to select a `tracing` level. Now, the board can start up with all tracing disabled, and `crowtty` can send the desired tracing level once it connects. This way, we don't collect or format traces at all when `crowtty` isn't connected. In order to ensure `crowtty` waits to send the tracing level message only once the board's tracing code has been initialized, we add a periodic "heartbeat" message sent by the board on the tracing port while tracing is idle. This is used by the host which is listening for traces to detect the presence of the tracing collector on the debug target. The same message is used to ack a successful request to select the tracing level. When the tracing level is selected, the target rebuilds `tracing`'s callsite cache, which means all metadata for callsites which have previously been hit will be sent to the host. This ensures that `crowtty` always has the metadata for all tracing spans and events that are enabled, even if the target encountered them before `crowtty` connected. Making this work required fixing an upstream `tracing` bug, tokio-rs/tracing#2634, where calling into code that includes `tracing` diagnostics from inside a `Collect::register_callsite` method would cause a deadlock. Additionally, I had to add code to the collector for tracking whether it's inside its own `send` method, in order to temporarily disable `bbq` tracing. This is because the collector's use of `bbq` creates an infinite loop when the TRACE level is enabled. Check this out: 
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.
This suggestion is invalid because no changes were made to the code.
Suggestions cannot be applied while the pull request is closed.
Suggestions cannot be applied while viewing a subset of changes.
Only one suggestion per line can be applied in a batch.
Add this suggestion to a batch that can be applied as a single commit.
Applying suggestions on deleted lines is not supported.
You must change the existing code in this line in order to create a valid suggestion.
Outdated suggestions cannot be applied.
This suggestion has been applied or marked resolved.
Suggestions cannot be applied from pending reviews.
Suggestions cannot be applied on multi-line comments.
Suggestions cannot be applied while the pull request is queued to merge.
Suggestion cannot be applied right now. Please check back later.
Motivation
A deadlock exists when a collector's
register_callsitemethod callsinto code that also contains tracing instrumentation and triggers a
second
register_callsitecall for the same callsite. This is becausethe current implementation of the
MacroCallsitetype holds acore::sync::Oncewhich it uses to ensure that it is only added to thecallsite registry a single time. This deadlock was fixed in v0.1.x in PR
#2083, but the issue still exists on v0.2.x.
Solution
This branch forward-ports the solution from #2083. Rather than using a
core::sync::Once, we now track the callsite's registration statedirectly in
MacroCallsite. If a callsite has started registering, buthas not yet completed, subsequent
registercalls will just immediatelyreceive an
Interest::sometimesuntil the registration has completed,rather than waiting to attempt their own registration.
I've also forward-ported the tests for this that were added in #2083.