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

performance regression and occasionnal dead-lock when linking with llvm 3.9 #36905

Closed
semarie opened this issue Oct 2, 2016 · 7 comments
Closed

Comments

@semarie
Copy link
Contributor

semarie commented Oct 2, 2016

I experiment some problems with rustc 1.12.0 (under OpenBSD):

There are two kind of problems:

  • performance regression from stable to stable : I saw lot of xxx has been running for over 60 seconds messages in make check
  • occasionnally rustc compiler dead-lock: all threads are in thrslee state.

For the performance problem, by tracing the syscalls I saw lot of __thrsleep(), __thrwakeup() and sched_yield() dance: the process makes high usage of thread-syscalls, and it slows down.

Some stats for 1 second, I have 16314 syscalls:

  • 7344 __thrwakeup
  • 7343 __thrsleep
  • 1605 sched_yield
  • 11 mmap
  • 4 write
  • 4 mquery
  • 2 munmap
  • 1 fstat

For this second, by thread:

  • thread 1031567:
    • 1850 __thrsleep
    • 1850 __thrwakeup
    • 443 sched_yield
  • thread 1048099
    • 1848 __thrsleep
    • 1848 __thrwakeup
    • 298 sched_yield
  • thread 1056179:
    • 1844 __thrsleep
    • 1844 __thrwakeup
    • 483 sched_yield
    • 4 write
    • 3 mmap
    • 2 mquery
    • 1 munmap
    • 1 fstat
  • thread 1065035:
    • 1801 __thrsleep
    • 1802 __thrwakeup
    • 381 sched_yield
    • 8 mmap
    • 2 mquery
    • 1 munmap

I am unsure about the way to better describe the problem or reduce it.

@nagisa
Copy link
Member

nagisa commented Oct 2, 2016

7344 __thrwakeup
7343 __thrsleep

Looks a lot like some thread synchronisation (mutexes?). Does OpenBSD pthread mutex make a syscall each time the mutex is locked and unlocked?

occasionnally rustc compiler dead-lock: all threads are in thrslee state.

That’s amusing. Could you get a backtrace for all the threads when this happens? (You can cause a coredump with SIGQUIT, after setting ulimit to allow coredumps. Opening the coredump with gdb should then allow you to recover the backtrace)

@semarie
Copy link
Contributor Author

semarie commented Oct 3, 2016

Under OpenBSD, threads synchronisation primitives relies on syscalls. I am unsure for all the details (when a syscall is called / when it is unneed). But __thrwakeup, __thrsleep and sched_yield are used by pthread.

Here is the gdb backtrace for all threads.

GNU gdb (GDB) 7.11.1
Copyright (C) 2016 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-unknown-openbsd6.0".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
<http://www.gnu.org/software/gdb/documentation/>.
For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from x86_64-unknown-openbsd/stage2/bin/rustc...(no debugging symbols found)...done.
[New process 14838]
[New process 10955]
[New process 97746]
[New process 50564]
[New process 74568]
[New process 18828]
Core was generated by `rustc'.
Program terminated with signal SIGQUIT, Quit.
#0  0x00001ea89f12bd6a in _thread_sys___thrsleep () at <stdin>:2
[Current thread is 1 (process 14838)]
(gdb) thread apply all bt

Thread 6 (process 18828):
#0  0x00001ea89f12bd6a in _thread_sys___thrsleep () at <stdin>:2
#1  0x00001ea8b87363ec in _rthread_mutex_lock (mutexp=0x1ea8031c66e8 <std::__get_once_mutex()::once_mutex>, trywait=0, abstime=0x0) at /usr/src/lib/librthread/rthread_sync.c:149
#2  0x00001ea824888819 in __gthread_mutex_lock(pthread_mutex volatile**) () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_llvm-40393716.so
#3  0x00001ea82488a6e6 in std::mutex::lock() () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_llvm-40393716.so
#4  0x00001ea82489d10d in std::unique_lock<std::mutex>::lock() () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_llvm-40393716.so
#5  0x00001ea8248989af in std::unique_lock<std::mutex>::unique_lock(std::mutex&) () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_llvm-40393716.so
#6  0x00001ea824894cca in void std::call_once<void* (&)(llvm::PassRegistry&), std::reference_wrapper<llvm::PassRegistry> >(std::once_flag&, void* (&)(llvm::PassRegistry&), std::reference_wrapper<llvm::PassRegistry>&&) () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_llvm-40393716.so
#7  0x00001ea824890f41 in void llvm::call_once<void* (&)(llvm::PassRegistry&), std::reference_wrapper<llvm::PassRegistry> >(std::once_flag&, void* (&)(llvm::PassRegistry&), std::reference_wrapper<llvm::PassRegistry>&&) () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_llvm-40393716.so
#8  0x00001ea8257e1436 in llvm::initializeMachineSinkingPass(llvm::PassRegistry&) () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_llvm-40393716.so
#9  0x00001ea8257e1296 in (anonymous namespace)::MachineSinking::MachineSinking() () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_llvm-40393716.so
#10 0x00001ea8257e3c56 in llvm::Pass* llvm::callDefaultCtor<(anonymous namespace)::MachineSinking>() () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_llvm-40393716.so
#11 0x00001ea8262597cc in llvm::PassInfo::createPass() const () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_llvm-40393716.so
#12 0x00001ea82629d5a3 in llvm::Pass::createPass(void const*) () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_llvm-40393716.so
#13 0x00001ea825917bc3 in llvm::TargetPassConfig::addPass(void const*, bool, bool) () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_llvm-40393716.so
#14 0x00001ea825918d6a in llvm::TargetPassConfig::addMachineSSAOptimization() () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_llvm-40393716.so
#15 0x00001ea8259187a8 in llvm::TargetPassConfig::addMachinePasses() () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_llvm-40393716.so
#16 0x00001ea825730b8e in addPassesToGenerateCode(llvm::LLVMTargetMachine*, llvm::legacy::PassManagerBase&, bool, void const*, void const*, void const*, llvm::MachineFunctionInitializer*) () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_llvm-40393716.so
#17 0x00001ea825730c75 in llvm::LLVMTargetMachine::addPassesToEmitFile(llvm::legacy::PassManagerBase&, llvm::raw_pwrite_stream&, llvm::TargetMachine::CodeGenFileType, bool, void const*, void const*, void const*, llvm::MachineFunctionInitializer*) () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_llvm-40393716.so
#18 0x00001ea8247dfc7e in LLVMRustWriteOutputFile (Target=0x1ea828f57000, PMR=0x1ea86b6a00f0, M=0x1ea8a8345c00, path=<optimized out>, rust_FileType=<optimized out>) at /home/semarie/data/src/rust/src/rustllvm/PassWrapper.cpp:481
#19 0x00001ea87b7595c4 in rustc_trans::back::write::write_output_file::h0e1786ed60f8f07f () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_trans-40393716.so
#20 0x00001ea87b86026a in rustc_trans::back::write::optimize_and_codegen::_$u7b$$u7b$closure$u7d$$u7d$::h25034d2a8e2d0336 () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_trans-40393716.so
#21 0x00001ea87b761e9f in rustc_trans::back::write::execute_work_item::h16483495753d2a00 () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_trans-40393716.so
#22 0x00001ea87b6ee4d2 in std::panicking::try::do_call::hd805aff4cb5a7af6 () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_trans-40393716.so
#23 0x00001ea812449bb7 in __rust_maybe_catch_panic () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/libstd-40393716.so
#24 0x00001ea87b706baf in _$LT$F$u20$as$u20$alloc..boxed..FnBox$LT$A$GT$$GT$::call_box::h81d7664434da1b99 () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_trans-40393716.so
#25 0x00001ea812438a93 in std::sys::thread::Thread::new::thread_start::h4c0ad33b336bc6ea () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/libstd-40393716.so
#26 0x00001ea8b873846e in _rthread_start (v=0x5e) at /usr/src/lib/librthread/rthread.c:114
#27 0x00001ea89f0c33ab in __tfork_thread () at /usr/src/lib/libc/arch/amd64/sys/tfork_thread.S:75
#28 0x0000000000000000 in ?? ()

Thread 5 (process 74568):
#0  0x00001ea89f12bd6a in _thread_sys___thrsleep () at <stdin>:2
#1  0x00001ea8b87363ec in _rthread_mutex_lock (mutexp=0x1ea828584d28 <InitializeSpillPlacementPassFlag+8>, trywait=0, abstime=0x0) at /usr/src/lib/librthread/rthread_sync.c:149
#2  0x00001ea8b8738ce5 in pthread_once (once_control=0x1ea828584d20 <InitializeSpillPlacementPassFlag>, init_routine=0x0) at /usr/src/lib/librthread/rthread_once.c:24
#3  0x00001ea8248887ea in __gthread_once(pthread_once*, void (*)()) () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_llvm-40393716.so
#4  0x00001ea824894d3a in void std::call_once<void* (&)(llvm::PassRegistry&), std::reference_wrapper<llvm::PassRegistry> >(std::once_flag&, void* (&)(llvm::PassRegistry&), std::reference_wrapper<llvm::PassRegistry>&&) () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_llvm-40393716.so
#5  0x00001ea824890f41 in void llvm::call_once<void* (&)(llvm::PassRegistry&), std::reference_wrapper<llvm::PassRegistry> >(std::once_flag&, void* (&)(llvm::PassRegistry&), std::reference_wrapper<llvm::PassRegistry>&&) () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_llvm-40393716.so
#6  0x00001ea8258cbc42 in llvm::initializeSpillPlacementPass(llvm::PassRegistry&) () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_llvm-40393716.so
#7  0x00001ea8258476cb in (anonymous namespace)::RAGreedy::RAGreedy() () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_llvm-40393716.so
#8  0x00001ea825847245 in llvm::createGreedyRegisterAllocator() () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_llvm-40393716.so
#9  0x00001ea825918e56 in llvm::TargetPassConfig::createTargetRegisterAllocator(bool) () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_llvm-40393716.so
#10 0x00001ea825918ec1 in llvm::TargetPassConfig::createRegAllocPass(bool) () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_llvm-40393716.so
#11 0x00001ea825918826 in llvm::TargetPassConfig::addMachinePasses() () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_llvm-40393716.so
#12 0x00001ea825730b8e in addPassesToGenerateCode(llvm::LLVMTargetMachine*, llvm::legacy::PassManagerBase&, bool, void const*, void const*, void const*, llvm::MachineFunctionInitializer*) () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_llvm-40393716.so
#13 0x00001ea825730c75 in llvm::LLVMTargetMachine::addPassesToEmitFile(llvm::legacy::PassManagerBase&, llvm::raw_pwrite_stream&, llvm::TargetMachine::CodeGenFileType, bool, void const*, void const*, void const*, llvm::MachineFunctionInitializer*) () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_llvm-40393716.so
#14 0x00001ea8247dfc7e in LLVMRustWriteOutputFile (Target=0x1ea8ad3e7000, PMR=0x1ea86b6a01e0, M=0x1ea866fc1c00, path=<optimized out>, rust_FileType=<optimized out>) at /home/semarie/data/src/rust/src/rustllvm/PassWrapper.cpp:481
#15 0x00001ea87b7595c4 in rustc_trans::back::write::write_output_file::h0e1786ed60f8f07f () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_trans-40393716.so
#16 0x00001ea87b86026a in rustc_trans::back::write::optimize_and_codegen::_$u7b$$u7b$closure$u7d$$u7d$::h25034d2a8e2d0336 () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_trans-40393716.so
#17 0x00001ea87b761e9f in rustc_trans::back::write::execute_work_item::h16483495753d2a00 () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_trans-40393716.so
#18 0x00001ea87b6ee4d2 in std::panicking::try::do_call::hd805aff4cb5a7af6 () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_trans-40393716.so
#19 0x00001ea812449bb7 in __rust_maybe_catch_panic () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/libstd-40393716.so
#20 0x00001ea87b706baf in _$LT$F$u20$as$u20$alloc..boxed..FnBox$LT$A$GT$$GT$::call_box::h81d7664434da1b99 () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_trans-40393716.so
#21 0x00001ea812438a93 in std::sys::thread::Thread::new::thread_start::h4c0ad33b336bc6ea () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/libstd-40393716.so
#22 0x00001ea8b873846e in _rthread_start (v=0x5e) at /usr/src/lib/librthread/rthread.c:114
#23 0x00001ea89f0c33ab in __tfork_thread () at /usr/src/lib/libc/arch/amd64/sys/tfork_thread.S:75
#24 0x0000000000000000 in ?? ()

Thread 4 (process 50564):
#0  0x00001ea89f12bd6a in _thread_sys___thrsleep () at <stdin>:2
#1  0x00001ea8b8735f73 in *_libpthread_pthread_cond_wait (condp=<optimized out>, mutexp=<optimized out>) at /usr/src/lib/librthread/rthread_sync.c:511
#2  0x00001ea812405db9 in std::thread::park::h7910c58d95aefb89 () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/libstd-40393716.so
#3  0x00001ea812425940 in std::sync::mpsc::blocking::WaitToken::wait::h8c83dcef69d58c2b () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/libstd-40393716.so
#4  0x00001ea7f679d3c1 in _$LT$std..sync..mpsc..Receiver$LT$T$GT$$GT$::recv::hf6df6e46efa6a635 () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc-40393716.so
#5  0x00001ea7f683dfe5 in rustc::dep_graph::thread::main::hd5b76861353f3aba () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc-40393716.so
#6  0x00001ea7f6796d4f in std::panicking::try::do_call::h75ba0ac486cb1fa8 () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc-40393716.so
#7  0x00001ea812449bb7 in __rust_maybe_catch_panic () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/libstd-40393716.so
#8  0x00001ea7f67c2199 in _$LT$F$u20$as$u20$alloc..boxed..FnBox$LT$A$GT$$GT$::call_box::h554387e4c648b36f () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc-40393716.so
#9  0x00001ea812438a93 in std::sys::thread::Thread::new::thread_start::h4c0ad33b336bc6ea () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/libstd-40393716.so
#10 0x00001ea8b873846e in _rthread_start (v=0x5e) at /usr/src/lib/librthread/rthread.c:114
#11 0x00001ea89f0c33ab in __tfork_thread () at /usr/src/lib/libc/arch/amd64/sys/tfork_thread.S:75
#12 0x0000000000000000 in ?? ()

Thread 3 (process 97746):
#0  0x00001ea89f12bd6a in _thread_sys___thrsleep () at <stdin>:2
#1  0x00001ea8b8735f73 in *_libpthread_pthread_cond_wait (condp=<optimized out>, mutexp=<optimized out>) at /usr/src/lib/librthread/rthread_sync.c:511
#2  0x00001ea812405db9 in std::thread::park::h7910c58d95aefb89 () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/libstd-40393716.so
#3  0x00001ea812425940 in std::sync::mpsc::blocking::WaitToken::wait::h8c83dcef69d58c2b () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/libstd-40393716.so
#4  0x00001ea87b75d74c in rustc_trans::back::write::run_passes::hfe2f5491c3937c7d () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_trans-40393716.so
#5  0x00001ea8886959c0 in rustc_driver::driver::phase_5_run_llvm_passes::hebb06729f3c92d6e () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_driver-40393716.so
#6  0x00001ea88867e5c1 in rustc_driver::driver::compile_input::h4d6bc655b7baad10 () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_driver-40393716.so
#7  0x00001ea8886aab97 in rustc_driver::run_compiler::h9165e61fc2dd486f () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_driver-40393716.so
#8  0x00001ea8885f1b13 in std::panicking::try::do_call::hc52dd3bdae996640 () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_driver-40393716.so
#9  0x00001ea812449bb7 in __rust_maybe_catch_panic () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/libstd-40393716.so
#10 0x00001ea88860b1ab in _$LT$F$u20$as$u20$alloc..boxed..FnBox$LT$A$GT$$GT$::call_box::h3aad53cfb9d2713a () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_driver-40393716.so
#11 0x00001ea812438a93 in std::sys::thread::Thread::new::thread_start::h4c0ad33b336bc6ea () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/libstd-40393716.so
#12 0x00001ea8b873846e in _rthread_start (v=0x5e) at /usr/src/lib/librthread/rthread.c:114
#13 0x00001ea89f0c33ab in __tfork_thread () at /usr/src/lib/libc/arch/amd64/sys/tfork_thread.S:75
#14 0x0000000000000000 in ?? ()

Thread 2 (process 10955):
#0  0x00001ea89f12bd6a in _thread_sys___thrsleep () at <stdin>:2
#1  0x00001ea8b873a07f in _sem_wait (sem=0x1ea84e58b238, tryonly=0, abstime=0x0, delayed_cancel=0x1ea8b894230c <_initial_thread+204>) at /usr/src/lib/librthread/rthread_sem.c:74
#2  0x00001ea8b873841b in pthread_join (thread=0x1ea84e58b238, retval=0x0) at /usr/src/lib/librthread/rthread.c:373
#3  0x00001ea8886a9015 in rustc_driver::run::ha6bc7b823ad700af () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_driver-40393716.so
#4  0x00001ea8886b7e56 in rustc_driver::main::h1cac4fa29a384d12 () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_driver-40393716.so
#5  0x00001ea812449bb7 in __rust_maybe_catch_panic () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/libstd-40393716.so
#6  0x00001ea8124398fb in std::rt::lang_start::h53bf99b0829cc03c () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/libstd-40393716.so
#7  0x00001ea5eba00432 in _start ()

Thread 1 (process 14838):
#0  0x00001ea89f12bd6a in _thread_sys___thrsleep () at <stdin>:2
#1  0x00001ea8b87363ec in _rthread_mutex_lock (mutexp=0x1ea8031c66e8 <std::__get_once_mutex()::once_mutex>, trywait=0, abstime=0x0) at /usr/src/lib/librthread/rthread_sync.c:149
#2  0x00001ea824888819 in __gthread_mutex_lock(pthread_mutex volatile**) () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_llvm-40393716.so
#3  0x00001ea82488a6e6 in std::mutex::lock() () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_llvm-40393716.so
#4  0x00001ea82489d10d in std::unique_lock<std::mutex>::lock() () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_llvm-40393716.so
#5  0x00001ea8248989af in std::unique_lock<std::mutex>::unique_lock(std::mutex&) () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_llvm-40393716.so
#6  0x00001ea824894cca in void std::call_once<void* (&)(llvm::PassRegistry&), std::reference_wrapper<llvm::PassRegistry> >(std::once_flag&, void* (&)(llvm::PassRegistry&), std::reference_wrapper<llvm::PassRegistry>&&) () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_llvm-40393716.so
#7  0x00001ea824890f41 in void llvm::call_once<void* (&)(llvm::PassRegistry&), std::reference_wrapper<llvm::PassRegistry> >(std::once_flag&, void* (&)(llvm::PassRegistry&), std::reference_wrapper<llvm::PassRegistry>&&) () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_llvm-40393716.so
#8  0x00001ea825697232 in llvm::initializeEdgeBundlesPass(llvm::PassRegistry&) () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_llvm-40393716.so
#9  0x00001ea8258cbb85 in initializeSpillPlacementPassOnce(llvm::PassRegistry&) () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_llvm-40393716.so
#10 0x00001ea82489d355 in void* std::_Bind_simple<void* (*(std::reference_wrapper<llvm::PassRegistry>))(llvm::PassRegistry&)>::_M_invoke<0ul>(std::_Index_tuple<0ul>) () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_llvm-40393716.so
#11 0x00001ea824898a90 in std::_Bind_simple<void* (*(std::reference_wrapper<llvm::PassRegistry>))(llvm::PassRegistry&)>::operator()() () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_llvm-40393716.so
#12 0x00001ea824894c8f in void std::call_once<void* (&)(llvm::PassRegistry&), std::reference_wrapper<llvm::PassRegistry> >(std::once_flag&, void* (&)(llvm::PassRegistry&), std::reference_wrapper<llvm::PassRegistry>&&)::{lambda()#1}::operator()() const () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_llvm-40393716.so
#13 0x00001ea82489ff33 in std::_Function_handler<void (), void std::call_once<void* (&)(llvm::PassRegistry&), std::reference_wrapper<llvm::PassRegistry> >(std::once_flag&, void* (&)(llvm::PassRegistry&), std::reference_wrapper<llvm::PassRegistry>&&)::{lambda()#1}>::_M_invoke(std::_Any_data const&) () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_llvm-40393716.so
#14 0x00001ea802f02411 in std::__once_proxy () at /usr/obj/ports/gcc-4.9.4/gcc-4.9.4/libstdc++-v3/src/c++11/mutex.cc:90
#15 0x00001ea8b8738cee in pthread_once (once_control=0x1ea828584d20 <InitializeSpillPlacementPassFlag>, init_routine=0x1ea802f02370 <std::__once_proxy()>) at /usr/src/lib/librthread/rthread_once.c:26
#16 0x00001ea8248887ea in __gthread_once(pthread_once*, void (*)()) () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_llvm-40393716.so
#17 0x00001ea824894d3a in void std::call_once<void* (&)(llvm::PassRegistry&), std::reference_wrapper<llvm::PassRegistry> >(std::once_flag&, void* (&)(llvm::PassRegistry&), std::reference_wrapper<llvm::PassRegistry>&&) () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_llvm-40393716.so
#18 0x00001ea824890f41 in void llvm::call_once<void* (&)(llvm::PassRegistry&), std::reference_wrapper<llvm::PassRegistry> >(std::once_flag&, void* (&)(llvm::PassRegistry&), std::reference_wrapper<llvm::PassRegistry>&&) () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_llvm-40393716.so
#19 0x00001ea8258cbc42 in llvm::initializeSpillPlacementPass(llvm::PassRegistry&) () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_llvm-40393716.so
#20 0x00001ea8258476cb in (anonymous namespace)::RAGreedy::RAGreedy() () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_llvm-40393716.so
#21 0x00001ea825847245 in llvm::createGreedyRegisterAllocator() () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_llvm-40393716.so
#22 0x00001ea825918e56 in llvm::TargetPassConfig::createTargetRegisterAllocator(bool) () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_llvm-40393716.so
#23 0x00001ea825918ec1 in llvm::TargetPassConfig::createRegAllocPass(bool) () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_llvm-40393716.so
#24 0x00001ea825918826 in llvm::TargetPassConfig::addMachinePasses() () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_llvm-40393716.so
#25 0x00001ea825730b8e in addPassesToGenerateCode(llvm::LLVMTargetMachine*, llvm::legacy::PassManagerBase&, bool, void const*, void const*, void const*, llvm::MachineFunctionInitializer*) () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_llvm-40393716.so
#26 0x00001ea825730c75 in llvm::LLVMTargetMachine::addPassesToEmitFile(llvm::legacy::PassManagerBase&, llvm::raw_pwrite_stream&, llvm::TargetMachine::CodeGenFileType, bool, void const*, void const*, void const*, llvm::MachineFunctionInitializer*) () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_llvm-40393716.so
#27 0x00001ea8247dfc7e in LLVMRustWriteOutputFile (Target=0x1ea805aef000, PMR=0x1ea80806bd60, M=0x1ea8a8345400, path=<optimized out>, rust_FileType=<optimized out>) at /home/semarie/data/src/rust/src/rustllvm/PassWrapper.cpp:481
#28 0x00001ea87b7595c4 in rustc_trans::back::write::write_output_file::h0e1786ed60f8f07f () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_trans-40393716.so
#29 0x00001ea87b86026a in rustc_trans::back::write::optimize_and_codegen::_$u7b$$u7b$closure$u7d$$u7d$::h25034d2a8e2d0336 () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_trans-40393716.so
#30 0x00001ea87b761e9f in rustc_trans::back::write::execute_work_item::h16483495753d2a00 () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_trans-40393716.so
#31 0x00001ea87b6ee4d2 in std::panicking::try::do_call::hd805aff4cb5a7af6 () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_trans-40393716.so
#32 0x00001ea812449bb7 in __rust_maybe_catch_panic () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/libstd-40393716.so
#33 0x00001ea87b706baf in _$LT$F$u20$as$u20$alloc..boxed..FnBox$LT$A$GT$$GT$::call_box::h81d7664434da1b99 () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/librustc_trans-40393716.so
#34 0x00001ea812438a93 in std::sys::thread::Thread::new::thread_start::h4c0ad33b336bc6ea () from /data/semarie/obj/rust/x86_64-unknown-openbsd/stage2/lib/libstd-40393716.so
#35 0x00001ea8b873846e in _rthread_start (v=0x4) at /usr/src/lib/librthread/rthread.c:114
#36 0x00001ea89f0c33ab in __tfork_thread () at /usr/src/lib/libc/arch/amd64/sys/tfork_thread.S:75
#37 0x0000000000000000 in ?? ()
(gdb) quit

@semarie
Copy link
Contributor Author

semarie commented Oct 3, 2016

I assume the performance problem to be related to OpenBSD pthread implementation.
The dead-lock could be something else.

@alexcrichton
Copy link
Member

Interesting, sure does look like a lot of mutexes going around! I wonder if LLVM 3.9 tweaked something to grab a lock where it didn't before, and now these problems are happening?

@ghost
Copy link

ghost commented Oct 3, 2016

From the stacktrace it looks like a deadlock in std::call_once implementation,
which is used by LLVM to initialize passes. The initialization of an LLVM pass
may trigger initialization of dependencies, causing reentrant calls to
std::call_once. As far as I can see the implementation of std::call_once in
libstdc++ is not reentrant when _GLIBCXX_HAVE_TLS is undefined.

Moreover the _GLIBCXX_HAVE_TLS seems to be indeed undefined on OpenBSD (or in
this particular build), because a global mutex is used to implement
std::call_once. This global mutex is visible on stacktrace as
std::__get_once_mutex()::once_mutex (on call to _rthread_mutex_lock).

One possible execution trace (corresponding to above stracktrace) would be more
or less following:

T1. std::call_once(initializeSpillPlacementPassFlag)
T1.   acquires global once_mutex
T1.   acquires mutex for initializeSpillPlacementPassFlag
T1.   unlocks global once_mutex 
T1.   proceeds with initializeSpillPlacementPassOnce

T5. std::call_once(initializeSpillPlacementPassFlag)
T5.   acquires global once_mutex
T5.   waits for initializeSpillPlacementPassFlag (hold by T1)

T1.   SpillPlacement initializes a dependency - EdgeBundles pass
T1.   std::call_once(initializeEdgeBundlesPassFlag)
T1.     waits for global once_mutex (hold by T5)

Deadlock, because T1 waits for once_mutex hold by T5, and T5 waits for
initializeSpillPlacementPassFlag hold by T1.

For potential workaround, take a look at src/llvm/include/llvm/Support/Threading.h
and stick OpenBSD around there to make LLVM_THREADING_USE_STD_CALL_ONCE zero.

@semarie
Copy link
Contributor Author

semarie commented Oct 4, 2016

I am currently testing it. Thanks.

@semarie
Copy link
Contributor Author

semarie commented Oct 4, 2016

The workaround works well. Thanks for your help !

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

3 participants