-
Notifications
You must be signed in to change notification settings - Fork 12.9k
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
Implement a self profiler #51657
Implement a self profiler #51657
Conversation
(rust_highfive has picked a reviewer for you, use r? to override) |
The job Click to expand the log.
I'm a bot! I can only do what humans tell me to, so if this was not helpful or you have suggestions for improvements, please ping or otherwise contact |
@@ -666,13 +675,15 @@ pub fn phase_1_parse_input<'a>( | |||
profile::begin(sess); | |||
} | |||
|
|||
sess.profiler(|p| p.start_activity(ProfileCategory::Parsing)); |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Could you make the time
function take an Option<ProfileCategory>
and have it do these calls instead where appropriate?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Yes, that would probably work. Good idea!
cc @rust-lang/compiler and specifically @eddyb |
src/librustc/ty/query/mod.rs
Outdated
@@ -97,228 +98,228 @@ pub use self::on_disk_cache::OnDiskCache; | |||
// as they will raise an fatal error on query cycles instead. | |||
define_queries! { <'tcx> | |||
/// Records the type of every item. | |||
[] fn type_of: TypeOfItem(DefId) -> Ty<'tcx>, | |||
[] category<Other> fn type_of: TypeOfItem(DefId) -> Ty<'tcx>, |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
This is interesting! I like the way you can label the categories so declaratively, but I don't love the syntax. I'd sort of like #[category(Other)]
or something that looks more like Rust.
It could also go inside the []
-- this was always meant to "house" important flags and so forth. Are we even using that for anything anymore? Maybe we should remove it...
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Yeah, the current syntax is not very good. My macro-foo is pretty weak so I just did this temporarily. I'd be happy to circle back and try to make it work in the []
.
src/librustc/ty/query/mod.rs
Outdated
[fatal_cycle] category<Codegen> fn is_sanitizer_runtime: IsSanitizerRuntime(CrateNum) -> bool, | ||
[fatal_cycle] category<Codegen> fn is_profiler_runtime: IsProfilerRuntime(CrateNum) -> bool, | ||
[fatal_cycle] category<Codegen> fn panic_strategy: GetPanicStrategy(CrateNum) -> PanicStrategy, | ||
[fatal_cycle] category<Codegen> fn is_no_builtins: IsNoBuiltins(CrateNum) -> bool, |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Answer: yes, we are still using []
for something. Maybe we should change that to #[fatal_cycle]
as well.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I kind of like that idea, but it seems a little surprising to me that in this context #[whatever]
doesn't mean what it normally would. For example, #[derive(Clone)]
would result in some kind of weird macro expansion error.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I think this is what #[...]
normally means. That is, #[..]
is some kind of meta-data interpreted by the context. In this context, this is a macro, and macros often re-interpret #[foo]
annotations. (Consider for example #[derive]
which allows for annotations on fields etc that aren't normally used.) That doesn't mean that all attributes would be appropriate of course (e.g. #[derive(Clone)]
doesn't make sense on a function anyhow)
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Fair enough! I don't think I've seen a macro re-interpret #[]
annotations before so it seemed strange to me. I can certainly do this though.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Interestingly enough, it looks like define_queries!
already handles attributes. This doesn't appear to be used currently or in the recent history of this file. @nikomatsakis would you like me to continue with this idea and remove support for regular #[thing]
attributes from the macro? What do you think of @eddyb's idea? I quite like it myself.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I'm fine with @eddyb's idea too
@@ -340,6 +341,8 @@ pub fn provide(providers: &mut Providers) { | |||
pub fn check_crate<'a, 'tcx>(tcx: TyCtxt<'a, 'tcx, 'tcx>) | |||
-> Result<(), CompileIncomplete> | |||
{ | |||
tcx.sess.profiler(|p| p.start_activity(ProfileCategory::TypeChecking)); |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
(is there a non-trivial amount of work here that takes place outside of queries?)
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Hmm... I'm not sure off hand. I can investigate.
@@ -351,6 +352,14 @@ pub fn compile_input( | |||
sess.print_perf_stats(); | |||
} |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
one question I'm wondering: how do we find the "total compilation time" number? I'd like to see some "start activity" and "end activity" that takes place at a really high-up place, like main
, that should truly account for everything
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I believe this is just a matter of creating the SelfProfiler
earlier in the process lifecycle. Right now it's created when Session::new()
is called, but there's no real reason it couldn't be created earlier.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
That's probably early enough -- when does it make its final measurement?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
At the end of compile_input()
right after we run the linker and output the other performance diagnostics.
@wesleywiser I left a few comments, but overall I'm pretty excited. I'd love to have simple-and-easy profiling, and this seems like a good start. Hmm, another question I didn't satisfy for myself: how do we separate out the timing results from sub-queries from the parent query? @Zoxc will have to weigh in on the best way to handle parallelization, but it seems like we ought to be able to sum up the timing results per-thread and them sum them up at the end across all threads. |
Right now, when |
r? @Zoxc |
This is really neat! I've wanted this for a while now 🎉 |
BorrowChecking, | ||
Codegen, | ||
Linking, | ||
Other, |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
My suggestion would make code like this auto-generatable so I prefer it even more.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
@eddyb Latest commit makes this all auto-generated
Well, this sounded good to me at first, but now I'm wondering if people will wind up miscategorizing things because they'll just insert queries into some random category without being able to easily see if it's the right or wrong place. It sort of reminds me of |
☔ The latest upstream changes (presumably #51538) made this pull request unmergeable. Please resolve the merge conflicts. |
@nikomatsakis Worst case we can move them later, seems like less of a problem than line noise. |
Ping from triage @wesleywiser! It's been a while since we heard from you, will you have time to work on this again? |
Yes! I've been working on this for a while now but I think I'm stuck on the macro changes suggested above. I'm going to continue trying to make progress but help from anybody in the community familiar with writing macros would be greatly appreciated! |
Not sure if this is the best way to do it, but the easiest thing I can think of would be to rename what you have to macro_rules! define_queries {
(Category1 { $(queries1:tt);* }
Category2 { $(queries2:tt);* }
... ) => {
define_queries_inner!(
$(category<Category1> $queries1)*
$(category<Category2> $queries2)*
...
);
}
} |
Thanks @mark-i-m, that's helpful! Unfortunately, I'm still not quite seeing the solution. I have this: macro_rules! define_queries {
$($category:ident {
$(queries:tt),*
}),* => {
define_queries_inner!(
$($(category<$category> $queries)), //issue
)
}
} but when expanding the queries, the macro needs to look "up" to the enclosing category. I can't think of anyway to do that. |
Hmm... Slight modification: macro_rules! define_queries {
$($category:ident {
$(queries:tt);* // note `;` instead of comma
}),* => {
define_queries_inner!(
$($(category<$category> $queries);*)* // note the two `*`s and `;`
)
}
} IIUC Of course, you will need to modify define_queries_inner to accept Let me know if this didn't work. |
@mark-i-m Perfect! That's just what I needed. I ran into some issues trying to get the macro_rules! define_queries {
(<$tcx:tt> $($category:ident {
$($(#[$attr:meta])* [$($modifiers:tt)*] fn $name:ident: $node:ident($K:ty) -> $V:ty,)*
},)*) => {
define_queries_inner! { <$tcx>
$($( $(#[$attr])* category<$category> [$($modifiers)*] fn $name: $node($K) -> $V,)*)*
}
}
}
macro_rules! define_queries_inner {
(<$tcx:tt>
$($(#[$attr:meta])*
category<$category:ident> [$($modifiers:tt)*] fn $name:ident: $node:ident($K:ty) -> $V:ty,)*) => {
....
}
} Thank you!! |
Great! Glad I could help :) Nice work! |
f937779
to
b8198ac
Compare
Rebased and updated with the snazzy new macro syntax |
The job Click to expand the log.
I'm a bot! I can only do what humans tell me to, so if this was not helpful or you have suggestions for improvements, please ping or otherwise contact |
Ping from triage @Zoxc! This PR needs your review. |
I haven't seen @Zoxc around in a while. Assigning to @nikomatsakis, who worked with @wesleywiser on this PR already. If you are too busy, @nikomatsakis, I can take a look too. |
@Zoxc Do you object to merging this PR? I think I want to r+ it. |
7e3f300
to
2d3a0a9
Compare
@eddyb Rebased |
@bors r+ Thanks! |
📌 Commit 2d3a0a9 has been approved by |
Implement a self profiler This is a work in progress implementation of #50780. I'd love feedback on the overall structure and code as well as some specific things: - [The query categorization mechanism](https://github.com/rust-lang/rust/compare/master...wesleywiser:wip_profiling?expand=1#diff-19e0a69c10eff31eb2d16805e79f3437R101). This works but looks kind of ugly to me. Perhaps there's a better way? - [The profiler assumes only one activity can run at a time](https://github.com/rust-lang/rust/compare/master...wesleywiser:wip_profiling?expand=1#diff-f8a403b2d88d873e4b27c097c614a236R177). This is obviously incompatible with the ongoing parallel queries. - [The output code is just a bunch of `format!()`s](https://github.com/rust-lang/rust/compare/master...wesleywiser:wip_profiling?expand=1#diff-f8a403b2d88d873e4b27c097c614a236R91). Is there a better way to generate markdown or json in the compiler? - [The query categorizations are likely wrong](https://github.com/rust-lang/rust/compare/master...wesleywiser:wip_profiling?expand=1#diff-19e0a69c10eff31eb2d16805e79f3437R101). I've marked what seemed obvious to me but I'm sure I got a lot of them wrong. The overhead currently seems very low. Running `perf` on a sample compilation with profiling enabled reveals: ![image](https://user-images.githubusercontent.com/831192/41657821-9775efec-7462-11e8-9e5e-47ec94105d9d.png)
☀️ Test successful - status-appveyor, status-travis |
This is a work in progress implementation of #50780. I'd love feedback on the overall structure and code as well as some specific things:
The query categorization mechanism. This works but looks kind of ugly to me. Perhaps there's a better way?
The profiler assumes only one activity can run at a time. This is obviously incompatible with the ongoing parallel queries.
The output code is just a bunch of
format!()
s. Is there a better way to generate markdown or json in the compiler?The query categorizations are likely wrong. I've marked what seemed obvious to me but I'm sure I got a lot of them wrong.
The overhead currently seems very low. Running
perf
on a sample compilation with profiling enabled reveals: