ICE on nightly-2021-12-21 and later: change source file timestamp, get "failed to lookup SourceFile in new context"

[mypetyak]

Summary

By changing the timestamp on a rust source file between builds, I'm able to reliably reproduce an ICE with nightly-2021-12-21 and later.

I've included a minimal repro repository, and the ICE can be recreated on alternating builds simply by modifying an input file timestamp. So far, I'm only able to reproduce this in a repo that includes a build script to generate gRPC stubs via Tonic & Prost, so my example repo attempts to whittle things down to the bare minimum.

Code

$ git clone https://github.com/mypetyak/ice_repro_2021-12.git     
                                               
# produces a successful build                                                                                                                     
$ cargo +nightly build --bin server

# modify timestamp of source file
$ touch src/bin/server.rs 

$ RUST_BACKTRACE=1 cargo +nightly build --bin server
   Compiling hello v0.1.0 (/tmp/ice_repro_2021-12)
thread 'rustc' panicked at 'failed to lookup `SourceFile` in new context', compiler/rustc_query_impl/src/on_disk_cache.rs:500:22
stack backtrace:
   0: rust_begin_unwind
             at /rustc/51e8031e14a899477a5e2d78ce461cab31123354/library/std/src/panicking.rs:498:5
   1: core::panicking::panic_fmt
             at /rustc/51e8031e14a899477a5e2d78ce461cab31123354/library/core/src/panicking.rs:107:14
   2: core::panicking::panic_display
             at /rustc/51e8031e14a899477a5e2d78ce461cab31123354/library/core/src/panicking.rs:63:5
   3: core::panicking::panic_str
             at /rustc/51e8031e14a899477a5e2d78ce461cab31123354/library/core/src/panicking.rs:55:5
   4: core::option::expect_failed
             at /rustc/51e8031e14a899477a5e2d78ce461cab31123354/library/core/src/option.rs:1821:5
   5: <rustc_span::span_encoding::Span as rustc_serialize::serialize::Decodable<rustc_query_impl::on_disk_cache::CacheDecoder>>::decode
   6: <rustc_middle::ty::VariantDef as rustc_serialize::serialize::Decodable<rustc_query_impl::on_disk_cache::CacheDecoder>>::decode
   7: <rustc_query_impl::on_disk_cache::CacheDecoder as rustc_serialize::serialize::Decoder>::read_seq::<alloc::vec::Vec<rustc_middle::ty::VariantDef>, <alloc::vec::Vec<rustc_middle::ty::VariantDef> as rustc_serialize::serialize::Decodable<rustc_query_impl::on_disk_cache::CacheDecoder>>::decode::{closure#0}>
   8: <rustc_middle::ty::adt::AdtDef as rustc_serialize::serialize::Decodable<rustc_query_impl::on_disk_cache::CacheDecoder>>::decode
   9: <rustc_middle::ty::sty::TyKind as rustc_serialize::serialize::Decodable<rustc_query_impl::on_disk_cache::CacheDecoder>>::decode
  10: <&rustc_middle::ty::TyS as rustc_serialize::serialize::Decodable<rustc_query_impl::on_disk_cache::CacheDecoder>>::decode
  11: <&rustc_middle::ty::TyS as rustc_serialize::serialize::Decodable<rustc_query_impl::on_disk_cache::CacheDecoder>>::decode
  12: <smallvec::SmallVec<[rustc_middle::ty::subst::GenericArg; 8]> as core::iter::traits::collect::Extend<rustc_middle::ty::subst::GenericArg>>::extend::<core::iter::adapters::ResultShunt<core::iter::adapters::map::Map<core::ops::range::Range<usize>, <&rustc_middle::ty::list::List<rustc_middle::ty::subst::GenericArg> as rustc_serialize::serialize::Decodable<rustc_query_impl::on_disk_cache::CacheDecoder>>::decode::{closure#0}>, alloc::string::String>>
  13: <&rustc_middle::ty::list::List<rustc_middle::ty::subst::GenericArg> as rustc_serialize::serialize::Decodable<rustc_query_impl::on_disk_cache::CacheDecoder>>::decode
  14: <rustc_middle::ty::sty::TyKind as rustc_serialize::serialize::Decodable<rustc_query_impl::on_disk_cache::CacheDecoder>>::decode
  15: <&rustc_middle::ty::TyS as rustc_serialize::serialize::Decodable<rustc_query_impl::on_disk_cache::CacheDecoder>>::decode
  16: <&rustc_middle::ty::TyS as rustc_serialize::serialize::Decodable<rustc_query_impl::on_disk_cache::CacheDecoder>>::decode
  17: <rustc_middle::ty::sty::TyKind as rustc_serialize::serialize::Decodable<rustc_query_impl::on_disk_cache::CacheDecoder>>::decode
  18: <&rustc_middle::ty::TyS as rustc_serialize::serialize::Decodable<rustc_query_impl::on_disk_cache::CacheDecoder>>::decode
  19: <&rustc_middle::ty::TyS as rustc_serialize::serialize::Decodable<rustc_query_impl::on_disk_cache::CacheDecoder>>::decode
  20: <core::result::Result<rustc_middle::ty::subst::GenericArg, alloc::string::String> as rustc_middle::ty::context::InternIteratorElement<rustc_middle::ty::subst::GenericArg, &rustc_middle::ty::list::List<rustc_middle::ty::subst::GenericArg>>>::intern_with::<core::iter::adapters::map::Map<core::ops::range::Range<usize>, <&rustc_middle::ty::list::List<rustc_middle::ty::subst::GenericArg> as rustc_serialize::serialize::Decodable<rustc_query_impl::on_disk_cache::CacheDecoder>>::decode::{closure#0}>, <rustc_middle::ty::context::TyCtxt>::mk_substs<core::iter::adapters::map::Map<core::ops::range::Range<usize>, <&rustc_middle::ty::list::List<rustc_middle::ty::subst::GenericArg> as rustc_serialize::serialize::Decodable<rustc_query_impl::on_disk_cache::CacheDecoder>>::decode::{closure#0}>>::{closure#0}>
  21: <rustc_middle::ty::sty::TyKind as rustc_serialize::serialize::Decodable<rustc_query_impl::on_disk_cache::CacheDecoder>>::decode
  22: <&rustc_middle::ty::TyS as rustc_serialize::serialize::Decodable<rustc_query_impl::on_disk_cache::CacheDecoder>>::decode
  23: <&rustc_middle::ty::TyS as rustc_serialize::serialize::Decodable<rustc_query_impl::on_disk_cache::CacheDecoder>>::decode
  24: <rustc_query_impl::on_disk_cache::CacheDecoder as rustc_serialize::serialize::Decoder>::read_map::<std::collections::hash::map::HashMap<rustc_hir::hir_id::ItemLocalId, &rustc_middle::ty::TyS, core::hash::BuildHasherDefault<rustc_hash::FxHasher>>, <std::collections::hash::map::HashMap<rustc_hir::hir_id::ItemLocalId, &rustc_middle::ty::TyS, core::hash::BuildHasherDefault<rustc_hash::FxHasher>> as rustc_serialize::serialize::Decodable<rustc_query_impl::on_disk_cache::CacheDecoder>>::decode::{closure#0}>
  25: <rustc_middle::ty::context::TypeckResults as rustc_serialize::serialize::Decodable<rustc_query_impl::on_disk_cache::CacheDecoder>>::decode::{closure#0}
  26: <rustc_query_impl::on_disk_cache::OnDiskCache>::try_load_query_result::<&rustc_middle::ty::context::TypeckResults>
  27: rustc_query_system::query::plumbing::try_load_from_disk_and_cache_in_memory::<rustc_query_impl::plumbing::QueryCtxt, rustc_span::def_id::LocalDefId, &rustc_middle::ty::context::TypeckResults>
  28: rustc_query_system::query::plumbing::try_execute_query::<rustc_query_impl::plumbing::QueryCtxt, rustc_query_system::query::caches::DefaultCache<rustc_span::def_id::LocalDefId, &rustc_middle::ty::context::TypeckResults>>
  29: <rustc_query_impl::Queries as rustc_middle::ty::query::QueryEngine>::typeck
  30: <rustc_middle::ty::context::TyCtxt>::typeck_body
  31: rustc_hir::intravisit::walk_item::<rustc_passes::dead::MarkSymbolVisitor>
  32: rustc_passes::dead::check_crate
  33: <core::panic::unwind_safe::AssertUnwindSafe<rustc_interface::passes::analysis::{closure#5}::{closure#0}::{closure#1}> as core::ops::function::FnOnce<()>>::call_once
  34: <core::panic::unwind_safe::AssertUnwindSafe<rustc_interface::passes::analysis::{closure#5}::{closure#0}> as core::ops::function::FnOnce<()>>::call_once
  35: <rustc_session::session::Session>::time::<(), rustc_interface::passes::analysis::{closure#5}>
  36: rustc_interface::passes::analysis
  37: <rustc_query_system::dep_graph::graph::DepGraph<rustc_middle::dep_graph::dep_node::DepKind>>::with_task::<rustc_middle::ty::context::TyCtxt, (), core::result::Result<(), rustc_errors::ErrorReported>>
  38: rustc_data_structures::stack::ensure_sufficient_stack::<(core::result::Result<(), rustc_errors::ErrorReported>, rustc_query_system::dep_graph::graph::DepNodeIndex), rustc_query_system::query::plumbing::execute_job<rustc_query_impl::plumbing::QueryCtxt, (), core::result::Result<(), rustc_errors::ErrorReported>>::{closure#3}>
  39: rustc_query_system::query::plumbing::try_execute_query::<rustc_query_impl::plumbing::QueryCtxt, rustc_query_system::query::caches::DefaultCache<(), core::result::Result<(), rustc_errors::ErrorReported>>>
  40: rustc_query_system::query::plumbing::get_query::<rustc_query_impl::queries::analysis, rustc_query_impl::plumbing::QueryCtxt>
  41: <rustc_interface::passes::QueryContext>::enter::<rustc_driver::run_compiler::{closure#1}::{closure#2}::{closure#3}, core::result::Result<(), rustc_errors::ErrorReported>>
  42: <rustc_interface::interface::Compiler>::enter::<rustc_driver::run_compiler::{closure#1}::{closure#2}, core::result::Result<core::option::Option<rustc_interface::queries::Linker>, rustc_errors::ErrorReported>>
  43: rustc_span::with_source_map::<core::result::Result<(), rustc_errors::ErrorReported>, rustc_interface::interface::create_compiler_and_run<core::result::Result<(), rustc_errors::ErrorReported>, rustc_driver::run_compiler::{closure#1}>::{closure#1}>
  44: rustc_interface::interface::create_compiler_and_run::<core::result::Result<(), rustc_errors::ErrorReported>, rustc_driver::run_compiler::{closure#1}>
  45: <scoped_tls::ScopedKey<rustc_span::SessionGlobals>>::set::<rustc_interface::util::setup_callbacks_and_run_in_thread_pool_with_globals<rustc_interface::interface::run_compiler<core::result::Result<(), rustc_errors::ErrorReported>, rustc_driver::run_compiler::{closure#1}>::{closure#0}, core::result::Result<(), rustc_errors::ErrorReported>>::{closure#0}::{closure#0}, core::result::Result<(), rustc_errors::ErrorReported>>
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.

error: internal compiler error: unexpected panic

note: the compiler unexpectedly panicked. this is a bug.

note: we would appreciate a bug report: https://github.com/rust-lang/rust/issues/new?labels=C-bug%2C+I-ICE%2C+T-compiler&template=ice.md

note: rustc 1.59.0-nightly (51e8031e1 2021-12-25) running on x86_64-unknown-linux-gnu

note: compiler flags: -C embed-bitcode=no -C debuginfo=2 -C incremental --crate-type bin

note: some of the compiler flags provided by cargo are hidden

query stack during panic:
#0 [typeck] type-checking `main`
#1 [analysis] running analysis passes on this crate
end of query stack
error: could not compile `hello`

Subsequent iterations of the following produce a clean build, followed by the ICE:

$ cargo +nightly clean -p hello

# generates a successful build
$ cargo +nightly build --bin server

$ touch src/bin/server.rs 

# results in ICE
$ cargo +nightly build --bin server

Meta

This does not reproduce on the stable or beta channels. It reproduces on nightly-2021-12-21 and later, but does not reproduce on nightly-2021-12-20.

The current nightly toolchain with reproduction:

❯ rustc +nightly --version --verbose
rustc 1.59.0-nightly (51e8031e1 2021-12-25)
binary: rustc
commit-hash: 51e8031e14a899477a5e2d78ce461cab31123354
commit-date: 2021-12-25
host: x86_64-unknown-linux-gnu
release: 1.59.0-nightly
LLVM version: 13.0.0

Earliest toolchain with which I found a reproduction:

❯ rustc +nightly-2021-12-21 --version --verbose
rustc 1.59.0-nightly (23f69235a 2021-12-20)
binary: rustc
commit-hash: 23f69235ad2eb9b44ac1a55eeaa3f9b484d9de4a
commit-date: 2021-12-20
host: x86_64-unknown-linux-gnu
release: 1.59.0-nightly
LLVM version: 13.0.0

Dec 20 toolchain does not reproduce:

❯ rustc +nightly-2021-12-20 --version --verbose
rustc 1.59.0-nightly (e95e084a1 2021-12-19)
binary: rustc
commit-hash: e95e084a14870a718c712936ab5a8f8cd0159485
commit-date: 2021-12-19
host: x86_64-unknown-linux-gnu
release: 1.59.0-nightly
LLVM version: 13.0.0

[mypetyak]

@Aaron1011, any chance this is related to what you're working on with #92175?

[Aaron1011]

@mypetyak: This should hopefully be fixed by #92175 (if it isn't, then it will be fixed by #92210)

[BGR360]

@rustbot label +A-incr-comp

[mypetyak]

This was broken up until nightly-2021-12-31, but I just re-tested with nightly-2022-01-01, which includes 984a6bf, and this bug is now resolved - thanks @Aaron1011!

Fixed by #92175