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

cargo build dumps core on latest nightly with Hello World project (macOS) #46505

Closed
gibfahn opened this issue Dec 4, 2017 · 23 comments
Closed
Labels
I-compiletime Issue: Problems and improvements with respect to compile times. regression-from-stable-to-nightly Performance or correctness regression from stable to nightly. T-compiler Relevant to the compiler team, which will review and decide on the PR/issue.

Comments

@gibfahn
Copy link
Contributor

gibfahn commented Dec 4, 2017

Updated to the latest nightly earlier today, and immediately started noticing a marked compile time slowdown in cargo build (debug mode) for small projects.

EDIT: Turns out the slowdown is because it's dumping a core to /cores, I worked this out when my machine became completely full 😁 .

Platform: macOS High Sierra.

NOTE (added by @pnkfelix): it appears you need to turn up a core dump threshold to observe this, e.g. via ulimit -c unlimited

$ rustup update                                                                                                                                                                                         ~/tmp
info: syncing channel updates for 'stable-x86_64-apple-darwin'
info: syncing channel updates for 'nightly-x86_64-apple-darwin'
info: checking for self-updates

   stable-x86_64-apple-darwin unchanged - rustc 1.22.1 (05e2e1c41 2017-11-22)
  nightly-x86_64-apple-darwin unchanged - rustc 1.24.0-nightly (1956d5535 2017-12-03)

$ cargo new --bin hello_nightly && cd hello_nightly                                                                                                                                                 ~/tmp
     Created binary (application) `hello_nightly` project

$ time rustup run nightly cargo build                                                                                                                                       ~/tmp/hello_nightly (master*)
   Compiling hello_nightly v0.1.0 (file:///Users/gib/tmp/hello_nightly)
    Finished dev [unoptimized + debuginfo] target(s) in 3.0 secs
rustup run nightly cargo build  0.32s user 1.17s system 46% cpu 3.229 total

$ touch src/main.rs && time rustup run nightly cargo build                                                                                                               ~/tmp/hello_nightly 3s (master*)
   Compiling hello_nightly v0.1.0 (file:///Users/gib/tmp/hello_nightly)
    Finished dev [unoptimized + debuginfo] target(s) in 2.90 secs
rustup run nightly cargo build  0.33s user 1.07s system 44% cpu 3.133 total

$ cd ..                                                                                                                                                                  ~/tmp/hello_nightly 3s (master*)

$ cargo new --bin hello_stable && cd hello_stable                                                                                                                                                   ~/tmp
     Created binary (application) `hello_stable` project

$ time rustup run stable cargo build                                                                                                                                         ~/tmp/hello_stable (master*)
   Compiling hello_stable v0.1.0 (file:///Users/gib/tmp/hello_stable)
    Finished dev [unoptimized + debuginfo] target(s) in 0.53 secs
rustup run stable cargo build  0.37s user 0.23s system 65% cpu 0.908 total

$ touch src/main.rs && time rustup run stable cargo build                                                                                                                 ~/tmp/hello_stable 1s (master*)
   Compiling hello_stable v0.1.0 (file:///Users/gib/tmp/hello_stable)
    Finished dev [unoptimized + debuginfo] target(s) in 0.31 secs
rustup run stable cargo build  0.33s user 0.17s system 92% cpu 0.542 total

Sorry if this is a duplicate, didn't see anything relevant in the issue tracker.

@gibfahn
Copy link
Contributor Author

gibfahn commented Dec 4, 2017

Doesn't seem to happen with cargo build --release:

$ touch src/main.rs && time rustup run stable cargo build --release                                                                                                      ~/tmp/hello_nightly 1s (master*)
   Compiling hello_nightly v0.1.0 (file:///Users/gib/tmp/hello_nightly)
    Finished release [optimized] target(s) in 0.25 secs
rustup run stable cargo build --release  0.29s user 0.15s system 93% cpu 0.478 total
$ touch src/main.rs && time rustup run nightly cargo build --release                                                                                                        ~/tmp/hello_nightly (master*)
   Compiling hello_nightly v0.1.0 (file:///Users/gib/tmp/hello_nightly)
    Finished release [optimized] target(s) in 0.25 secs
rustup run nightly cargo build --release  0.29s user 0.16s system 93% cpu 0.482 total

@Mark-Simulacrum Mark-Simulacrum added the I-compiletime Issue: Problems and improvements with respect to compile times. label Dec 6, 2017
@sfackler sfackler added the regression-from-stable-to-nightly Performance or correctness regression from stable to nightly. label Dec 6, 2017
@nikomatsakis
Copy link
Contributor

@gibfahn I'm a bit confused. If I'm not misreading things, it appears that the nightly build is faster (at least in the one case where the numbers are not identical):

rustup run nightly cargo build 0.32s user 1.17s system 46% cpu 3.229 total

vs

rustup run stable cargo build 0.37s user 0.23s system 65% cpu 0.908 total

@nikomatsakis
Copy link
Contributor

nikomatsakis commented Dec 7, 2017

No, nm, I was getting confused by time output. I see... 3.229 total vs 0.908 total. =)

@gibfahn
Copy link
Contributor Author

gibfahn commented Dec 7, 2017

Still happens with the newest nightly (rustc 1.24.0-nightly (5a2465e2b 2017-12-06)). Reproduced on someone else's laptop as well (also macOS).

Pretty easy to reproduce:

# Get rust if you haven't already
curl https://sh.rustup.rs -sSf | sh
rustup install nightly
cargo new --bin rust-foo && cd rust-foo
cargo build
touch src/main.rs && time cargo +stable build
touch src/main.rs && time cargo +nightly build
cd .. && rm -rf rust-foo

EDIT: Can't reproduce this on Ubuntu

@nikomatsakis
Copy link
Contributor

@gibfahn just to be clear, if you diff those two projects, do you see any difference? i.e., it seems to me you should be able to just have one project and do cargo +nightly build and compare to cargo +stable build... can you check that?

@nikomatsakis
Copy link
Contributor

nikomatsakis commented Dec 7, 2017

I don't see any significant difference on linux, anyway.

@gibfahn
Copy link
Contributor Author

gibfahn commented Dec 7, 2017

@nikomatsakis are you running on macOS? I'll keep a list of platforms I tried it on.

Using the shortened script above I reproduced with the same code.

Platform Fast (💚 ) / Slow (🔴 )
macOS High Sierra 10.13.1 🔴
macOS Sierra 🔴
Ubuntu 16.04 💚
Rhel 7.4 💚
$ cargo new --bin rust-foo && cd rust-foo
     Created binary (application) `rust-foo` project
Cargo.toml src

$ cargo build
   Compiling rust-foo v0.1.0 (file:///Users/gib/tmp/rust-foo)
    Finished dev [unoptimized + debuginfo] target(s) in 2.92 secs

$ touch src/main.rs && time cargo +stable build
   Compiling rust-foo v0.1.0 (file:///Users/gib/tmp/rust-foo)
    Finished dev [unoptimized + debuginfo] target(s) in 0.39 secs
cargo +stable build  0.37s user 0.22s system 92% cpu 0.639 total

$ touch src/main.rs && time cargo +nightly build
   Compiling rust-foo v0.1.0 (file:///Users/gib/tmp/rust-foo)
    Finished dev [unoptimized + debuginfo] target(s) in 2.74 secs
cargo +nightly build  0.34s user 1.06s system 47% cpu 2.995 total

@Mark-Simulacrum
Copy link
Member

I cannot reproduce on macOS High Sierra 10.13.2.

@gibfahn
Copy link
Contributor Author

gibfahn commented Dec 11, 2017

I cannot reproduce on macOS High Sierra 10.13.2.

Odd, not sure what the difference could be.

In case it's a hardware thing, this is my machine's configuration:

image

@Mark-Simulacrum
Copy link
Member

It might be helpful to have a bash script that'll run the commands for me just in case, but as far as I can tell I have the same make of hardware, just a slightly different version of macOS. Seems unlikely that would be the culprit, though...

@gibfahn
Copy link
Contributor Author

gibfahn commented Dec 12, 2017

@Mark-Simulacrum the script in #46505 (comment) is exactly what I'm doing.

I tried this on a different machine (same OS level, different hardware configuration) and it didn't have the same problem. I'm not sure how else to debug.

@Mark-Simulacrum
Copy link
Member

Clearing out ~/.cargo or at least make sure both machines have the same content might help.

@gibfahn
Copy link
Contributor Author

gibfahn commented Dec 13, 2017

Did an uninstall and reinstall (rustup self uninstall), and I can no longer reproduce:

$ cargo new --bin rust-foo && cd rust-foo
     Created binary (application) `rust-foo` project
$ cargo build
   Compiling rust-foo v0.1.0 (file:///Users/gib/tmp/rust-foo)
    Finished dev [unoptimized + debuginfo] target(s) in 0.92 secs
$ touch src/main.rs && time cargo +stable build
   Compiling rust-foo v0.1.0 (file:///Users/gib/tmp/rust-foo)
    Finished dev [unoptimized + debuginfo] target(s) in 0.31 secs
cargo +stable build  0.26s user 0.17s system 92% cpu 0.466 total
$ touch src/main.rs && time cargo +nightly build
   Compiling rust-foo v0.1.0 (file:///Users/gib/tmp/rust-foo)
    Finished dev [unoptimized + debuginfo] target(s) in 0.57 secs
cargo +nightly build  0.31s user 0.22s system 68% cpu 0.774 total

I did have a fair amount of stuff in $CARGO_HOME, so I guess something in there must have affected it:

▶▶▶ ls *                                                                                                                                                                             ~/.local/share/cargo
env

bin:
cargo             cargo-fmt         cargo-watch       cobalt            ion               racer             rust-gdb          rustc             rustfmt           s                 xi-syntect-plugin
cargo-clippy      cargo-wa          clippy-driver     exa               pijul             rls               rust-lldb         rustdoc           rustup            xi-core

git:
checkouts db

registry:
cache index src

Thanks for troubleshooting!

@gibfahn gibfahn closed this as completed Dec 13, 2017
@gibfahn gibfahn reopened this Dec 17, 2017
@gibfahn
Copy link
Contributor Author

gibfahn commented Dec 17, 2017

Okay, I worked out what's going on. I'm seeing this behaviour because I have ulimit -c unlimited in my rc files, and the nightly build generates a coredump every time I run cargo build.

Updated repro:

ls /cores
cargo new --bin rust-foo && cd rust-foo
cargo build
ulimit -c unlimited
touch src/main.rs && time cargo +stable build # Doesn't generate a dump.
ls /cores
touch src/main.rs && time cargo +nightly build # Does generate a dump (thus slower).
ls /cores
ulimit -c 0
touch src/main.rs && time cargo +stable build
touch src/main.rs && time cargo +nightly build # Faster as dumps turned off.
cd .. && rm -rf rust-foo
$ ls /cores

$ cargo new --bin rust-foo && cd rust-foo
     Created binary (application) `rust-foo` project

$ cargo build
   Compiling rust-foo v0.1.0 (file:///Users/gib/tmp/rust-foo)
    Finished dev [unoptimized + debuginfo] target(s) in 0.26 secs

$ ulimit -c unlimited
$ touch src/main.rs && time cargo +stable build
   Compiling rust-foo v0.1.0 (file:///Users/gib/tmp/rust-foo)
    Finished dev [unoptimized + debuginfo] target(s) in 0.31 secs
cargo +stable build  0.27s user 0.16s system 93% cpu 0.467 total

$ ls /cores

$ touch src/main.rs && time cargo +nightly build
   Compiling rust-foo v0.1.0 (file:///Users/gib/tmp/rust-foo)
    Finished dev [unoptimized + debuginfo] target(s) in 1.51 secs
cargo +nightly build  0.24s user 1.03s system 75% cpu 1.679 total

$ ls /cores
core.68358

$ ulimit -c 0
$ touch src/main.rs && time cargo +stable build
   Compiling rust-foo v0.1.0 (file:///Users/gib/tmp/rust-foo)
    Finished dev [unoptimized + debuginfo] target(s) in 0.31 secs
cargo +stable build  0.27s user 0.17s system 94% cpu 0.466 total

$ touch src/main.rs && time cargo +nightly build
   Compiling rust-foo v0.1.0 (file:///Users/gib/tmp/rust-foo)
    Finished dev [unoptimized + debuginfo] target(s) in 0.27 secs
cargo +nightly build  0.24s user 0.15s system 93% cpu 0.429 total

$ cd .. && rm -rf rust-foo

Now I know the issue this is easy enough to work around, I can just disable core dumps. But it'd be good to know why the cores get dumped, maybe it's a mac-specific feature, as the build does complete successfully.

@gibfahn gibfahn changed the title cargo build slowdown on latest nightly with Hello World project cargo build dumps core on latest nightly with Hello World project (macOS) Dec 17, 2017
@arielb1 arielb1 added the T-cargo Relevant to the cargo team, which will review and decide on the PR/issue. label Dec 21, 2017
@arielb1
Copy link
Contributor

arielb1 commented Dec 21, 2017

Assigning to @pnkfelix

Could you try to confirm you can reproduce this today?

@arielb1 arielb1 added T-compiler Relevant to the compiler team, which will review and decide on the PR/issue. and removed T-cargo Relevant to the cargo team, which will review and decide on the PR/issue. labels Dec 21, 2017
@pnkfelix
Copy link
Member

I have now reproduced this, by invoking ulimit -c unlimited before doing the build, as described in @gibfahn 's comment

@pnkfelix
Copy link
Member

This apparently was injected between the nightlies for 2017-11-25 and 2017-11-26:

% ls /cores/ && touch src/main.rs && cargo +nightly-2017-11-25 build && ls /cores/
   Compiling rust-foo v0.1.0 (file:///Users/fklock/Dev/Rust/rust-foo)
    Finished dev [unoptimized + debuginfo] target(s) in 0.28 secs
% ls /cores/ && touch src/main.rs && cargo +nightly-2017-11-26 build && ls /cores/
   Compiling rust-foo v0.1.0 (file:///Users/fklock/Dev/Rust/rust-foo)
    Finished dev [unoptimized + debuginfo] target(s) in 17.21 secs
core.93867
%

rustup's build of cargo didn't change between those dates, but of course rustc did:

% cargo +nightly-2017-11-25 --version
cargo 0.24.0-nightly (abd137ad1 2017-11-12)
% cargo +nightly-2017-11-26 --version
cargo 0.24.0-nightly (abd137ad1 2017-11-12)
% rustc +nightly-2017-11-25 --version
rustc 1.23.0-nightly (5f44c653c 2017-11-24)
% rustc +nightly-2017-11-26 --version
rustc 1.23.0-nightly (e97ba8328 2017-11-25)
%

@pnkfelix
Copy link
Member

pnkfelix commented Dec 21, 2017

The last entries in ouput from RUST_LOG=debug before the core dump are:

DEBUG:rustc::session::filesearch: using sysroot = /Users/fklock/Dev/Mozilla/rust.git/objdir-dbgopt/build/x86_64-apple-darwin/stage1, triple = x86_64-apple-darwin
DEBUG:rustc::session::filesearch: using sysroot = /Users/fklock/Dev/Mozilla/rust.git/objdir-dbgopt/build/x86_64-apple-darwin/stage1, triple = x86_64-apple-darwin
DEBUG:rustc::session::filesearch: filesearch: searching lib path
DEBUG:rustc::session::filesearch: using sysroot = /Users/fklock/Dev/Mozilla/rust.git/objdir-dbgopt/build/x86_64-apple-darwin/stage1, triple = x86_64-apple-darwin
DEBUG:rustc::session::filesearch: filesearch: searching lib path
INFO:rustc_trans::back::link: "cc" "-m64" "-L" "/Users/fklock/Dev/Mozilla/rust.git/objdir-dbgopt/build/x86_64-apple-darwin/stage1/lib/rustlib/x86_64-apple-darwin/lib" "/Users/fklock/Dev/Rust/rust-foo/target/debug/deps/rust_foo-66727de05aaedbe2.rust_foo0.rcgu.o" "/Users/fklock/Dev/Rust/rust-foo/target/debug/deps/rust_foo-66727de05aaedbe2.rust_foo1.rcgu.o" "-o" "/Users/fklock/Dev/Rust/rust-foo/target/debug/deps/rust_foo-66727de05aaedbe2" "/Users/fklock/Dev/Rust/rust-foo/target/debug/deps/rust_foo-66727de05aaedbe2.crate.allocator.rcgu.o" "-Wl,-dead_strip" "-nodefaultlibs" "-L" "/Users/fklock/Dev/Rust/rust-foo/target/debug/deps" "-L" "/Users/fklock/Dev/Mozilla/rust.git/objdir-dbgopt/build/x86_64-apple-darwin/stage1/lib/rustlib/x86_64-apple-darwin/lib" "/Users/fklock/Dev/Mozilla/rust.git/objdir-dbgopt/build/x86_64-apple-darwin/stage1/lib/rustlib/x86_64-apple-darwin/lib/libstd-57382b22bf67ee83.rlib" "/Users/fklock/Dev/Mozilla/rust.git/objdir-dbgopt/build/x86_64-apple-darwin/stage1/lib/rustlib/x86_64-apple-darwin/lib/liballoc_jemalloc-2a6027a0176044f1.rlib" "/Users/fklock/Dev/Mozilla/rust.git/objdir-dbgopt/build/x86_64-apple-darwin/stage1/lib/rustlib/x86_64-apple-darwin/lib/libpanic_unwind-e390cab187e3dd7a.rlib" "/Users/fklock/Dev/Mozilla/rust.git/objdir-dbgopt/build/x86_64-apple-darwin/stage1/lib/rustlib/x86_64-apple-darwin/lib/libunwind-92a61c3bc0a0bb37.rlib" "/Users/fklock/Dev/Mozilla/rust.git/objdir-dbgopt/build/x86_64-apple-darwin/stage1/lib/rustlib/x86_64-apple-darwin/lib/liballoc_system-5b4db32676842192.rlib" "/Users/fklock/Dev/Mozilla/rust.git/objdir-dbgopt/build/x86_64-apple-darwin/stage1/lib/rustlib/x86_64-apple-darwin/lib/liblibc-ced140dd899f4b45.rlib" "/Users/fklock/Dev/Mozilla/rust.git/objdir-dbgopt/build/x86_64-apple-darwin/stage1/lib/rustlib/x86_64-apple-darwin/lib/liballoc-22e63b537c61a4f8.rlib" "/Users/fklock/Dev/Mozilla/rust.git/objdir-dbgopt/build/x86_64-apple-darwin/stage1/lib/rustlib/x86_64-apple-darwin/lib/libstd_unicode-aa82a4fba39f1481.rlib" "/Users/fklock/Dev/Mozilla/rust.git/objdir-dbgopt/build/x86_64-apple-darwin/stage1/lib/rustlib/x86_64-apple-darwin/lib/libcore-a1b407ed3953731d.rlib" "/Users/fklock/Dev/Mozilla/rust.git/objdir-dbgopt/build/x86_64-apple-darwin/stage1/lib/rustlib/x86_64-apple-darwin/lib/libcompiler_builtins-16b5d3749fd37ffd.rlib" "-l" "System" "-l" "resolv" "-l" "pthread" "-l" "c" "-l" "m"
INFO:rustc_trans::back::link: linker stderr:

INFO:rustc_trans::back::link: linker stdout:


Additionally, I tried running rustc under lldb to see if the stacktrace there would be more informative, but it did not tell me much:

% lldb /Users/fklock/Dev/Mozilla/rust.git/objdir-dbgopt/build/x86_64-apple-darwin/stage1/bin/rustc -- --crate-name rust_foo src/main.rs --crate-type bin --emit=dep-info,link -C debuginfo=2 -C metadata=66727de05aaedbe2 -C extra-filename=-66727de05aaedbe2 --out-dir /Users/fklock/Dev/Rust/rust-foo/target/debug/deps -L dependency=/Users/fklock/Dev/Rust/rust-foo/target/debug/deps
(lldb) target create "/Users/fklock/Dev/Mozilla/rust.git/objdir-dbgopt/build/x86_64-apple-darwin/stage1/bin/rustc"
Current executable set to '/Users/fklock/Dev/Mozilla/rust.git/objdir-dbgopt/build/x86_64-apple-darwin/stage1/bin/rustc' (x86_64).
(lldb) settings set -- target.run-args  "--crate-name" "rust_foo" "src/main.rs" "--crate-type" "bin" "--emit=dep-info,link" "-C" "debuginfo=2" "-C" "metadata=66727de05aaedbe2" "-C" "extra-filename=-66727de05aaedbe2" "--out-dir" "/Users/fklock/Dev/Rust/rust-foo/target/debug/deps" "-L" "dependency=/Users/fklock/Dev/Rust/rust-foo/target/debug/deps"
(lldb) r
Process 94919 launched: '/Users/fklock/Dev/Mozilla/rust.git/objdir-dbgopt/build/x86_64-apple-darwin/stage1/bin/rustc' (x86_64)
Process 94919 stopped
* thread #2, stop reason = signal SIGUSR1
    frame #0: 0x0000000100008813 dyld`dyld::fastBindLazySymbol(ImageLoader**, unsigned long)
dyld`dyld::fastBindLazySymbol:
->  0x100008813 <+0>: pushq  %rbp
    0x100008814 <+1>: movq   %rsp, %rbp
    0x100008817 <+4>: pushq  %r14
    0x100008819 <+6>: pushq  %rbx
Target 0: (rustc) stopped.
(lldb) bt
* thread #2, stop reason = signal SIGUSR1
  * frame #0: 0x0000000100008813 dyld`dyld::fastBindLazySymbol(ImageLoader**, unsigned long)
    frame #1: 0x00007fff9b4bf282 libdyld.dylib`dyld_stub_binder + 282
    frame #2: 0x0000000106e4e008 librustc-a48978afc4e78e65.dylib
    frame #3: 0x0000000106abd7cf librustc-a48978afc4e78e65.dylib`std::sys_common::backtrace::__rust_begin_short_backtrace::h58c39d6d297406e3 + 399
    frame #4: 0x0000000106ab78f0 librustc-a48978afc4e78e65.dylib`_$LT$std..panic..AssertUnwindSafe$LT$F$GT$$u20$as$u20$core..ops..function..FnOnce$LT$$LP$$RP$$GT$$GT$::call_once::hf4d567cb0f4d1e3c + 80
    frame #5: 0x0000000106ab7b20 librustc-a48978afc4e78e65.dylib`std::panicking::try::do_call::h9b33a9c46ac13d05 + 80
    frame #6: 0x000000010954e658 libstd-e514f1ff308a6a87.dylib`__rust_maybe_catch_panic + 40
    frame #7: 0x0000000106ab7a53 librustc-a48978afc4e78e65.dylib`std::panicking::try::h103437c28968e1f9 + 115
    frame #8: 0x0000000106ab7954 librustc-a48978afc4e78e65.dylib`std::panic::catch_unwind::h36510de003523451 + 84
    frame #9: 0x0000000106abe843 librustc-a48978afc4e78e65.dylib`_$LT$F$u20$as$u20$alloc..boxed..FnBox$LT$A$GT$$GT$::call_box::h9bc74a6deca9ec7d + 195
    frame #10: 0x000000010953fcc1 libstd-e514f1ff308a6a87.dylib`std::sys_common::thread::start_thread::hbccb1a1515a8b445 + 33
    frame #11: 0x0000000109511169 libstd-e514f1ff308a6a87.dylib`std::sys::unix::thread::Thread::new::thread_start::ha9d840ea903629e8 + 9
    frame #12: 0x00007fff9b6dc93b libsystem_pthread.dylib`_pthread_body + 180
    frame #13: 0x00007fff9b6dc887 libsystem_pthread.dylib`_pthread_start + 286
    frame #14: 0x00007fff9b6dc08d libsystem_pthread.dylib`thread_start + 13
(lldb) 

@pnkfelix
Copy link
Member

I suppose another option is to load the core dump itself into the debugger and see what it says:

lldb -c /cores/core.95085 
(lldb) target create --core "/cores/core.95085"
warning: (x86_64) /cores/core.95085 load command 352 LC_SEGMENT_64 has a fileoff + filesize (0x2ffef000) that extends beyond the end of the file (0x2ffee000), the segment will be truncated to match
warning: (x86_64) /cores/core.95085 load command 353 LC_SEGMENT_64 has a fileoff (0x2ffef000) that extends beyond the end of the file (0x2ffee000), ignoring this section
Core file '/cores/core.95085' (x86_64) was loaded.
(lldb) bt -- backtrace
error: _regexp-bt
(lldb) bt
* thread #1, stop reason = signal SIGSTOP
  * frame #0: 0x000000010d543e1a dsymutil`llvm::dsymutil::(anonymous namespace)::DwarfLinker::lookForDIEsToKeep(llvm::dsymutil::(anonymous namespace)::DwarfLinker::RelocationManager&, llvm::DWARFDie const&, llvm::dsymutil::DebugMapObject const&, llvm::dsymutil::(anonymous namespace)::CompileUnit&, unsigned int) + 1066
    frame #1: 0x000000010d544042 dsymutil`llvm::dsymutil::(anonymous namespace)::DwarfLinker::lookForDIEsToKeep(llvm::dsymutil::(anonymous namespace)::DwarfLinker::RelocationManager&, llvm::DWARFDie const&, llvm::dsymutil::DebugMapObject const&, llvm::dsymutil::(anonymous namespace)::CompileUnit&, unsigned int) + 1618
    frame #2: 0x000000010d54418f dsymutil`llvm::dsymutil::(anonymous namespace)::DwarfLinker::lookForDIEsToKeep(llvm::dsymutil::(anonymous namespace)::DwarfLinker::RelocationManager&, llvm::DWARFDie const&, llvm::dsymutil::DebugMapObject const&, llvm::dsymutil::(anonymous namespace)::CompileUnit&, unsigned int) + 1951
    frame #3: 0x000000010d54418f dsymutil`llvm::dsymutil::(anonymous namespace)::DwarfLinker::lookForDIEsToKeep(llvm::dsymutil::(anonymous namespace)::DwarfLinker::RelocationManager&, llvm::DWARFDie const&, llvm::dsymutil::DebugMapObject const&, llvm::dsymutil::(anonymous namespace)::CompileUnit&, unsigned int) + 1951
    frame #4: 0x000000010d54418f dsymutil`llvm::dsymutil::(anonymous namespace)::DwarfLinker::lookForDIEsToKeep(llvm::dsymutil::(anonymous namespace)::DwarfLinker::RelocationManager&, llvm::DWARFDie const&, llvm::dsymutil::DebugMapObject const&, llvm::dsymutil::(anonymous namespace)::CompileUnit&, unsigned int) + 1951
    frame #5: 0x000000010d54418f dsymutil`llvm::dsymutil::(anonymous namespace)::DwarfLinker::lookForDIEsToKeep(llvm::dsymutil::(anonymous namespace)::DwarfLinker::RelocationManager&, llvm::DWARFDie const&, llvm::dsymutil::DebugMapObject const&, llvm::dsymutil::(anonymous namespace)::CompileUnit&, unsigned int) + 1951
    frame #6: 0x000000010d544042 dsymutil`llvm::dsymutil::(anonymous namespace)::DwarfLinker::lookForDIEsToKeep(llvm::dsymutil::(anonymous namespace)::DwarfLinker::RelocationManager&, llvm::DWARFDie const&, llvm::dsymutil::DebugMapObject const&, llvm::dsymutil::(anonymous namespace)::CompileUnit&, unsigned int) + 1618
    frame #7: 0x000000010d54418f dsymutil`llvm::dsymutil::(anonymous namespace)::DwarfLinker::lookForDIEsToKeep(llvm::dsymutil::(anonymous namespace)::DwarfLinker::RelocationManager&, llvm::DWARFDie const&, llvm::dsymutil::DebugMapObject const&, llvm::dsymutil::(anonymous namespace)::CompileUnit&, unsigned int) + 1951
    frame #8: 0x000000010d544042 dsymutil`llvm::dsymutil::(anonymous namespace)::DwarfLinker::lookForDIEsToKeep(llvm::dsymutil::(anonymous namespace)::DwarfLinker::RelocationManager&, llvm::DWARFDie const&, llvm::dsymutil::DebugMapObject const&, llvm::dsymutil::(anonymous namespace)::CompileUnit&, unsigned int) + 1618
    frame #9: 0x000000010d54418f dsymutil`llvm::dsymutil::(anonymous namespace)::DwarfLinker::lookForDIEsToKeep(llvm::dsymutil::(anonymous namespace)::DwarfLinker::RelocationManager&, llvm::DWARFDie const&, llvm::dsymutil::DebugMapObject const&, llvm::dsymutil::(anonymous namespace)::CompileUnit&, unsigned int) + 1951
    frame #10: 0x000000010d544042 dsymutil`llvm::dsymutil::(anonymous namespace)::DwarfLinker::lookForDIEsToKeep(llvm::dsymutil::(anonymous namespace)::DwarfLinker::RelocationManager&, llvm::DWARFDie const&, llvm::dsymutil::DebugMapObject const&, llvm::dsymutil::(anonymous namespace)::CompileUnit&, unsigned int) + 1618
    frame #11: 0x000000010d544042 dsymutil`llvm::dsymutil::(anonymous namespace)::DwarfLinker::lookForDIEsToKeep(llvm::dsymutil::(anonymous namespace)::DwarfLinker::RelocationManager&, llvm::DWARFDie const&, llvm::dsymutil::DebugMapObject const&, llvm::dsymutil::(anonymous namespace)::CompileUnit&, unsigned int) + 1618
    frame #12: 0x000000010d54418f dsymutil`llvm::dsymutil::(anonymous namespace)::DwarfLinker::lookForDIEsToKeep(llvm::dsymutil::(anonymous namespace)::DwarfLinker::RelocationManager&, llvm::DWARFDie const&, llvm::dsymutil::DebugMapObject const&, llvm::dsymutil::(anonymous namespace)::CompileUnit&, unsigned int) + 1951
    frame #13: 0x000000010d544042 dsymutil`llvm::dsymutil::(anonymous namespace)::DwarfLinker::lookForDIEsToKeep(llvm::dsymutil::(anonymous namespace)::DwarfLinker::RelocationManager&, llvm::DWARFDie const&, llvm::dsymutil::DebugMapObject const&, llvm::dsymutil::(anonymous namespace)::CompileUnit&, unsigned int) + 1618
    frame #14: 0x000000010d54418f dsymutil`llvm::dsymutil::(anonymous namespace)::DwarfLinker::lookForDIEsToKeep(llvm::dsymutil::(anonymous namespace)::DwarfLinker::RelocationManager&, llvm::DWARFDie const&, llvm::dsymutil::DebugMapObject const&, llvm::dsymutil::(anonymous namespace)::CompileUnit&, unsigned int) + 1951
    frame #15: 0x000000010d544042 dsymutil`llvm::dsymutil::(anonymous namespace)::DwarfLinker::lookForDIEsToKeep(llvm::dsymutil::(anonymous namespace)::DwarfLinker::RelocationManager&, llvm::DWARFDie const&, llvm::dsymutil::DebugMapObject const&, llvm::dsymutil::(anonymous namespace)::CompileUnit&, unsigned int) + 1618
    frame #16: 0x000000010d54418f dsymutil`llvm::dsymutil::(anonymous namespace)::DwarfLinker::lookForDIEsToKeep(llvm::dsymutil::(anonymous namespace)::DwarfLinker::RelocationManager&, llvm::DWARFDie const&, llvm::dsymutil::DebugMapObject const&, llvm::dsymutil::(anonymous namespace)::CompileUnit&, unsigned int) + 1951
    frame #17: 0x000000010d544042 dsymutil`llvm::dsymutil::(anonymous namespace)::DwarfLinker::lookForDIEsToKeep(llvm::dsymutil::(anonymous namespace)::DwarfLinker::RelocationManager&, llvm::DWARFDie const&, llvm::dsymutil::DebugMapObject const&, llvm::dsymutil::(anonymous namespace)::CompileUnit&, unsigned int) + 1618
    frame #18: 0x000000010d54418f dsymutil`llvm::dsymutil::(anonymous namespace)::DwarfLinker::lookForDIEsToKeep(llvm::dsymutil::(anonymous namespace)::DwarfLinker::RelocationManager&, llvm::DWARFDie const&, llvm::dsymutil::DebugMapObject const&, llvm::dsymutil::(anonymous namespace)::CompileUnit&, unsigned int) + 1951
    frame #19: 0x000000010d543dc4 dsymutil`llvm::dsymutil::(anonymous namespace)::DwarfLinker::lookForDIEsToKeep(llvm::dsymutil::(anonymous namespace)::DwarfLinker::RelocationManager&, llvm::DWARFDie const&, llvm::dsymutil::DebugMapObject const&, llvm::dsymutil::(anonymous namespace)::CompileUnit&, unsigned int) + 980
    frame #20: 0x000000010d54418f dsymutil`llvm::dsymutil::(anonymous namespace)::DwarfLinker::lookForDIEsToKeep(llvm::dsymutil::(anonymous namespace)::DwarfLinker::RelocationManager&, llvm::DWARFDie const&, llvm::dsymutil::DebugMapObject const&, llvm::dsymutil::(anonymous namespace)::CompileUnit&, unsigned int) + 1951
    frame #21: 0x000000010d54418f dsymutil`llvm::dsymutil::(anonymous namespace)::DwarfLinker::lookForDIEsToKeep(llvm::dsymutil::(anonymous namespace)::DwarfLinker::RelocationManager&, llvm::DWARFDie const&, llvm::dsymutil::DebugMapObject const&, llvm::dsymutil::(anonymous namespace)::CompileUnit&, unsigned int) + 1951
    frame #22: 0x000000010d54418f dsymutil`llvm::dsymutil::(anonymous namespace)::DwarfLinker::lookForDIEsToKeep(llvm::dsymutil::(anonymous namespace)::DwarfLinker::RelocationManager&, llvm::DWARFDie const&, llvm::dsymutil::DebugMapObject const&, llvm::dsymutil::(anonymous namespace)::CompileUnit&, unsigned int) + 1951
    frame #23: 0x000000010d54418f dsymutil`llvm::dsymutil::(anonymous namespace)::DwarfLinker::lookForDIEsToKeep(llvm::dsymutil::(anonymous namespace)::DwarfLinker::RelocationManager&, llvm::DWARFDie const&, llvm::dsymutil::DebugMapObject const&, llvm::dsymutil::(anonymous namespace)::CompileUnit&, unsigned int) + 1951
    frame #24: 0x000000010d53f4a4 dsymutil`llvm::dsymutil::(anonymous namespace)::DwarfLinker::link(llvm::dsymutil::DebugMap const&) + 14964
    frame #25: 0x000000010d53b2ca dsymutil`llvm::dsymutil::linkDwarf(llvm::StringRef, llvm::dsymutil::DebugMap const&, llvm::dsymutil::LinkOptions const&) + 2762
    frame #26: 0x000000010d52af95 dsymutil`main + 8421
    frame #27: 0x00007fff9b4c3235 libdyld.dylib`start + 1
    frame #28: 0x00007fff9b4c3235 libdyld.dylib`start + 1
(lldb) 

I have to go home now. I probably will not look at this again until tomorrow (and it will have to take lower precedence than fixes to the beta branch in preparation for the upcoming release).

@pnkfelix
Copy link
Member

pnkfelix commented Dec 21, 2017

In other fronts of investigation: I worked on analyzing the actual rustc invocation that cargo is using for this code, since I do not see this same behavior of dumping core in my day-to-day work on Rust.

Starting from the original invocation and whittling it down, I have determined that adding -C debuginfo=2 to the rustc invocation is how one replicates the core dump (and to be clear: this is on OS X, with ulimit -c unlimited)

So:

% rm -f /cores/*
% ls /cores/
% cat hello.rs
fn main() {
    println!("Hello World");
}
% ./build/x86_64-apple-darwin/stage1/bin/rustc hello.rs 
% ls /cores/
% ./build/x86_64-apple-darwin/stage1/bin/rustc hello.rs -C debuginfo=2
% ls /cores/
core.97645
% 

@pnkfelix
Copy link
Member

pnkfelix commented Dec 21, 2017

Oh.

Looking at my "OS X" terminal window during that long pause where the core dump is happening, the title bar of the window shows (I think) the current active child process.

In this case, it appears to be dsymutil

  • Update: this explains the stack trace I saw in the core dump, which had dsymutil`main + 8421 at frame #26

Maybe something has gone wrong with how we are invoking that utility?

@kennytm
Copy link
Member

kennytm commented Dec 21, 2017

dsymutil? Sounds like #46346 (fixed 8 hours ago). Check with the next nightly?

@gibfahn
Copy link
Contributor Author

gibfahn commented Dec 28, 2017

I can no longer reproduce this with the latest nightly, so I'm guessing #46346 was the fix.

Thanks for all the investigation!

@gibfahn gibfahn closed this as completed Dec 28, 2017
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
I-compiletime Issue: Problems and improvements with respect to compile times. regression-from-stable-to-nightly Performance or correctness regression from stable to nightly. T-compiler Relevant to the compiler team, which will review and decide on the PR/issue.
Projects
None yet
Development

No branches or pull requests

7 participants