Firmware validation harness: instrumented RIO_TAP mash test in RioSerialMonitor

New --mash mode (tools/RioSerialMonitor/MashTest.cs) mechanizes the
wedge-patch validation plan from RIOv4_2-ANALYSIS.md:
- Runs the live link with the app's >5s reset-recovery DISABLED so a
  board wedge stays observable, and echoes lamps on every press
  (lamp/reply collisions are the wedge trigger).
- Gap timing uses ANY AnalogReply packet (0xFE sentinels included -
  a sentinel still proves the reply path is alive); logs a gap
  histogram + top-10 longest gaps with timestamps.
- WEDGE detector: analog silent past the threshold (default 2s) ->
  beep + banner; on resume, classifies self-recovered (patched
  expectation) vs button-revived (button event within 300ms of resume,
  the unpatched signature) vs unresolved at run end.
- Board self-reported RestartCount/AbandonCount/FullBufferCount
  snapshotted before/after via CheckRequest, delta printed
  (7-bit wrap-aware).
- Fixed-layout summary teed to riomash-<label>-<stamp>.log so
  baseline-vs-patched runs diff directly. Exit 0 = no wedge, 1 = wedge.

--mash --selftest drives the whole instrument against a scripted
in-memory board (SelftestTransport) that goes silent at t=4.0s and
revives 200ms after a button at t=6.5s: verified end-to-end - alarm at
6.0s, wedge classified button-revived (2.75s), counter delta +4/+0/+1,
verdict FAIL, exit 1. Use it to sanity-check the alarm at the cabinet.

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
This commit is contained in:
Cyd
2026-07-17 14:35:27 -05:00
co-authored by Claude Fable 5
parent 52712f8409
commit fcf26cfd15
5 changed files with 499 additions and 1 deletions
+365
View File
@@ -0,0 +1,365 @@
using System.Diagnostics;
using RioJoy.Core.Mapping;
using RioJoy.Core.Protocol;
using RioJoy.Core.Serial;
namespace RioSerialMonitor;
/// <summary>
/// Instrumented firmware mash test (the RIO_TAP protocol, mechanized) for
/// validating the RIOv4.2 reply-latch wedge patch — see
/// rio-firmware/RIOv4_2-ANALYSIS.md "Validation plan".
///
/// Runs the live link with the app's own &gt;5s reset-recovery DISABLED (so a
/// board wedge stays observable instead of being revived by our watchdog),
/// echoes lamps on every press (lamp writes colliding with analog replies are
/// the wedge trigger), and records:
/// - an inter-analog-reply gap histogram + the longest gaps with timestamps
/// (gap timing uses ANY AnalogReply packet, valid or 0xFE-sentinel — a
/// sentinel still proves the reply path is alive);
/// - WEDGE events: analog silent past the threshold while button traffic
/// continues; on resume, whether it self-recovered or was revived by a
/// button press (the known unpatched revival mechanism);
/// - the board's own RestartCount/AbandonCount/FullBufferCount before and
/// after (CheckReply), with the delta;
/// - a fixed-layout summary block, teed to a log file, so runs on the
/// original vs patched chip diff cleanly.
///
/// Usage:
/// dotnet run --project tools/RioSerialMonitor -- --mash [port] [seconds]
/// [--label name] [--no-lamps] [--wedge seconds]
/// Defaults: COM1, 300 s, label "unlabeled", lamps on, wedge threshold 2 s.
/// Exit: 0 = ran with no wedge, 1 = wedge detected, 2 = could not open port.
/// </summary>
internal static class MashTest
{
private sealed class WedgeEvent
{
public TimeSpan Start;
public TimeSpan Duration;
public int ButtonEventsDuring;
public bool RevivedByButton;
public bool Unresolved; // run ended while still wedged
}
public static async Task<int> RunAsync(string[] args)
{
// --- args ------------------------------------------------------------
string port = "COM1";
int seconds = 300;
string label = "unlabeled";
bool lampEcho = true;
double wedgeSec = 2.0;
bool selftest = false;
var positional = new List<string>();
for (int i = 0; i < args.Length; i++)
{
switch (args[i])
{
case "--mash": break;
case "--no-lamps": lampEcho = false; break;
case "--selftest": selftest = true; break;
case "--label" when i + 1 < args.Length: label = args[++i]; break;
case "--wedge" when i + 1 < args.Length && double.TryParse(args[i + 1], out double w):
wedgeSec = w; i++; break;
default: positional.Add(args[i]); break;
}
}
if (positional.Count > 0) port = positional[0];
if (positional.Count > 1 && int.TryParse(positional[1], out int s)) seconds = s;
if (selftest)
{
// Scripted board (SelftestTransport): short fixed run, expect exactly
// one button-revived wedge and a +4/+1 counter delta → exit 1.
port = "selftest";
seconds = 10;
if (label == "unlabeled") label = "selftest";
}
string logPath = $"riomash-{label}-{DateTime.Now:yyyyMMdd-HHmmss}.log";
using var logFile = new StreamWriter(logPath) { AutoFlush = true };
var gate = new object();
var sw = Stopwatch.StartNew();
void Log(string msg)
{
lock (gate)
{
string line = $"[{sw.Elapsed.TotalSeconds,7:F2}s] {msg}";
Console.WriteLine(line);
logFile.WriteLine(line);
}
}
void Raw(string msg)
{
lock (gate) { Console.WriteLine(msg); logFile.WriteLine(msg); }
}
Raw($"== RIO mash test :: {port} @ 9600 8N1, {seconds}s, chip label '{label}' ==");
Raw($" lamp echo {(lampEcho ? "ON (drives reply/lamp collisions)" : "OFF")}, " +
$"wedge threshold {wedgeSec:F1}s, app auto-recovery DISABLED");
Raw($" log: {Path.GetFullPath(logPath)}");
IRioTransport transport;
try
{
transport = selftest ? new SelftestTransport() : new SerialPortTransport(port);
}
catch (Exception ex)
{
Raw($" FAILED to open {port}: {ex.GetType().Name}: {ex.Message}");
return 2;
}
// Recovery timeout effectively infinite: a wedge must be OURS to observe,
// not silently repaired by the link's legacy >5s general-reset rule.
var link = new RioSerialLink(transport, new RioSerialLinkOptions
{
AnalogRecoveryTimeout = TimeSpan.FromDays(365),
});
// --- shared state (guarded by 'gate') ---------------------------------
int presses = 0, releases = 0, framing = 0, naks = 0, sentinels = 0;
long analogReplies = 0;
TimeSpan lastAnalog = TimeSpan.Zero;
TimeSpan lastButton = TimeSpan.MinValue;
// Gap histogram buckets (upper bounds in ms; last = overflow).
double[] bucketMs = { 100, 250, 500, 1000, 2000, 5000, double.MaxValue };
string[] bucketNames = { "<100ms", "100-250ms", "250-500ms", "0.5-1s", "1-2s", "2-5s", ">5s" };
long[] buckets = new long[bucketMs.Length];
var longestGaps = new List<(TimeSpan At, double Ms)>(); // keep top 10
bool inWedge = false;
var currentWedge = default(WedgeEvent);
var wedges = new List<WedgeEvent>();
bool statusCollecting = false;
var statusItems = new List<CheckStatus>();
VersionInfo? version = null;
void NoteGap(double ms, TimeSpan at)
{
for (int i = 0; i < bucketMs.Length; i++)
{
if (ms <= bucketMs[i]) { buckets[i]++; break; }
}
longestGaps.Add((at, ms));
if (longestGaps.Count > 10)
{
longestGaps.Sort((a, b) => b.Ms.CompareTo(a.Ms));
longestGaps.RemoveAt(10);
}
}
link.PacketReceived += p =>
{
lock (gate)
{
switch (p.Command)
{
case RioCommand.AnalogReply:
{
TimeSpan now = sw.Elapsed;
analogReplies++;
foreach (byte b in p.Payload)
{
if (b == (byte)RioControl.Restart) { sentinels++; break; }
}
if (lastAnalog != TimeSpan.Zero)
NoteGap((now - lastAnalog).TotalMilliseconds, lastAnalog);
if (inWedge && currentWedge is not null)
{
currentWedge.Duration = now - currentWedge.Start;
currentWedge.RevivedByButton =
lastButton > currentWedge.Start &&
(now - lastButton) < TimeSpan.FromMilliseconds(300);
wedges.Add(currentWedge);
Log($"*** WEDGE ENDED after {currentWedge.Duration.TotalSeconds:F2}s — " +
(currentWedge.RevivedByButton
? "revived by a button press (unpatched-firmware signature)"
: "self-recovered (patched-firmware expectation)") +
$", {currentWedge.ButtonEventsDuring} button events during");
inWedge = false;
currentWedge = null;
}
lastAnalog = now;
break;
}
case RioCommand.ButtonPressed:
case RioCommand.KeyPressed:
presses++;
lastButton = sw.Elapsed;
if (inWedge && currentWedge is not null) currentWedge.ButtonEventsDuring++;
// Lamp echo on lamp buttons (keypads have none): the lamp
// number is the RIO address, not the raw button code.
if (lampEcho && p.Command == RioCommand.ButtonPressed &&
p.Payload[0] < RioAddress.ButtonCount)
_ = link.SetLampAsync((byte)RioAddress.FromButton(p.Payload[0]), RioLampState.SolidBright);
break;
case RioCommand.ButtonReleased:
case RioCommand.KeyReleased:
releases++;
lastButton = sw.Elapsed;
if (inWedge && currentWedge is not null) currentWedge.ButtonEventsDuring++;
if (lampEcho && p.Command == RioCommand.ButtonReleased &&
p.Payload[0] < RioAddress.ButtonCount)
_ = link.SetLampAsync((byte)RioAddress.FromButton(p.Payload[0]), RioLampState.SolidDim);
break;
}
}
};
link.VersionReceived += v => { lock (gate) version = v; };
link.CheckReceived += c => { lock (gate) { if (statusCollecting) statusItems.Add(c); } };
link.FramingError += () => { lock (gate) framing++; };
link.ControlReceived += b => { if ((RioControl)b == RioControl.Nak) lock (gate) naks++; };
using var cts = new CancellationTokenSource();
Task run = link.RunAsync(cts.Token);
// --- counters BEFORE ---------------------------------------------------
await Task.Delay(500);
Dictionary<RioStatusType, int> before = await SnapshotStatusAsync();
Raw($" firmware: {(version is null ? "(no version reply!)" : version.ToString())}");
Raw($" counters before: {FormatCounters(before)}");
Raw("");
Raw(">>> MASH NOW: two hands, 8 lamp buttons, as fast as you can. <<<");
Raw($">>> Test runs {seconds}s. A wedge alarm will beep + banner. <<<");
Raw("");
// --- wedge watchdog + progress ticker ----------------------------------
TimeSpan runEnd = sw.Elapsed + TimeSpan.FromSeconds(seconds);
TimeSpan nextProgress = sw.Elapsed + TimeSpan.FromSeconds(30);
while (sw.Elapsed < runEnd)
{
await Task.Delay(100);
lock (gate)
{
if (!inWedge && lastAnalog != TimeSpan.Zero &&
(sw.Elapsed - lastAnalog).TotalSeconds > wedgeSec)
{
inWedge = true;
currentWedge = new WedgeEvent { Start = lastAnalog };
Log($"*** WEDGE: no analog reply for >{wedgeSec:F1}s (last at {lastAnalog.TotalSeconds:F2}s). " +
"Keep pressing buttons — do NOT power cycle. ***");
try { Console.Beep(880, 400); } catch { /* no console beep available */ }
}
}
if (sw.Elapsed >= nextProgress)
{
lock (gate)
{
double rate = presses / Math.Max(1.0, sw.Elapsed.TotalMinutes);
double maxGap = longestGaps.Count > 0 ? longestGaps.Max(g => g.Ms) : 0;
Log($"progress: presses={presses} ({rate:F0}/min) analog={analogReplies} " +
$"maxGap={maxGap / 1000:F2}s wedges={wedges.Count}{(inWedge ? " [WEDGED NOW]" : "")}");
}
nextProgress = sw.Elapsed + TimeSpan.FromSeconds(30);
}
}
// Close out an unresolved wedge.
lock (gate)
{
if (inWedge && currentWedge is not null)
{
currentWedge.Duration = sw.Elapsed - currentWedge.Start;
currentWedge.Unresolved = true;
wedges.Add(currentWedge);
Log($"*** RUN ENDED WHILE WEDGED ({currentWedge.Duration.TotalSeconds:F1}s and counting) ***");
}
}
// --- counters AFTER ------------------------------------------------------
Dictionary<RioStatusType, int> after = await SnapshotStatusAsync();
cts.Cancel();
try { await run; } catch { /* shutdown */ }
transport.Dispose();
// --- summary (fixed layout for diffing runs) ------------------------------
double mins = Math.Max(sw.Elapsed.TotalMinutes, 0.001);
long expectedPolls = (long)(seconds * 1000.0 / 55.0);
bool anyWedge = wedges.Count > 0;
bool endedWedged = wedges.Any(w => w.Unresolved);
bool anyButtonRevival = wedges.Any(w => w.RevivedByButton);
Raw("");
Raw($"== MASH SUMMARY [{label}] ==");
Raw($"run : {seconds}s on {port}, lamps {(lampEcho ? "on" : "off")}, wedge threshold {wedgeSec:F1}s");
Raw($"firmware : {(version is null ? "(no reply)" : version.ToString())}");
Raw($"presses/releases : {presses} / {releases} ({presses / mins:F0} presses/min)");
Raw($"analog replies : {analogReplies} (~{expectedPolls} poll slots; {100.0 * analogReplies / Math.Max(1, expectedPolls):F1}%), sentinels {sentinels}");
Raw($"framing / NAK : {framing} / {naks}");
Raw("gap histogram : " + string.Join(" ", bucketNames.Select((n, i) => $"{n}:{buckets[i]}")));
Raw("longest gaps : " + (longestGaps.Count == 0
? "(none)"
: string.Join(", ", longestGaps.OrderByDescending(g => g.Ms).Take(10)
.Select(g => $"{g.Ms / 1000:F2}s@{g.At.TotalSeconds:F1}s"))));
Raw($"wedge events : {wedges.Count}" + (wedges.Count == 0 ? "" :
" — " + string.Join("; ", wedges.Select(w =>
$"{w.Duration.TotalSeconds:F1}s@{w.Start.TotalSeconds:F1}s " +
(w.Unresolved ? "UNRESOLVED" : w.RevivedByButton ? "button-revived" : "self-recovered")))));
Raw($"counters before : {FormatCounters(before)}");
Raw($"counters after : {FormatCounters(after)}");
Raw($"counter delta : {FormatDelta(before, after)}");
string verdict =
endedWedged ? "FAIL — board wedged and never recovered (power cycle it now)" :
anyButtonRevival ? "FAIL — wedge required a button press to revive (unpatched behavior)" :
anyWedge ? "MARGINAL — wedge(s) occurred but self-recovered; compare durations to baseline" :
"PASS — no wedge; compare gap histogram + counter delta to baseline";
Raw($"verdict : {verdict}");
Raw($"log file : {Path.GetFullPath(logPath)}");
return anyWedge ? 1 : 0;
// --- helpers ---------------------------------------------------------
async Task<Dictionary<RioStatusType, int>> SnapshotStatusAsync()
{
lock (gate) { statusItems.Clear(); statusCollecting = true; }
try
{
await link.RequestVersionAsync();
await link.RequestCheckAsync();
}
catch { /* port trouble surfaces as an empty snapshot */ }
await Task.Delay(1200);
lock (gate)
{
statusCollecting = false;
// Counters arrive one item per type; keep the last value per type.
var map = new Dictionary<RioStatusType, int>();
foreach (CheckStatus item in statusItems)
map[item.Type] = item.Number;
return map;
}
}
static string FormatCounters(Dictionary<RioStatusType, int> c) =>
c.Count == 0
? "(no status reply — reply path dead?)"
: string.Join(" ", new[] { RioStatusType.RestartCount, RioStatusType.AbandonCount, RioStatusType.FullBufferCount }
.Select(t => $"{t}={(c.TryGetValue(t, out int v) ? v.ToString() : "-")}"))
+ (c.ContainsKey(RioStatusType.BoardBad) || c.ContainsKey(RioStatusType.LampBad)
? " [board/lamp faults reported!]" : "");
static string FormatDelta(Dictionary<RioStatusType, int> b, Dictionary<RioStatusType, int> a)
{
if (b.Count == 0 || a.Count == 0) return "(incomplete — a snapshot got no reply)";
return string.Join(" ", new[] { RioStatusType.RestartCount, RioStatusType.AbandonCount, RioStatusType.FullBufferCount }
.Select(t =>
{
bool hb = b.TryGetValue(t, out int vb), ha = a.TryGetValue(t, out int va);
// 7-bit payload counters can wrap at 128.
return hb && ha ? $"{t}=+{(va - vb + 128) % 128}" : $"{t}=?";
}));
}
}
}
+7 -1
View File
@@ -9,7 +9,13 @@ using RioJoy.Core.Serial;
// It flashes all lamps once to prove the PC -> RIO output path, then echoes a lamp
// on each button press so a physical press lights up.
// dotnet run --project tools/RioSerialMonitor -- [port] [seconds]
// Exit: 0 = ran, 2 = could not open the port.
// Firmware wedge-patch validation (RIO_TAP mash test, see MashTest.cs):
// dotnet run --project tools/RioSerialMonitor -- --mash [port] [seconds]
// [--label baseline|patched] [--no-lamps] [--wedge seconds]
// Exit: 0 = ran, 2 = could not open the port (mash: 1 = wedge detected).
if (args.Contains("--mash"))
return await RioSerialMonitor.MashTest.RunAsync(args);
string port = args.Length > 0 ? args[0] : "COM1";
int seconds = args.Length > 1 && int.TryParse(args[1], out int s) ? s : 30;
+108
View File
@@ -0,0 +1,108 @@
using System.Collections.Concurrent;
using System.Diagnostics;
using RioJoy.Core.Protocol;
using RioJoy.Core.Serial;
namespace RioSerialMonitor;
/// <summary>
/// Scripted in-memory RIO for <c>--mash --selftest</c>: proves the mash-test
/// instrumentation (wedge alarm, revival classification, counter delta) works
/// before it is trusted to judge firmware at the cabinet.
///
/// Timeline (seconds from open):
/// 0.0 4.0 analog replies every 50 ms (healthy)
/// 4.0 6.7 analog SILENT (the wedge; alarm must fire at ~6.0 with the
/// default 2 s threshold) while the port stays open
/// 6.5 / 7.0 ButtonPressed / ButtonReleased 0x05 (masher still mashing)
/// 6.7 end analog resumes 200 ms after the button — the tool must
/// classify the wedge as "button-revived" (unpatched signature)
/// CheckRequest is answered with RestartCount 3 / FullBufferCount 1 on the
/// first ask and 7 / 2 afterwards, so the counter delta must read +4 / +1.
/// Expected run outcome: 1 wedge event, verdict FAIL (button-revived), exit 1.
/// </summary>
internal sealed class SelftestTransport : IRioTransport
{
private readonly ConcurrentQueue<byte[]> _rx = new();
private readonly SemaphoreSlim _rxReady = new(0);
private readonly CancellationTokenSource _cts = new();
private readonly Stopwatch _clock = Stopwatch.StartNew();
private int _checkCalls;
public SelftestTransport() => _ = ProduceAsync(_cts.Token);
public string Description => "selftest (scripted in-memory RIO)";
public async Task<int> ReadAsync(byte[] buffer, CancellationToken cancellationToken)
{
using var linked = CancellationTokenSource.CreateLinkedTokenSource(cancellationToken, _cts.Token);
await _rxReady.WaitAsync(linked.Token).ConfigureAwait(false);
if (!_rx.TryDequeue(out byte[]? chunk))
return 0;
Array.Copy(chunk, buffer, chunk.Length);
return chunk.Length;
}
public Task WriteAsync(byte[] data, CancellationToken cancellationToken)
{
// Answer the requests the test sends; swallow analog polls + lamp writes.
if (data.Length > 0)
{
if (data[0] == (byte)RioCommand.VersionRequest)
{
Enqueue(PacketBuilder.Build(RioCommand.VersionReply, new byte[] { 4, 2 }));
}
else if (data[0] == (byte)RioCommand.CheckRequest)
{
bool first = Interlocked.Increment(ref _checkCalls) == 1;
Enqueue(PacketBuilder.Build(RioCommand.CheckReply,
new[] { (byte)RioStatusType.RestartCount, first ? (byte)3 : (byte)7 }));
Enqueue(PacketBuilder.Build(RioCommand.CheckReply,
new[] { (byte)RioStatusType.AbandonCount, (byte)0 }));
Enqueue(PacketBuilder.Build(RioCommand.CheckReply,
new[] { (byte)RioStatusType.FullBufferCount, first ? (byte)1 : (byte)2 }));
}
}
return Task.CompletedTask;
}
private async Task ProduceAsync(CancellationToken ct)
{
bool pressSent = false, releaseSent = false;
var analogPayload = new byte[10]; // all axes zero — valid sample
while (!ct.IsCancellationRequested)
{
await Task.Delay(50, ct).ConfigureAwait(false);
double t = _clock.Elapsed.TotalSeconds;
bool inGap = t >= 4.0 && t < 6.7;
if (!inGap)
Enqueue(PacketBuilder.Build(RioCommand.AnalogReply, analogPayload));
if (!pressSent && t >= 6.5)
{
pressSent = true;
Enqueue(PacketBuilder.Build(RioCommand.ButtonPressed, new byte[] { 0x05 }));
}
if (!releaseSent && t >= 7.0)
{
releaseSent = true;
Enqueue(PacketBuilder.Build(RioCommand.ButtonReleased, new byte[] { 0x05 }));
}
}
}
private void Enqueue(byte[] packet)
{
_rx.Enqueue(packet);
_rxReady.Release();
}
public void Dispose()
{
_cts.Cancel();
_rxReady.Release(); // wake a pending read so the loop can wind down
_cts.Dispose();
}
}