Don't use full tracing spans in full-tree passes by default #687
Conversation
| let _span = global_state | ||
| .trace | ||
| .access | ||
| .then(|| widget.item.make_trace_span().entered()); |
There was a problem hiding this comment.
I'm surprised just creating the spans has such a heavy performance impact. Are you sure we're not conflating them with something else?
There was a problem hiding this comment.
I believe that this is correct. Creating a filtered out span has very little performance impact, obviously, but the log file layer has no filtering.
A large amount of the work in using a span is done on creation - see https://github.com/tokio-rs/tracing/blob/bdbaf8007364ed2a766cca851d63de31b7c47e72/tracing-subscriber/src/registry/sharded.rs#L237-L269.
An alternative approach we could take would be to cache the span for each widget in its state. That approach would be likely to get most of the same advantages, but requires more fundamental changes. That is also done in bevyengine/bevy#9390. I think I'll do that as a follow-up to this PR; I still think this is useful, because the current logs are extraordinarily spammy; but if we can maintain a proper tracing stack at all times, that would be neat.
There was a problem hiding this comment.
Yeah, I'm in favor of removing spammy logs, but removing spans (and/or making span code more verbose) bothers me a bit.
If we do caching, we could simply create the cached span during the WidgetAdded event. To avoid using an optional span we could create WidgetState with a default placeholder span.
This can be toggled using the `MASONRY_TRACE_PASSES` environment variable
Inspired by #687, I thought some more tidying up of the log file was in order. The main differences are: 1) Higher-scale spans exist for key operations 2) Something is always logged for each event, but less for high-density eventskey 3) Less is logged for high-density events 4) Key repeats are no longer treated as high density 5) We no longer do extra work if the hover and focus paths haven't changed (which also means less logging) This PR *does not* depend on #687
This can be toggled using the
MASONRY_TRACE_PASSESenvironment variable.This is as-discussed in #xilem > Scrolling is insanely laggy. There are a few overlapping issues, but this significantly improves performance in debug mode.
The main pass which was problematic was the compose pass, however this also had a significant impact on the time taken by the accessibility/paint passes.
This only applies to the passes which traverse the entire tree, so not the targeted passes. I also chose to exclude update_disabled and update_stashed, as those will not necessarily happen to all widgets.
This also significantly reduces the size of the created log files - see #masonry > Heavy amounts of logs with large app. In most cases, if you're using the log file, you will be in development, which means that you can hopefully recreate the issue with the logging for the passes you need enabled.