ci: set a ctest test timeout of 1200 (20 minutes)

fanquake commented at 1:03 pm on October 3, 2024: member

This should be long enough (with headroom) for our longest running tests, which even under MSAN, TSAN, Valgrind, etc max out at about 800s.

i.e under Valgrind I see the longer runtimes as:

0135/136 Test   [#8](/bitcoin-bitcoin/8/): bench_sanity_check_high_priority .....   Passed  371.19 sec
1136/136 Test [#122](/bitcoin-bitcoin/122/): coinselector_tests ...................   Passed  343.39 sec

In the CI tests under TSAN:

0tests ................................   Passed  795.20 sec

and MSAN:

0tests ................................   Passed  658.48 sec

This will also prevent the current issue we are seeing of ctest running until it reaches the CI timeout, see #30969.

We still need to figure out what underlying issue is causing the tests to (sometimes) run for so long, but in the mean time, this will stop ctest wasting our CI CPU. It should also make it more clear in the logs, exactly which test is the one that is hitting the timeout.

DrahtBot commented at 1:03 pm on October 3, 2024: contributor

The following sections might be updated with supplementary metadata relevant to reviewers and maintainers.

Code Coverage

For detailed information about the code coverage, see the test coverage report.

Reviews

See the guideline for information on the review process.

Type	Reviewers
ACK	maflcko, tdb3
Stale ACK	laanwj, willcl-ark, hebasto, BrandonOdiwuor, theuni, naiyoma

If your review is incorrectly listed, please react with 👎 to this comment and the bot will ignore it on the next update.

DrahtBot added the label Tests on Oct 3, 2024

laanwj commented at 2:01 pm on October 3, 2024: member

ACK 93dda4c70254750a5b5c0e7f7d2d89032519b999 Yes, we’ve had some ridiculously overloaded CI VPSes in the past, but one’d say 20 minutes should be enough for the unit tests even under the most adverse conditions.

willcl-ark commented at 2:16 pm on October 3, 2024: member

ACK 93dda4c70254750a5b5c0e7f7d2d89032519b999

I tried for quite some time to get this to work using CTEST_TEST_TIMEOUT from within CMakeLists.txt but it does not appear to be possible. This therefore seems like the next best option to limit this test time.

I am curious to see if this actually manages to curtail the long-running/hanging test, or whether the system is locking up in some way that this will have no effect.

Theghost256 approved

hebasto approved

hebasto commented at 7:59 pm on October 3, 2024: member

ACK 93dda4c70254750a5b5c0e7f7d2d89032519b999, I agree with the PR goal and the choice of timeout value.

hebasto commented at 8:06 pm on October 3, 2024: member

I tried for quite some time to get this to work using CTEST_TEST_TIMEOUT from within CMakeLists.txt but it does not appear to be possible.

According to CMake docs, CTEST_TEST_TIMEOUT

Specify the CTest TimeOut setting in a ctest dashboard client script.

which is a use case different from ours.

tdb3 approved

tdb3 commented at 11:45 pm on October 3, 2024: contributor

ACK 93dda4c70254750a5b5c0e7f7d2d89032519b999

Looks like a good way to cut off abnormally running unit tests. As a sanity check, confirmed that ctest returns non-zero when the timeout is hit (e.g. ctest --timeout 10 --test-dir build).

willcl-ark commented at 1:36 pm on October 4, 2024: member

I tried for quite some time to get this to work using CTEST_TEST_TIMEOUT from within CMakeLists.txt but it does not appear to be possible.

According to CMake docs, CTEST_TEST_TIMEOUT

Specify the CTest TimeOut setting in a ctest dashboard client script.

which is a use case different from ours.

Huh, for some reason I thought I had read that the dart dashboard used DART_TESTING_TIMEOUT, but it seems that this is just a more ancient version of CTEST_TEST_TIMEOUT. I guess I must have gotten onto some old docs by mistake. Ah well.

BrandonOdiwuor approved

BrandonOdiwuor commented at 3:35 pm on October 4, 2024: contributor

ACK 93dda4c70254750a5b5c0e7f7d2d89032519b999

LGTM

theuni approved

theuni commented at 5:11 pm on October 4, 2024: member

ACK 93dda4c70254750a5b5c0e7f7d2d89032519b999

naiyoma commented at 5:48 pm on October 5, 2024: contributor

ACK https://github.com/bitcoin/bitcoin/pull/31026/commits/93dda4c70254750a5b5c0e7f7d2d89032519b999

ci: set a ctest timeout of 1200 (20 minutes)

This should be long enough (with headroom) for our longest running tests,
which even under MSAN, TSAN, Valgrind, etc max out at about 800s.

i.e under Valgrind I see the longer runtimes as:
```bash
135/136 Test   #8: bench_sanity_check_high_priority .....   Passed  371.19 sec
136/136 Test #122: coinselector_tests ...................   Passed  343.39 sec
```

In the CI `tests` under TSAN:
```bash
tests ................................   Passed  795.20 sec
```
and MSAN:
```bash
tests ................................   Passed  658.48 sec
```

This will also prevent the current issue we are seeing of `ctest`
running until it reaches the CI timeout, see #30969.

However, we still need to figure out what underlying issue is causing
the tests to (sometimes) run for so long, but in the mean time, this
will stop `ctest` wasting our CI CPU.

56aad83307

in ci/test/03_test_script.sh:149 in 93dda4c702 outdated

145@@ -146,7 +146,7 @@ if [ "$RUN_CHECK_DEPS" = "true" ]; then
146 fi
147 
148 if [ "$RUN_UNIT_TESTS" = "true" ]; then
149-  DIR_UNIT_TEST_DATA="${DIR_UNIT_TEST_DATA}" LD_LIBRARY_PATH="${DEPENDS_DIR}/${HOST}/lib" CTEST_OUTPUT_ON_FAILURE=ON ctest "${MAKEJOBS}"
150+  DIR_UNIT_TEST_DATA="${DIR_UNIT_TEST_DATA}" LD_LIBRARY_PATH="${DEPENDS_DIR}/${HOST}/lib" CTEST_OUTPUT_ON_FAILURE=ON ctest "${MAKEJOBS}" --timeout 1200

maflcko commented at 9:02 am on October 7, 2024:

Did you also check the qemu builds? Valgrind and Tsan may be faster than system- or user- qemu, but I haven’t checked. I wonder if TEST_RUNNER_TIMEOUT_FACTOR * 30 can be re-used here, in case someone wants to run in qemu in addition to a sanitizer? (Either way is fine for the CI in this repo, but I don’t know what people are doing outside this repo)

fanquake commented at 10:05 am on October 7, 2024:

I wonder if TEST_RUNNER_TIMEOUT_FACTOR * 30 can be re-used here,

Sure, updated to use this. I haven’t run a s390x build for a while, but I’d assume it would fail here. Started one in any case.

fanquake force-pushed on Oct 7, 2024

maflcko commented at 10:10 am on October 7, 2024: member

review ACK 56aad83307e46983a397236bd0959e634207f83e

No change to the new timeout value of 1200 in this force push, but making it configurable, in case someone needs that, and also in symmetry with the functional tests.

DrahtBot requested review from willcl-ark on Oct 7, 2024

DrahtBot requested review from laanwj on Oct 7, 2024

DrahtBot requested review from hebasto on Oct 7, 2024

DrahtBot requested review from BrandonOdiwuor on Oct 7, 2024

DrahtBot requested review from naiyoma on Oct 7, 2024

DrahtBot requested review from tdb3 on Oct 7, 2024

DrahtBot requested review from theuni on Oct 7, 2024

tdb3 approved

tdb3 commented at 12:06 pm on October 7, 2024: contributor

re ACK 56aad83307e46983a397236bd0959e634207f83e

fanquake merged this on Oct 7, 2024

fanquake closed this on Oct 7, 2024

fanquake deleted the branch on Oct 7, 2024

hebasto commented at 1:17 pm on October 7, 2024: member

Post-merge ACK 56aad83307e46983a397236bd0959e634207f83e.

fanquake commented at 2:38 pm on October 7, 2024: member

Looks like this is working: https://cirrus-ci.com/task/5848920612405248?logs=ci#L2234

 0[14:18:46.371] 126/135 Test [#130](/bitcoin-bitcoin/130/): spend_tests ..........................   Passed   19.83 sec
 1[14:19:14.504] 127/135 Test [#110](/bitcoin-bitcoin/110/): txvalidationcache_tests ..............   Passed  122.32 sec
 2[14:19:15.437] 128/135 Test   [#8](/bitcoin-bitcoin/8/): bench_sanity_check_high_priority .....   Passed  318.61 sec
 3[14:19:24.864] 129/135 Test  [#76](/bitcoin-bitcoin/76/): random_tests .........................   Passed  208.03 sec
 4[14:19:25.959] 130/135 Test [#135](/bitcoin-bitcoin/135/): walletload_tests .....................   Passed   40.74 sec
 5[14:19:36.138] 131/135 Test [#132](/bitcoin-bitcoin/132/): wallet_tests .........................   Passed   67.56 sec
 6[14:20:26.873] 132/135 Test  [#30](/bitcoin-bitcoin/30/): coins_tests ..........................   Passed  379.37 sec
 7[14:21:06.675] 133/135 Test [#122](/bitcoin-bitcoin/122/): coinselector_tests ...................   Passed  176.09 sec
 8[14:23:22.523] 134/135 Test   [#5](/bitcoin-bitcoin/5/): noverify_tests .......................   Passed  565.71 sec
 9[14:33:56.903] 135/135 Test   [#6](/bitcoin-bitcoin/6/): tests ................................***Timeout 1200.09 sec
10[14:33:56.903] test count = 64
11[14:33:56.903] random seed = 651903683e0e49d7bd7deaf6fac1ad67
12[14:33:56.903] 
13[14:33:56.905] 
14[14:33:56.905] 99% tests passed, 1 tests failed out of 135
15[14:33:56.905] 
16[14:33:56.905] Total Test time (real) = 1200.12 sec
17[14:33:56.905] 
18[14:33:56.905] The following tests FAILED:
19[14:33:56.905] 	  6 - tests (Timeout)
20[14:33:56.906] Errors while running CTest
21[14:33:57.002] 
22[14:33:57.002] Exit status: 8

maflcko commented at 3:01 pm on October 7, 2024: member

Looks like this is working: https://cirrus-ci.com/task/5848920612405248?logs=ci#L2234

Though, this is msan (not the win-cross wine tests), which seems just like a slow machine, because out of 10 runs, it sometimes takes longer: https://cirrus-ci.com/task/6180976303276032?logs=ci#L2223

Once #30852 is fixed, the results should be hopefully both faster and more consistent.

ci: set a ctest test timeout of 1200 (20 minutes) #31026

Code Coverage

Reviews