using System.Diagnostics;
using RioJoy.Core.Mapping;
using RioJoy.Core.Protocol;
using RioJoy.Core.Serial;
namespace RioSerialMonitor;
///
/// 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 >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.
///
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 RunAsync(string[] args)
{
// --- args ------------------------------------------------------------
string port = "COM1";
int seconds = 300;
string label = "unlabeled";
bool lampEcho = true;
double wedgeSec = 2.0;
bool selftest = false;
int baud = 9600;
int pollMs = 55; // legacy cadence; FastRIO can sustain much faster
var positional = new List();
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;
case "--baud" when i + 1 < args.Length && int.TryParse(args[i + 1], out int b):
baud = b; i++; break;
case "--poll" when i + 1 < args.Length && int.TryParse(args[i + 1], out int p) && p > 0:
pollMs = p; 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} @ {baud} 8N1, {seconds}s, chip label '{label}' ==");
Raw($" lamp echo {(lampEcho ? "ON (drives reply/lamp collisions)" : "OFF")}, " +
$"wedge threshold {wedgeSec:F1}s, poll {pollMs}ms, app auto-recovery DISABLED");
Raw($" log: {Path.GetFullPath(logPath)}");
IRioTransport transport;
try
{
transport = selftest ? new SelftestTransport() : new SerialPortTransport(port, baud);
}
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),
AnalogPollInterval = TimeSpan.FromMilliseconds(pollMs),
});
// --- 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();
bool statusCollecting = false;
var statusItems = new List();
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);
// Ctrl+C = "my fingers hurt": end the run NOW but still snapshot the
// counters and print the full summary, instead of dying summary-less
// (and leaving an orphan holding the port, as an interrupted run did).
bool stopRequested = false;
Console.CancelKeyPress += (_, e) =>
{
e.Cancel = true; // we shut down ourselves
stopRequested = true;
};
// --- counters BEFORE ---------------------------------------------------
await Task.Delay(500);
Dictionary 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(">>> Ctrl+C ends the run early and still prints the summary. <<<");
Raw("");
// --- wedge watchdog + progress ticker ----------------------------------
TimeSpan runEnd = sw.Elapsed + TimeSpan.FromSeconds(seconds);
TimeSpan nextProgress = sw.Elapsed + TimeSpan.FromSeconds(30);
while (sw.Elapsed < runEnd)
{
if (stopRequested)
{
seconds = (int)sw.Elapsed.TotalSeconds; // summary reflects reality
Log("operator stop (Ctrl+C) — ending run, snapshotting counters...");
break;
}
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 after = await SnapshotStatusAsync();
// Dispose the transport BEFORE awaiting the link: on a wedged (silent)
// board the receive loop sits in a pending serial read that ignores
// cancellation — closing the port is what unblocks it. Awaiting first
// hangs forever and eats the summary (seen on the baseline chip run).
cts.Cancel();
transport.Dispose();
try { await run; } catch { /* shutdown */ }
// --- summary (fixed layout for diffing runs) ------------------------------
double mins = Math.Max(sw.Elapsed.TotalMinutes, 0.001);
long expectedPolls = (long)(seconds * 1000.0 / pollMs);
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} (command resends NAK/timeout: {link.Retransmits})");
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> SnapshotStatusAsync()
{
// Two attempts: the first request can lose a race with the board's
// post-DTR boot (port open pulses DTR = board reset), or get eaten
// by a reply collision — seen on the 31250 bench run.
for (int attempt = 0; ; attempt++)
{
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();
foreach (CheckStatus item in statusItems)
map[item.Type] = item.Number;
if (map.Count > 0 || attempt == 1)
return map;
}
}
}
static string FormatCounters(Dictionary 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 b, Dictionary 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}=?";
}));
}
}
}