Skip to content

Commit 81c5290

Browse files
committed
test: make TEST_TAP_TIMEOUT actually fire, and enable it by default
TEST_TAP_TIMEOUT could not catch the failure it exists for. The read loop was: line = fop.stdout.readline() # blocks ... if tap_timeout > 0 and (time.time() - start_time) > tap_timeout: readline() blocks until a full line arrives, so a test that hangs while producing no output never reached the deadline check at all. Verified directly: with tap_timeout=3 against 'sleep 300', the old loop was still blocked after 25 seconds; the new one raises at 3.0s. That is the exact profile of the CI-mysql84-g9 stall on #5991, where test_ssl_fast_forward-3_libmariadb-t ran for hours. Replaces the blocking readline() with select() on a bounded wait plus raw os.read() chunking. select() guarantees the deadline check runs even when the child is silent; chunking rather than line-reading means a test that stops mid-line cannot wedge the loop either. Output order and content are unchanged, a trailing partial line is now flushed instead of dropped, and decoding uses errors='replace' so a stray non-UTF-8 byte no longer throws. Verified against four cases: normal chatty test (all lines, in order), silent hang (timeout fires), partial-line-then-hang (timeout fires), and clean exit. Also flips the default from 0 (disabled) to 1800s. 1800 is ~2.4x the slowest single test measured across 47 groups: reg_test_3765_ssl_pollout-t 12.5 min test_cluster_sync-t 10.5 min set_testing-240-t 7.8 min test_auth_methods-t 7.7 min Only 4 of 401 tests exceed 5 minutes, so this cannot fire on a merely slow test, while still stopping a hang well inside the 90-minute step budget added in the companion CI PRs -- and, unlike a step or job timeout, it identifies WHICH test hung and lets the run continue to its archive steps.
1 parent 389929f commit 81c5290

2 files changed

Lines changed: 40 additions & 9 deletions

File tree

test/infra/control/env-isolated.bash

Lines changed: 8 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -104,7 +104,14 @@ export TEST_PY_TAP_REPEAT="${TEST_PY_TAP_REPEAT:-1}"
104104
export TEST_PY_TAP_SHUFFLE_LIMIT="${TEST_PY_TAP_SHUFFLE_LIMIT:-0}"
105105
export TEST_PY_TAP_DUMP_RUNTIME="${TEST_PY_TAP_DUMP_RUNTIME:-1}"
106106
export TEST_PY_TAP_DUMP_STATS="${TEST_PY_TAP_DUMP_STATS:-1}"
107-
export TEST_TAP_TIMEOUT="${TEST_TAP_TIMEOUT:-0}"
107+
# Per-test wall-clock budget, in seconds. 0 disables it entirely, which was
108+
# the previous default: a hung TAP test then ran until the CI job itself was
109+
# killed. 1800 is ~2.4x the slowest single test measured across 47 groups
110+
# (reg_test_3765_ssl_pollout-t, 12.5 min; then test_cluster_sync-t 10.5,
111+
# set_testing-240-t 7.8, test_auth_methods-t 7.7 -- only 4 tests exceed 5
112+
# minutes at all), so it cannot fire on a merely slow test while still
113+
# catching a hang long before the 90-minute step budget.
114+
export TEST_TAP_TIMEOUT="${TEST_TAP_TIMEOUT:-1800}"
108115

109116
# Cluster sync test support — expose first cluster node admin port for replica validation
110117
if [ "${NUM_CLUSTER_NODES}" -gt 0 ]; then

test/scripts/bin/proxysql-tester.py

Lines changed: 32 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -5,6 +5,7 @@
55
import os
66
import pymysql
77
import sys
8+
import select
89
import subprocess
910
import random
1011
import time
@@ -842,19 +843,42 @@ def disk_usage():
842843
sys.exit(1)
843844
continue
844845

845-
# Run test with timeout if specified
846+
# Run test with timeout if specified.
847+
#
848+
# The read has to be non-blocking for tap_timeout to mean
849+
# anything. readline() blocks until a full line arrives, so on
850+
# a test that hangs while producing no output -- precisely the
851+
# case this timeout exists to catch -- the deadline check below
852+
# it was simply never reached, and the test ran until CI killed
853+
# the job. select() bounds the wait so the check always runs,
854+
# and reading raw chunks rather than lines means a test that
855+
# stops mid-line cannot wedge us either.
846856
try:
847857
start_time = time.time()
858+
buf = b''
848859
while True:
849-
line = fop.stdout.readline()
850-
if not line and fop.poll() is not None:
851-
break
852-
if line:
853-
log.debug(f"msg: {line.decode('utf-8').strip()}")
854-
855860
if tap_timeout > 0 and (time.time() - start_time) > tap_timeout:
856861
raise subprocess.TimeoutExpired(fop.args, tap_timeout)
857-
862+
863+
wait = 1.0
864+
if tap_timeout > 0:
865+
wait = max(0.0, min(1.0, tap_timeout - (time.time() - start_time)))
866+
ready, _, _ = select.select([fop.stdout], [], [], wait)
867+
868+
if ready:
869+
chunk = os.read(fop.stdout.fileno(), 65536)
870+
if not chunk:
871+
break # EOF: test finished
872+
buf += chunk
873+
while b'\n' in buf:
874+
line, buf = buf.split(b'\n', 1)
875+
log.debug(f"msg: {line.decode('utf-8', 'replace').strip()}")
876+
elif fop.poll() is not None:
877+
break
878+
879+
if buf: # trailing partial line
880+
log.debug(f"msg: {buf.decode('utf-8', 'replace').strip()}")
881+
858882
fop.wait()
859883
except subprocess.TimeoutExpired:
860884
fop.kill()

0 commit comments

Comments
 (0)