From 0ba98d5c1825640fea7106cbb753670954b55c17 Mon Sep 17 00:00:00 2001 From: Luke Policinski Date: Mon, 27 Jul 2026 12:53:54 -0400 Subject: [PATCH 1/2] #build --- .../src/FiveStack.Events/GameEnd.cs | 52 +++++++++++++++++++ apps/swiftly/src/FiveStack.Events/GameEnd.cs | 41 +++++++++++++++ 2 files changed, 93 insertions(+) diff --git a/apps/counterstrikesharp/src/FiveStack.Events/GameEnd.cs b/apps/counterstrikesharp/src/FiveStack.Events/GameEnd.cs index f7c5ef5..00b8eec 100644 --- a/apps/counterstrikesharp/src/FiveStack.Events/GameEnd.cs +++ b/apps/counterstrikesharp/src/FiveStack.Events/GameEnd.cs @@ -1,10 +1,12 @@ using CounterStrikeSharp.API; using CounterStrikeSharp.API.Core; using CounterStrikeSharp.API.Core.Attributes.Registration; +using CounterStrikeSharp.API.Modules.Timers; using FiveStack.Entities; using FiveStack.Enums; using FiveStack.Utilities; using Microsoft.Extensions.Logging; +using Timer = CounterStrikeSharp.API.Modules.Timers.Timer; namespace FiveStack; @@ -72,10 +74,20 @@ public HookResult OnGameEnd(EventCsWinPanelMatch @event, GameEventInfo info) if (matchData.options.use_playcast) { + _logger.LogInformation( + "OnGameEnd: use_playcast enabled, deferring HandleEndOfMap by {TvDelay}s", + matchData.options.tv_delay + ); + + StartPlaycastWindowHeartbeat(match, matchData.options.tv_delay); + TimerUtility.AddTimer( matchData.options.tv_delay, () => { + _logger.LogInformation( + "OnGameEnd: playcast tv_delay elapsed, running HandleEndOfMap" + ); HandleEndOfMap(winningLineupId); } ); @@ -88,6 +100,46 @@ public HookResult OnGameEnd(EventCsWinPanelMatch @event, GameEventInfo info) return HookResult.Continue; } + private const int PlaycastHeartbeatIntervalSeconds = 15; + + // The playcast window is the only stretch of a match where the plugin goes + // silent for minutes with the map's result still unwritten. Without a + // heartbeat, a timer that never fired and a process that was killed leave + // the exact same trace: nothing. + private void StartPlaycastWindowHeartbeat(MatchManager match, int tvDelay) + { + // Anchored to a clock, not a tick count: CSS timers first fire after the + // interval and Swiftly's fire immediately, so counting down would report + // a different number on each runtime. + DateTime startedAt = DateTime.UtcNow; + Timer? heartbeat = null; + + heartbeat = TimerUtility.AddTimer( + PlaycastHeartbeatIntervalSeconds, + () => + { + int remaining = tvDelay - (int)(DateTime.UtcNow - startedAt).TotalSeconds; + + if (remaining <= 0) + { + heartbeat?.Kill(); + return; + } + + _logger.LogInformation( + "playcast window: {Remaining}s until HandleEndOfMap (match={MatchId} map={MapId} status={Status} gameEnded={GameEnded} players={Players})", + remaining, + match.GetMatchData()?.id, + match.GetActiveMapId(), + match.GetCurrentMapStatus(), + match.gameEnded, + MatchUtility.Players().Count + ); + }, + TimerFlags.REPEAT + ); + } + private void HandleEndOfMap(Guid? winningLineupId) { MatchManager? match = _matchService.GetCurrentMatch(); diff --git a/apps/swiftly/src/FiveStack.Events/GameEnd.cs b/apps/swiftly/src/FiveStack.Events/GameEnd.cs index 9912106..5126383 100644 --- a/apps/swiftly/src/FiveStack.Events/GameEnd.cs +++ b/apps/swiftly/src/FiveStack.Events/GameEnd.cs @@ -79,6 +79,8 @@ public HookResult OnGameEnd(EventCsWinPanelMatch @event) "OnGameEnd: use_playcast enabled, deferring HandleEndOfMap by {TvDelay}s", matchData.options.tv_delay ); + StartPlaycastWindowHeartbeat(match, matchData.options.tv_delay); + TimerUtility.AddTimer( matchData.options.tv_delay, () => @@ -98,6 +100,45 @@ public HookResult OnGameEnd(EventCsWinPanelMatch @event) return HookResult.Continue; } + private const int PlaycastHeartbeatIntervalSeconds = 15; + + // The playcast window is the only stretch of a match where the plugin goes + // silent for minutes with the map's result still unwritten. Without a + // heartbeat, a timer that never fired and a process that was killed leave + // the exact same trace: nothing. + private void StartPlaycastWindowHeartbeat(MatchManager match, int tvDelay) + { + // Anchored to a clock, not a tick count: CSS timers first fire after the + // interval and Swiftly's fire immediately, so counting down would report + // a different number on each runtime. + DateTime startedAt = DateTime.UtcNow; + CancellationTokenSource? heartbeat = null; + + heartbeat = TimerUtility.Repeat( + PlaycastHeartbeatIntervalSeconds, + () => + { + int remaining = tvDelay - (int)(DateTime.UtcNow - startedAt).TotalSeconds; + + if (remaining <= 0) + { + TimerUtility.Kill(heartbeat); + return; + } + + _logger.LogInformation( + "playcast window: {Remaining}s until HandleEndOfMap (match={MatchId} map={MapId} status={Status} gameEnded={GameEnded} players={Players})", + remaining, + match.GetMatchData()?.id, + match.GetActiveMapId(), + match.GetCurrentMapStatus(), + match.gameEnded, + MatchUtility.Players().Count + ); + } + ); + } + private void HandleEndOfMap(Guid? winningLineupId) { MatchManager? match = _matchService.GetCurrentMatch(); From 7dc9a64f519a55acf0c8d158507e0a5a724b73e7 Mon Sep 17 00:00:00 2001 From: Luke Policinski Date: Mon, 27 Jul 2026 12:59:11 -0400 Subject: [PATCH 2/2] wip --- .../src/FiveStack.Events/GameEnd.cs | 53 ++++--------------- .../src/FiveStack.Services/MatchManager.cs | 49 +++++++++++++++++ apps/swiftly/src/FiveStack.Events/GameEnd.cs | 45 ++-------------- .../src/FiveStack.Services/MatchManager.cs | 48 +++++++++++++++++ scripts/tail.sh | 29 ++++++++-- 5 files changed, 137 insertions(+), 87 deletions(-) diff --git a/apps/counterstrikesharp/src/FiveStack.Events/GameEnd.cs b/apps/counterstrikesharp/src/FiveStack.Events/GameEnd.cs index 00b8eec..f8b48da 100644 --- a/apps/counterstrikesharp/src/FiveStack.Events/GameEnd.cs +++ b/apps/counterstrikesharp/src/FiveStack.Events/GameEnd.cs @@ -1,12 +1,10 @@ using CounterStrikeSharp.API; using CounterStrikeSharp.API.Core; using CounterStrikeSharp.API.Core.Attributes.Registration; -using CounterStrikeSharp.API.Modules.Timers; using FiveStack.Entities; using FiveStack.Enums; using FiveStack.Utilities; using Microsoft.Extensions.Logging; -using Timer = CounterStrikeSharp.API.Modules.Timers.Timer; namespace FiveStack; @@ -67,6 +65,14 @@ public HookResult OnGameEnd(EventCsWinPanelMatch @event, GameEventInfo info) Guid? winningLineupId = _matchEvents.GetWinningLineupId(); + _logger.LogInformation( + "OnGameEnd: dispatching end-of-map (use_playcast={UsePlaycast} tv_delay={TvDelay} onGameNode={OnGameNode} winningLineupId={WinningLineupId})", + matchData.options.use_playcast, + matchData.options.tv_delay, + _environmentService.isOnGameServerNode(), + winningLineupId + ); + // Move the map off Live immediately so it reflects WaitingForTV during the // tv_delay window (HandleEndOfMap may be deferred by use_playcast). This is // deduped in UpdateMapStatus, so HandleEndOfMap re-setting it is a no-op. @@ -79,7 +85,7 @@ public HookResult OnGameEnd(EventCsWinPanelMatch @event, GameEventInfo info) matchData.options.tv_delay ); - StartPlaycastWindowHeartbeat(match, matchData.options.tv_delay); + match.StartPlaycastWindowHeartbeat(matchData.options.tv_delay); TimerUtility.AddTimer( matchData.options.tv_delay, @@ -88,6 +94,7 @@ public HookResult OnGameEnd(EventCsWinPanelMatch @event, GameEventInfo info) _logger.LogInformation( "OnGameEnd: playcast tv_delay elapsed, running HandleEndOfMap" ); + match.StopPlaycastWindowHeartbeat(); HandleEndOfMap(winningLineupId); } ); @@ -100,46 +107,6 @@ public HookResult OnGameEnd(EventCsWinPanelMatch @event, GameEventInfo info) return HookResult.Continue; } - private const int PlaycastHeartbeatIntervalSeconds = 15; - - // The playcast window is the only stretch of a match where the plugin goes - // silent for minutes with the map's result still unwritten. Without a - // heartbeat, a timer that never fired and a process that was killed leave - // the exact same trace: nothing. - private void StartPlaycastWindowHeartbeat(MatchManager match, int tvDelay) - { - // Anchored to a clock, not a tick count: CSS timers first fire after the - // interval and Swiftly's fire immediately, so counting down would report - // a different number on each runtime. - DateTime startedAt = DateTime.UtcNow; - Timer? heartbeat = null; - - heartbeat = TimerUtility.AddTimer( - PlaycastHeartbeatIntervalSeconds, - () => - { - int remaining = tvDelay - (int)(DateTime.UtcNow - startedAt).TotalSeconds; - - if (remaining <= 0) - { - heartbeat?.Kill(); - return; - } - - _logger.LogInformation( - "playcast window: {Remaining}s until HandleEndOfMap (match={MatchId} map={MapId} status={Status} gameEnded={GameEnded} players={Players})", - remaining, - match.GetMatchData()?.id, - match.GetActiveMapId(), - match.GetCurrentMapStatus(), - match.gameEnded, - MatchUtility.Players().Count - ); - }, - TimerFlags.REPEAT - ); - } - private void HandleEndOfMap(Guid? winningLineupId) { MatchManager? match = _matchService.GetCurrentMatch(); diff --git a/apps/counterstrikesharp/src/FiveStack.Services/MatchManager.cs b/apps/counterstrikesharp/src/FiveStack.Services/MatchManager.cs index 8897e2d..d4664a6 100644 --- a/apps/counterstrikesharp/src/FiveStack.Services/MatchManager.cs +++ b/apps/counterstrikesharp/src/FiveStack.Services/MatchManager.cs @@ -24,6 +24,7 @@ public class MatchManager private eMapStatus _currentMapStatus = eMapStatus.Unknown; private Guid? _activeMapId; private Timer? _resumeMessageTimer; + private Timer? _playcastWindowTimer; public bool gameEnded = false; private readonly MatchEvents _matchEvents; @@ -617,6 +618,53 @@ public void SetupTeams() ); } + private const int PlaycastHeartbeatIntervalSeconds = 15; + + // The playcast window is the only stretch of a match where the plugin goes + // silent for minutes with the map's result still unwritten. Without a + // heartbeat, a timer that never fired and a process that was killed leave + // the exact same trace: nothing. + public void StartPlaycastWindowHeartbeat(int tvDelay) + { + StopPlaycastWindowHeartbeat(); + + // Anchored to a clock, not a tick count: CSS timers first fire after the + // interval and Swiftly's fire immediately, so counting down would report + // a different number on each runtime. + DateTime startedAt = DateTime.UtcNow; + + _playcastWindowTimer = TimerUtility.AddTimer( + PlaycastHeartbeatIntervalSeconds, + () => + { + int remaining = tvDelay - (int)(DateTime.UtcNow - startedAt).TotalSeconds; + + if (remaining <= 0) + { + StopPlaycastWindowHeartbeat(); + return; + } + + _logger.LogInformation( + "playcast window: {Remaining}s until HandleEndOfMap (match={MatchId} map={MapId} status={Status} gameEnded={GameEnded} players={Players})", + remaining, + _matchData?.id, + _activeMapId, + _currentMapStatus, + gameEnded, + MatchUtility.Players().Count + ); + }, + TimerFlags.REPEAT + ); + } + + public void StopPlaycastWindowHeartbeat() + { + _playcastWindowTimer?.Kill(); + _playcastWindowTimer = null; + } + public void delayChangeMap(int delay) { _remainingMapChangeDelay = delay; @@ -1151,6 +1199,7 @@ public void Reset() _logger.LogInformation("resetting match state"); _resumeMessageTimer?.Kill(); _mapChangeCountdownTimer?.Kill(); + StopPlaycastWindowHeartbeat(); _currentMapStatus = eMapStatus.Unknown; diff --git a/apps/swiftly/src/FiveStack.Events/GameEnd.cs b/apps/swiftly/src/FiveStack.Events/GameEnd.cs index 5126383..d02780e 100644 --- a/apps/swiftly/src/FiveStack.Events/GameEnd.cs +++ b/apps/swiftly/src/FiveStack.Events/GameEnd.cs @@ -62,9 +62,10 @@ public HookResult OnGameEnd(EventCsWinPanelMatch @event) Guid? winningLineupId = _matchEvents.GetWinningLineupId(); _logger.LogInformation( - "OnGameEnd: dispatching end-of-map (use_playcast={UsePlaycast} tv_delay={TvDelay} winningLineupId={WinningLineupId})", + "OnGameEnd: dispatching end-of-map (use_playcast={UsePlaycast} tv_delay={TvDelay} onGameNode={OnGameNode} winningLineupId={WinningLineupId})", matchData.options.use_playcast, matchData.options.tv_delay, + _environmentService.isOnGameServerNode(), winningLineupId ); @@ -79,7 +80,7 @@ public HookResult OnGameEnd(EventCsWinPanelMatch @event) "OnGameEnd: use_playcast enabled, deferring HandleEndOfMap by {TvDelay}s", matchData.options.tv_delay ); - StartPlaycastWindowHeartbeat(match, matchData.options.tv_delay); + match.StartPlaycastWindowHeartbeat(matchData.options.tv_delay); TimerUtility.AddTimer( matchData.options.tv_delay, @@ -88,6 +89,7 @@ public HookResult OnGameEnd(EventCsWinPanelMatch @event) _logger.LogInformation( "OnGameEnd: playcast tv_delay elapsed, running HandleEndOfMap" ); + match.StopPlaycastWindowHeartbeat(); HandleEndOfMap(winningLineupId); } ); @@ -100,45 +102,6 @@ public HookResult OnGameEnd(EventCsWinPanelMatch @event) return HookResult.Continue; } - private const int PlaycastHeartbeatIntervalSeconds = 15; - - // The playcast window is the only stretch of a match where the plugin goes - // silent for minutes with the map's result still unwritten. Without a - // heartbeat, a timer that never fired and a process that was killed leave - // the exact same trace: nothing. - private void StartPlaycastWindowHeartbeat(MatchManager match, int tvDelay) - { - // Anchored to a clock, not a tick count: CSS timers first fire after the - // interval and Swiftly's fire immediately, so counting down would report - // a different number on each runtime. - DateTime startedAt = DateTime.UtcNow; - CancellationTokenSource? heartbeat = null; - - heartbeat = TimerUtility.Repeat( - PlaycastHeartbeatIntervalSeconds, - () => - { - int remaining = tvDelay - (int)(DateTime.UtcNow - startedAt).TotalSeconds; - - if (remaining <= 0) - { - TimerUtility.Kill(heartbeat); - return; - } - - _logger.LogInformation( - "playcast window: {Remaining}s until HandleEndOfMap (match={MatchId} map={MapId} status={Status} gameEnded={GameEnded} players={Players})", - remaining, - match.GetMatchData()?.id, - match.GetActiveMapId(), - match.GetCurrentMapStatus(), - match.gameEnded, - MatchUtility.Players().Count - ); - } - ); - } - private void HandleEndOfMap(Guid? winningLineupId) { MatchManager? match = _matchService.GetCurrentMatch(); diff --git a/apps/swiftly/src/FiveStack.Services/MatchManager.cs b/apps/swiftly/src/FiveStack.Services/MatchManager.cs index c219726..e707b2c 100644 --- a/apps/swiftly/src/FiveStack.Services/MatchManager.cs +++ b/apps/swiftly/src/FiveStack.Services/MatchManager.cs @@ -22,6 +22,7 @@ public class MatchManager private eMapStatus _currentMapStatus = eMapStatus.Unknown; private Guid? _activeMapId; private CancellationTokenSource? _resumeMessageTimer; + private CancellationTokenSource? _playcastWindowTimer; public bool gameEnded = false; private readonly ISwiftlyCore _core; @@ -612,6 +613,52 @@ public void SetupTeams() ); } + private const int PlaycastHeartbeatIntervalSeconds = 15; + + // The playcast window is the only stretch of a match where the plugin goes + // silent for minutes with the map's result still unwritten. Without a + // heartbeat, a timer that never fired and a process that was killed leave + // the exact same trace: nothing. + public void StartPlaycastWindowHeartbeat(int tvDelay) + { + StopPlaycastWindowHeartbeat(); + + // Anchored to a clock, not a tick count: CSS timers first fire after the + // interval and Swiftly's fire immediately, so counting down would report + // a different number on each runtime. + DateTime startedAt = DateTime.UtcNow; + + _playcastWindowTimer = TimerUtility.Repeat( + PlaycastHeartbeatIntervalSeconds, + () => + { + int remaining = tvDelay - (int)(DateTime.UtcNow - startedAt).TotalSeconds; + + if (remaining <= 0) + { + StopPlaycastWindowHeartbeat(); + return; + } + + _logger.LogInformation( + "playcast window: {Remaining}s until HandleEndOfMap (match={MatchId} map={MapId} status={Status} gameEnded={GameEnded} players={Players})", + remaining, + _matchData?.id, + _activeMapId, + _currentMapStatus, + gameEnded, + MatchUtility.Players().Count + ); + } + ); + } + + public void StopPlaycastWindowHeartbeat() + { + TimerUtility.Kill(_playcastWindowTimer); + _playcastWindowTimer = null; + } + public void delayChangeMap(int delay) { _remainingMapChangeDelay = delay; @@ -1127,6 +1174,7 @@ public void Reset() _logger.LogInformation("resetting match state"); TimerUtility.Kill(_resumeMessageTimer); TimerUtility.Kill(_mapChangeCountdownTimer); + StopPlaycastWindowHeartbeat(); _currentMapStatus = eMapStatus.Unknown; diff --git a/scripts/tail.sh b/scripts/tail.sh index c4f350c..70da95b 100755 --- a/scripts/tail.sh +++ b/scripts/tail.sh @@ -32,6 +32,13 @@ fi # SwiftlyS2 bug: the game process stops emitting to stdout after the first # plugin hot reload, but its own log files keep flowing — so for swiftly, # merge the managed log file into the stream alongside container stdout. +# +# Both streams carry the same plugin lines while stdout is alive, so the file +# tail is gated on a liveness stamp the stdout side touches: its lines are only +# printed once stdout has been quiet for STDOUT_QUIET_SECONDS, i.e. once the +# reload bug has actually bitten. Otherwise every plugin line shows up twice. +STDOUT_QUIET_SECONDS=10 + if [ "$workload" = "dev-swiftly-game-server" ] && command -v kubectl >/dev/null 2>&1; then export KUBECONFIG="${KUBECONFIG:-$HOME/.kube/5stackgg}" pod=$(kubectl -n 5stack get pods -l app="$workload" \ @@ -39,14 +46,30 @@ if [ "$workload" = "dev-swiftly-game-server" ] && command -v kubectl >/dev/null --sort-by=.metadata.creationTimestamp \ -o jsonpath='{.items[-1].metadata.name}' 2>/dev/null || true) if [ -n "$pod" ]; then + stdout_stamp="$(mktemp -t tail-stdout-stamp)" + date +%s > "$stdout_stamp" + kubectl -n 5stack exec "$pod" -c "$workload" -- sh -c \ 'tail -n 5 -F /opt/instance/game/csgo/addons/swiftlys2/logs/managed/*.log 2>/dev/null' \ - | sed -u 's/^/[sw-log] /' & + | while IFS= read -r line; do + last="$(cat "$stdout_stamp" 2>/dev/null || echo 0)" + if [ "$(( $(date +%s) - last ))" -ge "$STDOUT_QUIET_SECONDS" ]; then + printf '[sw-log] %s\n' "$line" + fi + done & file_tail_pid=$! - trap 'kill "$file_tail_pid" 2>/dev/null' EXIT + trap 'kill "$file_tail_pid" 2>/dev/null; rm -f "$stdout_stamp"' EXIT fi fi # the container carries the same name as its workload # (no exec: the EXIT trap must fire to reap the background file tail) -codepier tail --deployment "$workload" --container "$workload" +if [ -n "${stdout_stamp:-}" ]; then + codepier tail --deployment "$workload" --container "$workload" \ + | while IFS= read -r line; do + date +%s > "$stdout_stamp" + printf '%s\n' "$line" + done +else + codepier tail --deployment "$workload" --container "$workload" +fi