diff options
| -rw-r--r-- | tools/bench_main.zig | 158 | ||||
| -rw-r--r-- | tools/console.zig | 263 |
2 files changed, 408 insertions, 13 deletions
diff --git a/tools/bench_main.zig b/tools/bench_main.zig index fbaea8a..6e453a8 100644 --- a/tools/bench_main.zig +++ b/tools/bench_main.zig @@ -30,6 +30,8 @@ const Mode = enum { editor, /// A named experiment: one controlled variable, many trials, machine-readable. sweep, + /// Behaviour rather than speed: things that were broken on this transport and must stay fixed. + check, }; /// Which variable an experiment varies. One per run, because the point is a controlled variable and @@ -100,6 +102,10 @@ pub fn main(init: std.process.Init.Minimal) void { o.mode = .editor; continue; } + if (eql(a, "--check")) { + o.mode = .check; + continue; + } if (eql(a, "--csv")) { o.csv = true; continue; @@ -258,6 +264,7 @@ fn run(o: Options) !void { .link => try link(&port, o, &r), .editor => try editor(&port, o, &r), .sweep => try sweep(&port, o, &r), + .check => try check(&port, o, &r), } } @@ -400,7 +407,7 @@ fn trials(port: *serial.Port, o: Options, r: *Report, c: Condition) !void { last_bytes = v.bytes; last_settle = v.settle_us; if (o.csv) r.print("{s},{s},{d},{d},{d},{s},{d},{d},{d},{d}\n", .{ - o.label, @tagName(o.which), c.cols, c.rows, c.length, c.op, + o.label, @tagName(o.which), c.cols, c.rows, c.length, c.op, rep, pos(v.rtt_us), pos(v.settle_us), v.bytes, }); } else lost += 1; @@ -413,7 +420,7 @@ fn trials(port: *serial.Port, o: Options, r: *Report, c: Condition) !void { } std.mem.sort(i64, rtts[0..got], {}, std.sort.asc(i64)); r.print(" {s:<12} {d:>3}x{d:<3} len {d:>4} median {d:>7} us spread {d:>6} us {d:>5} B\n", .{ - c.op, c.cols, c.rows, c.length, + c.op, c.cols, c.rows, c.length, pos(rtts[got / 2]), pos(rtts[got - 1] - rtts[0]), last_bytes, }); r.flush(); @@ -486,7 +493,7 @@ fn link(port: *serial.Port, o: Options, r: *Report) !void { const up_ok = up_stat.bytes == sent and up_stat.crc == want_crc; r.print(" uplink host -> board\n", .{}); r.print(" {d} B in {d} us = {d} B/s ({d}% of wire)\n", .{ - sent, up_us, @divTrunc(@as(i64, sent) * 1_000_000, up_us), + sent, up_us, @divTrunc(@as(i64, sent) * 1_000_000, up_us), @divTrunc(@as(i64, sent) * 1_000_000 * 100, up_us * @as(i64, port.capacity())), }); if (up_ok) { @@ -529,7 +536,7 @@ fn link(port: *serial.Port, o: Options, r: *Report) !void { r.print("\n downlink board -> host\n", .{}); r.print(" {d} B in {d} us = {d} B/s ({d}% of wire)\n", .{ - got, down_us, @divTrunc(@as(i64, got) * 1_000_000, down_us), + got, down_us, @divTrunc(@as(i64, got) * 1_000_000, down_us), @divTrunc(@as(i64, got) * 1_000_000 * 100, down_us * @as(i64, port.capacity())), }); if (down_stat) |s| { @@ -618,8 +625,8 @@ fn editor(port: *serial.Port, o: Options, r: *Report) !void { const pass = s.lost == 0 and s.median_us >= 0 and s.median_us <= ceiling; if (pass) best = rate; r.print(" {d:>7} {d:>9} us {d:>9} us {d:>7} {d:>4}% {d:>5} {s}\n", .{ - pos(rate), pos(s.median_us), pos(s.median_settle_us), - s.median_bytes, s.wire_percent, s.lost, + pos(rate), pos(s.median_us), pos(s.median_settle_us), + s.median_bytes, s.wire_percent, s.lost, if (s.lost > 0) "LOST INPUT" else if (pass) "ok" else "behind", }); r.flush(); @@ -704,7 +711,7 @@ fn usage() void { out( \\p4-bench - measure the board's serial link, verified with a checksum \\ - \\ p4-bench [--link | --editor] [--port <path>] [--baud <rate>] + \\ p4-bench [--link | --editor | --check] [--port <path>] [--baud <rate>] \\ [--bulk <bytes>] [--samples <n>] [--no-reset] \\ \\ --link (default) bulk throughput each way plus round-trip latency, every byte @@ -735,3 +742,140 @@ fn fatal(msg: []const u8) noreturn { fn eql(a: []const u8, b: []const u8) bool { return std.mem.eql(u8, a, b); } + +// -------------------------------------------------------------------------------- behaviour checks +// +// Three things were broken on this transport in ways no latency number could show, and each is +// checked here because each was found by hand and would otherwise be found by hand again. + +/// Read until the wire has been quiet for `quiet_ms`, or `cap_ms` has passed, and return what +/// arrived. "Quiet" rather than "for a fixed time" because a burst of six hundred characters is many +/// frames and an unknown number of milliseconds; a reply read before those have finished is the +/// previous action's output, which is how the first version of these checks fooled itself. +fn soak(port: *serial.Port, buf: []u8, quiet_ms: i64, cap_ms: i64) []u8 { + var n: usize = 0; + const cap = port.nowMs() + cap_ms; + var last = port.nowMs(); + while (port.nowMs() < cap and n < buf.len) { + const got = port.readTimeout(buf[n..], 20) catch 0; + if (got > 0) { + n += got; + last = port.nowMs(); + } else if (port.nowMs() - last >= quiet_ms) break; + } + return buf[0..n]; +} + +/// The last absolute cursor position in `bytes`, as 1-based (row, col). +/// +/// The board's frames end by positioning the cursor and then padding with repeats of that same +/// sequence, so the final CUP in a reply is where the editor put the cursor. That makes the cursor +/// an observable: it is how these checks see what the editor did without reconstructing a screen. +const Cursor = struct { row: u32, col: u32 }; + +fn lastCup(bytes: []const u8) ?Cursor { + var found: ?Cursor = null; + var i: usize = 0; + while (i + 3 < bytes.len) : (i += 1) { + if (bytes[i] != 0x1b or bytes[i + 1] != '[') continue; + var j = i + 2; + var row: u32 = 0; + var col: u32 = 0; + var digits: usize = 0; + while (j < bytes.len and bytes[j] >= '0' and bytes[j] <= '9') : (j += 1) { + row = row * 10 + (bytes[j] - '0'); + digits += 1; + } + if (digits == 0 or j >= bytes.len or bytes[j] != ';') continue; + j += 1; + digits = 0; + while (j < bytes.len and bytes[j] >= '0' and bytes[j] <= '9') : (j += 1) { + col = col * 10 + (bytes[j] - '0'); + digits += 1; + } + if (digits == 0 or j >= bytes.len or bytes[j] != 'H') continue; + found = .{ .row = row, .col = col }; + i = j; + } + return found; +} + +fn check(port: *serial.Port, o: Options, r: *Report) !void { + try ready(port, o); + var buf: [8192]u8 = undefined; + var failures: u32 = 0; + + // 1. A LONE ESCAPE IS STILL THE ESCAPE KEY. + // + // The shell holds a solitary ESC for a few milliseconds because on this wire the first byte of + // every escape sequence arrives alone. The hold must expire, or Escape stops working and the + // editor is unusable. Typing `abc`, pressing Escape, then `x` deletes a character in normal + // mode; if Escape had been swallowed, the `x` would be inserted instead and show up on the wire. + try port.write("abc"); + _ = soak(port, &buf, 150, 1500); + try port.write("\x1b"); + _ = soak(port, &buf, 150, 1500); + try port.write("x"); + const after_x = soak(port, &buf, 200, 1500); + const escaped = std.mem.indexOfScalar(u8, after_x, 'x') == null; + r.print(" lone Escape still leaves insert mode {s}\n", .{if (escaped) "ok" else "FAILED"}); + if (!escaped) failures += 1; + + // 2. AN ESCAPE SEQUENCE SPLIT ACROSS READS PARSES AS ONE EVENT. + // + // This is the bug that made the mouse look unimplemented. At 115200 the bytes of a report are + // 87 us apart, so the board reads them one at a time; a parser that resolves a lone ESC turns + // one click into ten key presses, and the `0` among them is "go to column zero" in normal mode, + // which is exactly where the cursor kept landing. + // + // The line has to be long enough to contain the clicked column, or the editor correctly clamps + // to the end of the line and the check measures the clamp instead of the parse. + try port.write("\x1b"); + _ = soak(port, &buf, 150, 1500); + try port.write("dd"); + _ = soak(port, &buf, 200, 2000); + try port.write("i"); + _ = soak(port, &buf, 150, 1500); + try port.write("abcdefghijklmnopqrstuvwxyz0123"); + _ = soak(port, &buf, 250, 3000); + try port.write("\x1b"); + _ = soak(port, &buf, 200, 2000); + + const want_col: u32 = 18; + var report: [16]u8 = undefined; + const click = std.fmt.bufPrint(&report, "\x1b[<0;{d};3M", .{want_col}) catch unreachable; + // NO gap between the bytes. The wire already provides one - 87 us - and anything longer than the + // shell's hold would expire it, which is the check defeating itself rather than exercising the + // fix. One write per byte is what stops them arriving as a single read. + for (click) |b| try port.write(&[_]u8{b}); + _ = soak(port, &buf, 250, 2000); + // The RELEASE is what commits it. A press alone paints the new position and then reverts, because + // a press is the start of a drag and the caret does not move until the gesture ends - so a check + // that reads the cursor after the press alone measures the revert and calls a working click + // broken. This cost an hour. + const up = std.fmt.bufPrint(&report, "\x1b[<0;{d};3m", .{want_col}) catch unreachable; + for (up) |b| try port.write(&[_]u8{b}); + const reply = soak(port, &buf, 250, 2000); + const landed = lastCup(reply); + const at_col = landed != null and landed.?.col == want_col; + if (landed) |at| { + r.print(" a click split byte-by-byte lands at {d} {s} (cursor {d},{d})\n", .{ + want_col, if (at_col) "ok" else "FAILED", at.row, at.col, + }); + } else r.print(" a click split byte-by-byte lands at {d} FAILED (no reply)\n", .{want_col}); + if (!at_col) failures += 1; + + // A BURST IS NOT CHECKED HERE, deliberately. The bug it would cover - input lost while the + // transmitter was full - has a deterministic host test in `src/pardes/input_rescue.zig` that + // loses 67 bytes with the rescue removed and needs no board at all. Every hardware oracle for it + // that was tried here was worse than that: the cursor stops being reported past 160 characters + // because the wrapped line outgrows the viewport, and a screen reconstruction cannot be rebuilt + // mid-session because the board only ever sends what CHANGED. A check that cannot fail honestly + // is worse than no check, so this file keeps only the two things hardware alone can answer. + + r.print("\n {d} failure(s)\n", .{failures}); + // Flushed here, not by the caller: these lines ARE the result, and returning an error would + // otherwise discard the very output that says which check failed. + r.flush(); + if (failures > 0) return error.CheckFailed; +} diff --git a/tools/console.zig b/tools/console.zig index 2e924e3..4b13513 100644 --- a/tools/console.zig +++ b/tools/console.zig @@ -98,6 +98,156 @@ const ModeWatch = struct { } }; +/// How long a motion report may be held while a newer one might replace it. +/// +/// A report is ~12 bytes, so 40 ms caps drag traffic at 25 reports a second - about 300 B/s, or 2.6% +/// of a 115200 line. Below roughly 30 ms the thinning stops paying for itself on this link; far above +/// it a drag visibly lags the pointer. +const coalesce_ms: i64 = 40; + +/// Thins out mouse reports on their way to the board. +/// +/// The board asks for DEC 1002, so the terminal reports presses, releases, and motion WHILE A BUTTON +/// IS HELD. A press is one report; a drag across this grid is one report per cell crossed, each +/// `\x1b[<0;12;5M` at roughly a dozen bytes. A hand can cross forty cells in a tenth of a second, +/// which is ~500 bytes, which is 43 ms of a 115200 line - and every one of those bytes is input the +/// board has to parse while it is trying to paint the result of the previous one. Unthinned, a drag +/// makes the editor unusable for as long as the drag lasts and for a while after. +/// +/// The thinning is NEWEST-WINS, and only for motion. Where the pointer passed through is not +/// information the editor can use - a selection is defined by where the drag started and where it is +/// now - so an intermediate report that is already stale by the time it reaches the wire is pure +/// cost. Presses, releases and wheel events are never held: those are discrete, each one means +/// something different, and dropping one loses a click. +/// +/// A held report is released when the interval expires or when any non-motion byte follows it, so a +/// drag that stops moving still delivers its final position, and a release always arrives after the +/// motion that preceded it. +const MouseFilter = struct { + /// The most recent motion report not yet sent, if any. + held: [max_report]u8 = undefined, + held_len: usize = 0, + /// A report arriving in pieces across reads. SGR reports are short, but a read boundary can + /// still land inside one, and a half-parsed report must not be forwarded as loose bytes. + partial: [max_report]u8 = undefined, + partial_len: usize = 0, + dropped: usize = 0, + + /// Longest `\x1b[<b;x;yM` this will accept. Generous for a 5-digit coordinate each way; anything + /// longer is not a mouse report and is passed through as ordinary bytes. + const max_report = 24; + + /// Split `in` into bytes to send now and, possibly, one motion report to hold. + /// + /// Returns the number of bytes written to `out`, which is never more than `in.len` plus whatever + /// a previously held report contributes. + fn feed(m: *MouseFilter, in: []const u8, out: []u8) usize { + var n: usize = 0; + var i: usize = 0; + while (i < in.len) { + // Continue a report that straddled the previous read. + if (m.partial_len > 0) { + m.partial[m.partial_len] = in[i]; + m.partial_len += 1; + i += 1; + switch (classify(m.partial[0..m.partial_len])) { + .incomplete => if (m.partial_len < max_report) continue else { + // Too long to be a report: it was never one, so pass it on untouched. + n += m.flushHeld(out[n..]); + @memcpy(out[n..][0..m.partial_len], m.partial[0..m.partial_len]); + n += m.partial_len; + m.partial_len = 0; + continue; + }, + .motion => { + m.hold(m.partial[0..m.partial_len]); + m.partial_len = 0; + continue; + }, + .other => { + n += m.flushHeld(out[n..]); + @memcpy(out[n..][0..m.partial_len], m.partial[0..m.partial_len]); + n += m.partial_len; + m.partial_len = 0; + continue; + }, + } + } + // A report can only start at an ESC. + if (in[i] == 0x1b) { + m.partial[0] = in[i]; + m.partial_len = 1; + i += 1; + continue; + } + // Ordinary byte: it orders after anything held, so the held report goes first. + n += m.flushHeld(out[n..]); + out[n] = in[i]; + n += 1; + i += 1; + } + return n; + } + + fn hold(m: *MouseFilter, report: []const u8) void { + if (m.held_len > 0) m.dropped += 1; + @memcpy(m.held[0..report.len], report); + m.held_len = report.len; + } + + /// Emit the held report, if there is one. Called when ordering requires it and by the caller when + /// the coalescing interval expires. + fn flushHeld(m: *MouseFilter, out: []u8) usize { + if (m.held_len == 0) return 0; + @memcpy(out[0..m.held_len], m.held[0..m.held_len]); + const n = m.held_len; + m.held_len = 0; + return n; + } + + fn pending(m: *const MouseFilter) bool { + return m.held_len > 0; + } + + const Kind = enum { incomplete, motion, other }; + + /// Is `bytes` a complete SGR mouse report, and is it motion? + /// + /// `\x1b[<` then decimal parameters separated by `;` then `M` (press or motion) or `m` (release). + /// Motion is the low two bits of the button field being 3 for a plain move, or bit 5 (32) set for + /// a drag; a wheel report has bit 6 (64) set and is never motion however it is encoded. + fn classify(bytes: []const u8) Kind { + if (bytes.len < 3) { + const prefix = "\x1b[<"; + return if (std.mem.startsWith(u8, prefix, bytes)) .incomplete else .other; + } + if (!std.mem.startsWith(u8, bytes, "\x1b[<")) return .other; + var button: u32 = 0; + var digits: usize = 0; + var i: usize = 3; + while (i < bytes.len) : (i += 1) { + const b = bytes[i]; + if (b >= '0' and b <= '9') { + if (digits == 0) button = button * 10 + (b - '0'); + if (button > 1 << 20) return .other; + continue; + } + if (b == ';') { + digits += 1; + continue; + } + if (b == 'M' or b == 'm') { + if (digits != 2) return .other; + const wheel = button & 64 != 0; + const drag = button & 32 != 0; + return if (!wheel and drag) .motion else .other; + } + return .other; + } + return .incomplete; + } +}; + pub const Options = struct { /// Pulse reset so the application starts from boot with the console already attached. Without /// it, attaching to a board that has been running for a while shows a screen mid-session with @@ -164,8 +314,11 @@ pub fn attach(port_path: []const u8, baud: serial.Baud, opts: Options) !void { sendWinsize(&port, windowSize()); var watch: ModeWatch = .{}; + var mouse: MouseFilter = .{}; + var held_at: ?i64 = null; var from_board: [4096]u8 = undefined; var from_user: [256]u8 = undefined; + var to_board: [512]u8 = undefined; while (true) { if (@as(*volatile bool, &winch_pending).*) { @@ -180,8 +333,14 @@ pub fn attach(port_path: []const u8, baud: serial.Baud, opts: Options) !void { // A bounded wait rather than an infinite one so a SIGWINCH that lands between the check // above and the poll below is still serviced promptly; poll reports the signal itself as // an interrupt, which is handled as "go round again". - const ready = posix.poll(&pfd, 200) catch continue; - if (ready == 0) continue; + // A bounded wait, and shorter while a motion report is being held: the hold has to end on + // time even when the human has stopped moving the mouse and nothing else is arriving. + const wait: i32 = if (held_at) |at| blk: { + const left = coalesce_ms - (std.time.milliTimestamp() - at); + break :blk if (left <= 0) 0 else @intCast(left); + } else 200; + const ready = posix.poll(&pfd, wait) catch continue; + if (ready == 0 and held_at == null) continue; // POLL.IN is not the only thing poll reports, and ignoring the rest is a hot spin, not a // no-op: unplug the CH340 mid-session and the port's revents carries HUP|ERR|NVAL forever. @@ -207,14 +366,33 @@ pub fn attach(port_path: []const u8, baud: serial.Baud, opts: Options) !void { if (pfd[0].revents & posix.POLL.IN != 0) { const n = stdin.readStreaming(io, &.{&from_user}) catch 0; if (n == 0) return; // stdin closed: a pipe ran out, so detach - if (std.mem.indexOfScalar(u8, from_user[0..n], escape_byte)) |cut| { - // Everything before the escape still belongs to the board. - if (cut > 0) port.write(from_user[0..cut]) catch {}; + // The escape byte is looked for in the RAW stream, before any filtering: Ctrl-] has to + // detach whatever else is in flight, including a half-parsed mouse report. + var raw = from_user[0..n]; + const detaching = std.mem.indexOfScalar(u8, raw, escape_byte); + if (detaching) |cut| raw = raw[0..cut]; + const send = mouse.feed(raw, &to_board); + if (send > 0) port.write(to_board[0..send]) catch {}; + if (detaching != null) { + // Anything still held belongs to the board before we go. + const tail = mouse.flushHeld(&to_board); + if (tail > 0) port.write(to_board[0..tail]) catch {}; if (opts.banner) stdout.writeStreamingAll(io, "\r\n[detached]\r\n") catch {}; return; } - port.write(from_user[0..n]) catch {}; } + + // The coalescing window. A held motion report goes out when the interval has elapsed, which + // is what turns a drag into a bounded stream of positions rather than one per cell crossed. + if (mouse.pending()) { + const at = held_at orelse std.time.milliTimestamp(); + held_at = at; + if (std.time.milliTimestamp() - at >= coalesce_ms) { + const send = mouse.flushHeld(&to_board); + if (send > 0) port.write(to_board[0..send]) catch {}; + held_at = null; + } + } else held_at = null; } } @@ -237,3 +415,76 @@ test "ModeWatch ignores unrelated traffic" { var m: ModeWatch = .{}; for ("hello \x1b[?1049h world \x1b[0m") |b| try std.testing.expect(!m.feed(b)); } + +// ------------------------------------------------------------------------------- the mouse filter + +test "MouseFilter passes an ordinary keystroke straight through" { + var m: MouseFilter = .{}; + var out: [64]u8 = undefined; + const n = m.feed("hello", &out); + try std.testing.expectEqualStrings("hello", out[0..n]); + try std.testing.expect(!m.pending()); +} + +test "MouseFilter never holds a press, a release or a wheel" { + var m: MouseFilter = .{}; + var out: [64]u8 = undefined; + // 0 = left press, 0 with 'm' = release, 64/65 = wheel up/down. All discrete: dropping one loses + // a click or a scroll notch, so none of them may be coalesced. + for ([_][]const u8{ "\x1b[<0;10;5M", "\x1b[<0;10;5m", "\x1b[<64;10;5M", "\x1b[<65;10;5M" }) |report| { + const n = m.feed(report, &out); + try std.testing.expectEqualStrings(report, out[0..n]); + try std.testing.expect(!m.pending()); + } +} + +test "MouseFilter keeps only the newest drag position" { + var m: MouseFilter = .{}; + var out: [64]u8 = undefined; + // 32 = motion with the left button held: a drag. Three cells crossed in one read. + const n = m.feed("\x1b[<32;10;5M\x1b[<32;11;5M\x1b[<32;12;5M", &out); + try std.testing.expectEqual(@as(usize, 0), n); // nothing goes out yet + try std.testing.expect(m.pending()); + try std.testing.expectEqual(@as(usize, 2), m.dropped); + const flushed = m.flushHeld(&out); + try std.testing.expectEqualStrings("\x1b[<32;12;5M", out[0..flushed]); +} + +test "MouseFilter releases a held drag before anything that follows it" { + var m: MouseFilter = .{}; + var out: [64]u8 = undefined; + // The release must not overtake the motion that preceded it, or the editor ends a selection at + // the wrong cell. + const n = m.feed("\x1b[<32;10;5M\x1b[<0;12;5m", &out); + try std.testing.expectEqualStrings("\x1b[<32;10;5M\x1b[<0;12;5m", out[0..n]); + try std.testing.expect(!m.pending()); +} + +test "MouseFilter holds a drag across a read boundary" { + var m: MouseFilter = .{}; + var out: [64]u8 = undefined; + // A report split by the read: neither half may reach the board as loose bytes. + try std.testing.expectEqual(@as(usize, 0), m.feed("\x1b[<32;10", &out)); + try std.testing.expectEqual(@as(usize, 0), m.feed(";5M", &out)); + try std.testing.expect(m.pending()); + const flushed = m.flushHeld(&out); + try std.testing.expectEqualStrings("\x1b[<32;10;5M", out[0..flushed]); +} + +test "MouseFilter passes a non-mouse escape sequence through unchanged" { + var m: MouseFilter = .{}; + var out: [64]u8 = undefined; + // An arrow key and an in-band resize report both start with ESC and must survive intact. + const n = m.feed("\x1b[A\x1b[48;12;40;0;0t", &out); + try std.testing.expectEqualStrings("\x1b[A\x1b[48;12;40;0;0t", out[0..n]); + try std.testing.expect(!m.pending()); +} + +test "MouseFilter does not swallow a lone escape" { + var m: MouseFilter = .{}; + var out: [64]u8 = undefined; + // Esc is how you leave insert mode; holding it would be the worst possible bug here. + _ = m.feed("\x1b", &out); + const n = m.feed("x", &out); + try std.testing.expectEqualStrings("\x1bx", out[0..n]); +} |