Record /log whether or not anyone reads it, with the editor's messages in it

/log is now one ring (64 KiB, 4 KiB on the board) that records new, del,
rename and save, and a msg line for everything the editor says. An open
freezes it, so cat log shows what happened lately and ends; writing
follow to that same open makes reads past it wait for newer records, and
a follower the ring outran reads lost N first.

The message log keeps the pane's serial, not its reusable slot.

A test now fails when the tree serves a file /README never mentions; it
caught pty/status, now documented along with typing through pty/data.

Co-Authored-By: Claude Opus 5.5 <[email protected]>

1 files changed, 163 insertions, 27 deletions

diff --git a/src/ninep/events.zig b/src/ninep/events.zig
index d94fb54d..472a114f 100644
--- a/src/ninep/events.zig
+++ b/src/ninep/events.zig
@@ -25,6 +25,10 @@ pub fn now() u32 {
 pub const Queue = struct {
     buf: std.ArrayList(u8) = .empty,
     head: usize = 0,
+    cap: usize = queue_cap,
+    /// Records pushed out of the front to make room: the sequence number of
+    /// the oldest one still held.
+    dropped: u64 = 0,
 
     pub fn deinit(q: *Queue, gpa: std.mem.Allocator) void {
         q.buf.deinit(gpa);
@@ -33,9 +37,10 @@ pub const Queue = struct {
 
     pub fn push(q: *Queue, gpa: std.mem.Allocator, record: []const u8) void {
         if (record.len > std.math.maxInt(u32)) return;
-        while (q.buf.items.len - q.head + record.len + 4 > queue_cap) {
+        while (q.buf.items.len - q.head + record.len + 4 > q.cap) {
             if (q.peek() == null) return;
             q.pop();
+            q.dropped += 1;
         }
         q.compact();
         var head: [4]u8 = undefined;
@@ -136,15 +141,114 @@ pub fn announce(p: *Pardes) void {
     }
 }
 
-/// Records `<kind> <serial> <name>` while a reader holds /log open.
+/// Records `<kind> <serial> <name>`.
 pub fn noteLog(p: *Pardes, kind: LogKind, pane: *Pane) void {
-    if (p.fs.log_readers == 0) return;
     var buf: [4096 + 64]u8 = undefined;
     const name = pane_files.nameOf(pane);
-    const record = std.fmt.bufPrint(&buf, "{s} {d} {s}\n", .{ @tagName(kind), pane.serial, name[0..@min(name.len, 4096)] }) catch return;
+    pushLog(p, std.fmt.bufPrint(&buf, "{s} {d} {s}\n", .{ @tagName(kind), pane.serial, name[0..@min(name.len, 4096)] }) catch return);
+}
+
+/// Records `msg <serial> <text>` for what the editor said, `-` for no pane.
+pub fn noteMessage(p: *Pardes, serial: u32, text: []const u8) void {
+    var buf: [pardes.LoggedMessage.cap + 32]u8 = undefined;
+    pushLog(p, (if (serial == 0)
+        std.fmt.bufPrint(&buf, "msg - {s}\n", .{text})
+    else
+        std.fmt.bufPrint(&buf, "msg {d} {s}\n", .{ serial, text })) catch return);
+}
+
+/// The log is one ring that records whether or not anyone reads it. A record
+/// is one line: a newline in a message or a name would read as two records.
+fn pushLog(p: *Pardes, record: []u8) void {
+    for (record[0 .. record.len - 1]) |*c| if (c.* < ' ') {
+        c.* = ' ';
+    };
     p.fs.log.push(p.gpa, record);
 }
 
+/// An open freezes the ring's text, so `cat log` answers what happened lately
+/// and ends; `next` is where a follower picks up after it.
+pub fn openLog(p: *Pardes, req: Req) Reply {
+    for (&p.fs.snapshots, 0..) |*slot, i| {
+        if (slot.node != 0) continue;
+        var text: std.ArrayList(u8) = .empty;
+        var at = p.fs.log.head;
+        const items = p.fs.log.buf.items;
+        var n: u64 = 0;
+        while (at + 4 <= items.len) : (n += 1) {
+            const len = std.mem.readInt(u32, items[at..][0..4], .little);
+            text.appendSlice(p.gpa, items[at + 4 ..][0..len]) catch {
+                text.deinit(p.gpa);
+                return Reply.fail(req.tag, E.NOMEM);
+            };
+            at += 4 + len;
+        }
+        const bytes = text.toOwnedSlice(p.gpa) catch return Reply.fail(req.tag, E.NOMEM);
+        slot.* = .{ .node = req.node, .bytes = bytes, .next = p.fs.log.dropped + n };
+        return .{ .tag = req.tag, .handle = @intCast(i + 1) };
+    }
+    return Reply.fail(req.tag, E.NFILE);
+}
+
+/// Past the frozen text, a following open reads newer records one per read,
+/// parked until one arrives; one that fell behind the ring hears `lost N`.
+pub fn readLog(p: *Pardes, req: Req) Reply {
+    if (req.handle == 0 or req.handle > p.fs.snapshots.len) return Reply.fail(req.tag, E.INVAL);
+    const slot = &p.fs.snapshots[req.handle - 1];
+    if (slot.node != req.node) return Reply.fail(req.tag, E.INVAL);
+    const frozen = slot.bytes orelse &.{};
+    const out = p.fs.stage(p.gpa);
+    if (!slot.follow or req.off < frozen.len) {
+        const off = @min(req.off, frozen.len);
+        const len = @min(frozen.len - off, req.size);
+        out.appendSlice(p.gpa, frozen[off..][0..len]) catch return Reply.fail(req.tag, E.NOMEM);
+        return .{ .tag = req.tag, .payload = .{ .staged = @intCast(len) } };
+    }
+    const q = &p.fs.log;
+    if (slot.next < q.dropped) {
+        out.print(p.gpa, "lost {d}\n", .{q.dropped - slot.next}) catch return Reply.fail(req.tag, E.NOMEM);
+        slot.next = q.dropped;
+        return .{ .tag = req.tag, .payload = .{ .staged = @intCast(out.items.len) } };
+    }
+    // ponytail: walks the ring from its oldest record; it holds at most log_bytes.
+    var at = q.head;
+    var seq = q.dropped;
+    while (at + 4 <= q.buf.items.len) : (seq += 1) {
+        const len = std.mem.readInt(u32, q.buf.items[at..][0..4], .little);
+        if (seq == slot.next) {
+            if (req.size < len) return Reply.fail(req.tag, E.INVAL);
+            out.appendSlice(p.gpa, q.buf.items[at + 4 ..][0..len]) catch return Reply.fail(req.tag, E.NOMEM);
+            slot.next += 1;
+            return .{ .tag = req.tag, .payload = .{ .staged = @intCast(len) } };
+        }
+        at += 4 + len;
+    }
+    return .{ .tag = req.tag, .status = .again };
+}
+
+/// `follow`, written to an open of the log, makes that open wait for newer
+/// records instead of ending; closing it is the way back.
+pub fn writeLog(p: *Pardes, req: Req) Reply {
+    if (req.handle == 0 or req.handle > p.fs.snapshots.len) return Reply.fail(req.tag, E.INVAL);
+    const slot = &p.fs.snapshots[req.handle - 1];
+    if (slot.node != req.node) return Reply.fail(req.tag, E.INVAL);
+    if (!std.mem.eql(u8, std.mem.trim(u8, req.data, " \t\r\n"), "follow")) return Reply.fail(req.tag, E.INVAL);
+    slot.follow = true;
+    return .{ .tag = req.tag, .written = @intCast(req.data.len) };
+}
+
+/// The length a stat reports: the text an open would freeze now.
+pub fn logLen(q: *const Queue) u64 {
+    var n: u64 = 0;
+    var at = q.head;
+    while (at + 4 <= q.buf.items.len) {
+        const len = std.mem.readInt(u32, q.buf.items[at..][0..4], .little);
+        n += len;
+        at += 4 + len;
+    }
+    return n;
+}
+
 // ---- per-pane event records ----
 
 pub const max_record_text = 256;
@@ -517,49 +621,81 @@ test "writing an event record back performs the action it names" {
     try testing.expectEqual(@as(u8, 'F'), p.fs.origin);
 }
 
-test "the log parks until a pane is created, renamed, saved or deleted" {
+test "the log records whether or not anyone reads, and an open that follows waits" {
     const gpa = testing.allocator;
     const p = try withFile(gpa, "logged\n");
     defer p.deinit();
     const log = @intFromEnum(tree.TopFile.log);
-    _ = try th.newPane(p);
-    try testing.expect(p.fs.log.empty());
+    var expected: [4200]u8 = undefined;
+
+    // Nobody holds /log open, and the pane is recorded anyway.
+    const early = try th.newPane(p);
+    const early_line = try std.fmt.bufPrint(&expected, "new {d} {s}\n", .{ early, pane_files.nameOf(p.panes[p.paneBySerial(early).?].?) });
+    const early_owned = try gpa.dupe(u8, early_line);
+    defer gpa.free(early_owned);
 
-    const opened = call(p, .{ .tag = 1, .op = .open, .node = log });
-    try testing.expectEqual(Status.ok, opened.reply.status);
-    try testing.expectEqual(@as(u16, 1), p.fs.log_readers);
-    try testing.expectEqual(Status.again, rd(p, log, 0, 4096).reply.status);
+    // A plain open answers what happened so far, and ends: `cat log` never hangs.
+    const plain = call(p, .{ .tag = 1, .op = .open, .node = log });
+    try testing.expectEqual(Status.ok, plain.reply.status);
+    const first = call(p, .{ .tag = 2, .op = .read, .node = log, .handle = plain.reply.handle, .size = 8192 });
+    try testing.expect(std.mem.endsWith(u8, first.bytes, early_owned));
+    const past = call(p, .{ .tag = 3, .op = .read, .node = log, .handle = plain.reply.handle, .off = first.bytes.len, .size = 8192 });
+    try testing.expectEqual(Status.ok, past.reply.status);
+    try testing.expectEqual(@as(usize, 0), past.bytes.len);
+    _ = call(p, .{ .tag = 4, .op = .release, .node = log, .handle = plain.reply.handle });
+
+    // `follow` on an open makes it wait past what it froze, one record a read.
+    const f = call(p, .{ .tag = 5, .op = .open, .node = log });
+    const fh = f.reply.handle;
+    const frozen = call(p, .{ .tag = 6, .op = .read, .node = log, .handle = fh, .size = 8192 }).bytes.len;
+    try testing.expectEqual(Status.err, call(p, .{ .tag = 7, .op = .write, .node = log, .handle = fh, .data = "tail\n" }).reply.status);
+    try testing.expectEqual(Status.ok, call(p, .{ .tag = 8, .op = .write, .node = log, .handle = fh, .data = "follow\n" }).reply.status);
+    const rdf = struct {
+        fn next(pp: *Pardes, node: u64, h: u32, off: u64) th.Answer {
+            return call(pp, .{ .tag = 9, .op = .read, .node = node, .handle = h, .off = off, .size = 8192 });
+        }
+    };
+    try testing.expectEqual(Status.again, rdf.next(p, log, fh, frozen).reply.status);
 
     const serial = try th.newPane(p);
     const id = p.paneBySerial(serial).?;
-    var expected: [4200]u8 = undefined;
     try testing.expectEqualStrings(
         try std.fmt.bufPrint(&expected, "new {d} {s}\n", .{ serial, pane_files.nameOf(p.panes[id].?) }),
-        rd(p, log, 0, 4096).bytes,
+        rdf.next(p, log, fh, frozen).bytes,
     );
     try testing.expectEqual(Status.ok, wr(p, Node.of(serial, .name), "/tmp/logged.txt\n").reply.status);
     try testing.expectEqualStrings(
         try std.fmt.bufPrint(&expected, "rename {d} /tmp/logged.txt\n", .{serial}),
-        rd(p, log, 0, 4096).bytes,
+        rdf.next(p, log, fh, frozen).bytes,
     );
-    const saving = wr(p, Node.of(serial, .exec), "Save\n");
-    try testing.expectEqual(Status.ok, saving.reply.status);
-    try testing.expect(saving.saved);
-    p.perform(.{ .save_file = .{ .pane = @intCast(id) } });
+    // What the editor says is in the same stream, one line even when the
+    // message had several.
+    p.setMessage(id, "save: two\nlines");
     try testing.expectEqualStrings(
-        try std.fmt.bufPrint(&expected, "save {d} /tmp/logged.txt\n", .{serial}),
-        rd(p, log, 0, 4096).bytes,
+        try std.fmt.bufPrint(&expected, "msg {d} save: two lines\n", .{serial}),
+        rdf.next(p, log, fh, frozen).bytes,
     );
+    // A builtin announces itself on the message row, so the log says which ran.
     try testing.expectEqual(Status.ok, wr(p, Node.of(serial, .exec), "Del\n").reply.status);
     try testing.expectEqualStrings(
+        try std.fmt.bufPrint(&expected, "msg {d} Del\n", .{serial}),
+        rdf.next(p, log, fh, frozen).bytes,
+    );
+    try testing.expectEqualStrings(
         try std.fmt.bufPrint(&expected, "del {d} /tmp/logged.txt\n", .{serial}),
-        rd(p, log, 0, 4096).bytes,
+        rdf.next(p, log, fh, frozen).bytes,
     );
-    try testing.expectEqual(Status.again, rd(p, log, 0, 4096).reply.status);
+    try testing.expectEqual(Status.again, rdf.next(p, log, fh, frozen).reply.status);
 
-    _ = call(p, .{ .tag = 2, .op = .release, .node = log, .handle = opened.reply.handle });
-    try testing.expectEqual(@as(u16, 0), p.fs.log_readers);
-    _ = try th.newPane(p);
-    try testing.expect(p.fs.log.empty());
-    try testing.expectEqual(@as(usize, 0), p.fs.log.buf.capacity);
+    // A follower the ring outran hears how much it missed, then carries on.
+    var filler: [200]u8 = @splat('x');
+    for (0..p.fs.log.cap / filler.len + 8) |i| {
+        _ = std.fmt.bufPrint(&filler, "{d:0>6}", .{i}) catch unreachable; // a repeat would collapse
+        p.setMessage(0, &filler);
+    }
+    const lost = rdf.next(p, log, fh, frozen).bytes;
+    try testing.expect(std.mem.startsWith(u8, lost, "lost "));
+    try testing.expect(std.mem.startsWith(u8, rdf.next(p, log, fh, frozen).bytes, "msg "));
+    _ = call(p, .{ .tag = 10, .op = .release, .node = log, .handle = fh });
+    for (p.fs.snapshots) |slot| try testing.expect(slot.node == 0);
 }