Cirrus CI / Win64 doesn't print assert errors from test_bitcoin.exe #24261

Cirrus CI / Win64 build does not seem to print errors from test_bitcoin.exe if an assert statement fails. I saw this recently in https://cirrus-ci.com/task/6752891435220992?logs=ci#L3597 from #24251, and reproduced it locally running FILE_ENV=./ci/test/00_setup_env_win64.sh ./ci/test_run_all.sh.

If I run test_bitcoin.exe manually with docker exec I can see:

test/util_tests.cpp(54): Entering test case "util_datadir"
Assertion failed: fs::equivalent(result, path), file util/system.cpp, line 256

But the default docker / cirrus output just shows the test_bitcoin.exe process exiting without any information about a failing assert.

I don't know if this is a known limitation, but it would be helpful if windows CI builds were able to print why they are failing in cases like this.

This should not happen, maybe stderr isn't redirected properly or so?

Does this also happen in Ubuntu?

For reference, the command is:

src/Makefile.test.include:      $(AM_V_at)$(TEST_BINARY) --catch_system_errors=no -l test_suite -t "`cat $< | grep -E "(BOOST_FIXTURE_TEST_SUITE\\(|BOOST_AUTO_TEST_SUITE\\()" | cut -d '(' -f 2 | cut -d ',' -f 1 | cut -d ')' -f 1`" -- DEBUG_LOG_OUT > $<.log 2>&1 || (cat $<.log && false)

Hmm, this is weird. The assert does come from stderr, but it seems it is not printed if stderr is directed to a file, only if it is directed to a terminal. This suggests t may be a buffering issue, Often output buffering is enabled writing to a file, but not to a terminal. And in this case the assert message is very short and wouldn't exceed a really long buffer.

Tested adding assert(0) to util_tests/util_datadir test and running:

# Assert printed to terminal
wine src/test/test_bitcoin.exe  -l test_suite -t util_tests/util_datadir > out

# No assert
wine src/test/test_bitcoin.exe  -l test_suite -t util_tests/util_datadir > out 2>&1

# No assert
wine src/test/test_bitcoin.exe  -l test_suite -t util_tests/util_datadir > out 2> err

# Assert printed to terminal
wine src/test/test_bitcoin.exe  -l test_suite -t util_tests/util_datadir > out 2> /dev/tty

problem seems to be that assert is not captured if it is directed to a file, but

Piping to another process also doesn't help. Running in a script session does

# No assert
wine src/test/test_bitcoin.exe  -l test_suite -t util_tests/util_datadir 2>&1 | tee out

# Assert is printed to terminal and file
script out -c 'wine src/test/test_bitcoin.exe  -l test_suite -t util_tests/util_datadir'

Cirrus CI / Win64 build does not seem to print errors from test_bitcoin.exe if an assert statement fails.

Confirming such misbehavior in the Win64 cross compile CI build. All of other CI builds do print "Assertion failed..." error messages.

Further investigation makes me believe that this issue is not Boost-specific, rather MinGW-specific:

--- a/src/bitcoind.cpp
+++ b/src/bitcoind.cpp
@@ -254,6 +254,7 @@ static bool AppInit(NodeContext& node, int argc, char* argv[])
 int main(int argc, char* argv[])
 {
 #ifdef WIN32
+    assert(false);
     util::WinCmdLineArgs winArgs;
     std::tie(argc, argv) = winArgs.get();
 #endif

Using strace shows that to print an assertion error, it uses fcntl with a descriptor that is not mentioned in the launch command. Weird...

Should fixed in #24363.

But the default docker / cirrus output just shows the test_bitcoin.exe process exiting without any information about a failing assert.

It seems it has no longer the case on the master branch. For example, with the following diff applied:

--- a/src/test/amount_tests.cpp
+++ b/src/test/amount_tests.cpp
@@ -5,6 +5,7 @@
 #include <consensus/amount.h>
 #include <policy/feerate.h>
 
+#include <cassert>
 #include <limits>
 
 #include <boost/test/unit_test.hpp>
@@ -13,6 +14,7 @@ BOOST_AUTO_TEST_SUITE(amount_tests)
 
 BOOST_AUTO_TEST_CASE(MoneyRangeTest)
 {
+    assert(false);
     BOOST_CHECK_EQUAL(MoneyRange(CAmount(-1)), false);
     BOOST_CHECK_EQUAL(MoneyRange(CAmount(0)), true);
     BOOST_CHECK_EQUAL(MoneyRange(CAmount(1)), true);

the CI task output is:

...
test/amount_tests.cpp(15): Entering test case "MoneyRangeTest"
Assertion failed: false, file test/amount_tests.cpp, line 17
...

So we can close this now then?

So we can close this now then?

Yes, I think.

cc @ryanofsky

Can be re-opened if still an issue.