Enforce that query results implement Debug #80692

Aaron1011 · 2021-01-04T15:55:25Z

Currently, we require that query keys implement Debug, but we do not do the same for query values. This can make incremental compilation bugs difficult to debug - there isn't a good place to print out the result loaded from disk.

This PR adds Debug bounds to several query-related functions, allowing us to debug-print the query value when an 'unstable fingerprint' error occurs. This required adding #[derive(Debug)] to a fairly large number of types - hopefully, this doesn't have much of an impact on compiler bootstrapping times.

rust-highfive · 2021-01-04T15:55:28Z

r? @estebank

(rust-highfive has picked a reviewer for you, use r? to override)

Aaron1011 · 2021-01-04T15:56:09Z

@bors try @rust-timer queue

rust-timer · 2021-01-04T15:56:10Z

Awaiting bors try build completion.

bors · 2021-01-04T15:56:19Z

⌛ Trying commit 6294e9c904fa3c14aa1935385037f58ec8ec7793 with merge 3bf0928529d2653a392113783e402c573c81c8a8...

bors · 2021-01-04T16:46:02Z

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

rust-timer · 2021-01-04T16:46:04Z

Queued 3bf0928529d2653a392113783e402c573c81c8a8 with parent 6163bfd, future comparison URL.

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

rust-timer · 2021-01-04T20:23:42Z

Finished benchmarking try commit (3bf0928529d2653a392113783e402c573c81c8a8): comparison url.

Benchmarking this pull request likely means that it is perf-sensitive, so we're automatically marking it as not fit for rolling up. Please note that if the perf results are neutral, you should likely undo the rollup=never given below by specifying rollup- to bors.

Importantly, though, if the results of this run are non-neutral do not roll this PR up -- it will mask other regressions or improvements in the roll up.

@bors rollup=never
@rustbot label: +S-waiting-on-review -S-waiting-on-perf

Aaron1011 · 2021-01-04T20:29:09Z

The debug formatting of the value should only run when the assertion fails, which is never. I have no idea how adding a bunch of #[derive(Debug)]s managed to slow down the compiler - something to do with CGU partitioning?

cjgillot · 2021-01-05T20:40:14Z

Putting the bound on rustc_query_system::query::config::QueryConfig::{Value, Stored} may be simpler. You shouldn't need to add it in rustc_query_system::query::caches.

cjgillot · 2021-01-05T20:44:07Z

The debug formatting of the value should only run when the assertion fails, which is never. I have no idea how adding a bunch of #[derive(Debug)]s managed to slow down the compiler - something to do with CGU partitioning?

Changes in rustc_query_system tend to have an absurdly high impact, but those perf results take it to a whole new level.

estebank · 2021-01-08T02:01:42Z

I love how the regressions are all for incremental runs with no code changes (except externs-debug where it affects only full runs). 🙃

estebank · 2021-01-08T02:03:32Z

I'm unopposed to the change itself, but share the concern of compiling rustc timing after the change.

tgnottingham · 2021-01-08T05:12:28Z

If it's CGU partitioning, which seems plausible, you might rebase and see if you're luckier the next time around.

Aaron1011 · 2021-01-13T20:27:29Z

Let's see if things are any different with the latest master:

@bors try @rust-timer queue

rust-timer · 2021-01-13T20:27:30Z

Awaiting bors try build completion.

bors · 2021-01-13T20:27:39Z

⌛ Trying commit 6294e9c904fa3c14aa1935385037f58ec8ec7793 with merge 3e5e3a74a65f250eef3d36243bbcdf15bcbc454a...

bors · 2021-01-13T20:40:17Z

💔 Test failed - checks-actions

rust-log-analyzer · 2021-01-13T20:41:36Z

The job dist-x86_64-linux failed! Check out the build log: (web) (plain)

Click to see the possible cause of the failure (guessed by this bot)

   Compiling rustc_middle v0.0.0 (/checkout/compiler/rustc_middle)
   Compiling rustc_ast_passes v0.0.0 (/checkout/compiler/rustc_ast_passes)
   Compiling rustc_expand v0.0.0 (/checkout/compiler/rustc_expand)
   Compiling rustc_builtin_macros v0.0.0 (/checkout/compiler/rustc_builtin_macros)
error[E0277]: `DefIdForest` doesn't implement `std::fmt::Debug`
    --> compiler/rustc_middle/src/ty/query/plumbing.rs:519:36
     |
250  |  /    macro_rules! define_queries {
251  |  |        (<$tcx:tt>
252  |  |         $($(#[$attr:meta])*
253  |  |            [$($modifiers:tt)*] fn $name:ident($($K:tt)*) -> $V:ty,)*) => {
...     |
262  | /|            define_queries_struct! {
263  | ||                tcx: $tcx,
264  | ||                input: ($(([$($modifiers)*] [$($attr)*] [$name]))*)
265  | ||            }
     | ||____________- in this macro invocation (#3)
500  |  |        }
501  |  |    }
501  |  |    }
     |  |____- in this expansion of `define_queries!` (#2)
...
506  | /     macro_rules! define_queries_struct {
507  | |         (tcx: $tcx:tt,
508  | |          input: ($(([$($modifiers:tt)*] [$($attr:tt)*] [$name:ident]))*)) => {
509  | |             pub struct Queries<$tcx> {
...    |
519  |                   $($(#[$attr])*  $name: QueryState<
     |  ________________________________________^
520  |                       crate::dep_graph::DepKind,
521  |                       <TyCtxt<$tcx> as QueryContext>::Query,
522  |                       <queries::$name<$tcx> as QueryAccessors<TyCtxt<'tcx>>>::Cache,
523  | |                 >,)*
     | |_________________^ `DefIdForest` cannot be formatted using `{:?}`
556  | |         };
557  | |     }
557  | |     }
     | |_____- in this expansion of `define_queries_struct!` (#3)
     | 
    ::: compiler/rustc_middle/src/ty/query/mod.rs:104:1
     |
104  |       rustc_query_append! { [define_queries!][<'tcx>] }
     |       ------------------------------------------------- in this macro invocation (#1)
     | 
    ::: compiler/rustc_middle/src/query/mod.rs:37:1
     |
37   |     / rustc_queries! {
38   |     |     Other {
39   |     |         query trigger_delay_span_bug(key: DefId) -> () {
40   |     |             desc { "trigger a delay span bug" }
1690 |     |     }
1691 |     | }
     |     | -
     |     | |
     |     | |
     |     |_in this expansion of `rustc_query_append!` (#1)
     |       in this macro invocation (#2)
     |
     = help: the trait `std::fmt::Debug` is not implemented for `DefIdForest`
     = note: add `#[derive(Debug)]` or manually implement `std::fmt::Debug`
     = note: required because of the requirements on the impl of `QueryCache` for `rustc_query_system::query::caches::DefaultCache<ty::ParamEnvAnd<'_, &TyS<'_>>, DefIdForest>`

error[E0277]: `DefIdForest` doesn't implement `std::fmt::Debug`
    --> compiler/rustc_middle/src/ty/query/plumbing.rs:349:13
     |
250  |  /  macro_rules! define_queries {
251  |  |      (<$tcx:tt>
252  |  |       $($(#[$attr:meta])*
253  |  |          [$($modifiers:tt)*] fn $name:ident($($K:tt)*) -> $V:ty,)*) => {
...     |
349  | /|              type Stored = <
350  | ||                  query_storage!([$($modifiers)*][$($K)*, $V])
351  | ||                  as QueryStorage
352  | ||              >::Stored;
     | ||_______________________^ `DefIdForest` cannot be formatted using `{:?}`
500  |  |      }
501  |  |  }
501  |  |  }
     |  |__- in this expansion of `define_queries!` (#2)
     | 
    ::: compiler/rustc_middle/src/query/mod.rs:37:1
     |
37   |   / rustc_queries! {
38   |   |     Other {
39   |   |         query trigger_delay_span_bug(key: DefId) -> () {
40   |   |             desc { "trigger a delay span bug" }
1690 |   |     }
1691 |   | }
     |   | -
     |   | |
     |   | |
     |   |_in this expansion of `rustc_query_append!` (#1)
     |     in this macro invocation (#2)
     | 
    ::: compiler/rustc_middle/src/ty/query/mod.rs:104:1
     |
104  |     rustc_query_append! { [define_queries!][<'tcx>] }
     |     ------------------------------------------------- in this macro invocation (#1)
     |
     = help: the trait `std::fmt::Debug` is not implemented for `DefIdForest`
     = note: add `#[derive(Debug)]` or manually implement `std::fmt::Debug`
     = note: required because of the requirements on the impl of `rustc_query_system::query::QueryStorage` for `rustc_query_system::query::caches::DefaultCache<ty::ParamEnvAnd<'tcx, &'tcx TyS<'tcx>>, DefIdForest>`

error[E0277]: `DefIdForest` doesn't implement `std::fmt::Debug`
    --> compiler/rustc_middle/src/ty/query/plumbing.rs:364:54
     |
250  | /  macro_rules! define_queries {
251  | |      (<$tcx:tt>
252  | |       $($(#[$attr:meta])*
253  | |          [$($modifiers:tt)*] fn $name:ident($($K:tt)*) -> $V:ty,)*) => {
...    |
364  | |              fn query_state<'a>(tcx: TyCtxt<$tcx>) -> &'a QueryState<crate::dep_graph::DepKind, <TyCtxt<$tcx> as QueryContext>::Query, Self::Cache...
     | |                                                       ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ `DefIdForest` cannot be formatted using `{:?}`
500  | |      }
501  | |  }
501  | |  }
     | |__- in this expansion of `define_queries!` (#2)
     | 
    ::: compiler/rustc_middle/src/ty/query/mod.rs:104:1
     |
104  |    rustc_query_append! { [define_queries!][<'tcx>] }
     |    ------------------------------------------------- in this macro invocation (#1)
     | 
    ::: compiler/rustc_middle/src/query/mod.rs:37:1
     |
37   |  / rustc_queries! {
38   |  |     Other {
39   |  |         query trigger_delay_span_bug(key: DefId) -> () {
40   |  |             desc { "trigger a delay span bug" }
1690 |  |     }
1691 |  | }
     |  | -
     |  | |
     |  | |
     |  |_in this expansion of `rustc_query_append!` (#1)
     |    in this macro invocation (#2)
     |
     = help: the trait `std::fmt::Debug` is not implemented for `DefIdForest`
     = note: add `#[derive(Debug)]` or manually implement `std::fmt::Debug`
     = note: required because of the requirements on the impl of `QueryCache` for `rustc_query_system::query::caches::DefaultCache<ty::ParamEnvAnd<'_, &TyS<'_>>, DefIdForest>`

error[E0277]: `DefIdForest` doesn't implement `std::fmt::Debug`
    --> compiler/rustc_middle/src/ty/query/plumbing.rs:445:13
     |
250  |  /  macro_rules! define_queries {
251  |  |      (<$tcx:tt>
252  |  |       $($(#[$attr:meta])*
253  |  |          [$($modifiers:tt)*] fn $name:ident($($K:tt)*) -> $V:ty,)*) => {
...     |
445  | /|              pub fn $name(self, key: query_helper_param_ty!($($K)*))
446  | ||                  -> <queries::$name<$tcx> as QueryConfig>::Stored
447  | ||              {
448  | ||                  self.at(DUMMY_SP).$name(key.into_query_param())
449  | ||              })*
     | ||______________^ `DefIdForest` cannot be formatted using `{:?}`
500  |  |      }
501  |  |  }
501  |  |  }
     |  |__- in this expansion of `define_queries!` (#2)
     | 
    ::: compiler/rustc_middle/src/query/mod.rs:37:1
     |
37   |   / rustc_queries! {
38   |   |     Other {
39   |   |         query trigger_delay_span_bug(key: DefId) -> () {
40   |   |             desc { "trigger a delay span bug" }
1690 |   |     }
1691 |   | }
     |   | -
     |   | |
     |   | |
     |   |_in this expansion of `rustc_query_append!` (#1)
     |     in this macro invocation (#2)
     | 
    ::: compiler/rustc_middle/src/ty/query/mod.rs:104:1
     |
104  |     rustc_query_append! { [define_queries!][<'tcx>] }
     |     ------------------------------------------------- in this macro invocation (#1)
     |
     = help: the trait `std::fmt::Debug` is not implemented for `DefIdForest`
     = note: add `#[derive(Debug)]` or manually implement `std::fmt::Debug`
     = note: required because of the requirements on the impl of `rustc_query_system::query::QueryStorage` for `rustc_query_system::query::caches::DefaultCache<ty::ParamEnvAnd<'_, &TyS<'_>>, DefIdForest>`

error[E0277]: `DefIdForest` doesn't implement `std::fmt::Debug`
    --> compiler/rustc_middle/src/ty/query/plumbing.rs:484:13
     |
250  |  /  macro_rules! define_queries {
251  |  |      (<$tcx:tt>
252  |  |       $($(#[$attr:meta])*
253  |  |          [$($modifiers:tt)*] fn $name:ident($($K:tt)*) -> $V:ty,)*) => {
...     |
484  | /|              pub fn $name(self, key: query_helper_param_ty!($($K)*))
485  | ||                  -> <queries::$name<$tcx> as QueryConfig>::Stored
486  | ||              {
487  | ||                  get_query::<queries::$name<'_>, _>(self.tcx, self.span, key.into_query_param())
488  | ||              })*
     | ||______________^ `DefIdForest` cannot be formatted using `{:?}`
500  |  |      }
501  |  |  }
501  |  |  }
     |  |__- in this expansion of `define_queries!` (#2)
     | 
    ::: compiler/rustc_middle/src/query/mod.rs:37:1
     |
37   |   / rustc_queries! {
38   |   |     Other {
39   |   |         query trigger_delay_span_bug(key: DefId) -> () {
40   |   |             desc { "trigger a delay span bug" }
1690 |   |     }
1691 |   | }
     |   | -
     |   | |
     |   | |
     |   |_in this expansion of `rustc_query_append!` (#1)
     |     in this macro invocation (#2)
     | 
    ::: compiler/rustc_middle/src/ty/query/mod.rs:104:1
     |
104  |     rustc_query_append! { [define_queries!][<'tcx>] }
     |     ------------------------------------------------- in this macro invocation (#1)
     |
     = help: the trait `std::fmt::Debug` is not implemented for `DefIdForest`
     = note: add `#[derive(Debug)]` or manually implement `std::fmt::Debug`
     = note: required because of the requirements on the impl of `rustc_query_system::query::QueryStorage` for `rustc_query_system::query::caches::DefaultCache<ty::ParamEnvAnd<'_, &TyS<'_>>, DefIdForest>`
error: aborting due to 5 previous errors

For more information about this error, try `rustc --explain E0277`.
error: could not compile `rustc_middle`
error: could not compile `rustc_middle`

To learn more, run the command again with --verbose.
warning: build failed, waiting for other jobs to finish...
error: build failed
command did not execute successfully: "/checkout/obj/build/x86_64-unknown-linux-gnu/stage0/bin/cargo" "build" "--target" "x86_64-unknown-linux-gnu" "-Zbinary-dep-depinfo" "-j" "16" "--release" "--locked" "--color" "always" "--features" "jemalloc llvm max_level_info" "--manifest-path" "/checkout/compiler/rustc/Cargo.toml" "--message-format" "json-render-diagnostics"
failed to run: /checkout/obj/build/bootstrap/debug/bootstrap build --target=x86_64-unknown-linux-gnu --host=x86_64-unknown-linux-gnu --stage 2 library/std --rust-profile-generate=/tmp/rustc-pgo
Build completed unsuccessfully in 0:08:36

cjgillot · 2021-01-17T01:16:24Z

compiler/rustc_query_system/src/query/caches.rs

@@ -15,7 +15,7 @@ pub trait CacheSelector<K, V> {
 }

 pub trait QueryStorage: Default {
- type Value;
+ type Value: Debug;


Are bounds in this file necessary? Putting them on QueryConfig::Value should be enough.

rust-timer · 2021-01-17T02:32:53Z

Finished benchmarking try commit (c23f8d7d27456bf28becd5d64f41bcab2259a949): comparison url.

Benchmarking this pull request likely means that it is perf-sensitive, so we're automatically marking it as not fit for rolling up. Please note that if the perf results are neutral, you should likely undo the rollup=never given below by specifying rollup- to bors.

Importantly, though, if the results of this run are non-neutral do not roll this PR up -- it will mask other regressions or improvements in the roll up.

@bors rollup=never
@rustbot label: +S-waiting-on-review -S-waiting-on-perf

Aaron1011 · 2021-01-17T02:38:53Z

@bors try @rust-timer queue

rust-timer · 2021-01-17T02:38:55Z

Awaiting bors try build completion.

bors · 2021-01-17T02:39:04Z

⌛ Trying commit 056fbbf with merge 5fae81261f5ea323985073465c301d8fa35e7d93...

Aaron1011 · 2021-01-17T02:41:03Z

#79100 (comment) showed that the cold path of an assert! can have a significant performance impact, even when it's not executed. Let's see if just adding #[derive(Debug)] and Debug bounds has any impact.

bors · 2021-01-17T03:39:32Z

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

rust-timer · 2021-01-17T03:39:34Z

Queued 5fae81261f5ea323985073465c301d8fa35e7d93 with parent 2e46cb3, future comparison URL.

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

rust-timer · 2021-01-17T10:47:11Z

Finished benchmarking try commit (5fae81261f5ea323985073465c301d8fa35e7d93): comparison url.

Benchmarking this pull request likely means that it is perf-sensitive, so we're automatically marking it as not fit for rolling up. Please note that if the perf results are neutral, you should likely undo the rollup=never given below by specifying rollup- to bors.

Importantly, though, if the results of this run are non-neutral do not roll this PR up -- it will mask other regressions or improvements in the roll up.

@bors rollup=never
@rustbot label: +S-waiting-on-review -S-waiting-on-perf

Aaron1011 · 2021-01-17T19:44:50Z

There's still some perf changes, but they're much smaller, and hopefully just noise.

estebank · 2021-01-26T00:50:27Z

@bors r+

bors · 2021-01-26T00:50:29Z

📌 Commit 056fbbf has been approved by estebank

bors · 2021-01-26T05:47:29Z

⌛ Testing commit 056fbbf with merge a8f7075...

bors · 2021-01-26T08:42:39Z

☀️ Test successful - checks-actions
Approved by: estebank
Pushing a8f7075 to master...

Debug-print result when an unstable fingerprint is detected Helps with issues like rust-lang#83311 I had previously tried to do this in rust-lang#80692, but it had a significant performance impact (even though the code was never actually run). Hopefully, this will be better now that rust-lang#79100 has been merged.

rust-highfive assigned estebank Jan 4, 2021

rust-highfive added the S-waiting-on-review Status: Awaiting review from the assignee but also interested parties. label Jan 4, 2021

rustbot added the S-waiting-on-perf Status: Waiting on a perf run to be completed. label Jan 4, 2021

rustbot removed the S-waiting-on-perf Status: Waiting on a perf run to be completed. label Jan 4, 2021

bors 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 Jan 13, 2021

Aaron1011 added 4 commits January 16, 2021 17:53

Enforce that query results implement Debug

7afb325

Print result on unstable fingerprint error

93ab705

Run fmt

6417760

Implement Debug for DefIdForest

0295237

rustbot added the S-waiting-on-perf Status: Waiting on a perf run to be completed. label Jan 16, 2021

cjgillot reviewed Jan 17, 2021

View reviewed changes

rustbot 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 Jan 17, 2021

Undo assertion change

056fbbf

rustbot added the S-waiting-on-perf Status: Waiting on a perf run to be completed. label Jan 17, 2021

rustbot removed the S-waiting-on-perf Status: Waiting on a perf run to be completed. label Jan 17, 2021

bors added the merged-by-bors This PR was explicitly merged by bors. label Jan 26, 2021

bors merged commit a8f7075 into rust-lang:master Jan 26, 2021

rustbot added this to the 1.51.0 milestone Jan 26, 2021

Aaron1011 mentioned this pull request Mar 20, 2021

Debug-print result when an unstable fingerprint is detected #83314

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Enforce that query results implement Debug #80692

Enforce that query results implement Debug #80692

Aaron1011 commented Jan 4, 2021

rust-highfive commented Jan 4, 2021

Aaron1011 commented Jan 4, 2021

rust-timer commented Jan 4, 2021

bors commented Jan 4, 2021

bors commented Jan 4, 2021

rust-timer commented Jan 4, 2021

rust-timer commented Jan 4, 2021

Aaron1011 commented Jan 4, 2021

cjgillot commented Jan 5, 2021

cjgillot commented Jan 5, 2021

estebank commented Jan 8, 2021

estebank commented Jan 8, 2021

tgnottingham commented Jan 8, 2021

Aaron1011 commented Jan 13, 2021

rust-timer commented Jan 13, 2021

bors commented Jan 13, 2021

bors commented Jan 13, 2021

rust-log-analyzer commented Jan 13, 2021

cjgillot Jan 17, 2021

rust-timer commented Jan 17, 2021

Aaron1011 commented Jan 17, 2021

rust-timer commented Jan 17, 2021

bors commented Jan 17, 2021

Aaron1011 commented Jan 17, 2021

bors commented Jan 17, 2021

rust-timer commented Jan 17, 2021

rust-timer commented Jan 17, 2021

Aaron1011 commented Jan 17, 2021

estebank commented Jan 26, 2021

bors commented Jan 26, 2021

bors commented Jan 26, 2021

bors commented Jan 26, 2021

Enforce that query results implement Debug #80692

Enforce that query results implement Debug #80692

Conversation

Aaron1011 commented Jan 4, 2021

rust-highfive commented Jan 4, 2021

Aaron1011 commented Jan 4, 2021

rust-timer commented Jan 4, 2021

bors commented Jan 4, 2021

bors commented Jan 4, 2021

rust-timer commented Jan 4, 2021

rust-timer commented Jan 4, 2021

Aaron1011 commented Jan 4, 2021

cjgillot commented Jan 5, 2021

cjgillot commented Jan 5, 2021

estebank commented Jan 8, 2021

estebank commented Jan 8, 2021

tgnottingham commented Jan 8, 2021

Aaron1011 commented Jan 13, 2021

rust-timer commented Jan 13, 2021

bors commented Jan 13, 2021

bors commented Jan 13, 2021

rust-log-analyzer commented Jan 13, 2021

cjgillot Jan 17, 2021

Choose a reason for hiding this comment

rust-timer commented Jan 17, 2021

Aaron1011 commented Jan 17, 2021

rust-timer commented Jan 17, 2021

bors commented Jan 17, 2021

Aaron1011 commented Jan 17, 2021

bors commented Jan 17, 2021

rust-timer commented Jan 17, 2021

rust-timer commented Jan 17, 2021

Aaron1011 commented Jan 17, 2021

estebank commented Jan 26, 2021

bors commented Jan 26, 2021

bors commented Jan 26, 2021

bors commented Jan 26, 2021