Bizarre test_bitcoin crash, but passes in debugger #5795

I'm building Bitcoin from source and trying to track down a strange test failure. When I run make check, test_bitcoin crashes with a segmentation fault. But if I actually run it in gdb then it completes normally and passes!

Here is a backtrace from the core file:

[error@buildserver2 src]$ ./test/test_bitcoin 
Running 133 test cases...
Segmentation fault (core dumped)
[error@buildserver2 src]$ file core.8246 
core.8246: ELF 32-bit LSB core file ARM, version 1 (SYSV), SVR4-style, from './test/test_bitcoin'
[error@buildserver2 src]$ gdb ./test/test_bitcoin core.8246 
GNU gdb (GDB) Fedora 7.8.2-38.fc21
Copyright (C) 2014 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 "armv7hl-redhat-linux-gnueabi".
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 ./test/test_bitcoin...done.
[New LWP 8247]
[New LWP 8248]
[New LWP 8246]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/libthread_db.so.1".
Core was generated by `./test/test_bitcoin'.
Program terminated with signal SIGSEGV, Segmentation fault.
[#0](/bitcoin-bitcoin/0/)  0x00000000 in ?? ()
Missing separate debuginfos, use: debuginfo-install boost-chrono-1.55.0-8.fc21.armv7hl boost-filesystem-1.55.0-8.fc21.armv7hl boost-program-options-1.55.0-8.fc21.armv7hl boost-system-1.55.0-8.fc21.armv7hl boost-test-1.55.0-8.fc21.armv7hl boost-thread-1.55.0-8.fc21.armv7hl glibc-2.20-7.fc21.armv7hl keyutils-libs-1.5.9-4.fc21.armv7hl krb5-libs-1.12.2-9.fc21.armv7hl libcom_err-1.42.12-1.fc21.armv7hl libdb4-cxx-4.8.30-16.fc21.armv7hl libgcc-4.9.2-1.fc21.armv7hl libselinux-2.3-5.fc21.armv7hl libstdc++-4.9.2-1.fc21.armv7hl miniupnpc-1.9-4.fc21.armv7hl openssl-compat-bitcoin-libs-1.0.1k-1.fc21.armv7hl pcre-8.35-8.fc21.armv7hl xz-libs-5.1.2-14alpha.fc21.armv7hl zlib-1.2.8-7.fc21.armv7hl
(gdb) thread apply all bt

Thread 3 (Thread 0xb5f1a000 (LWP 8246)):
[#0](/bitcoin-bitcoin/0/)  0xb6507ee4 in BN_rshift1 ()
   from /opt/openssl-compat-bitcoin/lib/libcrypto.so.10
[#1](/bitcoin-bitcoin/1/)  0xb650a274 in BN_mod_inverse ()
   from /opt/openssl-compat-bitcoin/lib/libcrypto.so.10
[#2](/bitcoin-bitcoin/2/)  0xb6516698 in ec_GFp_simple_points_make_affine ()
   from /opt/openssl-compat-bitcoin/lib/libcrypto.so.10
[#3](/bitcoin-bitcoin/3/)  0xb65183f4 in ec_wNAF_mul ()
   from /opt/openssl-compat-bitcoin/lib/libcrypto.so.10
[#4](/bitcoin-bitcoin/4/)  0xb651408c in EC_POINT_mul ()
   from /opt/openssl-compat-bitcoin/lib/libcrypto.so.10
[#5](/bitcoin-bitcoin/5/)  0xb652e268 in ?? () from /opt/openssl-compat-bitcoin/lib/libcrypto.so.10
[#6](/bitcoin-bitcoin/6/)  0xb652f020 in ECDSA_verify ()
   from /opt/openssl-compat-bitcoin/lib/libcrypto.so.10
[#7](/bitcoin-bitcoin/7/)  0xb6c68b78 in CECKey::Verify (this=this@entry=0xbeab0fc8, hash=..., 
    vchSig=std::vector of length 70, capacity 70 = {...}) at ecwrapper.cpp:145
[#8](/bitcoin-bitcoin/8/)  0xb6c571f4 in CPubKey::Verify (this=this@entry=0xbeab1038, hash=..., 
    vchSig=std::vector of length 70, capacity 70 = {...}) at pubkey.cpp:25
[#9](/bitcoin-bitcoin/9/)  0xb6b1e84c in CAlert::CheckSignature (this=this@entry=0xbeab13d0)
    at alert.cpp:151
[#10](/bitcoin-bitcoin/10/) 0xb6b1f0f0 in CAlert::ProcessAlert (this=this@entry=0xbeab13d0, 
    fThread=fThread@entry=false) at alert.cpp:174
[#11](/bitcoin-bitcoin/11/) 0xb698e4d0 in Alert_tests::AlertNotify::test_method (
    this=this@entry=0xbeab15e0) at test/alert_tests.cpp:167
[#12](/bitcoin-bitcoin/12/) 0xb699152c in Alert_tests::AlertNotify_invoker ()
    at test/alert_tests.cpp:157
[#13](/bitcoin-bitcoin/13/) 0xb6992214 in invoke<void (*)()> (this=<optimized out>, f=<optimized out>)
    at /usr/include/boost/test/utils/callback.hpp:56
[#14](/bitcoin-bitcoin/14/) boost::unit_test::ut_detail::callback0_impl_t<boost::unit_test::ut_detail::unused, void (*)()>::invoke (this=<optimized out>)
    at /usr/include/boost/test/utils/callback.hpp:89
[#15](/bitcoin-bitcoin/15/) 0xb682e6a0 in boost::unit_test::ut_detail::callback0_impl_t<int, boost::unit_test::(anonymous namespace)::zero_return_wrapper_t<boost::unit_test::callback0<boost::unit_test::ut_detail::unused> > >::invoke() ()
   from /lib/libboost_unit_test_framework.so.1.55.0
[#16](/bitcoin-bitcoin/16/) 0xb68069bc in boost::execution_monitor::catch_signals(boost::unit_test::callback0<int> const&) () from /lib/libboost_unit_test_framework.so.1.55.0
[#17](/bitcoin-bitcoin/17/) 0xb6807264 in boost::execution_monitor::execute(boost::unit_test::callback0<int> const&) () from /lib/libboost_unit_test_framework.so.1.55.0
[#18](/bitcoin-bitcoin/18/) 0xb682e7bc in boost::unit_test::unit_test_monitor_t::execute_and_translate(boost::unit_test::test_case const&) ()
   from /lib/libboost_unit_test_framework.so.1.55.0
[#19](/bitcoin-bitcoin/19/) 0xb6815dd4 in boost::unit_test::framework_impl::visit(boost::unit_test::test_case const&) () from /lib/libboost_unit_test_framework.so.1.55.0
[#20](/bitcoin-bitcoin/20/) 0xb6847614 in boost::unit_test::traverse_test_tree(boost::unit_test::test_suite const&, boost::unit_test::test_tree_visitor&) ()
   from /lib/libboost_unit_test_framework.so.1.55.0
[#21](/bitcoin-bitcoin/21/) 0xb6847614 in boost::unit_test::traverse_test_tree(boost::unit_test::test_suite const&, boost::unit_test::test_tree_visitor&) ()
   from /lib/libboost_unit_test_framework.so.1.55.0
[#22](/bitcoin-bitcoin/22/) 0xb68121bc in boost::unit_test::framework::run(unsigned long, bool) ()
   from /lib/libboost_unit_test_framework.so.1.55.0
[#23](/bitcoin-bitcoin/23/) 0xb682cb70 in boost::unit_test::unit_test_main(bool (*)(), int, char**) ()
   from /lib/libboost_unit_test_framework.so.1.55.0
[#24](/bitcoin-bitcoin/24/) 0xb61ac4fc in __libc_start_main () from /lib/libc.so.6
[#25](/bitcoin-bitcoin/25/) 0xb698a928 in _start ()

Thread 2 (Thread 0xaf95a3c0 (LWP 8248)):
[#0](/bitcoin-bitcoin/0/)  0xb62eeb70 in pthread_cond_wait@@GLIBC_2.4 () from /lib/libpthread.so.0
[#1](/bitcoin-bitcoin/1/)  0xb6a78d3c in boost::condition_variable::wait (
    this=0xb6f891c0 <scriptcheckqueue+24>, m=...)
    at /usr/include/boost/thread/pthread/condition_variable.hpp:73
[#2](/bitcoin-bitcoin/2/)  0xb6b765bc in CCheckQueue<CScriptCheck>::Loop (
    this=0xb6f891a8 <scriptcheckqueue>, fMaster=<optimized out>)
    at checkqueue.h:102
[#3](/bitcoin-bitcoin/3/)  0xb687bef0 in thread_proxy () from /lib/libboost_thread.so.1.55.0
[#4](/bitcoin-bitcoin/4/)  0xb62e8f4c in start_thread () from /lib/libpthread.so.0
[#5](/bitcoin-bitcoin/5/)  0xb62774a0 in ?? () from /lib/libc.so.6
Backtrace stopped: previous frame identical to this frame (corrupt stack?)

Thread 1 (Thread 0xb015a3c0 (LWP 8247)):
[#0](/bitcoin-bitcoin/0/)  0x00000000 in ?? ()
Backtrace stopped: previous frame identical to this frame (corrupt stack?)
(gdb) 

And here is the debugger running test_bitcoin with no problems:

[error@buildserver2 src]$ gdb ./test/test_bitcoin 
GNU gdb (GDB) Fedora 7.8.2-38.fc21
Copyright (C) 2014 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 "armv7hl-redhat-linux-gnueabi".
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 ./test/test_bitcoin...done.
(gdb) run
Starting program: /home/error/bitcoin-0.10.0/src/test/test_bitcoin 
Missing separate debuginfos, use: debuginfo-install glibc-2.20-7.fc21.armv7hl
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/libthread_db.so.1".
[New Thread 0xb08073c0 (LWP 8346)]
[New Thread 0xb00073c0 (LWP 8347)]
Running 133 test cases...
Detaching after fork from child process 8348.
Detaching after fork from child process 8349.
Detaching after fork from child process 8350.
Detaching after fork from child process 8351.
[New Thread 0xb65c3b40 (LWP 8352)]
[New Thread 0xaf4ff3c0 (LWP 8353)]
[New Thread 0xaecff3c0 (LWP 8354)]
[Thread 0xaecff3c0 (LWP 8354) exited]
[Thread 0xaf4ff3c0 (LWP 8353) exited]
[Thread 0xb65c3b40 (LWP 8352) exited]
[Thread 0xb08073c0 (LWP 8346) exited]
[Thread 0xb00073c0 (LWP 8347) exited]

*** No errors detected
[Inferior 1 (process 8343) exited normally]
Missing separate debuginfos, use: debuginfo-install boost-chrono-1.55.0-8.fc21.armv7hl boost-filesystem-1.55.0-8.fc21.armv7hl boost-program-options-1.55.0-8.fc21.armv7hl boost-system-1.55.0-8.fc21.armv7hl boost-test-1.55.0-8.fc21.armv7hl boost-thread-1.55.0-8.fc21.armv7hl keyutils-libs-1.5.9-4.fc21.armv7hl krb5-libs-1.12.2-9.fc21.armv7hl libcom_err-1.42.12-1.fc21.armv7hl libdb4-cxx-4.8.30-16.fc21.armv7hl libgcc-4.9.2-1.fc21.armv7hl libselinux-2.3-5.fc21.armv7hl libstdc++-4.9.2-1.fc21.armv7hl miniupnpc-1.9-4.fc21.armv7hl openssl-compat-bitcoin-libs-1.0.1k-1.fc21.armv7hl pcre-8.35-8.fc21.armv7hl xz-libs-5.1.2-14alpha.fc21.armv7hl zlib-1.2.8-7.fc21.armv7hl
(gdb) 

I'm at a complete loss. What's going on here?

Have you solved this? What is /opt/openssl-compat-bitcoin? Have you tried doing a full build of the depends tree? (ie: make depends)?

That's a clean build of OpenSSL against which bitcoin is linked. It doesn't appear to be relevant.

From further testing it looks like some sort of bizarre race condition in the boost test framework itself. If I pass --catch_system_errors=no, which is supposed to make it dump core on a segfault, then the test passes. Without it, when this defaults to yes, I get the segfault and core dump!

A more verbose run is:

[error@buildserver2 test]$ ./test_bitcoin --log_level=all --catch_system_errors=yes
Running 133 test cases...
Entering test suite "Bitcoin Test Suite"
Entering test suite "Alert_tests"
Entering test case "AlertApplies"
...
Leaving test case "AlertApplies"; testing time: 301504mks
Entering test case "AlertNotify"
Segmentation fault (core dumped)

The successful run is:

[error@buildserver2 test]$ ./test_bitcoin --log_level=all --catch_system_errors=no
Running 133 test cases...
Entering test suite "Bitcoin Test Suite"
Entering test suite "Alert_tests"
Entering test case "AlertApplies"
...
Leaving test case "AlertApplies"; testing time: 298194mks
Entering test case "AlertNotify"
test/alert_tests.cpp(170): info: check r.size() == 4u passed
test/alert_tests.cpp(176): info: check r[0] == "Alert 1" passed
test/alert_tests.cpp(177): info: check r[1] == "Alert 2, cancels 1" passed
test/alert_tests.cpp(178): info: check r[2] == "Alert 2, cancels 1" passed
test/alert_tests.cpp(179): info: check r[3] == "Evil Alert; /bin/ls; echo " passed
Leaving test case "AlertNotify"; testing time: 346342mks
Leaving test suite "Alert_tests"
...

Since this is probably a bug in Boost rather than in Bitcoin, and I have a workaround available, I don't really expect any further action. But I'm presenting it here just in case it is a bug in the Bitcoin tests and that isn't obvious to me for some reason.

If you do a make depends, it will download and compile known good versions of all the dependencies, including boost and the following build will statically link them all in. If you're going to run your own build for anything that matters, I would highly suggest this, as running on slightly different versions of some of the dependencies has resulted in forking issues in the past...

I'm running make depends now, but it'll be a while before that finishes.

In the meantime,... does that mean that it's possible for the test suite to pass and still end up with a forking issue?

Yes, but let me clarify. Forking in terms of your node rejecting something it shouldn't or accepting something it shouldn't thereby ending up with a different view from how the rest of the network sees things. Not in terms of process management.

There was a recent issue where OpenSSL tightened up their rules for what constitutes a valid signature encoding. Nodes that were built static were unaffected, but nodes that had bitcoinds that were linked against an automatically updated system OpenSSL started rejecting blocks that most of the network saw as valid.

Static linking and dependency control are really just better for this distributed consensus type of stuff.

On Sat, Feb 28, 2015 at 4:07 PM, error10 notifications@github.com wrote:

I'm running make depends now, but it'll be a while before that finishes.

In the meantime,... does that mean that it's possible for the test suite to pass and still end up with a forking issue?

— Reply to this email directly or view it on GitHub #5795 (comment).