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.

Sign up for GitHub

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

Jump to bottom

track individual proc-macro expansions in the self-profiler #95473

Merged
merged 1 commit into from
Apr 6, 2022
Merged

track individual proc-macro expansions in the self-profiler #95473

merged 1 commit into from
Apr 6, 2022

Conversation

lqd
Copy link
Member

@lqd lqd commented Mar 30, 2022

As described in this zulip thread, users don't currently have a lot of information to diagnose macro expansion performance issues. That comment suggests using the macro names to add further timing information.

This PR starts to do this for proc-macros which have the same issue, and performance problems happening in the wild in this other zulip thread could be helped by such information.

It uses the available proc-macro name to track their individual expansions with self-profiling events.

r? @Aaron1011 who mentioned this idea originally

@rustbot rustbot added the T-compiler Relevant to the compiler team, which will review and decide on the PR/issue. label Mar 30, 2022
@lqd
Copy link
Member Author

lqd commented Mar 30, 2022

@bors try

@bors
Copy link
Contributor

bors commented Mar 30, 2022

⌛ Trying commit f47f3f35ba9738b9101cc7ef6f62ae2908dd8404 with merge a121de4a30502064e6d60b71f035e0b005beeaff...

@bors
Copy link
Contributor

bors commented Mar 30, 2022

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

@petrochenkov petrochenkov self-assigned this Mar 30, 2022
@petrochenkov petrochenkov added the S-waiting-on-perf Status: Waiting on a perf run to be completed. label Mar 30, 2022
@lqd
Copy link
Member Author

lqd commented Mar 30, 2022

@petrochenkov I see you added the "waiting on perf" label, do you want to run this through the bot ?
I wasn't planning to (the self profiler should already be properly filtering these events out when it's disabled, and avoid allocating the strings it records) but we can do that.

The try build was just so that people on zulip like @djc could try the artifacts on their problematic crates.

@petrochenkov
Copy link
Contributor

The try build was just so that people on zulip like @djc could try the artifacts on their problematic crates.

Ah, ok.
I noticed that there's no label, so I set some label that seemed reasonable.

@petrochenkov petrochenkov added S-waiting-on-review Status: Awaiting review from the assignee but also interested parties. and removed S-waiting-on-perf Status: Waiting on a perf run to be completed. labels Mar 30, 2022
petrochenkov
petrochenkov reviewed Apr 3, 2022
View reviewed changes
compiler/rustc_expand/src/proc_macro.rs Outdated Show resolved Hide resolved
compiler/rustc_expand/src/proc_macro.rs Outdated Show resolved Hide resolved
@petrochenkov petrochenkov added S-waiting-on-author Status: This is awaiting some action (such as code changes or more information) from the author. and removed S-waiting-on-review Status: Awaiting review from the assignee but also interested parties. labels Apr 3, 2022
@lqd
track proc-macro expansions in the self-profiler
9ac8d2f 
Use the proc-macro descr to track their individual expansions with
self-profiling events. This will help diagnose performance issues
with slow proc-macros.
@lqd lqd force-pushed the macro-expansion branch from f47f3f3 to 9ac8d2f Compare April 5, 2022 13:38
@lqd
Copy link
Member Author

lqd commented Apr 5, 2022 •
edited
Loading

I've updated the PR to address the great review comments.

@rustbot ready

@rustbot rustbot added S-waiting-on-review Status: Awaiting review from the assignee but also interested parties. and removed S-waiting-on-author Status: This is awaiting some action (such as code changes or more information) from the author. labels Apr 5, 2022
@lqd lqd mentioned this pull request Apr 5, 2022
Merged
1 task
@petrochenkov
Copy link
Contributor

@bors r+

@bors
Copy link
Contributor

bors commented Apr 5, 2022

📌 Commit 9ac8d2f has been approved by petrochenkov

@bors bors added S-waiting-on-bors Status: Waiting on bors to run and complete tests. Bors will change the label on completion. and removed S-waiting-on-review Status: Awaiting review from the assignee but also interested parties. labels Apr 5, 2022
@Dylan-DPC Dylan-DPC mentioned this pull request Apr 5, 2022
Merged
bors added a commit to rust-lang-ci/rust that referenced this pull request Apr 5, 2022
@bors
Auto merge of rust-lang#95702 - Dylan-DPC:rollup-793rz6v, r=Dylan-DPC
bbe9d27 
Rollup of 8 pull requests

Successful merges:

 - rust-lang#88025 (ScmCredentials netbsd implementation.)
 - rust-lang#95473 (track individual proc-macro expansions in the self-profiler)
 - rust-lang#95547 (caution against ptr-to-int transmutes)
 - rust-lang#95585 (Explain why `&T` is cloned when `T` is not `Clone`)
 - rust-lang#95591 (Use revisions to track NLL test output (part 1))
 - rust-lang#95663 (diagnostics: give a special note for unsafe fn / Fn/FnOnce/FnMut)
 - rust-lang#95673 (:arrow_up: rust-analyzer)
 - rust-lang#95681 (resolve: Fix resolution of empty paths passed from rustdoc)

Failed merges:

r? `@ghost`
`@rustbot` modify labels: rollup
@bors bors merged commit c5e7e95 into rust-lang:master Apr 6, 2022
@rustbot rustbot added this to the 1.62.0 milestone Apr 6, 2022
@lqd lqd deleted the macro-expansion branch April 6, 2022 04:48
@lqd lqd mentioned this pull request Apr 6, 2022
Merged
2 tasks
bors added a commit to rust-lang-ci/rust that referenced this pull request Apr 16, 2022
@bors
Auto merge of rust-lang#95689 - lqd:self-profiler, r=wesleywiser
febce1f 
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.
bors added a commit to rust-lang-ci/rust that referenced this pull request Apr 22, 2022
@bors
Auto merge of rust-lang#95739 - lqd:proc-macro-expansions, r=wesleywiser
c2b4c2d 
self-profiler: record spans for proc-macro expansions

This PR is a follow-up to rust-lang#95473, using the arg recorder feature from rust-lang#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:
- [x] the API and names: the `SpannedEventArgRecorder` trait and its method, much like rust-lang#95689 had the same question about the `EventArgRecorder` naming
- [x] 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 ?
antoyo pushed a commit to antoyo/rust that referenced this pull request Jun 7, 2022
@bors
Auto merge of rust-lang#95689 - lqd:self-profiler, r=wesleywiser
21be9da 
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.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Reviewers

@petrochenkov petrochenkov petrochenkov left review comments

Assignees

@petrochenkov petrochenkov

Labels
S-waiting-on-bors Status: Waiting on bors to run and complete tests. Bors will change the label on completion. T-compiler Relevant to the compiler team, which will review and decide on the PR/issue.
Projects
None yet
Milestone
1.62.0
Development

Successfully merging this pull request may close these issues.
4 participants
@lqd @bors @petrochenkov @rustbot