Incremental ICE (DepNode Hir should have been pre-allocated but wasn't)

[jhpratt]

I've pushed a commit to this branch of the time repository, containing the full code that causes the error. I haven't yet tried to create a minimal example; I can do that at some point if it's desired.

This code does not have any issue running cargo check on rustc 1.41.0. It fails on 1.41.1.

Output with RUST_BACKTRACE=1:

error: internal compiler error: src/librustc/dep_graph/graph.rs:680: DepNode Hir(time[a7e0]::format[0]::parse[0]::parse[0]::{{misc}}[1]::{{misc}}[0]) should have been pre-allocated but wasn't.

thread 'rustc' panicked at 'Box<Any>', src/librustc_errors/lib.rs:905:9
stack backtrace:
   0: backtrace::backtrace::libunwind::trace
             at /cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.40/src/backtrace/libunwind.rs:88
   1: backtrace::backtrace::trace_unsynchronized
             at /cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.40/src/backtrace/mod.rs:66
   2: std::sys_common::backtrace::_print_fmt
             at src/libstd/sys_common/backtrace.rs:84
   3: <std::sys_common::backtrace::_print::DisplayBacktrace as core::fmt::Display>::fmt
             at src/libstd/sys_common/backtrace.rs:61
   4: core::fmt::write
             at src/libcore/fmt/mod.rs:1025
   5: std::io::Write::write_fmt
             at src/libstd/io/mod.rs:1426
   6: std::sys_common::backtrace::_print
             at src/libstd/sys_common/backtrace.rs:65
   7: std::sys_common::backtrace::print
             at src/libstd/sys_common/backtrace.rs:50
   8: std::panicking::default_hook::{{closure}}
             at src/libstd/panicking.rs:193
   9: std::panicking::default_hook
             at src/libstd/panicking.rs:210
  10: rustc_driver::report_ice
  11: <alloc::boxed::Box<F> as core::ops::function::Fn<A>>::call
             at /rustc/f3e1a954d2ead4e2fc197c7da7d71e6c61bad196/src/liballoc/boxed.rs:1036
  12: proc_macro::bridge::client::<impl proc_macro::bridge::Bridge>::enter::{{closure}}::{{closure}}
             at /rustc/f3e1a954d2ead4e2fc197c7da7d71e6c61bad196/src/libproc_macro/bridge/client.rs:305
  13: std::panicking::rust_panic_with_hook
             at src/libstd/panicking.rs:475
  14: std::panicking::begin_panic
  15: rustc_errors::HandlerInner::bug
  16: rustc_errors::Handler::bug
  17: rustc::util::bug::opt_span_bug_fmt::{{closure}}
  18: rustc::ty::context::tls::with_opt::{{closure}}
  19: rustc::ty::context::tls::with_opt
  20: rustc::util::bug::opt_span_bug_fmt
  21: rustc::util::bug::bug_fmt
  22: rustc::dep_graph::graph::DepGraph::try_mark_previous_green
  23: rustc::dep_graph::graph::DepGraph::try_mark_green
  24: rustc::dep_graph::graph::DepGraph::try_mark_green_and_read
  25: rustc::ty::query::plumbing::<impl rustc::ty::context::TyCtxt>::ensure_query
  26: rustc_typeck::impl_wf_check::impl_wf_check
  27: rustc::util::common::time
  28: rustc_typeck::check_crate
  29: rustc_interface::passes::analysis
  30: rustc::ty::query::__query_compute::analysis
  31: rustc::dep_graph::graph::DepGraph::with_task_impl
  32: rustc::ty::query::plumbing::<impl rustc::ty::context::TyCtxt>::get_query
  33: rustc::ty::context::tls::enter_global
  34: rustc_interface::interface::run_compiler_in_existing_thread_pool
  35: std::thread::local::LocalKey<T>::with
  36: scoped_tls::ScopedKey<T>::set
  37: syntax::with_globals
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.

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

note: we would appreciate a bug report: https://github.com/rust-lang/rust/blob/master/CONTRIBUTING.md#bug-reports

note: rustc 1.41.1 (f3e1a954d 2020-02-24) running on x86_64-unknown-linux-gnu

note: compiler flags: -C debuginfo=2 -C incremental --crate-type lib

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

query stack during panic:
#0 [analysis] running analysis passes on this crate
end of query stack
error: aborting due to previous error

error: could not compile `time`.

Looks like there are a number of issues possibly related. Feel free to close if it's a duplicate, of course.

[Mark-Simulacrum]

Do we have confirmation that this isn't an incremental bug (and unrelated to 1.41.1?).

cc @michaelwoerister @Zoxc

[jonas-schievink]

Confirmed incremental compilation bug. Not a 1.41.1 regression.

[jonas-schievink]

To reproduce: Run cargo check on time-rs/time@10e931b, then on time-rs/time@1deef90. Happens on 1.40.0, 1.41.0, and 1.41.1. Haven't checked other versions.

[jonas-schievink]

Maybe run cargo clean before?

[jhpratt]

That did it. Confirming I'm seeing the same behavior as you — not a regression (at least recently).

[Zoxc]

This seems like it could have been fixed by #68289.

[jonas-schievink]

It still reproduces on rustc 1.43.0-nightly (0eb878d 2020-02-28)

[jhpratt]

This goes away when stripping the proc macros. Apart from nuking the two directories, it's a couple changes to eliminate the usage.

I've just uploaded my test case to jhpratt/time-ice-repro. master is where the issue originates — going from HEAD^ to HEAD breaks. However, going from master to no-proc-macros fixes things. So somewhere in there lies an issue…

[Zoxc]

This seems to be fixed by #69015 / #68944.

[jonas-schievink]

Great! Marking needstest to get a usable test for those PRs then. Maybe someone can help reduce this to a single file without dependencies?

@rustbot ping icebreakers-llvm

[rustbot]

Hey LLVM ICE-breakers! This bug has been identified as a good
"LLVM ICE-breaking candidate". In case it's useful, here are some
instructions for tackling these sorts of bugs. Maybe take a look?
Thanks! <3

cc @comex @DutchGhost @hanna-kruppe @hdhoang @heyrutvik @JOE1994 @jryans @mmilenko @nagisa @nikic @Noah-Kennedy @SiavoshZarrasvand @spastorino @vertexclique @vgxbj

[jonas-schievink]

Oh darn, wrong team, sorry about that. I meant:

@rustbot ping icebreakers-cleanup-crew

[rustbot]

Hey Cleanup Crew ICE-breakers! This bug has been identified as a good
"Cleanup ICE-breaking candidate". In case it's useful, here are some
instructions for tackling these sorts of bugs. Maybe take a look?
Thanks! <3

cc @AminArria @chrissimpkins @contrun @DutchGhost @elshize @ethanboxx @h-michael @HallerPatrick @hdhoang @hellow554 @imtsuki @jakevossen5 @KarlK90 @LeSeulArtichaut @matheus-consoli @mental32 @nmccarty @Noah-Kennedy @pard68 @PeytonT @pierreN @Redblueflame @RobbieClarken @RobertoSnap @robjtede @SarthakSingh31 @senden9 @shekohex @sinato @spastorino @turboladen @woshilapin @yerke

[RobbieClarken]

I've managed to replicate the error in a project with only a few modules and a single external dependency on proc-macro-hack: https://github.com/RobbieClarken/ice-repro-69596 . I will try to remove that dependency and reduce it to a single file but I'm not sure how easy that will be as even this minor refactoring prevented the ICE from occurring. Any suggestions would be very welcome.

[RobbieClarken]

Here is a reproduction in a single file:

mod mod_a {
    mod name_of_proc_macro {}

    use crate::mod_b::*;

    mod mod_c {
        fn _foobar() {
            use super::name_of_proc_macro;
        }
    }
}

mod mod_b {
    pub(crate) use std::format as name_of_proc_macro; // DELETE TO TRIGGER ICE
}

The ICE can be triggered by:

1. Placing this code in lib.rs in a project (or clone https://github.com/RobbieClarken/ice-repro-69596).
2. Running cargo check.
3. Deleting the line with the DELETE TO TRIGGER ICE comment.
4. Running cargo check again.

The error occurred in the time crate because there were procedural macros named date and time which happened to collide with the names of modules.

[jhpratt]

Note that this is not a result of the same name referring to different things between builds, as placing use crate::mod_b::*; before mod name_of_proc_macro {} yields the same result.

mod_c can also further be removed, leaving an otherwise useless use name_of_proc_macro; statement. mod_a cannot be removed in the same fashion.

mod mod_a {
    mod name_of_proc_macro {}

    use crate::mod_b::*;

    fn _foobar() {
        use name_of_proc_macro;
    }
}

mod mod_b {
    pub(crate) use std::format as name_of_proc_macro;
}

[hellow554]

reduced, without any dependencies. Much thanks to robbie an jhpratt!

// Regression test for #69596. 
// TODO: Some explanation please :)

// revisions: rpass1 rpass2
// check-pass


#![allow(unused_imports)]

#[macro_export]
macro_rules! a_macro {
    () => {};
}

#[cfg(rpass1)]
use a_macro as same_name;

mod same_name {}

mod needed_mod {
    fn _crash() {
        use super::same_name;
    }
}   

fn main() {}

rm -rf inc; rustc -C incremental=inc --cfg rpass1 file.rs; rustc -C incremental=inc --cfg rpass2 file.rs

[Zoxc]

This happens because there is a missing dependency on items inside a function in visit_item_likes_in_module. The _crash function turns out to effectively be:

fn _crash() {
    #[cfg(rpass1)]
    use super::same_name;
}

This is because the use item disappears in HIR when it refers to the module.

When try to mark check_mod_impl_wf (which uses visit_item_likes_in_module) green in rpass2, we end up trying to mark Hir(test[317d]::needed_mod[0]::_crash[0]::{{misc}}[0]::{{misc}}[0]) as green, but that no longer exists. check_mod_impl_wf should have had a dependency before that that ended up red, since it uses visit_item_likes_in_module and the items in the module changed.

This bug is fixed in #68944 where visit_item_likes_in_module uses a query to get the items in a module. It is not fixed in #69015 however and @hellow554's reduced test case still ICEs with it.

We have a workaround in place which treats Hir dep nodes which no longer exists as red (using extract_def_id), but that did not trigger in this case since we actually assign a DefId to test[317d]::needed_mod[0]::_crash[0]::{{misc}}[0]::{{misc}}[0].

[Zoxc]

Fixed by #68944.