Skip to content

Commit 4d641c5

Browse files
dalkiadalkia
authored
chore: kill hung Unity test containers via stale editor-log watchdog (#9645)
1 parent f3a535d commit 4d641c5

2 files changed

Lines changed: 148 additions & 0 deletions

File tree

‎.github/workflows/test.yml‎

Lines changed: 50 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -677,6 +677,25 @@ jobs:
677677
echo "image=$derived" >> $GITHUB_OUTPUT
678678
echo "Built derived image with ripgrep: $derived"
679679
680+
# game-ci pipes the editor output to artifacts/<mode>.log, so a deadlocked
681+
# editor keeps the step console silent and burns the full 80-minute step
682+
# timeout (run 29613116640 attempt 1: editmode console silent for 70 min
683+
# after "Testing in editmode" until manually cancelled). The watchdog polls
684+
# that log from the host and kills the Unity container when it stops
685+
# growing, failing the step within ~15 min instead. It survives across
686+
# steps as a background process and is stopped by the step after the
687+
# runner; if the runner dies without cleanup it self-expires (MAX_LIFETIME).
688+
- name: Start stale-log watchdog
689+
env:
690+
UNITY_IMAGE: ${{ matrix.testMode == 'editmode' && steps.rg-img.outputs.image || steps.img.outputs.ghcr }}
691+
TEST_MODE: ${{ matrix.testMode }}
692+
run: |
693+
nohup bash scripts/ci/test-stale-log-watchdog.sh \
694+
"artifacts/$TEST_MODE.log" "$UNITY_IMAGE" watchdog-status.json \
695+
> watchdog-output.log 2>&1 &
696+
echo $! > watchdog.pid
697+
echo "Stale-log watchdog started (pid $(cat watchdog.pid)) for artifacts/$TEST_MODE.log"
698+
680699
# Configure test runner
681700
- uses: game-ci/unity-test-runner@v4.3.1
682701
id: testRunner
@@ -692,6 +711,37 @@ jobs:
692711
customParameters: -buildTarget StandaloneLinux64 -testCategory "!Performance" -burst-disable-compilation -accept-apiupdate
693712
githubToken: ${{ env.GITHUB_TOKEN }}
694713

714+
# Fails the job with an explicit cause when the watchdog killed the
715+
# container — without this the only signals are the confusing follow-on
716+
# errors ("Input required and not supplied: path", "No test report files
717+
# were found") seen in run 29613116640.
718+
- name: Stop stale-log watchdog and fail on stall
719+
if: always()
720+
env:
721+
TEST_MODE: ${{ matrix.testMode }}
722+
RUNNER_OUTCOME: ${{ steps.testRunner.outcome }}
723+
run: |
724+
if [ -f watchdog.pid ]; then
725+
kill "$(cat watchdog.pid)" 2>/dev/null || true
726+
fi
727+
echo "::group::Watchdog output"
728+
cat watchdog-output.log 2>/dev/null || echo "(no watchdog output)"
729+
echo "::endgroup::"
730+
# An unarmed watchdog gave this job no hang protection at all, usually
731+
# because the editor log moved; don't let that pass unremarked. Runs
732+
# that never reached a verdict (cancelled by cancel-in-progress, or
733+
# skipped) ended before the editor wrote anything, so there is no
734+
# drift to report there.
735+
if { [ "$RUNNER_OUTCOME" = success ] || [ "$RUNNER_OUTCOME" = failure ]; } \
736+
&& ! grep -q "stall detection armed" watchdog-output.log 2>/dev/null; then
737+
echo "::warning::Stale-log watchdog never armed - artifacts/$TEST_MODE.log never grew, so a hang would still have run to the step timeout. Check that game-ci still writes the editor log there."
738+
fi
739+
if [ -f watchdog-status.json ]; then
740+
stalled=$(jq -r '.stalledSeconds' watchdog-status.json 2>/dev/null || echo unknown)
741+
echo "::error::Unity $TEST_MODE tests hung: artifacts/$TEST_MODE.log did not grow for ${stalled}s, so the stale-log watchdog killed the Unity container. See 'Dump Unity Editor log on failure' below for the log tail."
742+
exit 1
743+
fi
744+
695745
- name: Dump Unity Editor log on failure
696746
if: always() && steps.testRunner.outcome != 'success'
697747
env:

‎scripts/ci/test-stale-log-watchdog.sh‎

Lines changed: 98 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,98 @@
1+
#!/usr/bin/env bash
2+
# Stale-log watchdog for game-ci Unity test containers.
3+
#
4+
# game-ci/unity-test-runner starts the Unity editor with
5+
# `-logFile <workspace>/artifacts/<mode>.log`, so while the step runs the
6+
# editor log grows on the host but the step's own console stays silent. When
7+
# the editor deadlocks mid-run the job burns the whole `timeout-minutes`
8+
# budget with no output (run 29613116640 attempt 1: console silent from
9+
# 21:04:21 right after the "Testing in editmode" banner until manually
10+
# cancelled at 22:14:52 — 70 minutes).
11+
#
12+
# This script polls the editor log's byte size from the host and kills the
13+
# Unity container when the log stops growing, failing the test step within
14+
# ~STALL_THRESHOLD seconds instead. Arming rules mirror the build-phase
15+
# watchdog in scripts/cloudbuild/build.py (LOG_STALL_THRESHOLD):
16+
# - the stall clock arms only after one observed size *increase* — a log
17+
# that never grows reads as "watchdog inactive", never as "stalled";
18+
# - a size *decrease* (log replaced or truncated) resets the clock.
19+
# If the log stalls but no container matches the image, the step is already
20+
# tearing down — the watchdog exits without reporting a stall.
21+
#
22+
# Usage: test-stale-log-watchdog.sh <editor-log> <container-image> <status-file>
23+
# <editor-log> host path of the Unity editor log to watch
24+
# <container-image> image the Unity container runs (docker ancestor filter)
25+
# <status-file> written (JSON) only when a stall kill actually happened
26+
# Env overrides:
27+
# STALL_THRESHOLD seconds without log growth before the kill (default 900)
28+
# POLL_INTERVAL seconds between size probes (default 30)
29+
# MAX_LIFETIME hard cap on the watchdog's own runtime (default 7200)
30+
#
31+
# Deliberately no `set -e`: the poll loop must survive transient stat/docker
32+
# failures; every external call is individually guarded instead.
33+
set -u
34+
35+
LOG_FILE=$1
36+
IMAGE=$2
37+
STATUS_FILE=$3
38+
STALL_THRESHOLD=${STALL_THRESHOLD:-900}
39+
POLL_INTERVAL=${POLL_INTERVAL:-30}
40+
MAX_LIFETIME=${MAX_LIFETIME:-7200}
41+
42+
start=$(date +%s)
43+
last_size=-1
44+
last_growth=$start
45+
growth_observed=false
46+
47+
echo "Watching $LOG_FILE for container image $IMAGE (stall threshold ${STALL_THRESHOLD}s, poll ${POLL_INTERVAL}s)"
48+
49+
while :; do
50+
sleep "$POLL_INTERVAL"
51+
now=$(date +%s)
52+
53+
if (( now - start > MAX_LIFETIME )); then
54+
echo "Max lifetime (${MAX_LIFETIME}s) reached - exiting without a verdict."
55+
exit 0
56+
fi
57+
58+
size=$(stat -c%s "$LOG_FILE" 2>/dev/null) || continue
59+
60+
if (( last_size < 0 || size < last_size )); then
61+
# First observation, or the log was replaced/truncated.
62+
last_size=$size
63+
last_growth=$now
64+
continue
65+
fi
66+
67+
if (( size > last_size )); then
68+
if [ "$growth_observed" = false ]; then
69+
echo "Log is growing ($size bytes) - stall detection armed."
70+
fi
71+
last_size=$size
72+
last_growth=$now
73+
growth_observed=true
74+
continue
75+
fi
76+
77+
if [ "$growth_observed" = true ] && (( now - last_growth > STALL_THRESHOLD )); then
78+
stalled_for=$(( now - last_growth ))
79+
# Results on disk mean the editor already exited: the log went quiet
80+
# during game-ci's post-run work, which is not a hang.
81+
if compgen -G "$(dirname "$LOG_FILE")/*.xml" > /dev/null; then
82+
echo "Log stalled for ${stalled_for}s but test results are already written - exiting without a verdict."
83+
exit 0
84+
fi
85+
containers=$(docker ps -q --filter "ancestor=$IMAGE" 2>/dev/null || true)
86+
if [ -z "$containers" ]; then
87+
echo "Log stalled for ${stalled_for}s but no container is running $IMAGE - step is tearing down, exiting."
88+
exit 0
89+
fi
90+
echo "Log has not grown for ${stalled_for}s (size $size bytes). Killing Unity container(s): $containers"
91+
jq -n --argjson stalled "$stalled_for" --argjson size "$size" --arg log "$LOG_FILE" \
92+
'{stalledSeconds: $stalled, logSizeBytes: $size, log: $log}' > "$STATUS_FILE"
93+
# container ids are newline/space separated words
94+
# shellcheck disable=SC2086
95+
docker kill $containers || true
96+
exit 0
97+
fi
98+
done

0 commit comments

Comments
 (0)