ci(packaging): classify kill-after probe timeouts and keep output tails

Address review feedback on the time-boxed runtime probes:

- GNU timeout exits 137, not 124, when -k escalates to SIGKILL. Run it
  with --verbose and report a timeout for 124, or for 137 only when
  timeout announced its own KILL, so an app killed by something else is
  not misreported. Verified against coreutils 9.4 on ubuntu:24.04.
- Print the first and last 16 KiB of oversized Flatpak probe output so
  a late startup exception or the timeout notice stays in the log.
- Pin the hostile Snap probe's timeout-before-generic-failure ordering.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
This commit is contained in:
4grayandClaude Opus 5.5 committed 2026-09-26 23:07:11 +02:00
1 parent ae13b569ff
commit 7342ccd329
3 files changed
+75 -22

No files matched your search

+32 -9
View File
@@ -1099,6 +1099,15 @@ jobs:
sudo snap disconnect iptvnator:graphics-core22 mesa-core22:graphics-core22
snap connections iptvnator | awk \
'$2 == "iptvnator:graphics-core22" && $3 == "-" { found=1 } END { exit !found }'
probe_timed_out() {
# GNU timeout exits 124 when SIGTERM ends the app and 137 when -k
# escalates to SIGKILL. --verbose announces that KILL, so an app
# killed by anything else is not misreported as a timeout.
local status="$1" output="$2"
[ "${status}" -eq 124 ] && return 0
[ "${status}" -eq 137 ] &&
grep -Fq 'sending signal KILL to command' <<<"${output}"
}
# GNU timeout kills a packaged app that never exits, for example when the
# main process throws before app ready and Electron's uncaught-exception
# dialog blocks under xvfb. ELECTRON_ENABLE_LOGGING routes Chromium and
@@ -1107,13 +1116,13 @@ jobs:
set +e
disconnected_probe="$(
xvfb-run -a env LIBGL_ALWAYS_SOFTWARE=1 ELECTRON_ENABLE_LOGGING=1 \
timeout -k 10 300 \
timeout --verbose -k 10 300 \
snap run iptvnator --embedded-mpv-runtime-probe 2>&1
)"
disconnected_status=$?
set -e
printf '%s\n' "${disconnected_probe}"
if [ "${disconnected_status}" -eq 124 ]; then
if probe_timed_out "${disconnected_status}" "${disconnected_probe}"; then
echo "::error::The packaged Snap app did not exit within 300 seconds during the disconnected graphics runtime probe and was killed; inspect the probe output above for main-process startup errors."
exit 1
fi
@@ -1150,13 +1159,13 @@ jobs:
XDG_CONFIG_DIRS=/tmp/hostile-xdg-config-dirs \
XDG_DATA_HOME=/tmp/hostile-xdg-data-home \
XDG_DATA_DIRS=/tmp/hostile-xdg-data-dirs \
timeout -k 10 300 \
timeout --verbose -k 10 300 \
snap run iptvnator --embedded-mpv-runtime-probe 2>&1
)"
hostile_status=$?
set -e
printf '%s\n' "${hostile_probe}"
if [ "${hostile_status}" -eq 124 ]; then
if probe_timed_out "${hostile_status}" "${hostile_probe}"; then
echo "::error::The packaged Snap app did not exit within 300 seconds during the hostile-environment runtime probe and was killed; inspect the probe output above for main-process startup errors."
exit 1
fi
@@ -1249,13 +1258,22 @@ jobs:
ELF_MAGIC="$(od -An -tx1 -N4 "${LAUNCHER_PATH}" | tr -d "[:space:]")"
test "${ELF_MAGIC}" = "7f454c46"
'
probe_timed_out() {
# GNU timeout exits 124 when SIGTERM ends the app and 137 when -k
# escalates to SIGKILL. --verbose announces that KILL, so an app
# killed by anything else is not misreported as a timeout.
local status="$1" output="$2"
[ "${status}" -eq 124 ] && return 0
[ "${status}" -eq 137 ] &&
grep -Fq 'sending signal KILL to command' <<<"${output}"
}
# GNU timeout kills a packaged app that never exits, for example when the
# main process throws before app ready and Electron's uncaught-exception
# dialog blocks under xvfb. ELECTRON_ENABLE_LOGGING routes Chromium and
# main-process stderr into the captured output.
set +e
PROBE_OUTPUT="$(
xvfb-run -a dbus-run-session -- timeout -k 10 300 flatpak run \
xvfb-run -a dbus-run-session -- timeout --verbose -k 10 300 flatpak run \
--env=LIBGL_ALWAYS_SOFTWARE=1 \
--env=ELECTRON_ENABLE_LOGGING=1 \
com.fourgray.iptvnator \
@@ -1264,17 +1282,22 @@ jobs:
PROBE_STATUS=$?
set -e
# Keep both ends of oversized output: logging can push a startup
# exception or the timeout notice past the first window.
PROBE_OUTPUT_LIMIT=16384
printf '%s\n' "${PROBE_OUTPUT:0:PROBE_OUTPUT_LIMIT}"
if [ "${#PROBE_OUTPUT}" -gt "${PROBE_OUTPUT_LIMIT}" ]; then
echo "::warning::Flatpak runtime probe output was truncated to ${PROBE_OUTPUT_LIMIT} characters."
if [ "${#PROBE_OUTPUT}" -le $((PROBE_OUTPUT_LIMIT * 2)) ]; then
printf '%s\n' "${PROBE_OUTPUT}"
else
printf '%s\n' "${PROBE_OUTPUT:0:PROBE_OUTPUT_LIMIT}"
echo "::warning::Flatpak runtime probe output was truncated to its first and last ${PROBE_OUTPUT_LIMIT} characters."
printf '%s\n' "${PROBE_OUTPUT: -PROBE_OUTPUT_LIMIT}"
fi
if [[ "${PROBE_OUTPUT}" == *"not an ELF file"* ]] ||
[[ "${PROBE_OUTPUT}" == *"Zypak needs to be called directly"* ]]; then
echo "::error::Flatpak launched a wrapper instead of the Electron ELF."
exit 1
fi
if [ "${PROBE_STATUS}" -eq 124 ]; then
if probe_timed_out "${PROBE_STATUS}" "${PROBE_OUTPUT}"; then
echo "::error::The packaged Flatpak app did not exit within 300 seconds during the application runtime probe and was killed; inspect the probe output above for main-process startup errors."
exit 1
fi
+4 -3
View File
@@ -92,11 +92,12 @@ The Linux portable build uploads `packaged-frame-copy-smoke` reports and traces
even when the smoke fails. Check the paused-frame screenshot and trace before
classifying a zero rendered-frame signal as an infrastructure flake.
The Snap and Flatpak `--embedded-mpv-runtime-probe` launches in
`build-and-make.yaml` run under GNU `timeout -k 10 300` with
`build-and-make.yaml` run under GNU `timeout --verbose -k 10 300` with
`ELECTRON_ENABLE_LOGGING=1`, so a main process that throws before app ready
and blocks on Electron's uncaught-exception dialog under xvfb fails within
five minutes with a distinct `::error::` for exit 124 and its stderr in the
step log, instead of holding the job until the 120-minute limit.
five minutes with a distinct `::error::` (exit 124, or 137 after timeout's
announced KILL escalation) and its stderr in the step log, instead of holding
the job until the 120-minute limit.
## Main-process ownership
@@ -561,7 +561,7 @@ test('Flatpak application runtime probe runs under an isolated D-Bus session', (
assert.match(
flatpakVerificationStep,
/xvfb-run -a dbus-run-session -- timeout -k 10 300 flatpak run\s+\\\s+--env=LIBGL_ALWAYS_SOFTWARE=1\s+\\\s+--env=ELECTRON_ENABLE_LOGGING=1\s+\\\s+com\.fourgray\.iptvnator\s+\\\s+--embedded-mpv-runtime-probe/
/xvfb-run -a dbus-run-session -- timeout --verbose -k 10 300 flatpak run\s+\\\s+--env=LIBGL_ALWAYS_SOFTWARE=1\s+\\\s+--env=ELECTRON_ENABLE_LOGGING=1\s+\\\s+com\.fourgray\.iptvnator\s+\\\s+--embedded-mpv-runtime-probe/
);
assert.match(installStep, /^\s+dbus-daemon\s+\\$/m);
assert.match(
@@ -602,7 +602,7 @@ test('Flatpak CI verifies the direct Zypak ELF and preserves probe status', () =
assert.match(
flatpakVerificationStep,
/set \+e[\s\S]*PROBE_OUTPUT="\$\([\s\S]*xvfb-run -a dbus-run-session -- timeout -k 10 300 flatpak run[\s\S]*--embedded-mpv-runtime-probe 2>&1[\s\S]*\)"[\s\S]*PROBE_STATUS=\$\?[\s\S]*set -e/
/set \+e[\s\S]*PROBE_OUTPUT="\$\([\s\S]*xvfb-run -a dbus-run-session -- timeout --verbose -k 10 300 flatpak run[\s\S]*--embedded-mpv-runtime-probe 2>&1[\s\S]*\)"[\s\S]*PROBE_STATUS=\$\?[\s\S]*set -e/
);
assert.match(
flatpakVerificationStep,
@@ -624,9 +624,12 @@ test('packaged runtime probes are time-boxed and report a hung app distinctly',
'Verify Flatpak payload, launcher, and sandboxed runtime'
);
const probeInvocation =
/timeout -k 10 300 \\\s+snap run iptvnator --embedded-mpv-runtime-probe 2>&1/g;
/timeout --verbose -k 10 300 \\\s+snap run iptvnator --embedded-mpv-runtime-probe 2>&1/g;
const timeoutFailure =
/if \[ "\$\{(\w+)\}" -eq 124 \]; then\s+echo "::error::[^"]*did not exit within 300 seconds[^"]*"\s+exit 1\s+fi/g;
/if probe_timed_out "\$\{(\w+)\}" "\$\{\w+\}"; then\s+echo "::error::[^"]*did not exit within 300 seconds[^"]*"\s+exit 1\s+fi/g;
// 124 is SIGTERM; 137 counts only when timeout announced its own KILL.
const timeoutClassifier =
/probe_timed_out\(\) \{[\s\S]*?\[ "\$\{status\}" -eq 124 \] && return 0\s+\[ "\$\{status\}" -eq 137 \] &&\s+grep -Fq 'sending signal KILL to command' <<<"\$\{output\}"\s+\}/;
// Every `snap run` probe is wrapped by GNU timeout and captured, so a
// blocked uncaught-exception dialog cannot hold the job until its
@@ -639,18 +642,24 @@ test('packaged runtime probes are time-boxed and report a hung app distinctly',
assert.equal(snapStep.match(probeInvocation).length, 2);
assert.match(
snapStep,
/disconnected_probe="\$\([\s\S]*ELECTRON_ENABLE_LOGGING=1[\s\S]*timeout -k 10 300[\s\S]*\)"\s+disconnected_status=\$\?\s+set -e\s+printf '%s\\n' "\$\{disconnected_probe\}"/
/disconnected_probe="\$\([\s\S]*ELECTRON_ENABLE_LOGGING=1[\s\S]*timeout --verbose -k 10 300[\s\S]*\)"\s+disconnected_status=\$\?\s+set -e\s+printf '%s\\n' "\$\{disconnected_probe\}"/
);
assert.match(
snapStep,
/hostile_probe="\$\([\s\S]*ELECTRON_ENABLE_LOGGING=1[\s\S]*timeout -k 10 300[\s\S]*\)"\s+hostile_status=\$\?\s+set -e\s+printf '%s\\n' "\$\{hostile_probe\}"/
/hostile_probe="\$\([\s\S]*ELECTRON_ENABLE_LOGGING=1[\s\S]*timeout --verbose -k 10 300[\s\S]*\)"\s+hostile_status=\$\?\s+set -e\s+printf '%s\\n' "\$\{hostile_probe\}"/
);
assert.deepEqual(
[...snapStep.matchAll(timeoutFailure)].map(([, variable]) => variable),
['disconnected_status', 'hostile_status']
);
assert.match(snapStep, timeoutClassifier);
assert.ok(
snapStep.indexOf('-eq 124') <
snapStep.indexOf('probe_timed_out() {') <
snapStep.indexOf('disconnected_probe="$('),
'the timeout classifier must be defined before the first probe'
);
assert.ok(
snapStep.indexOf('if probe_timed_out "${disconnected_status}"') <
snapStep.indexOf('test "${disconnected_status}" -eq 1'),
'the disconnected probe must reject a timeout before asserting exit 1'
);
@@ -658,6 +667,11 @@ test('packaged runtime probes are time-boxed and report a hung app distinctly',
snapStep,
/if \[ "\$\{hostile_status\}" -ne 0 \]; then[\s\S]*exit "\$\{hostile_status\}"/
);
assert.ok(
snapStep.indexOf('if probe_timed_out "${hostile_status}"') <
snapStep.indexOf('if [ "${hostile_status}" -ne 0 ]'),
'the hostile probe must report a timeout before its generic status failure'
);
assert.ok(
snapStep.includes(
`grep -Fx '{"usable":false,"reason":"snap-graphics-provider-unavailable"}'`
@@ -666,7 +680,9 @@ test('packaged runtime probes are time-boxed and report a hung app distinctly',
);
assert.equal(
flatpakVerificationStep.match(/timeout -k 10 300 flatpak run/g).length,
flatpakVerificationStep.match(
/timeout --verbose -k 10 300 flatpak run/g
).length,
1
);
assert.deepEqual(
@@ -675,9 +691,22 @@ test('packaged runtime probes are time-boxed and report a hung app distinctly',
),
['PROBE_STATUS']
);
assert.match(flatpakVerificationStep, timeoutClassifier);
assert.ok(
flatpakVerificationStep.indexOf('-eq 124') <
flatpakVerificationStep.indexOf('if [ "${PROBE_STATUS}" -ne 0 ]'),
flatpakVerificationStep.indexOf('probe_timed_out() {') <
flatpakVerificationStep.indexOf('PROBE_OUTPUT="$('),
'the timeout classifier must be defined before the Flatpak probe'
);
// Oversized output keeps its tail, where a late exception or the
// timeout notice lands.
assert.match(
flatpakVerificationStep,
/if \[ "\$\{#PROBE_OUTPUT\}" -le \$\(\(PROBE_OUTPUT_LIMIT \* 2\)\) \]; then\s+printf '%s\\n' "\$\{PROBE_OUTPUT\}"\s+else\s+printf '%s\\n' "\$\{PROBE_OUTPUT:0:PROBE_OUTPUT_LIMIT\}"[\s\S]*?printf '%s\\n' "\$\{PROBE_OUTPUT: -PROBE_OUTPUT_LIMIT\}"\s+fi/
);
assert.ok(
flatpakVerificationStep.indexOf(
'if probe_timed_out "${PROBE_STATUS}"'
) < flatpakVerificationStep.indexOf('if [ "${PROBE_STATUS}" -ne 0 ]'),
'the timeout verdict must precede the generic non-zero status handling'
);
});