Talon/RemSound
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

Fix: service startup-volume re-punching on every restart + misleading suspend log

Browse Source 
Ed reported the service pulling his volume to 20% repeatedly. Diagnosis from the
service logs: NOT a runaway timer - one service process ran untouched for 36 hours,
proving there's no periodic restart. The volume-to-20 punches came from GENUINE
service restarts (deploys, the one self-update, profile saves, handovers during
active use), each re-applying because the mode was "every service restart". Two real
faults found and fixed:

1. Re-apply burst guard. "Every service restart" (and boot-only as belt-and-braces)
   now skips a re-apply within ReapplyCooldown (5 min) of the last successful apply,
   persisted as startup-volume-last.txt. This kills the double-apply we saw in the
   log at 08:20:48 then 08:21:02 (a self-update restart immediately followed by a
   follow-on start, 14s apart, both punching the volume), and any rapid churn from
   self-update / profile-save / deploy. ShouldApply gains lastApplied+now params;
   future-dated stamp (clock moved back) can't wedge it.

2. Misleading log. ServiceSendHost.Suspend() hard-coded "interactive app present" on
   EVERY suspend, including plain shutdown - which sent this very investigation
   chasing phantom app-handovers. Suspend now takes a reason; the run-loop-ending
   path says so, only a real app yield says "interactive app present".

readme: recommend "first start after boot" as the set-and-forget mode and explain
that "every restart" also fires on routine internal restarts (and is now burst-
guarded). Self-test extended: cooldown skip in both modes, 14s double-apply guard,
future-stamp safety. Gate 71/71 + 7 relay tests.

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
This commit is contained in:
Ednunp
2026-07-27 10:36:54 +01:00
co-authored by Claude Fable 5
parent 65e999466d
commit 93bf1d86eb
5 changed files with 87 additions and 19 deletions
Download Patch File Download Diff File Expand all files Collapse all files
src/RemSound.App/SelfTest.cs
+20 -6
View File
@@ -2633,13 +2633,27 @@ internal static class SelfTest
/// flag sharing its file (load-modify-save).</summary>
private static string? ServiceStartupVolume()
{
// Decision core. Boot instants within the tolerance are the SAME boot.
// Decision core. Boot instants within the tolerance are the SAME boot. now is well past any
// cooldown from lastApplied unless a test sets lastApplied recent.
var boot = new DateTime(2026, 7, 26, 6, 0, 0, DateTimeKind.Utc);
Check(!StartupVolume.ShouldApply(false, true, null, boot), "disabled → never applies");
Check(StartupVolume.ShouldApply(true, true, null, boot), "boot-only with no marker yet → applies (first ever start)");
Check(!StartupVolume.ShouldApply(true, true, boot.AddSeconds(-30), boot), "boot-only, marker from THIS boot → skipped (a same-boot service restart must not re-blast the volume)");
Check(StartupVolume.ShouldApply(true, true, boot.AddHours(-9), boot), "boot-only, marker from a PREVIOUS boot → applies again");
Check(StartupVolume.ShouldApply(true, false, boot.AddSeconds(-30), boot), "every-start mode ignores the marker entirely");
var now = new DateTime(2026, 7, 26, 12, 0, 0, DateTimeKind.Utc);
DateTime? noLast = null;
Check(!StartupVolume.ShouldApply(false, true, null, boot, noLast, now), "disabled → never applies");
Check(StartupVolume.ShouldApply(true, true, null, boot, noLast, now), "boot-only with no marker yet → applies (first ever start)");
Check(!StartupVolume.ShouldApply(true, true, boot.AddSeconds(-30), boot, noLast, now), "boot-only, marker from THIS boot → skipped (a same-boot service restart must not re-blast the volume)");
Check(StartupVolume.ShouldApply(true, true, boot.AddHours(-9), boot, noLast, now), "boot-only, marker from a PREVIOUS boot → applies again");
Check(StartupVolume.ShouldApply(true, false, boot.AddSeconds(-30), boot, noLast, now), "every-start mode past the cooldown ignores the boot marker");
// Re-apply burst guard (the fix for the volume-machine-gunning). A fresh apply within the
// cooldown of the last one is skipped in BOTH modes; past the cooldown it applies again.
Check(!StartupVolume.ShouldApply(true, false, null, boot, now.AddMinutes(-1), now),
"every-restart: a restart 1 min after the last apply must be SKIPPED (burst guard — self-update/deploy/handover churn)");
Check(StartupVolume.ShouldApply(true, false, null, boot, now.AddMinutes(-10), now),
"every-restart: a restart 10 min later (past the 5-min cooldown) applies again");
Check(!StartupVolume.ShouldApply(true, true, boot.AddHours(-9), boot, now.AddMinutes(-1), now),
"boot-only: even a genuine new boot is held off if the volume was applied seconds ago (double-apply guard — the 14s self-update case)");
Check(StartupVolume.ShouldApply(true, false, null, boot, now.AddMinutes(5), now),
"a last-applied stamp in the FUTURE (clock moved back) must not wedge — it still applies");
// Settings round-trip in a throwaway store; the volume save must preserve the logging flag.
var savedOverride = ServiceStore.TestDirectoryOverride;
src/RemSound.App/ServiceSendHost.cs
+7 -4
View File
@@ -391,8 +391,11 @@ public sealed class ServiceSendHost : IDisposable
}
}
/// <summary>Stops sending and releases capture. Safe to call when already stopped.</summary>
public void Suspend()
/// <summary>Stops sending and releases capture. Safe to call when already stopped. <paramref
/// name="reason"/> is logged so the diagnostic trail distinguishes a real yield-to-the-app from a
/// plain shutdown — the old hard-coded "interactive app present" was printed on BOTH, which sent a
/// bug hunt chasing phantom app-handovers (2026-07-27).</summary>
public void Suspend(string reason = "interactive app present")
{
lock (gate)
{
@@ -406,7 +409,7 @@ public sealed class ServiceSendHost : IDisposable
sessionKick = null;
try { PerformanceMode.Apply(false, msg => log?.Invoke($"service: {msg}")); } catch { /* best-effort */ }
running = false;
log?.Invoke("service: suspended (interactive app present)");
log?.Invoke($"service: suspended ({reason})");
}
}
@@ -513,7 +516,7 @@ public sealed class ServiceSendHost : IDisposable
ct.WaitHandle.WaitOne(pollMs);
}
wantSending = false;
Suspend();
Suspend("run loop ending — service stopping");
}
/// <summary>Force a re-open of capture if we intend to send — called after a power resume, when the
src/RemSound.App/StartupVolume.cs
+37 -8
View File
@@ -17,14 +17,35 @@ internal static class StartupVolume
/// granularity, clock adjustments); a real reboot separates instants by minutes at least.</summary>
internal static readonly TimeSpan SameBootTolerance = TimeSpan.FromMinutes(2);
/// <summary>Minimum gap between two volume applications, whatever the mode (2026-07-27). The
/// service can restart in quick succession for reasons the user never asked for — a self-update
/// (we saw two applies 14 s apart: the update restart, then a follow-on start), a profile save,
/// a test deploy, the app handing back. "Every service restart" must not machine-gun the volume
/// down on each of those, so a fresh apply inside this window is skipped. A genuine "I restarted
/// the service to reset the volume" a few minutes later still applies; a reboot (boot-only) is
/// unaffected. NOTE: this is a burst guard — the set-and-forget choice is "first start after
/// boot", which applies once per boot and never re-punches.</summary>
internal static readonly TimeSpan ReapplyCooldown = TimeSpan.FromMinutes(5);
/// <summary>When THIS boot began (UTC), from the monotonic uptime counter.</summary>
public static DateTime CurrentBootUtc() => DateTime.UtcNow - TimeSpan.FromMilliseconds(Environment.TickCount64);
/// <summary>Pure decision core, pinned by the self-test: apply when enabled, and — in boot-only
/// mode — when the recorded marker belongs to a DIFFERENT boot (or there is no marker yet).</summary>
internal static bool ShouldApply(bool enabled, bool bootOnly, DateTime? markerBootUtc, DateTime currentBootUtc)
/// <summary>Pure decision core, pinned by the self-test. Never apply within the re-apply cooldown
/// of the last successful apply (the burst guard — stops rapid/automatic restarts from re-punching
/// the volume). Otherwise: boot-only mode applies only when the boot marker belongs to a DIFFERENT
/// boot (or none yet); every-restart mode applies on any start past the cooldown.</summary>
internal static bool ShouldApply(bool enabled, bool bootOnly, DateTime? markerBootUtc, DateTime currentBootUtc,
DateTime? lastAppliedUtc, DateTime nowUtc)
{
if (!enabled) return false;
// Burst guard first, both modes: a fresh apply within the cooldown of the last one is skipped.
// Guard the negative case too (clock moved backwards) — treat only a positive, sub-cooldown
// gap as "too soon"; anything else falls through to the normal decision.
if (lastAppliedUtc is { } last)
{
var since = nowUtc - last;
if (since >= TimeSpan.Zero && since < ReapplyCooldown) return false;
}
if (!bootOnly) return true;
if (markerBootUtc is null) return true;
return (currentBootUtc - markerBootUtc.Value).Duration() > SameBootTolerance;
@@ -40,9 +61,13 @@ internal static class StartupVolume
var (enabled, percent, bootOnly) = ServiceStore.LoadStartupVolume();
if (!enabled) return;
var boot = CurrentBootUtc();
if (!ShouldApply(enabled, bootOnly, ServiceStore.LoadStartupVolumeBootMarker(), boot))
var nowUtc = DateTime.UtcNow;
if (!ShouldApply(enabled, bootOnly, ServiceStore.LoadStartupVolumeBootMarker(), boot,
ServiceStore.LoadStartupVolumeLastAppliedUtc(), nowUtc))
{
log?.Invoke("service: startup volume skipped — already applied this boot (boot-only mode)");
log?.Invoke(bootOnly
? "service: startup volume skipped — already applied this boot (boot-only mode)"
: "service: startup volume skipped — applied within the last few minutes (burst guard; a restart just happened)");
return;
}
var ok = SystemVolumeHelper.TrySetVolumeAndUnmute(percent);
@@ -53,9 +78,13 @@ internal static class StartupVolume
// Also into the always-on events log (not gated on the logging toggle): one line per
// qualifying start, so "did it fire?" is answerable without turning full logging on.
ServiceStore.AppendServiceEvent(outcome);
// Marker only on success: a boot-time failure (audio stack not up yet) leaves the next
// same-boot restart eligible to retry rather than silently never applying.
if (ok) ServiceStore.SaveStartupVolumeBootMarker(boot);
// Markers only on success: a boot-time failure (audio stack not up yet) leaves the next
// restart eligible to retry. The last-applied stamp drives the burst guard for both modes.
if (ok)
{
ServiceStore.SaveStartupVolumeBootMarker(boot);
ServiceStore.SaveStartupVolumeLastAppliedUtc(nowUtc);
}
}
catch (Exception ex)
{