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

Fix how the RUSTC_CTFE_BACKTRACE env var is gotten. #68792

Closed

Conversation

nnethercote
Copy link
Contributor

This environment variable is currently obtained very frequently in
CTFE-heavy code; using lazy_static avoids repeating the work.

For the ctfe-stress-4 benchmark this eliminates 67% of allocations
done, and for coercions it eliminates 17% of allocations done.

r? @RalfJung

This environment variable is currently obtained very frequently in
CTFE-heavy code; using `lazy_static` avoids repeating the work.

For the `ctfe-stress-4` benchmark this eliminates 67% of allocations
done, and for `coercions` it eliminates 17% of allocations done.
@rust-highfive rust-highfive added the S-waiting-on-review Status: Awaiting review from the assignee but also interested parties. label Feb 3, 2020
@nnethercote
Copy link
Contributor Author

@bors try @rust-timer queue

@bors
Copy link
Contributor

bors commented Feb 3, 2020

⌛ Trying commit 15dcf1f with merge c5dab8b1f4945c397a8affdd72965ce2b921ec83...

@bors
Copy link
Contributor

bors commented Feb 3, 2020

☀️ Try build successful - checks-azure
Build commit: c5dab8b1f4945c397a8affdd72965ce2b921ec83 (c5dab8b1f4945c397a8affdd72965ce2b921ec83)

@RalfJung
Copy link
Member

RalfJung commented Feb 3, 2020

Hm.. the issue is, Miri relies on changing this env var between MIR generation and running the interpreter. When working on Miri, I'd like backtraces only for Miri-related errors, not for CTFE-related errors.

Cc @oli-obk

@RalfJung
Copy link
Member

RalfJung commented Feb 3, 2020

For the ctfe-stress-4 benchmark this eliminates 67% of allocations
done, and for coercions it eliminates 17% of allocations done.

What the heck is going on there that so many interpreter errors are being raised? My first guess would be const-prop (Cc @wesleywiser). I am beginning to wonder if having many thousand interpreter errors raised during successful compilation is good design...

@oli-obk
Copy link
Contributor

oli-obk commented Feb 3, 2020

The alternative design is to basically duplicate all interpreter logic. I'm not sure how design this differently other than making the error type a generic part of the machine.

@RalfJung
Copy link
Member

RalfJung commented Feb 3, 2020

Can the error constructor somehow figure out if it is run in a CTFE query or in "main" Miri? To my understanding, queries already use thread-local state for some amount of tracking, so this could maybe tie into that.

@oli-obk
Copy link
Contributor

oli-obk commented Feb 3, 2020

well... that basically boils down to the above, but making the thread local global publically configurable

@wesleywiser
Copy link
Member

Could we add a function to the Machine trait which performs this check? Const prop could implement that to always return false and Miri could implement it to return true (or whatever behavior is appropriate for Miri).

@RalfJung
Copy link
Member

RalfJung commented Feb 3, 2020

The thing is, the conversion function doesn't have access to the Machine. And making InterpError extensible by the Machine would massively infect everything, so that doesn't seem great either.

@oli-obk I am not sure what you are saying my proposal boils down to. For now, I still think something involving TLS is the least ugly of the solutions proposed so far.

@oli-obk
Copy link
Contributor

oli-obk commented Feb 3, 2020

I'm thinking that we could add a function taking a closure that sets a thread local turning off backtraces and once the closure finishes, clears that thread local. Then const prop could invoke miri somewhat like

miri_backtrace_helper(|| ecx.some_code())

and all the code in some_code will see the global configured to not emit backtraces, and once outside of that closure, it's back to normal. Though we should take care to make the const eval query invert that again, otherwise we lose actual instances where we want backtraces.

@nnethercote
Copy link
Contributor Author

@rust-timer build c5dab8b1f4945c397a8affdd72965ce2b921ec83

@rust-timer
Copy link
Collaborator

Queued c5dab8b1f4945c397a8affdd72965ce2b921ec83 with parent 01db581, future comparison URL.

@nnethercote
Copy link
Contributor Author

What the heck is going on there that so many interpreter errors are being raised? My first guess would be const-prop (Cc @wesleywiser).

For ctfe-stress-4 it's almost entirely errors of the form "tried to treat a memory pointer as a function pointer".

I'm happy to close this PR because I can see that it's not the right approach. But this is a big perf hit for CTFE and should be fixed. @RalfJung, are you happy to take over? I can file an issue if that would be helpful.

@wesleywiser
Copy link
Member

If there's a chosen approach that's better than this, I would be happy to take this over and implement it.

@RalfJung
Copy link
Member

RalfJung commented Feb 3, 2020

I'm afraid I don't have much time I can invest into this. But I agree we should find some fix, and it looks like @wesleywiser is willing to do the implementation work once we found something resembling a solution.

Then const prop could invoke miri somewhat like
[...] const eval [...]

Right, so we actually have three possible contexts for Miri: const eval, const prop, stand-alone. And ideally we'd want to treat them all separately. This does feel like a Machine thing, but unfortunately InterpCx doesn't have a single well-defined entry point we could use for this...

Is there a way to identify the "active query", so that we could test whether that is const-eval, const-prop, or something else, without having to introduce our own (and, strictly speaking, redundant) tracking?

@RalfJung
Copy link
Member

RalfJung commented Feb 5, 2020

So, would that be a reasonable approach? Or would it be too fragile?

@oli-obk
Copy link
Contributor

oli-obk commented Feb 10, 2020

No, it seems like a reasonable solution, but should have some big comments on it stating that this information may only be used for backtracing or diagnostics.

@wesleywiser
Copy link
Member

I will work on that this week.

@nnethercote
Copy link
Contributor Author

I will close this PR because it's not the right approach. I look forward to seeing @wesleywiser's alternative :)

@wesleywiser
Copy link
Member

Interestingly, the vast majority of errors do not seem to be coming from const-prop. So checking what the active query is doesn't make a noticeable difference in terms of performance.

@oli-obk @RalfJung what do you think of this approach instead? This seems to recover all of the performance of this PR and miri can still setup its loggers here by setting compiler.tcx.sess.ctfe_backtrace.

@RalfJung
Copy link
Member

@wesleywiser where else do they come from?

The problem with ctfe_backtrace is that in a Miri execution, there are interleaved evaluates of const-eval queries. Ideally those would not be affected. (That would be better than what the current env var scheme achieves.)
But if the query-based approach does not work out, that could indeed be a viable fall-back -- it is at least no worse than the current approach.

@wesleywiser
Copy link
Member

I instrumented the function to dump the query stack at the time the function is called. Here's the results:

Count Stack
5767192 const_eval_raw, const_eval_validated, const_eval_validated, analysis
270 optimized_mir, const_eval_raw, const_eval_validated, const_eval_validated, analysis
144 const_eval_raw, const_eval_validated, const_eval_validated, optimized_mir, const_eval_raw, const_eval_validated, const_eval_validated, analysis
43 const_eval_validated, const_eval_validated, analysis
6 const_eval_validated, const_eval_validated, check_item_well_formed, analysis
3 const_eval_validated, const_eval_validated, typeck_tables_of, check_mod_item_types, analysis
2 const_eval_raw, const_eval_raw, const_eval_validated, const_eval_validated, analysis

Backtrace for the top group:

An error occurred in miri:
stack backtrace:
   0: <rustc::mir::interpret::error::InterpErrorInfo as core::convert::From<rustc::mir::interpret::error::InterpError>>::from
             at src/librustc/mir/interpret/error.rs:248
   1: <T as core::convert::Into<U>>::into
             at src/libcore/convert/mod.rs:558
      rustc_mir::interpret::memory::Memory<M>::get_fn_alloc
             at src/librustc_mir/interpret/memory.rs:612
   2: rustc_mir::interpret::memory::Memory<M>::get_size_and_align
             at src/librustc_mir/interpret/memory.rs:563
   3: rustc_mir::interpret::memory::Memory<M>::check_ptr_access_align
             at src/librustc_mir/interpret/memory.rs:372
   4: rustc_mir::interpret::memory::Memory<M>::check_ptr_access
             at src/librustc_mir/interpret/memory.rs:321
      rustc_mir::interpret::place::<impl rustc_mir::interpret::eval_context::InterpCx<M>>::check_mplace_access
             at src/librustc_mir/interpret/place.rs:359
      rustc_mir::interpret::operand::<impl rustc_mir::interpret::eval_context::InterpCx<M>>::try_read_immediate_from_mplace
             at src/librustc_mir/interpret/operand.rs:263
      rustc_mir::interpret::operand::<impl rustc_mir::interpret::eval_context::InterpCx<M>>::try_read_immediate
             at src/librustc_mir/interpret/operand.rs:316
   5: rustc_mir::interpret::place::<impl rustc_mir::interpret::eval_context::InterpCx<M>>::copy_op_no_validate
             at src/librustc_mir/interpret/place.rs:863
   6: rustc_mir::interpret::place::<impl rustc_mir::interpret::eval_context::InterpCx<M>>::copy_op
             at src/librustc_mir/interpret/place.rs:834
      rustc_mir::interpret::step::<impl rustc_mir::interpret::eval_context::InterpCx<M>>::eval_rvalue_into_place
             at src/librustc_mir/interpret/step.rs:150
   7: rustc_mir::interpret::step::<impl rustc_mir::interpret::eval_context::InterpCx<M>>::statement
             at src/librustc_mir/interpret/step.rs:91
      rustc_mir::interpret::step::<impl rustc_mir::interpret::eval_context::InterpCx<M>>::step
             at src/librustc_mir/interpret/step.rs:67
      rustc_mir::interpret::step::<impl rustc_mir::interpret::eval_context::InterpCx<M>>::run
             at src/librustc_mir/interpret/step.rs:34
   8: rustc_mir::const_eval::eval_queries::eval_body_using_ecx
             at src/librustc_mir/const_eval/eval_queries.rs:56
      rustc_mir::const_eval::eval_queries::const_eval_raw_provider::{{closure}}
             at src/librustc_mir/const_eval/eval_queries.rs:306
      core::result::Result<T,E>::and_then
             at src/libcore/result.rs:727
      rustc_mir::const_eval::eval_queries::const_eval_raw_provider
             at src/librustc_mir/const_eval/eval_queries.rs:306
   9: rustc::ty::query::<impl rustc::ty::query::config::QueryAccessors for rustc::ty::query::queries::const_eval_raw>::compute::{{closure}}
             at src/librustc/ty/query/plumbing.rs:951
      rustc::ty::query::__query_compute::const_eval_raw
             at src/librustc/ty/query/plumbing.rs:902
  10: rustc::ty::query::<impl rustc::ty::query::config::QueryAccessors for rustc::ty::query::queries::const_eval_raw>::compute
             at src/librustc/ty/query/plumbing.rs:943
  11: rustc::dep_graph::graph::DepGraph::with_task_impl
             at src/librustc/dep_graph/graph.rs:341
      rustc::dep_graph::graph::DepGraph::with_task
             at src/librustc/dep_graph/graph.rs:209
  12: rustc::ty::query::plumbing::<impl rustc::ty::context::TyCtxt>::force_query_with_job::{{closure}}::{{closure}}
             at src/librustc/ty/query/plumbing.rs:557
      rustc::ty::query::plumbing::<impl rustc::ty::context::TyCtxt>::start_query::{{closure}}::{{closure}}
             at src/librustc/ty/query/plumbing.rs:278
      rustc::ty::context::tls::enter_context::{{closure}}
             at src/librustc/ty/context.rs:1697
      rustc::ty::context::tls::set_tlv
             at src/librustc/ty/context.rs:1682
      rustc::ty::context::tls::enter_context
             at src/librustc/ty/context.rs:1697
      rustc::ty::query::plumbing::<impl rustc::ty::context::TyCtxt>::start_query::{{closure}}
             at src/librustc/ty/query/plumbing.rs:278
      rustc::ty::context::tls::with_related_context::{{closure}}
             at src/librustc/ty/context.rs:1785
      rustc::ty::context::tls::with_context::{{closure}}
             at src/librustc/ty/context.rs:1769
      rustc::ty::context::tls::with_context_opt
             at src/librustc/ty/context.rs:1758
      rustc::ty::context::tls::with_context
             at src/librustc/ty/context.rs:1769
      rustc::ty::context::tls::with_related_context
             at src/librustc/ty/context.rs:1782
      rustc::ty::query::plumbing::<impl rustc::ty::context::TyCtxt>::start_query
             at src/librustc/ty/query/plumbing.rs:267
      rustc::ty::query::plumbing::<impl rustc::ty::context::TyCtxt>::force_query_with_job::{{closure}}
             at src/librustc/ty/query/plumbing.rs:547
      rustc::ty::query::plumbing::with_diagnostics
             at src/librustc/ty/query/plumbing.rs:212
      rustc::ty::query::plumbing::<impl rustc::ty::context::TyCtxt>::force_query_with_job
             at src/librustc/ty/query/plumbing.rs:546
      rustc::ty::query::plumbing::<impl rustc::ty::context::TyCtxt>::get_query
             at src/librustc/ty/query/plumbing.rs:380
  13: rustc::ty::query::TyCtxtAt::const_eval_raw
             at src/librustc/ty/query/plumbing.rs:1057
      rustc::ty::query::<impl rustc::ty::context::TyCtxt>::const_eval_raw
             at src/librustc/ty/query/plumbing.rs:1020
      rustc_mir::const_eval::eval_queries::const_eval_validated_provider
             at src/librustc_mir/const_eval/eval_queries.rs:253
  14: rustc::ty::query::<impl rustc::ty::query::config::QueryAccessors for rustc::ty::query::queries::const_eval_validated>::compute::{{closure}}
             at src/librustc/ty/query/plumbing.rs:951
      rustc::ty::query::__query_compute::const_eval_validated
             at src/librustc/ty/query/plumbing.rs:902
  15: rustc::ty::query::<impl rustc::ty::query::config::QueryAccessors for rustc::ty::query::queries::const_eval_validated>::compute
             at src/librustc/ty/query/plumbing.rs:943
  16: rustc::dep_graph::graph::DepGraph::with_task_impl
             at src/librustc/dep_graph/graph.rs:341
      rustc::dep_graph::graph::DepGraph::with_task
             at src/librustc/dep_graph/graph.rs:209
  17: rustc::ty::query::plumbing::<impl rustc::ty::context::TyCtxt>::force_query_with_job::{{closure}}::{{closure}}
             at src/librustc/ty/query/plumbing.rs:557
      rustc::ty::query::plumbing::<impl rustc::ty::context::TyCtxt>::start_query::{{closure}}::{{closure}}
             at src/librustc/ty/query/plumbing.rs:278
      rustc::ty::context::tls::enter_context::{{closure}}
             at src/librustc/ty/context.rs:1697
      rustc::ty::context::tls::set_tlv
             at src/librustc/ty/context.rs:1682
      rustc::ty::context::tls::enter_context
             at src/librustc/ty/context.rs:1697
      rustc::ty::query::plumbing::<impl rustc::ty::context::TyCtxt>::start_query::{{closure}}
             at src/librustc/ty/query/plumbing.rs:278
      rustc::ty::context::tls::with_related_context::{{closure}}
             at src/librustc/ty/context.rs:1785
      rustc::ty::context::tls::with_context::{{closure}}
             at src/librustc/ty/context.rs:1769
      rustc::ty::context::tls::with_context_opt
             at src/librustc/ty/context.rs:1758
      rustc::ty::context::tls::with_context
             at src/librustc/ty/context.rs:1769
      rustc::ty::context::tls::with_related_context
             at src/librustc/ty/context.rs:1782
      rustc::ty::query::plumbing::<impl rustc::ty::context::TyCtxt>::start_query
             at src/librustc/ty/query/plumbing.rs:267
      rustc::ty::query::plumbing::<impl rustc::ty::context::TyCtxt>::force_query_with_job::{{closure}}
             at src/librustc/ty/query/plumbing.rs:547
      rustc::ty::query::plumbing::with_diagnostics
             at src/librustc/ty/query/plumbing.rs:212
      rustc::ty::query::plumbing::<impl rustc::ty::context::TyCtxt>::force_query_with_job
             at src/librustc/ty/query/plumbing.rs:546
      rustc::ty::query::plumbing::<impl rustc::ty::context::TyCtxt>::get_query
             at src/librustc/ty/query/plumbing.rs:380
  18: rustc::ty::query::TyCtxtAt::const_eval_validated
             at src/librustc/ty/query/plumbing.rs:1057
      rustc::ty::query::<impl rustc::ty::context::TyCtxt>::const_eval_validated
             at src/librustc/ty/query/plumbing.rs:1020
      rustc_mir::const_eval::eval_queries::const_eval_validated_provider
             at src/librustc_mir/const_eval/eval_queries.rs:230
  19: rustc::ty::query::<impl rustc::ty::query::config::QueryAccessors for rustc::ty::query::queries::const_eval_validated>::compute::{{closure}}
             at src/librustc/ty/query/plumbing.rs:951
      rustc::ty::query::__query_compute::const_eval_validated
             at src/librustc/ty/query/plumbing.rs:902
  20: rustc::ty::query::<impl rustc::ty::query::config::QueryAccessors for rustc::ty::query::queries::const_eval_validated>::compute
             at src/librustc/ty/query/plumbing.rs:943
  21: rustc::dep_graph::graph::DepGraph::with_task_impl
             at src/librustc/dep_graph/graph.rs:341
      rustc::dep_graph::graph::DepGraph::with_task
             at src/librustc/dep_graph/graph.rs:209
  22: rustc::ty::query::plumbing::<impl rustc::ty::context::TyCtxt>::force_query_with_job::{{closure}}::{{closure}}
             at src/librustc/ty/query/plumbing.rs:557
      rustc::ty::query::plumbing::<impl rustc::ty::context::TyCtxt>::start_query::{{closure}}::{{closure}}
             at src/librustc/ty/query/plumbing.rs:278
      rustc::ty::context::tls::enter_context::{{closure}}
             at src/librustc/ty/context.rs:1697
      rustc::ty::context::tls::set_tlv
             at src/librustc/ty/context.rs:1682
      rustc::ty::context::tls::enter_context
             at src/librustc/ty/context.rs:1697
      rustc::ty::query::plumbing::<impl rustc::ty::context::TyCtxt>::start_query::{{closure}}
             at src/librustc/ty/query/plumbing.rs:278
      rustc::ty::context::tls::with_related_context::{{closure}}
             at src/librustc/ty/context.rs:1785
      rustc::ty::context::tls::with_context::{{closure}}
             at src/librustc/ty/context.rs:1769
      rustc::ty::context::tls::with_context_opt
             at src/librustc/ty/context.rs:1758
      rustc::ty::context::tls::with_context
             at src/librustc/ty/context.rs:1769
      rustc::ty::context::tls::with_related_context
             at src/librustc/ty/context.rs:1782
      rustc::ty::query::plumbing::<impl rustc::ty::context::TyCtxt>::start_query
             at src/librustc/ty/query/plumbing.rs:267
      rustc::ty::query::plumbing::<impl rustc::ty::context::TyCtxt>::force_query_with_job::{{closure}}
             at src/librustc/ty/query/plumbing.rs:547
      rustc::ty::query::plumbing::with_diagnostics
             at src/librustc/ty/query/plumbing.rs:212
      rustc::ty::query::plumbing::<impl rustc::ty::context::TyCtxt>::force_query_with_job
             at src/librustc/ty/query/plumbing.rs:546
      rustc::ty::query::plumbing::<impl rustc::ty::context::TyCtxt>::get_query
             at src/librustc/ty/query/plumbing.rs:380
  23: rustc::ty::query::TyCtxtAt::const_eval_validated
             at src/librustc/ty/query/plumbing.rs:1057
      rustc::ty::query::<impl rustc::ty::context::TyCtxt>::const_eval_validated
             at src/librustc/ty/query/plumbing.rs:1020
      rustc::mir::interpret::queries::<impl rustc::ty::context::TyCtxt>::const_eval_poly
             at src/librustc/mir/interpret/queries.rs:22
  24: <rustc_lint::builtin::UnusedBrokenConst as rustc_lint::passes::LateLintPass>::check_item
             at src/librustc_lint/builtin.rs:0
  25: <rustc_lint::BuiltinCombinedLateLintPass as rustc_lint::passes::LateLintPass>::check_item
             at src/librustc_lint/passes.rs:113
  26: <rustc_lint::late::LateContextAndPass<T> as rustc_hir::intravisit::Visitor>::visit_item::{{closure}}::{{closure}}
             at src/librustc_lint/late.rs:42
      rustc_lint::late::LateContextAndPass<T>::with_param_env
             at src/librustc_lint/late.rs:73
      <rustc_lint::late::LateContextAndPass<T> as rustc_hir::intravisit::Visitor>::visit_item::{{closure}}
             at src/librustc_lint/late.rs:131
      rustc_lint::late::LateContextAndPass<T>::with_lint_attrs
             at src/librustc_lint/late.rs:61
      <rustc_lint::late::LateContextAndPass<T> as rustc_hir::intravisit::Visitor>::visit_item
             at src/librustc_lint/late.rs:130
      rustc_hir::intravisit::Visitor::visit_nested_item
             at <::syntax::visit::walk_list macros>:2
  27: rustc_hir::intravisit::walk_mod
             at src/librustc_hir/intravisit.rs:455
  28: rustc_lint::late::LateContextAndPass<T>::process_mod
             at src/librustc_lint/late.rs:79
      <rustc_lint::late::LateContextAndPass<T> as rustc_hir::intravisit::Visitor>::visit_mod
             at src/librustc_lint/late.rs:236
  29: rustc_hir::intravisit::walk_crate
             at src/librustc_hir/intravisit.rs:441
  30: rustc_lint::late::late_lint_pass_crate::{{closure}}
             at src/librustc_lint/late.rs:427
      rustc_lint::late::LateContextAndPass<T>::with_lint_attrs
             at src/librustc_lint/late.rs:61
      rustc_lint::late::late_lint_pass_crate
             at src/librustc_lint/late.rs:422
      rustc_lint::late::late_lint_crate
             at src/librustc_lint/late.rs:441
  31: rustc_lint::late::check_crate::{{closure}}::{{closure}}
             at src/librustc_lint/late.rs:471
      rustc_data_structures::profiling::VerboseTimingGuard::run
             at src/librustc_data_structures/profiling.rs:555
      rustc_session::utils::<impl rustc_session::session::Session>::time
             at src/librustc_session/utils.rs:9
  32: rustc_lint::late::check_crate::{{closure}}
             at src/librustc_lint/late.rs:469
      rustc_data_structures::sync::join
             at src/librustc_data_structures/sync.rs:160
  33: rustc_lint::late::check_crate
             at src/librustc_lint/late.rs:467
      rustc_interface::passes::analysis::{{closure}}::{{closure}}::{{closure}}::{{closure}}
             at src/librustc_interface/passes.rs:866
      rustc_data_structures::profiling::VerboseTimingGuard::run
             at src/librustc_data_structures/profiling.rs:555
      rustc_session::utils::<impl rustc_session::session::Session>::time
             at src/librustc_session/utils.rs:9
  34: rustc_interface::passes::analysis::{{closure}}::{{closure}}::{{closure}}
             at src/librustc_interface/passes.rs:865
      core::ops::function::FnOnce::call_once
             at src/libcore/ops/function.rs:232
      <std::panic::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once
             at src/libstd/panic.rs:318
      std::panicking::try::do_call
             at src/libstd/panicking.rs:303
  35: __rust_maybe_catch_panic
             at src/libpanic_unwind/lib.rs:86
  36: std::panicking::try
             at src/libstd/panicking.rs:281
  37: std::panic::catch_unwind
             at src/libstd/panic.rs:394
      rustc_interface::passes::analysis::{{closure}}::{{closure}}
             at src/librustc_interface/passes.rs:852
      core::ops::function::FnOnce::call_once
             at src/libcore/ops/function.rs:232
      <std::panic::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once
             at src/libstd/panic.rs:318
  38: std::panicking::try::do_call
             at src/libstd/panicking.rs:303
  39: __rust_maybe_catch_panic
             at src/libpanic_unwind/lib.rs:86
  40: std::panicking::try
             at src/libstd/panicking.rs:281
  41: std::panic::catch_unwind
             at src/libstd/panic.rs:394
      rustc_interface::passes::analysis::{{closure}}
             at src/librustc_interface/passes.rs:848
      rustc_data_structures::profiling::VerboseTimingGuard::run
             at src/librustc_data_structures/profiling.rs:555
      rustc_session::utils::<impl rustc_session::session::Session>::time
             at src/librustc_session/utils.rs:9
  42: rustc_interface::passes::analysis
             at src/librustc_interface/passes.rs:847
  43: rustc::ty::query::<impl rustc::ty::query::config::QueryAccessors for rustc::ty::query::queries::analysis>::compute::{{closure}}
             at src/librustc/ty/query/plumbing.rs:951
      rustc::ty::query::__query_compute::analysis
             at src/librustc/ty/query/plumbing.rs:902
  44: rustc::dep_graph::graph::DepGraph::with_task_impl
             at src/librustc/dep_graph/graph.rs:341
      rustc::dep_graph::graph::DepGraph::with_eval_always_task
             at src/librustc/dep_graph/graph.rs:388
  45: rustc::ty::query::plumbing::<impl rustc::ty::context::TyCtxt>::force_query_with_job::{{closure}}::{{closure}}
             at src/librustc/ty/query/plumbing.rs:549
      rustc::ty::query::plumbing::<impl rustc::ty::context::TyCtxt>::start_query::{{closure}}::{{closure}}
             at src/librustc/ty/query/plumbing.rs:278
      rustc::ty::context::tls::enter_context::{{closure}}
             at src/librustc/ty/context.rs:1697
      rustc::ty::context::tls::set_tlv
             at src/librustc/ty/context.rs:1682
      rustc::ty::context::tls::enter_context
             at src/librustc/ty/context.rs:1697
      rustc::ty::query::plumbing::<impl rustc::ty::context::TyCtxt>::start_query::{{closure}}
             at src/librustc/ty/query/plumbing.rs:278
      rustc::ty::context::tls::with_related_context::{{closure}}
             at src/librustc/ty/context.rs:1785
      rustc::ty::context::tls::with_context::{{closure}}
             at src/librustc/ty/context.rs:1769
      rustc::ty::context::tls::with_context_opt
             at src/librustc/ty/context.rs:1758
      rustc::ty::context::tls::with_context
             at src/librustc/ty/context.rs:1769
      rustc::ty::context::tls::with_related_context
             at src/librustc/ty/context.rs:1782
      rustc::ty::query::plumbing::<impl rustc::ty::context::TyCtxt>::start_query
             at src/librustc/ty/query/plumbing.rs:267
      rustc::ty::query::plumbing::<impl rustc::ty::context::TyCtxt>::force_query_with_job::{{closure}}
             at src/librustc/ty/query/plumbing.rs:547
      rustc::ty::query::plumbing::with_diagnostics
             at src/librustc/ty/query/plumbing.rs:212
      rustc::ty::query::plumbing::<impl rustc::ty::context::TyCtxt>::force_query_with_job
             at src/librustc/ty/query/plumbing.rs:546
      rustc::ty::query::plumbing::<impl rustc::ty::context::TyCtxt>::get_query
             at src/librustc/ty/query/plumbing.rs:380
  46: rustc::ty::query::TyCtxtAt::analysis
             at src/librustc/ty/query/plumbing.rs:1057
      rustc::ty::query::<impl rustc::ty::context::TyCtxt>::analysis
             at src/librustc/ty/query/plumbing.rs:1020
      rustc_driver::run_compiler::{{closure}}::{{closure}}::{{closure}}
             at src/librustc_driver/lib.rs:390
      rustc_interface::passes::QueryContext::enter::{{closure}}
             at src/librustc_interface/passes.rs:696
      rustc::ty::context::tls::enter_global::{{closure}}
             at src/librustc/ty/context.rs:1720
      rustc::ty::context::tls::enter_context::{{closure}}
             at src/librustc/ty/context.rs:1697
      rustc::ty::context::tls::set_tlv
             at src/librustc/ty/context.rs:1682
      rustc::ty::context::tls::enter_context
             at src/librustc/ty/context.rs:1697
      rustc::ty::context::tls::enter_global
             at src/librustc/ty/context.rs:1720
  47: rustc_interface::passes::QueryContext::enter
             at src/librustc_interface/passes.rs:696
      rustc_driver::run_compiler::{{closure}}::{{closure}}
             at src/librustc_driver/lib.rs:390
      rustc_interface::queries::<impl rustc_interface::interface::Compiler>::enter
             at src/librustc_interface/queries.rs:339
      rustc_driver::run_compiler::{{closure}}
             at src/librustc_driver/lib.rs:290
      rustc_interface::interface::run_compiler_in_existing_thread_pool
             at src/librustc_interface/interface.rs:186
  48: rustc_interface::interface::run_compiler::{{closure}}
             at src/librustc_interface/interface.rs:200
      rustc_interface::util::spawn_thread_pool::{{closure}}::{{closure}}::{{closure}}
             at src/librustc_interface/util.rs:155
      scoped_tls::ScopedKey<T>::set
             at /home/wesley/.cargo/registry/src/github.aaakk.us.kg-1ecc6299db9ec823/scoped-tls-1.0.0/src/lib.rs:137
      rustc_interface::util::spawn_thread_pool::{{closure}}::{{closure}}
             at src/librustc_interface/util.rs:151
      scoped_tls::ScopedKey<T>::set
             at /home/wesley/.cargo/registry/src/github.aaakk.us.kg-1ecc6299db9ec823/scoped-tls-1.0.0/src/lib.rs:137
      syntax::attr::with_globals::{{closure}}
             at src/libsyntax/attr/mod.rs:44
      scoped_tls::ScopedKey<T>::set
             at /home/wesley/.cargo/registry/src/github.aaakk.us.kg-1ecc6299db9ec823/scoped-tls-1.0.0/src/lib.rs:137
  49: syntax::attr::with_globals
             at src/libsyntax/attr/mod.rs:44
  50: rustc_interface::util::spawn_thread_pool::{{closure}}
             at src/librustc_interface/util.rs:150
      rustc_interface::util::scoped_thread::{{closure}}
             at src/librustc_interface/util.rs:125
      std::sys_common::backtrace::__rust_begin_short_backtrace
             at src/libstd/sys_common/backtrace.rs:129
  51: std::thread::Builder::spawn_unchecked::{{closure}}::{{closure}}
             at src/libstd/thread/mod.rs:475
      <std::panic::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once
             at src/libstd/panic.rs:318
      std::panicking::try::do_call
             at src/libstd/panicking.rs:303
  52: __rust_maybe_catch_panic
             at src/libpanic_unwind/lib.rs:86
  53: std::panicking::try
             at src/libstd/panicking.rs:281
  54: std::panic::catch_unwind
             at src/libstd/panic.rs:394
      std::thread::Builder::spawn_unchecked::{{closure}}
             at src/libstd/thread/mod.rs:474
      core::ops::function::FnOnce::call_once{{vtable.shim}}
             at src/libcore/ops/function.rs:232
  55: <alloc::boxed::Box<F> as core::ops::function::FnOnce<A>>::call_once
             at src/liballoc/boxed.rs:1016
  56: <alloc::boxed::Box<F> as core::ops::function::FnOnce<A>>::call_once
             at src/liballoc/boxed.rs:1016
  57: std::sys_common::thread::start_thread
             at src/libstd/sys_common/thread.rs:13
  58: std::sys::unix::thread::Thread::new::thread_start
             at src/libstd/sys/unix/thread.rs:80
  59: start_thread
             at /usr/src/debug/glibc-2.30-1.2.x86_64/nptl/pthread_create.c:479
  60: __clone

@nnethercote
Copy link
Contributor Author

Repeating from above, in case it's useful:

What the heck is going on there that so many interpreter errors are being raised? My first guess would be const-prop (Cc @wesleywiser).

For ctfe-stress-4 it's almost entirely errors of the form "tried to treat a memory pointer as a function pointer".

@RalfJung
Copy link
Member

@wesleywiser ah... and then after the error is raised, here we catch it again. Yeah, we should really be more careful about catching errors... given the backtrace generation, there are only few places where we want to do that.

The fix for this particular one, IMO, is not to catch an error. So, get_fn_alloc should return Option<FnVal<'tcx, M::ExtraFnVal>>, then the above user can use it normally, and get_fn can then be the one to turn None into an error.

@RalfJung
Copy link
Member

The more general question of course is, where else are we catching errors, and how can we avoid doing so accidentally?

wesleywiser added a commit to wesleywiser/rust that referenced this pull request Feb 19, 2020
Before this change, `get_size_and_align()`  calls `get_fn_alloc()` *a
lot* in CTFE heavy code. This previously returned an `Error` which would
check if `RUSTC_CTFE_BACKTRACE` was set on construction. Doing this
turned out to be a performance hotspot as @nnethercote discovered in
rust-lang#68792.

This is an alternate take on that PR which resolves the performance
issue by generating *many* fewer errors. Previously, `ctfe-stress-4`
would generate over 5,000,000 errors each of which would check for the
presence of the environment variable. With these changes, that number is
reduced to 30.
bors added a commit that referenced this pull request Feb 21, 2020
Check `RUSTC_CTFE_BACKTRACE` much less by generating fewer errors

Before this change, `get_size_and_align()`  calls `get_fn_alloc()` *a
lot* in CTFE heavy code. This previously returned an `Error` which would
check if `RUSTC_CTFE_BACKTRACE` was set on construction. Doing this
turned out to be a performance hotspot as @nnethercote discovered in
#68792.

This is an alternate take on that PR which resolves the performance
issue by generating *many* fewer errors. Previously, `ctfe-stress-4`
would generate over 5,000,000 errors each of which would check for the
presence of the environment variable. With these changes, that number is
reduced to 30.

r? @RalfJung
@wesleywiser wesleywiser mentioned this pull request Feb 26, 2020
2 tasks
@nnethercote nnethercote deleted the fix-RUSTC_CTFE_BACKTRACE branch April 1, 2020 19:47
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
S-waiting-on-review Status: Awaiting review from the assignee but also interested parties.
Projects
None yet
Development

Successfully merging this pull request may close these issues.

7 participants