ICE: RUST_LOG=rustc_trans::trans::cleanup: Index out of bounds

[Munksgaard]

When compiling this

fn main() {
    let v: Vec<u8>;
}

With RUST_LOG=rustc_trans::trans::cleanup, I get the following:

$ RUST_BACKTRACE=1 RUST_LOG=rustc_trans::trans::cleanup rustc foo.rs 
foo.rs:2:9: 2:10 warning: unused variable: `v`, #[warn(unused_variables)] on by default
foo.rs:2     let v: Vec<u8>;
                 ^
DEBUG:rustc_trans::trans::cleanup: push_custom_cleanup_scope(): 0
DEBUG:rustc_trans::trans::cleanup: push_ast_cleanup_scope(block { let v: Vec<u8>; } (id=6))
DEBUG:rustc_trans::trans::cleanup: push_ast_cleanup_scope(stmt let v: Vec<u8>; (id=7))
DEBUG:rustc_trans::trans::cleanup: var_scope(13) = AstScope(6)
DEBUG:rustc_trans::trans::cleanup: schedule_lifetime_end(AstScope(6), val=(%"struct.collections::vec::Vec<[\22u8\22]>[#3]"*:  %v = alloca %"struct.collections::vec::Vec<[\22u8\22]>[#3]"))
DEBUG:rustc_trans::trans::cleanup: schedule_clean_in_ast_scope(cleanup_scope=6)
DEBUG:rustc_trans::trans::cleanup: schedule_drop_mem(AstScope(6), val=(%"struct.collections::vec::Vec<[\22u8\22]>[#3]"*:  %v = alloca %"struct.collections::vec::Vec<[\22u8\22]>[#3]"), ty=collections::vec::Vec<u8>)
DEBUG:rustc_trans::trans::cleanup: schedule_clean_in_ast_scope(cleanup_scope=6)
DEBUG:rustc_trans::trans::cleanup: pop_and_trans_ast_cleanup_scope(stmt let v: Vec<u8>; (id=7))
DEBUG:rustc_trans::trans::cleanup: popping cleanup scope _ast_7_, 2 scopes remaining
DEBUG:rustc_trans::trans::cleanup: pop_and_trans_ast_cleanup_scope(block { let v: Vec<u8>; } (id=6))
DEBUG:rustc_trans::trans::cleanup: popping cleanup scope _ast_6_, 1 scopes remaining
DEBUG:rustc_trans::trans::cleanup: push_custom_cleanup_scope(): 0
DEBUG:rustc_trans::trans::cleanup: schedule_lifetime_end(CustomScope(CustomScopeIndex { index: 0 }), val=(%"struct.collections::vec::Vec<[\22u8\22]>[#3]"**:  %self = alloca %"struct.collections::vec::Vec<[\22u8\22]>[#3]"*))
DEBUG:rustc_trans::trans::cleanup: schedule_clean_in_custom_scope(custom_scope=0)
DEBUG:rustc_trans::trans::cleanup: push_ast_cleanup_scope(block {
    if self.cap != 0 {
        unsafe {
            match ::std::iter::IntoIterator::into_iter(self.iter()) {
                mut iter =>
                loop  {
                    match ::std::iter::Iterator::next(&mut iter) {
                        ::std::option::Option::Some(x) => { ptr::read(x); }
                        ::std::option::Option::None => break ,
                    }
                },
            }
            dealloc(*self.ptr, self.cap)
        }
    }
} (id=19))
DEBUG:rustc_trans::trans::cleanup: push_ast_cleanup_scope(expr if self.cap != 0 {
    unsafe {
        match ::std::iter::IntoIterator::into_iter(self.iter()) {
            mut iter =>
            loop  {
                match ::std::iter::Iterator::next(&mut iter) {
                    ::std::option::Option::Some(x) => { ptr::read(x); }
                    ::std::option::Option::None => break ,
                }
            },
        }
        dealloc(*self.ptr, self.cap)
    }
} (id=20))
DEBUG:rustc_trans::trans::cleanup: push_ast_cleanup_scope(expr self.cap != 0 (id=21))
DEBUG:rustc_trans::trans::cleanup: push_ast_cleanup_scope(expr self.cap (id=22))
DEBUG:rustc_trans::trans::cleanup: push_ast_cleanup_scope(expr self (id=23))
DEBUG:rustc_trans::trans::cleanup: pop_and_trans_ast_cleanup_scope(expr self (id=23))
DEBUG:rustc_trans::trans::cleanup: popping cleanup scope _ast_23_, 5 scopes remaining
DEBUG:rustc_trans::trans::cleanup: pop_and_trans_ast_cleanup_scope(expr self.cap (id=22))
DEBUG:rustc_trans::trans::cleanup: popping cleanup scope _ast_22_, 4 scopes remaining
DEBUG:rustc_trans::trans::cleanup: push_ast_cleanup_scope(expr 0 (id=24))
DEBUG:rustc_trans::trans::cleanup: pop_and_trans_ast_cleanup_scope(expr 0 (id=24))
DEBUG:rustc_trans::trans::cleanup: popping cleanup scope _ast_24_, 4 scopes remaining
DEBUG:rustc_trans::trans::cleanup: pop_and_trans_ast_cleanup_scope(expr self.cap != 0 (id=21))
DEBUG:rustc_trans::trans::cleanup: popping cleanup scope _ast_21_, 3 scopes remaining
DEBUG:rustc_trans::trans::cleanup: push_ast_cleanup_scope(block {
    unsafe {
        match ::std::iter::IntoIterator::into_iter(self.iter()) {
            mut iter =>
            loop  {
                match ::std::iter::Iterator::next(&mut iter) {
                    ::std::option::Option::Some(x) => { ptr::read(x); }
                    ::std::option::Option::None => break ,
                }
            },
        }
        dealloc(*self.ptr, self.cap)
    }
} (id=25))
DEBUG:rustc_trans::trans::cleanup: push_ast_cleanup_scope(expr unsafe {
    match ::std::iter::IntoIterator::into_iter(self.iter()) {
        mut iter =>
        loop  {
            match ::std::iter::Iterator::next(&mut iter) {
                ::std::option::Option::Some(x) => { ptr::read(x); }
                ::std::option::Option::None => break ,
            }
        },
    }
    dealloc(*self.ptr, self.cap)
} (id=26))
DEBUG:rustc_trans::trans::cleanup: push_ast_cleanup_scope(block unsafe {
    match ::std::iter::IntoIterator::into_iter(self.iter()) {
        mut iter =>
        loop  {
            match ::std::iter::Iterator::next(&mut iter) {
                ::std::option::Option::Some(x) => { ptr::read(x); }
                ::std::option::Option::None => break ,
            }
        },
    }
    dealloc(*self.ptr, self.cap)
} (id=27))
DEBUG:rustc_trans::trans::cleanup: push_ast_cleanup_scope(stmt match ::std::iter::IntoIterator::into_iter(self.iter()) {
    mut iter =>
    loop  {
        match ::std::iter::Iterator::next(&mut iter) {
            ::std::option::Option::Some(x) => { ptr::read(x); }
            ::std::option::Option::None => break ,
        }
    },
} (id=28))
DEBUG:rustc_trans::trans::cleanup: push_ast_cleanup_scope(expr match ::std::iter::IntoIterator::into_iter(self.iter()) {
    mut iter =>
    loop  {
        match ::std::iter::Iterator::next(&mut iter) {
            ::std::option::Option::Some(x) => { ptr::read(x); }
            ::std::option::Option::None => break ,
        }
    },
} (id=29))
DEBUG:rustc_trans::trans::cleanup: push_ast_cleanup_scope(expr ::std::iter::IntoIterator::into_iter(self.iter()) (id=30))
DEBUG:rustc_trans::trans::cleanup: push_custom_cleanup_scope(): 9
DEBUG:rustc_trans::trans::cleanup: push_custom_cleanup_scope(): 0
DEBUG:rustc_trans::trans::cleanup: schedule_lifetime_end(CustomScope(CustomScopeIndex { index: 0 }), val=(%"struct.core::slice::Iter<[\22u8\22]>[#2]"*:%"struct.core::slice::Iter<[\22u8\22]>[#2]"* %1))
DEBUG:rustc_trans::trans::cleanup: schedule_clean_in_custom_scope(custom_scope=0)
DEBUG:rustc_trans::trans::cleanup: push_ast_cleanup_scope(block { self } (id=67))
DEBUG:rustc_trans::trans::cleanup: push_ast_cleanup_scope(expr self (id=68))
DEBUG:rustc_trans::trans::cleanup: pop_and_trans_ast_cleanup_scope(expr self (id=68))
DEBUG:rustc_trans::trans::cleanup: popping cleanup scope _ast_68_, 2 scopes remaining
DEBUG:rustc_trans::trans::cleanup: pop_and_trans_ast_cleanup_scope(block { self } (id=67))
DEBUG:rustc_trans::trans::cleanup: popping cleanup scope _ast_67_, 1 scopes remaining
DEBUG:rustc_trans::trans::cleanup: pop_and_trans_custom_cleanup_scope(CustomScopeIndex { index: 0 })
DEBUG:rustc_trans::trans::cleanup: popping cleanup scope _custom_, 0 scopes remaining
DEBUG:rustc_trans::trans::cleanup: push_ast_cleanup_scope(expr self.iter() (id=32))
DEBUG:rustc_trans::trans::cleanup: push_custom_cleanup_scope(): 11
DEBUG:rustc_trans::trans::cleanup: push_custom_cleanup_scope(): 0
DEBUG:rustc_trans::trans::cleanup: schedule_lifetime_end(CustomScope(CustomScopeIndex { index: 0 }), val=({ i8*, i64 }*:{ i8*, i64 }* %1))
DEBUG:rustc_trans::trans::cleanup: schedule_clean_in_custom_scope(custom_scope=0)
error: internal compiler error: unexpected panic
note: the compiler unexpectedly panicked. this is a bug.
note: we would appreciate a bug report: http://doc.rust-lang.org/complement-bugreport.html
note: run with `RUST_BACKTRACE=1` for a backtrace
thread 'rustc' panicked at 'index out of bounds: the len is 916 but the index is 1539', /home/munksgaard/src/rust/src/libsyntax/lib.rs:1

stack backtrace:
   1:     0x7f581a760f90 - sys::backtrace::write::h05231eaa284f6244Aru
   2:     0x7f581a7845b0 - failure::on_fail::h199633f9964fe5659GB
   3:     0x7f581a6ef3e0 - rt::unwind::begin_unwind_inner::h9418c864201e5a95IlB
   4:     0x7f581a6eff00 - rt::unwind::begin_unwind_fmt::h2752d211a0fd31a7ekB
   5:     0x7f581a784410 - rust_begin_unwind
   6:     0x7f581a7d7c10 - panicking::panic_fmt::h479dcfa924d238a3ljw
   7:     0x7f581a7e09b0 - panicking::panic_bounds_check::h30928c8c0ce1c84dmiw
   8:     0x7f5817a7fe60 - util::interner::StrInterner::get::he9d63d350e469d366qa
   9:     0x7f5817c1e030 - print::pprust::State<'a>::print_name::hdfc8c31a93a19984bO3
  10:     0x7f5817c1e3c0 - print::pprust::State<'a>::print_path_parameters::he3a61e1dd2ade45aNV3
  11:     0x7f5817c087c0 - print::pprust::State<'a>::print_path::hf8bf3d9d586478caaQ3
  12:     0x7f5817ad8030 - print::pprust::State<'a>::print_expr::ha1b71339e1aa8496HQ2
  13:     0x7f5817c1ce00 - print::pprust::State<'a>::print_expr_struct::closure.54776
  14:     0x7f5817c1c7a0 - print::pprust::State<'a>::print_expr_struct::h03e80ef8a5a65eaazC2
  15:     0x7f5817ad8030 - print::pprust::State<'a>::print_expr::ha1b71339e1aa8496HQ2
  16:     0x7f5817c1b1d0 - print::pprust::State<'a>::print_block_maybe_unclosed::h0a641e3985af807fRb2
  17:     0x7f5817c1c160 - print::pprust::State<'a>::print_if::h62f9cb5c48213677Jn2
  18:     0x7f5817ad8030 - print::pprust::State<'a>::print_expr::ha1b71339e1aa8496HQ2
  19:     0x7f5817c1b1d0 - print::pprust::State<'a>::print_block_maybe_unclosed::h0a641e3985af807fRb2
  20:     0x7f5817ad8030 - print::pprust::State<'a>::print_expr::ha1b71339e1aa8496HQ2
  21:     0x7f5817c1b1d0 - print::pprust::State<'a>::print_block_maybe_unclosed::h0a641e3985af807fRb2
  22:     0x7f5817aded30 - print::pprust::block_to_string::hc6545d73cef6ce29fPZ
  23:     0x7f5817acd610 - ast_map::node_id_to_string::h8441c6e6a0397472QCA
  24:     0x7f5817acbc70 - ast_map::Map<'ast>::node_to_string::hd217c1aae8205a0521z
  25:     0x7f581942c1b0 - trans::cleanup::FunctionContext<'blk, 'tcx>.CleanupMethods<'blk, 'tcx>::push_ast_cleanup_scope::h5f6bd82c79e1be10bVK
  26:     0x7f581942d610 - trans::controlflow::trans_block::ha6710ce14b21fd80yae
  27:     0x7f58194f85e0 - trans::base::trans_closure::h7e23490ef5529b06l4t
  28:     0x7f5819419ce0 - trans::base::trans_fn::h525fca289c608987Hfu
  29:     0x7f581941a240 - trans::monomorphize::monomorphic_fn::h69e036c9514aeca1Dwd
  30:     0x7f581945ab80 - trans::callee::trans_fn_ref_with_substs::h1827e2dee44937fdeyg
  31:     0x7f5819470940 - trans::meth::trans_method_callee::ha759981f9d932b8dbUy
  32:     0x7f581946f210 - trans::callee::trans_call_inner::h18079871155530619635
  33:     0x7f5819476640 - trans::expr::trans_rvalue_dps_unadjusted::h36a4ddaf92e93ba2VTi
  34:     0x7f58194759d0 - trans::expr::trans_unadjusted::h501f1d136d476567xli
  35:     0x7f581942e1b0 - trans::expr::trans::hf58a24ab15abed80ADh
  36:     0x7f58194674e0 - trans::callee::trans_args::h9a1f29f3ae1886eaqdh
  37:     0x7f581946db90 - trans::callee::trans_call_inner::h10942245753906255274
  38:     0x7f5819476640 - trans::expr::trans_rvalue_dps_unadjusted::h36a4ddaf92e93ba2VTi
  39:     0x7f58194759d0 - trans::expr::trans_unadjusted::h501f1d136d476567xli
  40:     0x7f581942e1b0 - trans::expr::trans::hf58a24ab15abed80ADh
  41:     0x7f5819515bd0 - trans::_match::trans_match_inner::h20309c7d6adfe98bqsx
  42:     0x7f5819476640 - trans::expr::trans_rvalue_dps_unadjusted::h36a4ddaf92e93ba2VTi
  43:     0x7f581942d010 - trans::expr::trans_into::h905985b65b4d22f36zh
  44:     0x7f581942c480 - trans::controlflow::trans_stmt_semi::h97461a79191d3857H9d
  45:     0x7f581942d610 - trans::controlflow::trans_block::ha6710ce14b21fd80yae
  46:     0x7f5819476640 - trans::expr::trans_rvalue_dps_unadjusted::h36a4ddaf92e93ba2VTi
  47:     0x7f581942d010 - trans::expr::trans_into::h905985b65b4d22f36zh
  48:     0x7f581942d610 - trans::controlflow::trans_block::ha6710ce14b21fd80yae
  49:     0x7f5819476640 - trans::expr::trans_rvalue_dps_unadjusted::h36a4ddaf92e93ba2VTi
  50:     0x7f581942d010 - trans::expr::trans_into::h905985b65b4d22f36zh
  51:     0x7f581942d610 - trans::controlflow::trans_block::ha6710ce14b21fd80yae
  52:     0x7f58194f85e0 - trans::base::trans_closure::h7e23490ef5529b06l4t
  53:     0x7f5819419ce0 - trans::base::trans_fn::h525fca289c608987Hfu
  54:     0x7f581941a240 - trans::monomorphize::monomorphic_fn::h69e036c9514aeca1Dwd
  55:     0x7f5819440b00 - trans::glue::trans_struct_drop::ha3ff0b1d7c030d94POe
  56:     0x7f5819435830 - trans::glue::get_drop_glue::h4060dde62cee1bdfFHe
  57:     0x7f5819435530 - trans::glue::drop_ty::hf8ec8a717ad71facWDe
  58:     0x7f581956aea0 - trans::cleanup::DropValue<'tcx>.Cleanup<'tcx>::trans::he7ded553a9ae0600RaM
  59:     0x7f581942cb80 - trans::cleanup::FunctionContext<'blk, 'tcx>.CleanupMethods<'blk, 'tcx>::pop_and_trans_ast_cleanup_scope::h87e982779e518632L5K
  60:     0x7f581942d610 - trans::controlflow::trans_block::ha6710ce14b21fd80yae
  61:     0x7f58194f85e0 - trans::base::trans_closure::h7e23490ef5529b06l4t
  62:     0x7f5819419ce0 - trans::base::trans_fn::h525fca289c608987Hfu
  63:     0x7f5819414e30 - trans::base::trans_item::h4194be0282ff3bfcSDu
  64:     0x7f58194ff9b0 - trans::base::trans_crate::h5a83c959a64059a1CAv
  65:     0x7f581ad096c0 - driver::phase_4_translate_to_llvm::h4edec40b63cde28d2Oa
  66:     0x7f581ace2f90 - driver::compile_input::h069b14861a632ff8Bba
  67:     0x7f581adadaa0 - run_compiler::hfbc1e332296c6b439ac
  68:     0x7f581adac130 - thunk::F.Invoke<A, R>::invoke::h9964198321774557263
  69:     0x7f581adab060 - rt::unwind::try::try_fn::h15238212938126306553
  70:     0x7f581a7fa970 - rust_try_inner
  71:     0x7f581a7fa960 - rust_try
  72:     0x7f581adab310 - thunk::F.Invoke<A, R>::invoke::h15514854263126532375
  73:     0x7f581a770db0 - sys::thread::thread_start::hd4939dc2db48a5bcPnx
  74:     0x7f5814aea140 - <unknown>
  75:     0x7f581a389bb9 - __clone
  76:                0x0 - <unknown>

$ rustc --version
rustc 1.0.0-dev (76ce1ea42 2015-02-01 15:49:20 +0000)

[pnkfelix]

yes I too have noticed ICE's like this when using the RUST_LOG environment variable.

From the last time I investigated it, it seemed like it is due to Name values that do not originate from the input source, but rather from other places (I cannot recall offhand whether it was macro expansions / derive, or something else).

[Munksgaard]

It seems like RUST_LOG is broken now?

Specifically, the above sample doesn't produce the ICE any more, but it also doesn't output any debugging at all.

rustc 1.0.0-dev (f899513 2015-03-11) (built 2015-03-11)

[pnkfelix]

@Munksgaard I think debug! got broken recently; there's a PR somewhere about it ... #23257

[Munksgaard]

Rejoice! It looks like debug! is working again, and the above error has disappeared! I'm not sure specifically which commit fixed the issue, but I'm closing it now to reflect that it works.