1
0
mirror of https://github.com/coturn/coturn.git synced 2026-10-24 00:08:57 +03:00
Files
coturn/examples/run_tests.sh
Pavel Punsky 9600cbd603 ci: guard against test-script hangs (timeout wrappers + job timeouts) (#2061)
## Problem

The Clang workflow's `sanitize (thread)` job has been hanging for
**hours** (e.g. #2058's run hung 4h28m; an earlier run hit the **6h**
GitHub default), while normal runs finish in 5–15 min.

**Root cause (investigated under TSan):** `turnutils_uclient`'s threaded
load-gen has data races. ThreadSanitizer reports them in
`__turn_getMSTime()`
([uclient.c:1027-1035](../blob/master/src/apps/uclient/uclient.c#L1027))
— which writes the shared `current_time` / `current_mstime` /
`show_statistics` globals from both the **main thread**
(`start_mclient`) and every **sender thread** (`sender_timer_handler`)
with no synchronization — plus the shared session counters in
`start_mclient`. Under the TSan build's timing these races
intermittently leave the client **spinning after the transfer has
already completed**. `run_tests_ipv6_relay.sh` (scenario 2, `-y` c2c)
runs the client synchronously and only greps the log afterwards, so a
client that never exits blocks the script forever. With no job timeout,
the job then runs to GitHub's 6h default.

This is **not** a regression from any recent change — the ASan job runs
the identical steps and passes; the hang is purely the
TSan-timing-exposed load-gen race.

## Fix — two independent guards

1. **`timeout`-wrap the blocking `turnutils_uclient` calls** in the
run_tests scripts (`run_tests.sh`, `run_tests_conf.sh`,
`run_tests_mobile.sh`, `run_tests_ipv6_relay.sh`). Success is already
decided by grepping the log for the completion marker, which is written
*before* the client starts spinning — so a post-completion kill still
passes, while a genuine failure still shows no marker. Scripts that
already bound the client (`ratelimit_401`, `dtls_default`, the load-gen
smoke) are unchanged.
2. **`timeout-minutes` on every CI job that runs the test scripts**
(`clang` sanitize, `cmake` build, `linux` build, `macos` build +
build-cmake). Any future hang now fails in tens of minutes instead of
six hours.

## Validation (Linux container)

- **No regression** (plain autotools build): `run_tests.sh`,
`run_tests_conf.sh`, `run_tests_mobile.sh`, `run_tests_ipv6_relay.sh`
all pass with the wrappers.
- **TSan build**: `run_tests_ipv6_relay.sh` now **passes (rc=0)**
instead of hanging.
- All four workflow YAMLs parse; `bash -n` clean on all four scripts.

## Follow-up (separate PR)

The real fix is to eliminate the `turnutils_uclient` load-gen data races
(make `__turn_getMSTime`'s time cache thread-safe and audit the shared
session/counter state the sender/listener pools touch). This PR only
stops the CI bleeding.
2026-08-24 12:41:58 -07:00

246 lines
11 KiB
Bash
Executable File

#!/bin/bash
# Per-run log paths. $$ in the suffix keeps two concurrent script
# invocations (rare, but happens with manual debug) from clobbering
# each other's diagnostics. cleanup() removes them on exit.
TURNSERVER_LOG="/tmp/run_tests.$$.turnserver.log"
PEER_LOG="/tmp/run_tests.$$.peer.log"
UCLIENT_LOG="/tmp/run_tests.$$.uclient.log"
LOADGEN_LOG="/tmp/run_tests.$$.loadgen.log"
cleanup() {
kill "$turnserver_pid" "$peer_pid" 2>/dev/null
wait "$turnserver_pid" "$peer_pid" 2>/dev/null
rm -f "$TURNSERVER_LOG" "$PEER_LOG" "$UCLIENT_LOG" "$LOADGEN_LOG"
}
trap cleanup EXIT
# Detect cmake build and adjust path
BINDIR="../bin"
if [ ! -f $BINDIR/turnserver ]; then
BINDIR="../build/bin"
fi
# Bound the client where a timeout tool exists. A stock macOS runner has
# neither `timeout` nor `gtimeout` and never hits the Linux/TSan loadgen
# livelock this guards; its job timeout-minutes is the backstop.
if command -v timeout >/dev/null 2>&1; then
RUN_BOUNDED="timeout 120s"
elif command -v gtimeout >/dev/null 2>&1; then
RUN_BOUNDED="gtimeout 120s"
else
RUN_BOUNDED=""
fi
IS_DARWIN=0
if [ "$(uname -s)" = "Darwin" ]; then
IS_DARWIN=1
fi
# Server-side fast paths that we ship as Linux-only: enable them in the
# default test run so every CI cycle exercises the recvmmsg drain path.
# Stays off on non-Linux because the kernel APIs aren't available.
#
# Note: --udp-gso lives behind --multiplex-peer (that mode is what
# enables the sendmmsg batching GSO piggybacks on); driving GSO from
# this script would require flipping the server into multiplex-peer
# mode, which changes the relay-port model in ways the protocol tests
# below assume. run_tests_multiplex_peer.sh exercises the multiplex
# path explicitly — leave GSO to that script.
TURNSERVER_EXTRA_ARGS=""
if [ "$(uname -s)" = "Linux" ]; then
TURNSERVER_EXTRA_ARGS="--udp-recvmmsg"
echo "Using TURNSERVER_EXTRA_ARGS=\"$TURNSERVER_EXTRA_ARGS\""
fi
echo 'Running turnserver'
# --log-file=stdout forces turnserver's per-line log into our redirected
# stdout so $TURNSERVER_LOG actually gets populated. Without it,
# turnserver writes to its platform-default location (syslog or
# /var/log/turn_*.log) and our redirect captures an empty file; that
# breaks wait_for_turnserver, which polls the log for a known
# late-startup line, and it leaves the FAIL-path diagnostics useless.
# Both platforms capture the log: macOS used to launch with >/dev/null and
# a fixed sleep, which raced uclient against a still-initializing server on
# hosts with many local addresses (relay init runs per address).
$BINDIR/turnserver --use-auth-secret --sock-buf-size=1048576 --static-auth-secret=secret --realm=north.gov --allow-loopback-peers --log-file=stdout --dtls $TURNSERVER_EXTRA_ARGS --cert ../examples/ca/turn_server_cert.pem --pkey ../examples/ca/turn_server_pkey.pem > "$TURNSERVER_LOG" 2>&1 &
turnserver_pid="$!"
echo 'Running peer client'
if [ $IS_DARWIN -eq 1 ]; then
$BINDIR/turnutils_peer -L 127.0.0.1 -L ::1 -L 0.0.0.0 > /dev/null &
else
$BINDIR/turnutils_peer -L 127.0.0.1 -L ::1 -L 0.0.0.0 > "$PEER_LOG" 2>&1 &
fi
peer_pid="$!"
# Wait for OUR turnserver instance to finish coming up before running any
# client tests. The previous static `sleep 2` was tight for an uninstrumented
# binary and broke under sanitizer builds (ASan/TSan): instrumented
# turnserver routinely takes 5-10s before it has bound 3478, so uclient
# raced in and hit "Connection refused".
#
# We can't just poll /dev/tcp/127.0.0.1/3478: when this script runs
# back-to-back with another that didn't fully clean up, the dying
# previous turnserver may still answer the connect long enough to give
# a false positive, and uclient ends up talking to a half-dead server.
# Instead, poll OUR log file (uniquely named via $$) for a known late
# startup line. That's by-construction immune to other instances. "Total
# auth threads:" is emitted after relay setup and socket-per-thread UDP
# listener setup, so it is a better client-start gate than "Total relay
# threads:".
wait_for_turnserver() {
local i
for i in $(seq 1 40); do
if grep -q "Total auth threads:" "$TURNSERVER_LOG" 2>/dev/null; then
return 0
fi
if ! kill -0 "$turnserver_pid" 2>/dev/null; then
echo "FATAL: turnserver (pid $turnserver_pid) exited before init completed"
echo "--- turnserver log ---"
cat "$TURNSERVER_LOG" 2>/dev/null || echo "(log file missing)"
return 1
fi
if ! kill -0 "$peer_pid" 2>/dev/null; then
echo "FATAL: turnutils_peer (pid $peer_pid) exited before tests started"
echo "--- peer log ---"
cat "$PEER_LOG" 2>/dev/null || echo "(log file missing)"
return 1
fi
sleep 0.5
done
echo "FATAL: turnserver never reached 'Total auth threads:' init line within 20s"
echo "--- turnserver log (last 30 lines) ---"
tail -30 "$TURNSERVER_LOG" 2>/dev/null || echo "(log file missing)"
return 1
}
wait_for_turnserver || exit 1
# No-barrier builds can log readiness before all worker event loops have
# had a scheduling turn. Keep the old startup cushion after the active
# per-process readiness check.
sleep 2
# Dump the bits a maintainer needs to see when a protocol test fails: the
# uclient progress lines (shows where send/recv counters stalled), any
# uclient errors, and a tail of the turnserver + peer logs. The macOS
# run currently fails every protocol at tot_recv_msgs=0 because Darwin's
# loopback path drops the relay->peer echo; printing the diagnostics
# makes that immediately obvious instead of forcing a re-run with manual
# instrumentation. Caller passes the label so the banner identifies
# which protocol's run produced the dump.
diagnose_failure() {
local label="$1"
echo "=== Diagnostics for failed test: $label ==="
echo "--- uclient: tot_send/tot_recv progress (last 6 lines) ---"
grep "start_mclient: tot_send_msgs" "$UCLIENT_LOG" 2>/dev/null | tail -6
echo "--- uclient: errors / warnings ---"
grep -iE "error|warning|fail|broken|drop" "$UCLIENT_LOG" 2>/dev/null | tail -10
echo "--- turnserver: socket / relay / allocation errors (last 40 lines) ---"
grep -iE "508|capacity|socket|bind|available ports|relay|allocation" "$TURNSERVER_LOG" 2>/dev/null | tail -40
echo "--- turnserver log (last 20 lines) ---"
if [ -s "$TURNSERVER_LOG" ]; then
tail -20 "$TURNSERVER_LOG"
elif [ -e "$TURNSERVER_LOG" ]; then
echo "(turnserver log exists but is empty — likely never produced output)"
else
echo "(turnserver log missing — redirect path: $TURNSERVER_LOG)"
fi
echo "--- peer log (last 10 lines) ---"
if [ -s "$PEER_LOG" ]; then
tail -10 "$PEER_LOG"
elif [ -e "$PEER_LOG" ]; then
echo "(peer log exists but is empty)"
else
echo "(peer log missing — redirect path: $PEER_LOG)"
fi
echo "==="
}
# Each protocol test runs turnutils_uclient with the supplied flags and
# greps for the canonical end-of-run line. Factoring the loop body into a
# function lets us run each protocol once with the legacy single-threaded
# defaults and a second time with the listener+sender thread pools
# explicitly engaged, so a regression in either path fails CI rather than
# only being caught at -m >= auto-bump thresholds. The grep target stays
# stable across both variants because the workload (-m 1, -n default=5,
# 200 B msg) totals 1000 bytes each way regardless of threading.
run_uclient() {
local label="$1"
shift
echo "Running $label"
# Bound the run so a ThreadSanitizer-exposed loadgen livelock can't hang CI;
# success is decided by the grep below, so a post-completion timeout kill
# still passes, while a genuine failure still shows no marker.
$RUN_BOUNDED "$BINDIR/turnutils_uclient" "$@" -e 127.0.0.1 -X -g -u user -W secret 127.0.0.1 > "$UCLIENT_LOG" 2>&1
# Match the periodic progress line too, not only the final-summary line: a
# client the timeout had to kill never prints the summary, but a periodic
# line already carries the full byte counts once the round trip has completed.
if grep -q "tot_send_bytes ~ 1000, tot_recv_bytes ~ 1000" "$UCLIENT_LOG"; then
echo OK
else
echo FAIL
diagnose_failure "$label"
exit 1
fi
}
# Legacy single-threaded uclient (no -K, no --sender-threads).
run_uclient "turn client TCP" -t
run_uclient "turn client TLS" -t -S
run_uclient "turn client UDP"
run_uclient "turn client DTLS" -S
if [ $IS_DARWIN -eq 1 ]; then
sleep 2
exit 0
fi
# Same four protocols with both worker pools at minimum non-zero size so
# we exercise the threaded recv (#1911) and threaded send (#1913) paths.
# -m 1 keeps the workload small; the pools still spin up, register the
# session via pick_listener_base / pick_sender_id, and drive the
# per-thread timer + recv loop end-to-end.
run_uclient "turn client TCP (threaded)" -t --listener-threads 1 --sender-threads 1
run_uclient "turn client TLS (threaded)" -t -S --listener-threads 1 --sender-threads 1
run_uclient "turn client UDP (threaded)" --listener-threads 1 --sender-threads 1
run_uclient "turn client DTLS (threaded)" -S --listener-threads 1 --sender-threads 1
# Linux-only load-gen smoke. Confirms -Y packet mode emits the recv_pps
# metric introduced in #1913 alongside send_pps, and that both are
# non-zero (so we'd catch a regression where the listener pool stops
# accumulating into recv_count_snapshot). 4s of -m 4 traffic is enough
# to clear several progress prints without blowing CI runtime; --sender-
# threads 2 matches the auto rule for -m >= 4. -c suppresses EVEN-PORT
# requests so the test is compatible with --multiplex-peer (future).
if [ "$(uname -s)" = "Linux" ]; then
echo "Running turn client UDP load-gen smoke (-Y packet, threaded)"
# timeout exits 124 when it has to send SIGTERM; that's success here
# because we just want a fixed-duration run. Capture log for inspection.
timeout -s INT 6s "$BINDIR/turnutils_uclient" \
-Y packet -m 4 -l 100 -c -e 127.0.0.1 -g \
--listener-threads 1 --sender-threads 2 \
-u user -W secret 127.0.0.1 > "$LOADGEN_LOG" 2>&1
# Accept exit 124 (timeout killed) or 130 (SIGINT clean exit) as success.
rc=$?
if [ $rc -ne 0 ] && [ $rc -ne 124 ] && [ $rc -ne 130 ]; then
echo "FAIL: uclient exited with $rc"
echo "--- load-gen log ---"
cat "$LOADGEN_LOG"
echo "--- turnserver log (last 20 lines) ---"
tail -20 "$TURNSERVER_LOG"
exit 1
fi
if grep -qE "send_pps=[1-9][0-9]*\.[0-9]+, recv_pps=[1-9][0-9]*\.[0-9]+" "$LOADGEN_LOG"; then
echo OK
else
echo "FAIL: no non-zero send_pps/recv_pps line in load-gen output"
echo "--- load-gen log (last 20 lines) ---"
tail -20 "$LOADGEN_LOG"
echo "--- turnserver log (last 20 lines) ---"
tail -20 "$TURNSERVER_LOG"
exit 1
fi
fi
sleep 2