From b232483623a4e345b6036631e5e32ae63819cd5f Mon Sep 17 00:00:00 2001 From: simplysanatori <149214925+simplysanatori@users.noreply.github.com> Date: Fri, 16 Oct 2026 02:48:37 -0400 Subject: [PATCH] Wrapper: never start the panel recorder after the game is gone, stop it on every exit path; add test The recorder subshell slept 8 s and then started even when the game had died at 3 s, and kept recording the headset for hours. It now starts only if the game is alive, runs in its own session, and is stopped (SIGINT, bounded wait, TERM, KILL, pkill) on game exit and on TERM/INT/HUP, with a log line saying which path ran. Co-Authored-By: Claude Sonnet 5.5 --- frame/DEV.md | 8 +++ frame/kartframe.sh | 53 +++++++++++++++++-- frame/test-wrapper-recorder.sh | 95 ++++++++++++++++++++++++++++++++++ 3 files changed, 153 insertions(+), 3 deletions(-) create mode 100755 frame/test-wrapper-recorder.sh diff --git a/frame/DEV.md b/frame/DEV.md index afa8cbc..c3d249d 100644 --- a/frame/DEV.md +++ b/frame/DEV.md @@ -232,3 +232,11 @@ every end against its refresh's update window (before / inside / after, SteamVR' prints the game's lines. Mock: mockrun.sh runs the helper against frame/tools/openvr-stub.c (STUB_UPDATE_MS, KF_MOCKRUN_STUB_UPDATE_MS, KF_MOCKRUN_PHASE_SECONDS) with MOCK_XR_ALIGN_US. Analysis: frame/perf/LANE_X.md; next session: frame/perf/session-h20/README.md. + +## Wrapper recorder (KARTFRAME_RECORD) +The recorder starts 8 s after the game and only if the game is still alive then; it runs in its own +session (setsid) and the wrapper stops it on every exit path (game exit, Steam's TERM/INT/HUP): SIGINT +and up to 30 s for the file, then TERM, then KILL, then a pkill on anything writing into the session's +panels.mkv. The log says "recorder stopped" or "recorder was never started"; a leftover +panels.mkv.part is logged with its size and left for the owner. frame/test-wrapper-recorder.sh checks +the four paths with a fake game and a fake framecorder (about 45 s). diff --git a/frame/kartframe.sh b/frame/kartframe.sh index c8e9e5d..3305384 100755 --- a/frame/kartframe.sh +++ b/frame/kartframe.sh @@ -148,24 +148,71 @@ GAME_PID=$! echo "kartframe $GAME_PID" > "$HEADSET_MARK" 2> /dev/null # KARTFRAME_RECORD=raw records both panels as scanned out (framecorder; about 1.6 ms of GPU a frame) # into the session folder, for questions the logs cannot settle (per-eye ghosting, flicker). +# The recorder starts 8 s in and only if the game is still there then (it once started after a game +# that had died at 3 s and recorded the headset for hours). It runs in its own session (setsid), so +# stopping it can reach everything it started (the framecorder-grab helper too). .rec-started marks +# that it really began. REC_PID= # Steam starts games with a short PATH (no ~/.local/bin), so look for the recorder by its full path too. FRAMECORDER=$(command -v framecorder 2> /dev/null || ls "$HOME/.local/bin/framecorder" 2> /dev/null) if [ -n "$KARTFRAME_RECORD" ] && [ -z "$FRAMECORDER" ]; then log "RECORDING NOT POSSIBLE: framecorder not found"; fi if [ -n "$KARTFRAME_RECORD" ] && [ -n "$FRAMECORDER" ]; then - ( sleep 8; exec "$FRAMECORDER" --view "${KARTFRAME_RECORD}" --fps "${KARTFRAME_RECORD_FPS:-120}" --qp 18 "$SESSION/panels.mkv" ) \ + rm -f "$SESSION/.rec-started" + setsid bash -c 'for ((i = 0; i < 80; i++)); do kill -0 "$1" 2> /dev/null || exit 0; sleep 0.1; done + touch "$2/.rec-started"; shift 2; exec "$@"' _ "$GAME_PID" "$SESSION" \ + "$FRAMECORDER" --view "${KARTFRAME_RECORD}" --fps "${KARTFRAME_RECORD_FPS:-120}" --qp 18 "$SESSION/panels.mkv" \ > "$SESSION/framecorder.log" 2>&1 & REC_PID=$! log "recording the panels (framecorder --view $KARTFRAME_RECORD) into panels.mkv" fi -trap 'kill -TERM "$GAME_PID" 2> /dev/null' TERM INT HUP +# Anything of the recorder still alive (a finished process that nobody has waited for does not count). +rec_alive() { + ps -o stat= --sid "$REC_PGID" 2> /dev/null | grep -q '^[^Z]' || + pgrep -f "framecorder .* $SESSION/panels.mkv" > /dev/null +} +# Stops the recorder in every case: not started yet (the waiting subshell is killed and never starts it), +# running (SIGINT to finish the file, then a bounded wait, then TERM and KILL). Runs once. +stop_recorder() { + [ -n "$REC_PID" ] || return 0 + REC_PGID=$REC_PID; REC_PID= + local n how=stopped + if [ -f "$SESSION/.rec-started" ]; then + kill -INT "$REC_PGID" 2> /dev/null + for ((n = 0; n < 300; n++)); do rec_alive || break; sleep 0.1; done # up to 30 s to finish the file + if rec_alive; then + how="stopped after TERM (SIGINT did not finish it)" + kill -TERM -- "-$REC_PGID" 2> /dev/null; pkill -TERM -s "$REC_PGID" 2> /dev/null + pkill -TERM -f "framecorder .* $SESSION/panels.mkv" 2> /dev/null + for ((n = 0; n < 50; n++)); do rec_alive || break; sleep 0.1; done + fi + if rec_alive; then + how="killed (SIGINT and TERM did not stop it)" + kill -KILL -- "-$REC_PGID" 2> /dev/null; pkill -KILL -s "$REC_PGID" 2> /dev/null + pkill -KILL -f "framecorder .* $SESSION/panels.mkv" 2> /dev/null + sleep 0.5 + fi + wait "$REC_PGID" 2> /dev/null + rec_alive && log "WARNING: a recorder process is still alive for $SESSION/panels.mkv" + log "recorder $how" + else + kill -TERM "$REC_PGID" 2> /dev/null; kill -TERM -- "-$REC_PGID" 2> /dev/null + pkill -TERM -s "$REC_PGID" 2> /dev/null + wait "$REC_PGID" 2> /dev/null + log "recorder was never started (the game was gone before the 8 s were up)" + fi + # A leftover part file is the owner's to judge: logged, never deleted. + if [ -f "$SESSION/panels.mkv.part" ] && ! rec_alive; then + log "panels.mkv.part left in the session folder, $(stat -c %s "$SESSION/panels.mkv.part") bytes, no recorder alive" + fi +} +trap 'kill -TERM "$GAME_PID" 2> /dev/null; stop_recorder' TERM INT HUP rc=0 while kill -0 "$GAME_PID" 2> /dev/null; do wait "$GAME_PID"; rc=$? done trap - TERM INT HUP rm -f "$HEADSET_MARK" -[ -n "$REC_PID" ] && { pkill -INT -P "$REC_PID" framecorder 2> /dev/null; kill -INT "$REC_PID" 2> /dev/null; sleep 3; } +stop_recorder log "game exited with status $rc" [ -n "$VRT_PID" ] && { kill "$VRT_PID" 2> /dev/null; wait "$VRT_PID" 2> /dev/null; } diff --git a/frame/test-wrapper-recorder.sh b/frame/test-wrapper-recorder.sh new file mode 100755 index 0000000..b50cae5 --- /dev/null +++ b/frame/test-wrapper-recorder.sh @@ -0,0 +1,95 @@ +#!/bin/bash +# Test for the panel recorder handling in kartframe.sh (KARTFRAME_RECORD): the game dies early, the +# game ends normally, the wrapper is killed. Touches nothing real: a scratch KARTFRAME_HOME, HOME and +# cache, a fake game, a fake framecorder (and framecorder-grab) first on PATH. No Steam, no SteamVR. +# frame/test-wrapper-recorder.sh [SCRATCH_DIR] (default ~/.cache/kf-test-wrapper-recorder, emptied first) +HERE=$(cd "$(dirname "$0")" && pwd) +T=${1:-$HOME/.cache/kf-test-wrapper-recorder} +rm -rf "$T"; mkdir -p "$T/bin" "$T/home" "$T/cache" +fails=0 +ok() { echo "ok $*"; } +bad() { echo "FAIL $*"; fails=$((fails + 1)); } +check() { local d=$1; shift; if "$@"; then ok "$d"; else bad "$d"; fi; } + +# A game that lives N seconds (exec, so a TERM ends it). +printf '#!/bin/bash\necho $$ > "$KARTFRAME_HOME/game.pid"\nexec sleep "${FAKE_GAME_SECONDS:-1}"\n' > "$T/game" +# The recorder's helper: runs until killed. +printf '#!/bin/bash\nwhile :; do sleep 1; done\n' > "$T/bin/framecorder-grab" +# The recorder: grows panels.mkv.part, takes SIGINT to finish the file (python, as a signal handler +# must be installed explicitly: a background job of the wrapper starts with SIGINT ignored). +cat > "$T/bin/framecorder" << 'PY' +#!/usr/bin/python3 -I +import os, signal, subprocess, sys, time +out = sys.argv[-1] +grab = subprocess.Popen([os.path.join(os.path.dirname(os.path.realpath(__file__)), "framecorder-grab")]) +stop = [] +signal.signal(signal.SIGINT, lambda *a: stop.append(1)) +f = open(out + ".part", "wb") +print("fake framecorder started", flush=True) +while not stop: + f.write(b"x" * 4096); f.flush(); time.sleep(0.1) +print("fake framecorder got SIGINT, finishing", flush=True) +time.sleep(1) +f.close(); os.rename(out + ".part", out) +grab.terminate(); grab.wait() +print("fake framecorder finished the file", flush=True) +PY +chmod +x "$T/game" "$T/bin/framecorder" "$T/bin/framecorder-grab" + +survivors() { pgrep -f "$T/bin/framecorder" | tr '\n' ' '; } +# run NAME GAME_SECONDS: starts the wrapper in the background; WRAP_PID, KFH (its KARTFRAME_HOME) +run() { + KFH=$T/$1; mkdir -p "$KFH" + ( cd "$T" && exec env -u SteamAppId HOME="$T/home" XDG_CACHE_HOME="$T/cache" PATH="$T/bin:$PATH" \ + KARTFRAME_HOME="$KFH" KARTFRAME_EXE="$T/game" FAKE_GAME_SECONDS="$2" KARTFRAME_VRTIMING=0 \ + KARTFRAME_RECORD=raw bash "$HERE/kartframe.sh" ) > "$T/$1.out" 2>&1 & + WRAP_PID=$! +} +waitfor() { # waitfor PID SECONDS: true when PID is gone in time + local n; for ((n = 0; n < $2 * 10; n++)); do kill -0 "$1" 2> /dev/null || return 0; sleep 0.1; done; return 1 +} +LOG() { echo "$KFH/sessions/latest/launch.log"; } +show() { echo " --- launch.log (recorder lines)"; grep -i 'record\|panels\|game exited' "$KFH/sessions/latest/launch.log" | sed 's/^/ /'; } + +echo "== 1: game exits after 1 s, before the recorder's 8 s ==" +run early 1 +check "wrapper finished" waitfor "$WRAP_PID" 30 +sleep 9 # past the point where the old wrapper's recorder started anyway +check "no recorder process survives (survivors: $(survivors))" test -z "$(survivors)" +check "log says it was never started" grep -q 'recorder was never started' "$(LOG)" +check "no panels.mkv.part" test ! -e "$KFH/sessions/latest/panels.mkv.part" +show + +echo "== 2: game runs 12 s, recorder runs, game exits normally ==" +run normal 12 +check "wrapper finished" waitfor "$WRAP_PID" 60 +check "no recorder process survives (survivors: $(survivors))" test -z "$(survivors)" +check "log says recorder stopped" grep -q 'recorder stopped' "$(LOG)" +check "recorder got SIGINT and finished the file" grep -q 'finished the file' "$KFH/sessions/latest/framecorder.log" +check "panels.mkv exists, no .part left" test -s "$KFH/sessions/latest/panels.mkv" -a ! -e "$KFH/sessions/latest/panels.mkv.part" +show + +echo "== 3: wrapper killed with TERM while the game runs (recorder up) ==" +run killed 60 +sleep 10 +check "recorder is running before the kill" test -n "$(survivors)" +kill -TERM "$WRAP_PID" +check "wrapper finished" waitfor "$WRAP_PID" 30 +check "no recorder process survives (survivors: $(survivors))" test -z "$(survivors)" +check "game is gone" test ! -d "/proc/$(cat "$KFH/game.pid")" +check "log says recorder stopped" grep -q 'recorder stopped' "$(LOG)" +show + +echo "== 4: wrapper killed with TERM before the recorder started ==" +run killedearly 60 +sleep 3 +kill -TERM "$WRAP_PID" +check "wrapper finished" waitfor "$WRAP_PID" 30 +sleep 7 +check "no recorder process survives (survivors: $(survivors))" test -z "$(survivors)" +check "log says it was never started" grep -q 'recorder was never started' "$(LOG)" +show + +echo +[ "$fails" = 0 ] && echo "all passed" || echo "$fails FAILED" +exit $((fails > 0))