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

bump tracing version #98626

Merged
merged 5 commits into from Aug 29, 2022
Merged

bump tracing version #98626

merged 5 commits into from Aug 29, 2022

Conversation

oli-obk
Copy link
Contributor

@oli-obk oli-obk commented Jun 28, 2022

Bump tracing dependency to 0.1.35 to give us features like printing the return value of functions

@rustbot rustbot added T-compiler Relevant to the compiler team, which will review and decide on the PR/issue. T-rustdoc Relevant to the rustdoc team, which will review and decide on the PR/issue. labels Jun 28, 2022
@rust-highfive
Copy link
Collaborator

r? @michaelwoerister

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

@rustbot
Copy link
Collaborator

rustbot commented Jun 28, 2022

Some changes occurred to the CTFE / Miri engine

cc @rust-lang/miri

@rust-highfive rust-highfive added the S-waiting-on-review Status: Awaiting review from the assignee but also interested parties. label Jun 28, 2022
@@ -291,7 +291,7 @@ pub enum InternKind {
/// tracks where in the value we are and thus can show much better error messages.
/// Any errors here would anyway be turned into `const_err` lints, whereas validation failures
/// are hard errors.
#[tracing::instrument(level = "debug", skip(ecx))]
#[instrument(level = "debug", skip(ecx))]
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'd prefer if the tracing in the interpreter used the trace level. Currently we make debug already so drowned in noise that we basically lose the entire point of even having that distinction.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This is just for keeping the previous thing. I would like for the default to be trace and then opt in a few to debug

@@ -531,7 +531,7 @@ macro_rules! define_queries_struct {

$($(#[$attr])*
#[inline(always)]
#[tracing::instrument(level = "trace", skip(self, tcx))]
#[tracing::instrument(level = "trace", skip(self, tcx), ret)]
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggested change
#[tracing::instrument(level = "trace", skip(self, tcx), ret)]
#[instrument(level = "trace", skip(self, tcx), ret)]

does that work?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

nope, the macro is invoked $somewhere else, and it's weird to have to add an import at the call site in order for the macro expansion to compile

ControlFlow::Break(FoundFlags)
} else {
ControlFlow::CONTINUE
}
}

#[inline]
#[instrument(level = "trace")]
#[instrument(skip(self), level = "trace", ret)]
fn visit_const(&mut self, c: ty::Const<'tcx>) -> ControlFlow<Self::BreakTy> {
let flags = FlagComputation::for_const(c);
trace!(r.flags=?flags);
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggested change
trace!(r.flags=?flags);
trace!(c.flags=?flags);

@lcnr
Copy link
Contributor

lcnr commented Jun 29, 2022

small nits, then r=me

r? @lcnr

@lcnr
Copy link
Contributor

lcnr commented Jun 29, 2022

@bors try @rust-timer queue

probably won't negatively impact perf, but better to be sure

@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 Jun 29, 2022
@bors
Copy link
Contributor

bors commented Jun 29, 2022

⌛ Trying commit d8dd65118a3e14df8ec1a9bf4e9389519f369d86 with merge 341e73079846b165ae541bfce020672a57c7ff78...

@bors
Copy link
Contributor

bors commented Jun 29, 2022

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

@rust-timer
Copy link
Collaborator

Queued 341e73079846b165ae541bfce020672a57c7ff78 with parent 493c960, future comparison URL.

@rust-timer
Copy link
Collaborator

Finished benchmarking commit (341e73079846b165ae541bfce020672a57c7ff78): comparison url.

Instruction count

  • Primary benchmarks: mixed results
  • Secondary benchmarks: mixed results
mean1 max count2
Regressions 😿
(primary)
1.7% 1.9% 2
Regressions 😿
(secondary)
2.9% 4.7% 9
Improvements 🎉
(primary)
-0.4% -0.5% 13
Improvements 🎉
(secondary)
-0.9% -2.0% 14
All 😿🎉 (primary) -0.1% 1.9% 15

Max RSS (memory usage)

Results
  • Primary benchmarks: 😿 relevant regression found
  • Secondary benchmarks: mixed results
mean1 max count2
Regressions 😿
(primary)
2.3% 2.3% 1
Regressions 😿
(secondary)
2.1% 2.1% 1
Improvements 🎉
(primary)
N/A N/A 0
Improvements 🎉
(secondary)
-2.2% -2.2% 1
All 😿🎉 (primary) 2.3% 2.3% 1

Cycles

Results
  • Primary benchmarks: no relevant changes found
  • Secondary benchmarks: mixed results
mean1 max count2
Regressions 😿
(primary)
N/A N/A 0
Regressions 😿
(secondary)
2.2% 2.2% 1
Improvements 🎉
(primary)
N/A N/A 0
Improvements 🎉
(secondary)
-2.4% -2.5% 2
All 😿🎉 (primary) N/A N/A 0

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

Benchmarking this pull request likely means that it is perf-sensitive, so we're automatically marking it as not fit for rolling up. While you can manually mark this PR as fit for rollup, we strongly recommend not doing so since this PR may lead to changes in compiler perf.

Next Steps: If you can justify the regressions found in this try perf run, please indicate this with @rustbot label: +perf-regression-triaged along with sufficient written justification. If you cannot justify the regressions please fix the regressions and do another perf run. If the next run shows neutral or positive results, the label will be automatically removed.

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

Footnotes

  1. the arithmetic mean of the percent change 2 3

  2. number of relevant changes 2 3

@rustbot rustbot added perf-regression Performance regression. and removed S-waiting-on-perf Status: Waiting on a perf run to be completed. labels Jun 29, 2022
@oli-obk
Copy link
Contributor Author

oli-obk commented Jun 30, 2022

both the keccak and the cranelift regression seem to be

<ObligationForest<PendingPredicateObligation>>::process_obligations::<FulfillProcessor, Outcome<PendingPredicateObligation, FulfillmentErrorCode>>

seems like the ret does affect some inlining decisions after all

@oli-obk
Copy link
Contributor Author

oli-obk commented Jun 30, 2022

@bors try @rust-timer queue include=cranelift,keccak

@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 Jun 30, 2022
@bors
Copy link
Contributor

bors commented Jun 30, 2022

⌛ Trying commit c7f5245e6ed0f142d33ca6d7ba747ebeee3c37fd with merge 7b2a49496c07afd88c5fc948d16d2557d78a9b3a...

@bors
Copy link
Contributor

bors commented Jun 30, 2022

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

@rust-timer
Copy link
Collaborator

Queued 7b2a49496c07afd88c5fc948d16d2557d78a9b3a with parent a9eb9c5, future comparison URL.

@oli-obk
Copy link
Contributor Author

oli-obk commented Jul 29, 2022

@bors try @rust-timer queue

@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 Jul 29, 2022
@bors
Copy link
Contributor

bors commented Jul 29, 2022

⌛ Trying commit a4375cb with merge dfe07b2522d238f735a246a7434d284316bf2749...

@bors
Copy link
Contributor

bors commented Jul 29, 2022

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

@rust-timer
Copy link
Collaborator

Queued dfe07b2522d238f735a246a7434d284316bf2749 with parent 9fa62f2, future comparison URL.

@rust-timer
Copy link
Collaborator

Finished benchmarking commit (dfe07b2522d238f735a246a7434d284316bf2749): comparison url.

Instruction count

  • Primary benchmarks: no relevant changes found
  • Secondary benchmarks: mixed results
mean1 max count2
Regressions 😿
(primary)
N/A N/A 0
Regressions 😿
(secondary)
1.1% 1.4% 8
Improvements 🎉
(primary)
N/A N/A 0
Improvements 🎉
(secondary)
-0.3% -0.3% 17
All 😿🎉 (primary) N/A N/A 0

Max RSS (memory usage)

Results
  • Primary benchmarks: no relevant changes found
  • Secondary benchmarks: 😿 relevant regressions found
mean1 max count2
Regressions 😿
(primary)
N/A N/A 0
Regressions 😿
(secondary)
3.0% 3.7% 3
Improvements 🎉
(primary)
N/A N/A 0
Improvements 🎉
(secondary)
N/A N/A 0
All 😿🎉 (primary) N/A N/A 0

Cycles

Results
  • Primary benchmarks: no relevant changes found
  • Secondary benchmarks: mixed results
mean1 max count2
Regressions 😿
(primary)
N/A N/A 0
Regressions 😿
(secondary)
3.8% 5.3% 3
Improvements 🎉
(primary)
N/A N/A 0
Improvements 🎉
(secondary)
-5.3% -5.8% 3
All 😿🎉 (primary) N/A N/A 0

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

Benchmarking this pull request likely means that it is perf-sensitive, so we're automatically marking it as not fit for rolling up. While you can manually mark this PR as fit for rollup, we strongly recommend not doing so since this PR may lead to changes in compiler perf.

Next Steps: If you can justify the regressions found in this try perf run, please indicate this with @rustbot label: +perf-regression-triaged along with sufficient written justification. If you cannot justify the regressions please fix the regressions and do another perf run. If the next run shows neutral or positive results, the label will be automatically removed.

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

Footnotes

  1. the arithmetic mean of the percent change 2 3

  2. number of relevant changes 2 3

@rustbot rustbot removed the S-waiting-on-perf Status: Waiting on a perf run to be completed. label Jul 29, 2022
@apiraino
Copy link
Contributor

apiraino commented Aug 4, 2022

If it's ok, I'll switch back on author for a comment on the latest perf run (PR itself is already r'ed).

@rustbot author

@rustbot rustbot 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 Aug 4, 2022
@oli-obk
Copy link
Contributor Author

oli-obk commented Aug 24, 2022

no clue what happened here, but maybe we should just take the perf hit until tracing figures out how to make #[instrument] literally be a nop instead of always creating a "trivially inlineable" function that still consumes inlining fuel in LLVM

 66,326,322  ???:<rustc_middle::ty::fold::RegionFolder as rustc_middle::ty::fold::FallibleTypeFolder>::try_fold_ty
-54,806,907  ???:<rustc_middle::ty::Ty as rustc_middle::ty::fold::TypeSuperFoldable>::super_fold_with::<rustc_middle::ty::fold::RegionFolder>
 27,816,815  ???:<rustc_middle::ty::fold::RegionFolder as rustc_middle::ty::fold::TypeFolder>::fold_ty
-23,058,283  ???:<rustc_middle::ty::Ty as rustc_middle::ty::fold::TypeSuperFoldable>::super_fold_with::<rustc_borrowck::region_infer::opaque_types::ReverseMapper>
 14,925,063  ???:<rustc_borrowck::region_infer::opaque_types::ReverseMapper as rustc_middle::ty::fold::TypeFolder>::fold_ty
-14,151,962  ???:rustc_middle::ty::util::fold_list::<rustc_middle::ty::fold::RegionFolder, rustc_middle::ty::Ty, <&rustc_middle::ty::list::List<rustc_middle::ty::Ty> as rustc_middle::ty::fold::TypeFoldable>::try_fold_with<rustc_middle::ty::fold::RegionFolder>::{closure
 10,735,356  ???:<&rustc_middle::ty::list::List<rustc_middle::ty::Ty> as rustc_middle::ty::fold::TypeFoldable>::try_fold_with::<rustc_middle::ty::fold::RegionFolder>
 -7,081,191  ???:rustc_middle::ty::util::fold_list::<rustc_borrowck::region_infer::opaque_types::ReverseMapper, rustc_middle::ty::Ty, <&rustc_middle::ty::list::List<rustc_middle::ty::Ty> as rustc_middle::ty::fold::TypeFoldable>::try_fold_with<rustc_borrowck::region_infer::opaque_types::ReverseMapper>::{closure
  6,362,614  ???:<&rustc_middle::ty::list::List<rustc_middle::ty::subst::GenericArg> as rustc_middle::ty::fold::TypeFoldable>::try_fold_with::<rustc_middle::ty::fold::RegionFolder>
  6,229,682  ???:<rustc_infer::infer::nll_relate::TypeGeneralizer<rustc_borrowck::type_check::relate_tys::NllTypeRelatingDelegate> as rustc_middle::ty::relate::TypeRelation>::relate_with_variance::<rustc_middle::ty::subst::GenericArg>
 -5,967,390  ???:core::iter::adapters::try_process::<core::iter::adapters::map::Map<core::iter::adapters::zip::Zip<core::iter::adapters::copied::Copied<core::slice::iter::Iter<rustc_middle::ty::subst::GenericArg>>, core::iter::adapters::copied::Copied<core::slice::iter::Iter<rustc_middle::ty::subst::GenericArg>>>, rustc_middle::ty::relate::relate_substs<rustc_infer::infer::nll_relate::TypeGeneralizer<rustc_borrowck::type_check::relate_tys::NllTypeRelatingDelegate>>::{closure
  5,114,388  ???:<&rustc_middle::ty::list::List<rustc_middle::ty::Ty> as rustc_middle::ty::fold::TypeFoldable>::try_fold_with::<rustc_borrowck::region_infer::opaque_types::ReverseMapper>
 -5,048,914  ???:rustc_middle::ty::util::fold_list::<rustc_middle::ty::fold::RegionFolder, rustc_middle::ty::subst::GenericArg, <&rustc_middle::ty::list::List<rustc_middle::ty::subst::GenericArg> as rustc_middle::ty::fold::TypeFoldable>::try_fold_with<rustc_middle::ty::fold::RegionFolder>::{closure
  4,983,754  ???:<smallvec::SmallVec<[rustc_middle::ty::subst::GenericArg; 8]> as core::iter::traits::collect::Extend<rustc_middle::ty::subst::GenericArg>>::extend::<core::iter::adapters::GenericShunt<core::iter::adapters::map::Map<core::iter::adapters::zip::Zip<core::iter::adapters::copied::Copied<core::slice::iter::Iter<rustc_middle::ty::subst::GenericArg>>, core::iter::adapters::copied::Copied<core::slice::iter::Iter<rustc_middle::ty::subst::GenericArg>>>, rustc_middle::ty::relate::relate_substs<rustc_infer::infer::nll_relate::TypeGeneralizer<rustc_borrowck::type_check::relate_tys::NllTypeRelatingDelegate>>::{closure
 -4,458,532  ???:core::iter::adapters::try_process::<core::iter::adapters::map::Map<core::iter::adapters::zip::Zip<core::iter::adapters::copied::Copied<core::slice::iter::Iter<rustc_middle::ty::Ty>>, core::iter::adapters::copied::Copied<core::slice::iter::Iter<rustc_middle::ty::Ty>>>, <rustc_middle::ty::relate::GeneratorWitness as rustc_middle::ty::relate::Relate>::relate<rustc_infer::infer::nll_relate::TypeGeneralizer<rustc_borrowck::type_check::relate_tys::NllTypeRelatingDelegate>>::{closure
  3,868,486  ???:<smallvec::SmallVec<[rustc_middle::ty::Ty; 8]> as core::iter::traits::collect::Extend<rustc_middle::ty::Ty>>::extend::<core::iter::adapters::GenericShunt<core::iter::adapters::map::Map<core::iter::adapters::zip::Zip<core::iter::adapters::copied::Copied<core::slice::iter::Iter<rustc_middle::ty::Ty>>, core::iter::adapters::copied::Copied<core::slice::iter::Iter<rustc_middle::ty::Ty>>>, <rustc_middle::ty::relate::GeneratorWitness as rustc_middle::ty::relate::Relate>::relate<rustc_infer::infer::nll_relate::TypeGeneralizer<rustc_borrowck::type_check::relate_tys::NllTypeRelatingDelegate>>::{closure
  1,835,880  ???:<core::iter::adapters::GenericShunt<core::iter::adapters::map::Map<core::iter::adapters::zip::Zip<core::iter::adapters::copied::Copied<core::slice::iter::Iter<rustc_middle::ty::Ty>>, core::iter::adapters::copied::Copied<core::slice::iter::Iter<rustc_middle::ty::Ty>>>, <rustc_middle::ty::relate::GeneratorWitness as rustc_middle::ty::relate::Relate>::relate<rustc_infer::infer::nll_relate::TypeGeneralizer<rustc_borrowck::type_check::relate_tys::NllTypeRelatingDelegate>>::{closure
  1,803,285  ???:<rustc_middle::ty::subst::GenericArg as rustc_middle::ty::fold::TypeFoldable>::fold_with::<rustc_borrowck::region_infer::opaque_types::ReverseMapper>
 -1,803,285  ???:<rustc_middle::ty::subst::GenericArg as rustc_middle::ty::fold::TypeFoldable>::try_fold_with::<rustc_borrowck::region_infer::opaque_types::ReverseMapper>
  1,309,944  ???:<rustc_middle::ty::subst::GenericArg as rustc_middle::ty::fold::TypeFoldable>::try_fold_with::<rustc_middle::ty::fold::RegionFolder>
 -1,305,124  ???:<rustc_middle::ty::Ty as rustc_middle::ty::fold::TypeFoldable>::fold_with::<rustc_middle::ty::fold::RegionFolder>

@lcnr
Copy link
Contributor

lcnr commented Aug 29, 2022

while unfortunate, I am fine with that 👍

r=me after updating the PR description (or actually adding the rest of your work back in 😁)

@oli-obk oli-obk changed the title tracing::instrument cleanup bump tracing version Aug 29, 2022
@oli-obk
Copy link
Contributor Author

oli-obk commented Aug 29, 2022

@bors r=lcnr

@bors
Copy link
Contributor

bors commented Aug 29, 2022

📌 Commit a4375cb has been approved by lcnr

It is now in the queue for this repository.

@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-author Status: This is awaiting some action (such as code changes or more information) from the author. labels Aug 29, 2022
@bors
Copy link
Contributor

bors commented Aug 29, 2022

⌛ Testing commit a4375cb with merge b96fa1a...

@bors
Copy link
Contributor

bors commented Aug 29, 2022

☀️ Test successful - checks-actions
Approved by: lcnr
Pushing b96fa1a to master...

@bors bors added the merged-by-bors This PR was explicitly merged by bors. label Aug 29, 2022
@bors bors merged commit b96fa1a into rust-lang:master Aug 29, 2022
@rustbot rustbot added this to the 1.65.0 milestone Aug 29, 2022
@rust-timer
Copy link
Collaborator

Finished benchmarking commit (b96fa1a): comparison URL.

Overall result: ✅ improvements - no action needed

@rustbot label: -perf-regression

Instruction count

This is a highly reliable metric that was used to determine the overall result at the top of this comment.

mean1 range count2
Regressions ❌
(primary)
- - 0
Regressions ❌
(secondary)
- - 0
Improvements ✅
(primary)
- - 0
Improvements ✅
(secondary)
-1.2% [-1.2%, -1.2%] 2
All ❌✅ (primary) - - 0

Max RSS (memory usage)

Results

This is a less reliable metric that may be of interest but was not used to determine the overall result at the top of this comment.

mean1 range count2
Regressions ❌
(primary)
- - 0
Regressions ❌
(secondary)
- - 0
Improvements ✅
(primary)
-2.5% [-2.5%, -2.5%] 1
Improvements ✅
(secondary)
- - 0
All ❌✅ (primary) -2.5% [-2.5%, -2.5%] 1

Cycles

Results

This is a less reliable metric that may be of interest but was not used to determine the overall result at the top of this comment.

mean1 range count2
Regressions ❌
(primary)
- - 0
Regressions ❌
(secondary)
4.1% [4.1%, 4.1%] 1
Improvements ✅
(primary)
-5.4% [-5.4%, -5.4%] 1
Improvements ✅
(secondary)
- - 0
All ❌✅ (primary) -5.4% [-5.4%, -5.4%] 1

Footnotes

  1. the arithmetic mean of the percent change 2 3

  2. number of relevant changes 2 3

@rustbot rustbot removed the perf-regression Performance regression. label Aug 29, 2022
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. T-compiler Relevant to the compiler team, which will review and decide on the PR/issue. T-rustdoc Relevant to the rustdoc team, which will review and decide on the PR/issue.
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

10 participants