bitcoind aborts with boost exception in WSL guest #14200

<!-- This issue tracker is only for technical issues related to Bitcoin Core. General bitcoin questions and/or support requests are best directed to the Bitcoin StackExchange at https://bitcoin.stackexchange.com. For reporting security issues, please read instructions at https://bitcoincore.org/en/contact/. If the node is "stuck" during sync or giving "block checksum mismatch" errors, please ensure your hardware is stable by running memtest and observe CPU temperature with a load-test tool such as linpack before creating an issue! -->

<!-- Describe the issue -->

Running bitcoind results in a Boost related exception and bitcoind aborts.

<!--- What behavior did you expect? -->

bitcoind to start and wait for further input

<!--- What was the actual behavior (provide screenshots if the issue is GUI-related)? -->

Here is the output of running the bitcoind command

$ bitcoind -printtoconsole

2018-09-11 20:39:22



















2018-09-11 20:39:22 Bitcoin Core version v0.16.2 (release build)
2018-09-11 20:39:22 InitParameterInteraction: parameter interaction: -whitelistforcerelay=1 -> setting -whitelistrelay=1
2018-09-11 20:39:22 Assuming ancestors of block 0000000000000000005214481d2d96f898e3d5416e43359c145944a909d242e0 have valid signatures.
2018-09-11 20:39:22 Setting nMinimumChainWork=000000000000000000000000000000000000000000f91c579d57cad4bc5278cc
2018-09-11 20:39:22 Using the 'sse4' SHA256 implementation
2018-09-11 20:39:22 Using RdRand as an additional entropy source
2018-09-11 20:39:22 Default data directory /home/achandra/.bitcoin
2018-09-11 20:39:22 Using data directory /home/achandra/.bitcoin
2018-09-11 20:39:22 Using config file /home/achandra/.bitcoin/bitcoin.conf
2018-09-11 20:39:22 Using at most 125 automatic connections (1024 file descriptors available)
2018-09-11 20:39:22 Using 16 MiB out of 32/2 requested for signature cache, able to store 524288 elements
2018-09-11 20:39:22 Using 16 MiB out of 32/2 requested for script execution cache, able to store 524288 elements
2018-09-11 20:39:22 Using 2 threads for script verification
2018-09-11 20:39:22 scheduler thread start
2018-09-11 20:39:22 HTTP: creating work queue of depth 16
2018-09-11 20:39:22 No rpcpassword set - using random cookie authentication
2018-09-11 20:39:22 Generated RPC authentication cookie /home/achandra/.bitcoin/.cookie
2018-09-11 20:39:22 HTTP: starting 4 worker threads
2018-09-11 20:39:22 Using wallet directory /home/achandra/.bitcoin/wallets
2018-09-11 20:39:22 init message: Verifying wallet(s)...
2018-09-11 20:39:22 Using BerkeleyDB version Berkeley DB 4.8.30: (April  9, 2010)
2018-09-11 20:39:22 Using wallet wallet.dat
2018-09-11 20:39:22 CDBEnv::Open: LogDir=/home/achandra/.bitcoin/wallets/database ErrorFile=/home/achandra/.bitcoin/wallets/db.log
2018-09-11 20:39:22 Cache configuration:
2018-09-11 20:39:22

************************
EXCEPTION: N5boost16exception_detail10clone_implINS0_19error_info_injectorINS_15condition_errorEEEEE
boost::condition_variable::do_wait_until failed in pthread_cond_timedwait: Invalid argument
bitcoin in scheduler

2018-09-11 20:39:22 * Using 2.0MiB for block index database


************************
EXCEPTION: N5boost16exception_detail10clone_implINS0_19error_info_injectorINS_15condition_errorEEEEE
boost::condition_variable::do_wait_until failed in pthread_cond_timedwait: Invalid argument
bitcoin in scheduler

2018-09-11 20:39:22 * Using 8.0MiB for chain state database
terminate called after throwing an instance of '2018-09-11 20:39:22 * Using 440.0MiB for in-memory UTXO set (plus up to 286.1MiB of unused mempool space)
boost::exception_detail::clone_impl<boost::exception_detail::error_info_injector<boost::condition_error> >2018-09-11 20:39:22 init message: Loading block index...
'
2018-09-11 20:39:22 Opening LevelDB in /home/achandra/.bitcoin/blocks/index
  what():  boost::condition_variable::do_wait_until failed in pthread_cond_timedwait: Invalid argument
Aborted (core dumped)

<!--- How reliably can you reproduce the issue, what are the steps to do so? -->

Can produce it very reliably. Just keep running the same command i.e. bitcoind -printtoconsole

<!-- What version of Bitcoin Core are you using, where did you get it (website, self-compiled, etc)? -->

$ bitcoind --version Bitcoin Core Daemon version v0.16.2 Copyright (C) 2009-2018 The Bitcoin Core developers

<!-- What type of machine are you observing the error on (OS/CPU and disk type)? -->

Ubuntu 16.04 running on Windows 10. Intel i5 processor and 8 GB RAM. Processor: Intel(R) Core(TM) i5-3340M CPU @ 2.70GHz, 2701 Mhz, 2 Core(s), 4 Logical Processor(s)

<!-- Any extra information that might be useful in the debugging process. -->

<!--- This is normally the contents of a `debug.log` or `config.log` file. Raw text or a link to a pastebin type site are preferred. -->

this is strange; from the manpage of pthread_cond_timedwait: (ok see below, apparently I have a linuxthreads-specific man page, not the POSIX one)

       The pthread_cond_timedwait function returns the following error codes on error:
              ETIMEDOUT
                     the condition variable was not signaled until the timeout specified by abstime
              EINTR  pthread_cond_timedwait was interrupted by a signal

It's not supposed to ever return EINVAL ("invalid argument").

As you say you're running this on windows, my guess is that it has something to do with the WFL, emulating a POSIX function incorrectly.

Edit: if I have to guess, one possibility would be that pthread_cond_timedwait returns EINVAL on windows if the time is already in the past. This would be hard to work around without creating race conditions. It's also possible that either the cond or mutex argument is considered invalid, but this is wrapped in so many layers of boost:: that I can't see how that could happen.

Is this a WFL build or a MingW build?

Well,

Ubuntu 16.04 running on Windows 10

that seriously suggest WFL, not MingW

FWIW, my manpage has quite a bit more in possible errors:

       ENOTRECOVERABLE
              The state protected by the mutex is not recoverable.

       EOWNERDEAD
              The mutex is a robust mutex and the process containing the previous owning thread terminated while hold‐
              ing the mutex lock. The mutex lock shall be acquired by the calling thread and it is up to the new owner
              to make the state consistent.

       EPERM  The mutex type is PTHREAD_MUTEX_ERRORCHECK or the mutex is a robust mutex, and the current thread does
              not own the mutex.

       The pthread_cond_timedwait() function shall fail if:

       ETIMEDOUT
              The time specified by abstime to pthread_cond_timedwait() has passed.

       EINVAL The abstime argument specified a nanosecond value less than zero or greater than or equal to 1000 mil‐
              lion.

       These functions may fail if:

       EOWNERDEAD
              The mutex is a robust mutex and the previous owning thread terminated while holding the mutex lock. The
              mutex lock shall be acquired by the calling thread and it is up to the new owner to make the state con‐
              sistent.
       ENOTRECOVERABLE
              The state protected by the mutex is not recoverable.

       EOWNERDEAD
              The mutex is a robust mutex and the process containing the previous owning thread terminated while hold‐
              ing the mutex lock. The mutex lock shall be acquired by the calling thread and it is up to the new owner
              to make the state consistent.

       EPERM  The mutex type is PTHREAD_MUTEX_ERRORCHECK or the mutex is a robust mutex, and the current thread does
              not own the mutex.

       The pthread_cond_timedwait() function shall fail if:

       ETIMEDOUT
              The time specified by abstime to pthread_cond_timedwait() has passed.

       EINVAL The abstime argument specified a nanosecond value less than zero or greater than or equal to 1000 mil‐
              lion.

       These functions may fail if:

       EOWNERDEAD
              The mutex is a robust mutex and the previous owning thread terminated while holding the mutex lock. The
              mutex lock shall be acquired by the calling thread and it is up to the new owner to make the state con‐
              sistent.

Okay, so the time passed in through const struct timespec *abstime is invalid. I wonder in what sense, or at least how it ends up that way...

@ashishchandr70 Does WSL support GDB? Can you get a full backtrace?

@luke-jr here you go. Let me know if you need any more info:

**(gdb) run**
Starting program: /usr/local/bin/bitcoind
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
[New Thread 0x7ffffa670700 (LWP 27880)]
[New Thread 0x7ffff9e60700 (LWP 27881)]
[New Thread 0x7ffff9650700 (LWP 27882)]
[New Thread 0x7ffff8e40700 (LWP 27883)]
[New Thread 0x7ffff3ff0700 (LWP 27884)]
[New Thread 0x7ffff37e0700 (LWP 27885)]
[New Thread 0x7ffff2fd0700 (LWP 27886)]


************************
EXCEPTION: N5boost16exception_detail10clone_implINS0_19error_info_injectorINS_15condition_errorEEEEE
boost::condition_variable::do_wait_until failed in pthread_cond_timedwait: Invalid argument
bitcoin in scheduler

terminate called after throwing an instance of 'boost::exception_detail::clone_impl<boost::exception_detail::error_info_injector<boost::condition_error> >'
  what():  boost::condition_variable::do_wait_until failed in pthread_cond_timedwait: Invalid argument

Thread 3 "bitcoin-schedul" received signal SIGABRT, Aborted.
[Switching to Thread 0x7ffff9e60700 (LWP 27881)]
0x00007ffffce35428 in __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:54
54      ../sysdeps/unix/sysv/linux/raise.c: No such file or directory.
**(gdb) bt full**
[#0](/bitcoin-bitcoin/0/)  0x00007ffffce35428 in __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:54
        resultvar = 0
        pid = 27876
        selftid = 27881
[#1](/bitcoin-bitcoin/1/)  0x00007ffffce3702a in __GI_abort () at abort.c:89
        save_stage = 2
        act = {__sigaction_handler = {sa_handler = 0x0, sa_sigaction = 0x0}, sa_mask = {__val = {0, 0,
              140737436421119, 140737439880512, 1, 140737439880643, 140737385987728, 140737385987056, 140737436427273,
              140737385989856, 1058, 2, 145847040, 140737287031616, 140737439885168, 140737385989888}},
          sa_flags = -40187776, sa_restorer = 0x7ffff4000c90}
        sigs = {__val = {32, 0 <repeats 15 times>}}
[#2](/bitcoin-bitcoin/2/)  0x00007ffffd9af84d in __gnu_cxx::__verbose_terminate_handler() () from /usr/lib/x86_64-linux-gnu/libstdc++.so.6
No symbol table info available.
[#3](/bitcoin-bitcoin/3/)  0x00007ffffd9ad6b6 in ?? () from /usr/lib/x86_64-linux-gnu/libstdc++.so.6
No symbol table info available.
[#4](/bitcoin-bitcoin/4/)  0x00007ffffd9ad701 in std::terminate() () from /usr/lib/x86_64-linux-gnu/libstdc++.so.6
No symbol table info available.
[#5](/bitcoin-bitcoin/5/)  0x00007ffffd9ad969 in __cxa_rethrow () from /usr/lib/x86_64-linux-gnu/libstdc++.so.6
No symbol table info available.
[#6](/bitcoin-bitcoin/6/)  0x00000000080714f5 in TraceThread<std::function<void ()> >(char const*, std::function<void ()>) (
    name=0x84b7b5e "scheduler", func=...) at ./util.h:334
        e = <optimized out>
        s = "bitcoin-scheduler"
[#7](/bitcoin-bitcoin/7/)  0x00000000080731a1 in boost::_bi::list2<boost::_bi::value<char const*>, boost::_bi::value<std::function<void ()> > >::operator()<void (*)(char const*, std::function<void ()>), boost::_bi::list0>(boost::_bi::type<void>, void (*&)(char const*, std::function<void ()>), boost::_bi::list0&, int) (f=<optimized out>, a=<synthetic pointer>,
    this=<optimized out>) at /home/achandra/boost/boost_1_68_0/boost/bind/bind.hpp:319
No locals.
[#8](/bitcoin-bitcoin/8/)  boost::_bi::bind_t<void, void (*)(char const*, std::function<void ()>), boost::_bi::list2<boost::_bi::value<char con---Type <return> to continue, or q <return> to quit---
st*>, boost::_bi::value<std::function<void ()> > > >::operator()() (this=<optimized out>)
    at /home/achandra/boost/boost_1_68_0/boost/bind/bind.hpp:1294
No locals.
[#9](/bitcoin-bitcoin/9/)  boost::detail::thread_data<boost::_bi::bind_t<void, void (*)(char const*, std::function<void ()>), boost::_bi::list2<boost::_bi::value<char const*>, boost::_bi::value<std::function<void ()> > > > >::run() (this=0x8b177e0)
    at /home/achandra/boost/boost_1_68_0/boost/thread/detail/thread.hpp:117
No locals.
[#10](/bitcoin-bitcoin/10/) 0x00007ffffeb23e3d in thread_proxy () from /home/achandra/boost/boost_1_68_0/stage/lib/libboost_thread.so.1.68.0
No symbol table info available.
[#11](/bitcoin-bitcoin/11/) 0x00007ffffd1d76ba in start_thread (arg=0x7ffff9e60700) at pthread_create.c:333
        __res = <optimized out>
        pd = 0x7ffff9e60700
        now = <optimized out>
        unwind_buf = {cancel_jmp_buf = {{jmp_buf = {140737385989888, -6477113758224924360, 0, 140737488272895,
                140737385990592, 140737488280144, 6477118070383264056, 6477110163119489336}, mask_was_saved = 0}},
          priv = {pad = {0x0, 0x0, 0x0, 0x0}, data = {prev = 0x0, cleanup = 0x0, canceltype = 0}}}
        not_first_call = <optimized out>
        pagesize_m1 = <optimized out>
        sp = <optimized out>
        freesize = <optimized out>
        __PRETTY_FUNCTION__ = "start_thread"
[#12](/bitcoin-bitcoin/12/) 0x00007ffffcf0741d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109
No locals.
(gdb)

@ashishchandr70 I've tested bitcoind v0.16.3 on WSL with Ubuntu 18.04 and don't get this abort.

I'm (re)installing WSL with Ubuntu 16 to see if I can reproduce.

@ashishchandr70 tested v0.16.3 on WSL with Ubuntu 16.04.5 and don't get the abort.

Release v0.16.2 isn't available for download anymore. Can you check if you have the same problem with v0.16.3?

possibly when the system is put to sleep the abstime parameter is stale and pthread_cond_timedwait is called with an abstime in the past?