Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

self-profiler: record spans for proc-macro expansions #95739

Merged
merged 2 commits into from
Apr 23, 2022

Conversation

lqd
Copy link
Member

@lqd lqd commented Apr 6, 2022

This PR is a follow-up to #95473, using the arg recorder feature from #95689:

  • it adds support code to easily record spans in the event's arguments, when using generic_activity_with_arg_recorder.
  • uses that to record the spans where proc-macro expansions happen in addition to their name.

As for the other 2 PRs, the goal here is to provide visibility into proc-macro expansion performance, so that users can diagnose which uses of proc-macros in their code could be causing compile time issues.

Some areas where I'd love feedback:

@rustbot rustbot added the T-compiler Relevant to the compiler team, which will review and decide on the PR/issue. label Apr 6, 2022
@lqd lqd force-pushed the proc-macro-expansions branch from 98684ce to da5914d Compare April 7, 2022 18:46
@lqd lqd marked this pull request as ready for review April 14, 2022 16:46
@lqd
Copy link
Member Author

lqd commented Apr 14, 2022

As discussed on zulip (again, it's not urgent or anything :), r? @wesleywiser.

bors added a commit to rust-lang-ci/rust that referenced this pull request Apr 16, 2022
Allow self-profiler to only record potentially costly arguments when argument recording is turned on

As discussed [on zulip](https://rust-lang.zulipchat.com/#narrow/stream/247081-t-compiler.2Fperformance/topic/Identifying.20proc-macro.20slowdowns/near/277304909) with `@wesleywiser,` I'd like to record proc-macro expansions in the self-profiler, with some detailed data (per-expansion spans for example, to follow rust-lang#95473).

At the same time, I'd also like to avoid doing expensive things when tracking a generic activity's arguments, if they were not specifically opted into the event filter mask, to allow the self-profiler to be used in hotter contexts.

This PR tries to offer:
- a way to ensure a closure to record arguments will only be called in that situation, so that potentially costly arguments can still be recorded when needed. With the additional requirement that, if possible, it would offer a way to record non-owned data without adding many `generic_activity_with_arg_{...}`-style methods. This lead to the `generic_activity_with_arg_recorder` single entry-point, and the closure parameter would offer the new methods, able to be executed in a context where costly argument could be created without disturbing the profiled piece of code.
- some facilities/patterns allowing to record more rustc specific data in this situation, without making `rustc_data_structures`  where the self-profiler is defined, depend on other rustc crates (causing circular dependencies): in particular, spans. They are quite tricky to turn into strings (if the default `Debug` impl output does not match the context one needs them for), and since I'd also like to avoid the allocation there when arg recording is turned off today, that has turned into another flexibility requirement for the API in this PR (separating the span-specific recording into an extension trait). **edit**: I've removed this from the PR so that it's easier to review, and opened rust-lang#95739.
- allow for extensibility in the future: other ways to record arguments, or additional data attached to them could be added in the future (e.g. recording the argument's name as well as its data).

Some areas where I'd love feedback:
- the API and names: the `EventArgRecorder` and its method for example. As well as the verbosity that comes from the increased flexibility.
- if I should convert the existing `generic_activity_with_arg{s}` to just forward to `generic_activity_with_arg_recorder` + `recorder.record_arg` (or remove them altogether ? Probably not): I've used the new API in the simple case I could find of allocating for an arg that may not be recorded, and the rest don't seem costly.
- [x] whether this API should panic if no arguments were recorded by the user-provided closure (like this PR currently does: it seems like an error to use an API dedicated to record arguments but not call the methods to then do so) or if this should just record a generic activity without arguments ?
- whether the `record_arg` function should be `#[inline(always)]`, like the `generic_activity_*` functions ?

As mentioned, r? `@wesleywiser` following our recent discussion.
@lqd lqd force-pushed the proc-macro-expansions branch from da5914d to c90a74c Compare April 17, 2022 20:30
@lqd
Copy link
Member Author

lqd commented Apr 21, 2022

just for peace of mind: @bors try @rust-timer queue

(There should be no perf impact, since it's under a self-profiler flag; but self-profiling is enabled on perf.rlo IIRC, and it's to make sure it doesn't skew measurements there)

@rust-timer
Copy link
Collaborator

Awaiting bors try build completion.

@rustbot label: +S-waiting-on-perf

@rustbot rustbot added the S-waiting-on-perf Status: Waiting on a perf run to be completed. label Apr 21, 2022
@bors
Copy link
Contributor

bors commented Apr 21, 2022

⌛ Trying commit c90a74cb117fabfead969d499e92f33846507244 with merge 3986b4a956ab02b76ee416c11c439957d6504a53...

@bors
Copy link
Contributor

bors commented Apr 21, 2022

☀️ Try build successful - checks-actions
Build commit: 3986b4a956ab02b76ee416c11c439957d6504a53 (3986b4a956ab02b76ee416c11c439957d6504a53)

@rust-timer
Copy link
Collaborator

Queued 3986b4a956ab02b76ee416c11c439957d6504a53 with parent 3d3dafb, future comparison URL.

@rust-timer

This comment was marked as duplicate.

@rust-timer
Copy link
Collaborator

Finished benchmarking commit (3986b4a956ab02b76ee416c11c439957d6504a53): comparison url.

Summary: This benchmark run did not return any relevant results.

If you disagree with this performance assessment, please file an issue in rust-lang/rustc-perf.

compiler/rustc_span/src/profiling.rs Outdated Show resolved Hide resolved
compiler/rustc_span/src/profiling.rs Outdated Show resolved Hide resolved
@wesleywiser
Copy link
Member

we don't currently have a way to record the names of the event arguments, so should record_arg_spanned record the span as "location: {}" or similar ?

I think for now, if including the name like that is helpful to the reader, then we should do that. We really do need a way to provide argument names to measureme...

@lqd
Copy link
Member Author

lqd commented Apr 22, 2022

I'm not sure "location: $span" is absolutely required, much like we often only record an item's name, without prefixing it with a name or type.

A span is much more understandable than an item's name, so it should be clear from context. We can maybe add such a thing if people find it a bit obscure. And argument names in measureme will help in the future, so I'm not worried that this is super important today.

lqd added 2 commits April 22, 2022 18:06
The self-profiler's `EventArgRecorder` is general-purpose in its ability to record Strings (and `rustc_span` depends on the crate its defined in, `rustc_data_structure`).

Some generic activities could use recording locations where they happen in the user's code: to allow e.g. to track macro expansions and diagnose performance issues there.

This adds a `SpannedEventArgRecorder` that can record an argument given as a span, rather than a String, since turning spans into Strings can be tricky if you're not happy with its default Debug output. This way the recorder can have a `record_arg_spanned` method which will do that.
@lqd lqd force-pushed the proc-macro-expansions branch from c90a74c to c525396 Compare April 22, 2022 16:43
@wesleywiser
Copy link
Member

@bors r+

@bors
Copy link
Contributor

bors commented Apr 22, 2022

📌 Commit c525396 has been approved by wesleywiser

@bors bors added the S-waiting-on-bors Status: Waiting on bors to run and complete tests. Bors will change the label on completion. label Apr 22, 2022
@bors
Copy link
Contributor

bors commented Apr 22, 2022

⌛ Testing commit c525396 with merge c2b4c2d...

@bors
Copy link
Contributor

bors commented Apr 23, 2022

☀️ Test successful - checks-actions
Approved by: wesleywiser
Pushing c2b4c2d to master...

@bors bors added the merged-by-bors This PR was explicitly merged by bors. label Apr 23, 2022
@bors bors merged commit c2b4c2d into rust-lang:master Apr 23, 2022
@rustbot rustbot added this to the 1.62.0 milestone Apr 23, 2022
@rust-timer
Copy link
Collaborator

Finished benchmarking commit (c2b4c2d): comparison url.

Summary: This benchmark run did not return any relevant results.

If you disagree with this performance assessment, please file an issue in rust-lang/rustc-perf.

@lqd lqd deleted the proc-macro-expansions branch April 23, 2022 08:35
antoyo pushed a commit to rust-lang/rustc_codegen_gcc that referenced this pull request Jun 5, 2022
Allow self-profiler to only record potentially costly arguments when argument recording is turned on

As discussed [on zulip](https://rust-lang.zulipchat.com/#narrow/stream/247081-t-compiler.2Fperformance/topic/Identifying.20proc-macro.20slowdowns/near/277304909) with `@wesleywiser,` I'd like to record proc-macro expansions in the self-profiler, with some detailed data (per-expansion spans for example, to follow #95473).

At the same time, I'd also like to avoid doing expensive things when tracking a generic activity's arguments, if they were not specifically opted into the event filter mask, to allow the self-profiler to be used in hotter contexts.

This PR tries to offer:
- a way to ensure a closure to record arguments will only be called in that situation, so that potentially costly arguments can still be recorded when needed. With the additional requirement that, if possible, it would offer a way to record non-owned data without adding many `generic_activity_with_arg_{...}`-style methods. This lead to the `generic_activity_with_arg_recorder` single entry-point, and the closure parameter would offer the new methods, able to be executed in a context where costly argument could be created without disturbing the profiled piece of code.
- some facilities/patterns allowing to record more rustc specific data in this situation, without making `rustc_data_structures`  where the self-profiler is defined, depend on other rustc crates (causing circular dependencies): in particular, spans. They are quite tricky to turn into strings (if the default `Debug` impl output does not match the context one needs them for), and since I'd also like to avoid the allocation there when arg recording is turned off today, that has turned into another flexibility requirement for the API in this PR (separating the span-specific recording into an extension trait). **edit**: I've removed this from the PR so that it's easier to review, and opened rust-lang/rust#95739.
- allow for extensibility in the future: other ways to record arguments, or additional data attached to them could be added in the future (e.g. recording the argument's name as well as its data).

Some areas where I'd love feedback:
- the API and names: the `EventArgRecorder` and its method for example. As well as the verbosity that comes from the increased flexibility.
- if I should convert the existing `generic_activity_with_arg{s}` to just forward to `generic_activity_with_arg_recorder` + `recorder.record_arg` (or remove them altogether ? Probably not): I've used the new API in the simple case I could find of allocating for an arg that may not be recorded, and the rest don't seem costly.
- [x] whether this API should panic if no arguments were recorded by the user-provided closure (like this PR currently does: it seems like an error to use an API dedicated to record arguments but not call the methods to then do so) or if this should just record a generic activity without arguments ?
- whether the `record_arg` function should be `#[inline(always)]`, like the `generic_activity_*` functions ?

As mentioned, r? `@wesleywiser` following our recent discussion.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
merged-by-bors This PR was explicitly merged by bors. S-waiting-on-bors Status: Waiting on bors to run and complete tests. Bors will change the label on completion. S-waiting-on-perf Status: Waiting on a perf run to be completed. T-compiler Relevant to the compiler team, which will review and decide on the PR/issue.
Projects
None yet
Development

Successfully merging this pull request may close these issues.

5 participants