SelfProfiler API refactoring and part one of event review #64840

michaelwoerister · 2019-09-27T12:24:10Z

This PR refactors the SelfProfiler a little bit so that most profiling methods are RAII-based. The codegen backend code already had something similar, this refactoring pulls this functionality up into SelfProfiler itself, for general use.

The second commit of this PR is a review and update of the existing events we are already recording. Names have been made more consistent. CGU names have been removed from event names. They will be added back in when function parameter recording is implemented.

There is still some work to be done for adding new events, especially around trait resolution and the incremental system.

r? @wesleywiser

rust-highfive · 2019-09-27T12:43:31Z

The job x86_64-gnu-llvm-6.0 of your PR failed (pretty log, raw log). Through arcane magic we have determined that the following fragments from the build log may contain information about the problem.

Click to expand the log.

2019-09-27T12:24:48.7281969Z ##[command]git remote add origin https://github.com/rust-lang/rust
2019-09-27T12:24:48.7468361Z ##[command]git config gc.auto 0
2019-09-27T12:24:48.7521931Z ##[command]git config --get-all http.https://github.com/rust-lang/rust.extraheader
2019-09-27T12:24:48.7582616Z ##[command]git config --get-all http.proxy
2019-09-27T12:24:48.7716993Z ##[command]git -c http.extraheader="AUTHORIZATION: basic ***" fetch --force --tags --prune --progress --no-recurse-submodules --depth=2 origin +refs/heads/*:refs/remotes/origin/* +refs/pull/64840/merge:refs/remotes/pull/64840/merge
---
2019-09-27T12:31:46.6472538Z    Compiling serde_json v1.0.40
2019-09-27T12:31:48.4473081Z    Compiling tidy v0.1.0 (/checkout/src/tools/tidy)
2019-09-27T12:31:59.3912584Z     Finished release [optimized] target(s) in 1m 27s
2019-09-27T12:31:59.3998264Z tidy check
2019-09-27T12:32:00.2149914Z tidy error: /checkout/src/librustc_codegen_llvm/back/write.rs:528: line longer than 100 chars
2019-09-27T12:32:01.3504099Z some tidy checks failed
2019-09-27T12:32:01.3511357Z 
2019-09-27T12:32:01.3511357Z 
2019-09-27T12:32:01.3513305Z command did not execute successfully: "/checkout/obj/build/x86_64-unknown-linux-gnu/stage0-tools-bin/tidy" "/checkout/src" "/checkout/obj/build/x86_64-unknown-linux-gnu/stage0/bin/cargo" "--no-vendor"
2019-09-27T12:32:01.3513496Z 
2019-09-27T12:32:01.3513525Z 
2019-09-27T12:32:01.3571530Z failed to run: /checkout/obj/build/bootstrap/debug/bootstrap test src/tools/tidy
2019-09-27T12:32:01.3571623Z Build completed unsuccessfully in 0:01:31
2019-09-27T12:32:01.3571623Z Build completed unsuccessfully in 0:01:31
2019-09-27T12:32:01.3575675Z == clock drift check ==
2019-09-27T12:32:01.3592465Z   local time: Fri Sep 27 12:32:01 UTC 2019
2019-09-27T12:32:01.6359082Z   network time: Fri, 27 Sep 2019 12:32:01 GMT
2019-09-27T12:32:01.6359741Z == end clock drift check ==
2019-09-27T12:32:03.0196412Z ##[error]Bash exited with code '1'.
2019-09-27T12:32:03.0235204Z ##[section]Starting: Checkout
2019-09-27T12:32:03.0237563Z ==============================================================================
2019-09-27T12:32:03.0237623Z Task         : Get sources
2019-09-27T12:32:03.0237691Z Description  : Get sources from a repository. Supports Git, TfsVC, and SVN repositories.

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 @TimNN. (Feature Requests)

bors · 2019-09-28T07:41:14Z

☔ The latest upstream changes (presumably #64864) made this pull request unmergeable. Please resolve the merge conflicts.

andjo403 · 2019-09-28T10:36:27Z

shall the TimingGuard be moved to the measureme crate is useful for other then rustc.
moving to measureme makes it possible to only create one event for start and stop to save space and reduce the number of atomic writes, also kind of solves the rust-lang/measureme#47 or at least reduces the need for it.

src/librustc/util/profiling.rs

wesleywiser · 2019-09-28T11:01:19Z

src/librustc/util/profiling.rs

+    /// Start profiling a query being blocked on a concurrent execution.
+    /// Profiling continues until `query_blocked_end` is called.
+    #[inline(always)]
+    pub fn query_blocked_start(&self, query_name: QueryName) {


Should query_blocked_start() and query_blocked_end() be updated to work with the TimerGuard api?

I initially had it that way but these calls are only used in exactly one spot and that becomes more complicated with the TimerGuard approach.

src/librustc/util/profiling.rs

wesleywiser · 2019-09-28T11:17:24Z

src/librustc/ty/query/plumbing.rs

@@ -465,21 +465,17 @@ impl<'tcx> TyCtxt<'tcx> {

        let result = if let Some(result) = result {
            profq_msg!(self, ProfileQueriesMsg::CacheHit);
-            self.sess.profiler(|p| p.record_query_hit(Q::NAME));


We don't need this event?

I was pondering this question too. I opted to remove it because we already record the incr_cache_loading event above and strictly speaking this is not an in-memory cache hit. However, I also want to replace the query_provider event right below with something that indicates that this is not a regular query provider invocation but was triggered instead of a cache load.

Ok, sounds good

michaelwoerister · 2019-09-30T08:57:05Z

shall the TimingGuard be moved to the measureme crate is useful for other then rustc.

Yes, that's true. There's nothing in there that couldn't also be part of measureme.

moving to measureme makes it possible to only create one event for start and stop to save space and reduce the number of atomic writes, also kind of solves the rust-lang/measureme#47 or at least reduces the need for it.

Hm, maybe you are right. Having separate start and stop events makes sure that the nesting structure of events is always correct (without relying on possibly flaky timing functions). But maybe this could be done more efficiently somehow and then let post-processing tools reconstruct the structure.

I think both should be done in a subsequent PR though. Recording overhead is not much of a problem at the moment (at least with default event filters).

…ible.

… new API.

michaelwoerister · 2019-09-30T11:34:36Z

Rebased and typos fixed.

wesleywiser · 2019-09-30T12:04:40Z

@bors r+

bors · 2019-09-30T12:04:42Z

📌 Commit d942622 has been approved by wesleywiser

@wesleywiser

…i-refactor, r=wesleywiser SelfProfiler API refactoring and part one of event review This PR refactors the `SelfProfiler` a little bit so that most profiling methods are RAII-based. The codegen backend code already had something similar, this refactoring pulls this functionality up into `SelfProfiler` itself, for general use. The second commit of this PR is a review and update of the existing events we are already recording. Names have been made more consistent. CGU names have been removed from event names. They will be added back in when function parameter recording is implemented. There is still some work to be done for adding new events, especially around trait resolution and the incremental system. r? @wesleywiser

@wesleywiser

…i-refactor, r=wesleywiser SelfProfiler API refactoring and part one of event review This PR refactors the `SelfProfiler` a little bit so that most profiling methods are RAII-based. The codegen backend code already had something similar, this refactoring pulls this functionality up into `SelfProfiler` itself, for general use. The second commit of this PR is a review and update of the existing events we are already recording. Names have been made more consistent. CGU names have been removed from event names. They will be added back in when function parameter recording is implemented. There is still some work to be done for adding new events, especially around trait resolution and the incremental system. r? @wesleywiser

@wesleywiser

…i-refactor, r=wesleywiser SelfProfiler API refactoring and part one of event review This PR refactors the `SelfProfiler` a little bit so that most profiling methods are RAII-based. The codegen backend code already had something similar, this refactoring pulls this functionality up into `SelfProfiler` itself, for general use. The second commit of this PR is a review and update of the existing events we are already recording. Names have been made more consistent. CGU names have been removed from event names. They will be added back in when function parameter recording is implemented. There is still some work to be done for adding new events, especially around trait resolution and the incremental system. r? @wesleywiser

@wesleywiser

…i-refactor, r=wesleywiser SelfProfiler API refactoring and part one of event review This PR refactors the `SelfProfiler` a little bit so that most profiling methods are RAII-based. The codegen backend code already had something similar, this refactoring pulls this functionality up into `SelfProfiler` itself, for general use. The second commit of this PR is a review and update of the existing events we are already recording. Names have been made more consistent. CGU names have been removed from event names. They will be added back in when function parameter recording is implemented. There is still some work to be done for adding new events, especially around trait resolution and the incremental system. r? @wesleywiser

@ghost

Rollup of 11 pull requests Successful merges: - #64649 (Avoid ICE on return outside of fn with literal array) - #64722 (Make all alt builders produce parallel-enabled compilers) - #64801 (Avoid `chain()` in `find_constraint_paths_between_regions()`.) - #64805 (Still more `ObligationForest` improvements.) - #64840 (SelfProfiler API refactoring and part one of event review) - #64885 (use try_fold instead of try_for_each to reduce compile time) - #64942 (Fix clippy warnings) - #64952 (Update cargo.) - #64974 (Fix zebra-striping in generic dataflow visualization) - #64978 (Fully clear `HandlerInner` in `Handler::reset_err_count`) - #64979 (Update books) Failed merges: - #64959 (syntax: improve parameter without type suggestions) r? @ghost

andjo403 · 2019-10-05T18:07:44Z

src/librustc_codegen_ssa/back/write.rs

@@ -380,6 +323,9 @@ pub fn start_async_codegen<B: ExtraBackendMethods>(
 ) -> OngoingCodegen<B> {
    let (coordinator_send, coordinator_receive) = channel();
    let sess = tcx.sess;
+
+    sess.prof.generic_activity_start("codegen_and_optimize_crate");


this activity causes the events to get in the faulty order
i get a panic added som printout to see what event was the problem.

when I removed this trace it worked again

thread 'main' panicked at 'previous event on thread wasn't the start event , stopEvent Event { event_kind: "GenericActivity", label: "codegen_crate", additional_data: [], timestamp: SystemTime { tv_sec: 117, tv_nsec: 342291500 }, timestamp_kind: End, thread_id: 2 }, Event that do not match as a startEvent Event { event_kind: "GenericActivity", label: "codegen_and_optimize_crate", additional_data: [], timestamp: SystemTime { tv_sec: 62, tv_nsec: 748803800 }, timestamp_kind: Start, thread_id: 2 }', measureme/src/profiling_data.rs:140:

created #65137 to remove this event

I created #65137 to remove the event

@wesleywiser

…iser self-profiling: Add events for everything except trait selection. This is the followup PR to #64840. Trait selection events are still missing (at least those not covered by regular queries). r? @wesleywiser (or @Mark-Simulacrum if @wesleywiser is not available at the moment)

@wesleywiser

…-work-item-event-names, r=wesleywiser self-profiling: Remove module names from some event-ids in codegen backend. Event-IDs are not supposed to contain argument values. Event-IDs are the equivalent of function names. Proper support for parameters will be added to self-profiling down the line. This PR fixes an oversight from rust-lang#64840. r? @wesleywiser

@wesleywiser

…-work-item-event-names, r=wesleywiser self-profiling: Remove module names from some event-ids in codegen backend. Event-IDs are not supposed to contain argument values. Event-IDs are the equivalent of function names. Proper support for parameters will be added to self-profiling down the line. This PR fixes an oversight from rust-lang#64840. r? @wesleywiser

rust-highfive assigned wesleywiser Sep 27, 2019

rust-highfive added the S-waiting-on-review Status: Awaiting review from the assignee but also interested parties. label Sep 27, 2019

michaelwoerister force-pushed the self-profiling-raii-refactor branch from 5da752a to bb62d47 Compare September 27, 2019 12:59

wesleywiser reviewed Sep 28, 2019

View reviewed changes

michaelwoerister force-pushed the self-profiling-raii-refactor branch 2 times, most recently from 4c29a36 to 28de983 Compare September 30, 2019 11:29

michaelwoerister added 2 commits September 30, 2019 13:30

Self-Profiling: Refactor SelfProfiler API to be RAII based where poss…

b0b073c

…ible.

Self-Profiling: Make names of existing events more consistent and use…

d942622

… new API.

michaelwoerister force-pushed the self-profiling-raii-refactor branch from 28de983 to d942622 Compare September 30, 2019 11:34

wesleywiser approved these changes Sep 30, 2019

View reviewed changes

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 Sep 30, 2019

Centril mentioned this pull request Oct 1, 2019

Rollup of 4 pull requests #64951

Closed

Centril mentioned this pull request Oct 1, 2019

Rollup of 5 pull requests #64955

Closed

tmandry mentioned this pull request Oct 1, 2019

Rollup of 7 pull requests #64965

Closed

tmandry mentioned this pull request Oct 1, 2019

Rollup of 8 pull requests #64966

Closed

tmandry mentioned this pull request Oct 2, 2019

Rollup of 11 pull requests #64981

Merged

bors merged commit d942622 into rust-lang:master Oct 2, 2019

andjo403 reviewed Oct 5, 2019

View reviewed changes

michaelwoerister mentioned this pull request Oct 8, 2019

self-profiling: Add events for everything except trait selection. #65208

Merged

michaelwoerister mentioned this pull request Oct 22, 2019

self-profiling: Remove module names from some event-ids in codegen backend. #65695

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

SelfProfiler API refactoring and part one of event review #64840

SelfProfiler API refactoring and part one of event review #64840

michaelwoerister commented Sep 27, 2019

rust-highfive commented Sep 27, 2019

bors commented Sep 28, 2019

andjo403 commented Sep 28, 2019

wesleywiser Sep 28, 2019

michaelwoerister Sep 30, 2019 •

edited

Loading

wesleywiser Sep 28, 2019

michaelwoerister Sep 30, 2019

wesleywiser Sep 30, 2019

michaelwoerister commented Sep 30, 2019

michaelwoerister commented Sep 30, 2019

wesleywiser commented Sep 30, 2019

bors commented Sep 30, 2019

andjo403 Oct 5, 2019

andjo403 Oct 5, 2019

andjo403 Oct 5, 2019

SelfProfiler API refactoring and part one of event review #64840

SelfProfiler API refactoring and part one of event review #64840

Conversation

michaelwoerister commented Sep 27, 2019

rust-highfive commented Sep 27, 2019

bors commented Sep 28, 2019

andjo403 commented Sep 28, 2019

wesleywiser Sep 28, 2019

Choose a reason for hiding this comment

michaelwoerister Sep 30, 2019 • edited Loading

Choose a reason for hiding this comment

wesleywiser Sep 28, 2019

Choose a reason for hiding this comment

michaelwoerister Sep 30, 2019

Choose a reason for hiding this comment

wesleywiser Sep 30, 2019

Choose a reason for hiding this comment

michaelwoerister commented Sep 30, 2019

michaelwoerister commented Sep 30, 2019

wesleywiser commented Sep 30, 2019

bors commented Sep 30, 2019

andjo403 Oct 5, 2019

Choose a reason for hiding this comment

andjo403 Oct 5, 2019

Choose a reason for hiding this comment

andjo403 Oct 5, 2019

Choose a reason for hiding this comment

michaelwoerister Sep 30, 2019 •

edited

Loading