A failed builtin's err replaces its msg, and (xN) is a running total

A builtin failing a ctl write logged its Verbose announcement, its words as
a msg, and the write's err, so the same failure again never repeated the
newest record and never collapsed. Its err alone is logged now (the msg is
still shown and kept in +Messages). A repeat of a record a follower has
read is a new line with the running total, (xN) being N in all. fs.md
states both rules.

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

5 files changed, 71 insertions, 29 deletions

diff --git a/docs/fs.md b/docs/fs.md
index 428cc84c..5836215f 100644
--- a/docs/fs.md
+++ b/docs/fs.md
@@ -625,18 +625,22 @@ mapping the serial it had to the one it has now, and `restoredcol <old>
 for every line the editor says (with `verbose` on, that includes each
 builtin announcing itself as it runs, on purpose: the log says which ran --
 unless the builtin then says something of its own that starts with its
-name, `Kill: nothing running`, which takes the announcement's place; a line
-said again word for word before any follower read it is that line counted,
-`msg 3 Undo: nothing to undo (x40)`, as `err` is; its serial is the pane it ran at, `-` when the keyboard was on a
+name, `Kill: nothing running`, which takes the announcement's place; a
+builtin that fails a ctl write is logged by that write's `err` alone, no
+announcement and no `msg`, so the same failure again is the same record
+again; a line said again word for word is counted, `msg 3 Undo: nothing to
+undo (x40)`, as `err` is (below); its serial is the pane it ran at, `-` when the keyboard was on a
 column or workspace tag, or the line came to the root's ctl, `/tagexec` or
 a column's ctl or exec), and `err <serial|->
 <file>: <why>` for every write or truncation the tree refused or that
 failed -- through a mount a shell sees only the errno its kernel mapped the
 reply to, usually `Invalid argument`, and this is the reason (`err 3 addr:
-no match for regexp`). The same err again, before any follower has read
-the first, is that record counted (`err 3 addr: no match for regexp (x4)`),
-so a client retrying a failing write does not push the rest out of the
-ring; a follower that read it gets each repeat. Through a kernel mount a client sees only an errno, which 9ns reads from the
+no match for regexp`). A record said again word for word, straight after
+itself, is counted rather than repeated (`err 3 addr: no match for regexp
+(x4)`: four in all, counting the first), so a client retrying a failing
+write does not push the rest out of the ring. A record a follower has
+already read is never rewritten: the next repeat is a line of its own
+carrying the running total, `(x5)`, and counting goes on from there. Through a kernel mount a client sees only an errno, which 9ns reads from the
 error's words (cloud9's 9ns/src/nine.zig, `enameToErrno`): a malformed write
 -- an unknown or ill-formed control message, `bad address syntax`, `bad
 regular expression` -- is EINVAL; a lock another open holds, EBUSY; a pane
diff --git a/src/Messages.zig b/src/Messages.zig
index daf195bb..7970908e 100644
--- a/src/Messages.zig
+++ b/src/Messages.zig
@@ -412,9 +412,8 @@ fn logMessage(p: *Pardes, id: usize, text: []const u8) void {
     if (text.len == 0) return;
     const serial: u32 = if (p.fs.session_write) 0 else if (id < MAX_PANES) if (p.panes[id]) |pane| pane.serial else 0 else 0;
     const kept = text[0..@min(text.len, LoggedMessage.cap)];
-    // /log hears every one: a client that retried and failed the same way
-    // is waiting on that second line. Only the +Messages view collapses.
-    ctlfs.events.noteMessage(p, serial, kept);
+    // /log hears every one (a failure of a ctl write as its err record).
+    if (!p.fs.unlogged) ctlfs.events.noteMessage(p, serial, kept);
     if (p.messages.len > 0) {
         const last = &p.messages.log[(p.messages.head + limits.message_log - 1) % limits.message_log];
         if (last.serial == serial and
@@ -498,6 +497,16 @@ pub fn reportFailure(p: *Pardes, id: usize, text: []const u8) void {
         }
         p.fs.failure_len = @intCast(n);
     }
+    // The write fails with it, and its err record says it: no msg for it,
+    // and no Verbose announcement before that, so the same failure again is
+    // the same record again, counted (events.pushCounting).
+    if (p.fs.no_prompt) {
+        const serial: u32 = if (p.fs.session_write) 0 else if (id < MAX_PANES) if (p.panes[id]) |pane| pane.serial else 0 else 0;
+        ctlfs.events.dropAnnouncement(p, serial, text);
+        p.fs.unlogged = true;
+        defer p.fs.unlogged = false;
+        return setMessage(p, id, text);
+    }
     setMessage(p, id, text);
 }
 
diff --git a/src/fs.zig b/src/fs.zig
index 8be728a6..2c739115 100644
--- a/src/fs.zig
+++ b/src/fs.zig
@@ -1271,6 +1271,9 @@ pub const Namespace = struct {
     /// The root ctl is running a session builtin: its messages are the
     /// session's, logged `msg -`, though shown on the active pane.
     session_write: bool = false,
+    /// A ctl write's failure is being said: its err record logs it, so
+    /// no msg does (Messages.reportFailure).
+    unlogged: bool = false,
     refused: bool = false,
     failure: [256]u8 = undefined,
     failure_len: u16 = 0,
diff --git a/src/ninep/ctl.zig b/src/ninep/ctl.zig
index 76f09084..d1bb5907 100644
--- a/src/ninep/ctl.zig
+++ b/src/ninep/ctl.zig
@@ -1406,3 +1406,18 @@ test "Shell refuses a path that is no executable, and bare it goes back to the d
     var want: [300]u8 = undefined;
     try testing.expect(std.mem.indexOf(u8, rd(p, root_ctl, 0, 8192).bytes, try std.fmt.bufPrint(&want, "Shell {s}\n", .{config.defaultShell()})) != null);
 }
+
+test "a builtin that fails a ctl write logs only its err, so the same failure again is counted" {
+    const p = try withFile(testing.allocator, "x\n");
+    defer p.deinit();
+    p.update(.tick); // the pane's `new` is logged first
+    while (p.nextEffect()) |_| {}
+    const ctl_node = @intFromEnum(tree.TopFile.ctl);
+    for (0..3) |_| try testing.expectEqual(Status.err, wr(p, ctl_node, "Kill zzz\n").reply.status);
+    const log = @intFromEnum(tree.TopFile.log);
+    const h = call(p, .{ .tag = 1, .op = .open, .node = log }).reply.handle;
+    const text = call(p, .{ .tag = 2, .op = .read, .node = log, .handle = h, .size = 1 << 16 }).bytes;
+    try testing.expect(std.mem.endsWith(u8, text, "err - ctl: Kill: no running command has that first word \"Kill zzz\" (x3)\n"));
+    try testing.expect(std.mem.indexOf(u8, text, "msg - Kill") == null);
+    _ = call(p, .{ .tag = 3, .op = .release, .node = log, .handle = h });
+}
diff --git a/src/ninep/events.zig b/src/ninep/events.zig
index c54d8454..e0e66800 100644
--- a/src/ninep/events.zig
+++ b/src/ninep/events.zig
@@ -154,16 +154,7 @@ pub fn noteMessage(p: *Pardes, serial: u32, text: []const u8) void {
     // A builtin's own word for what it did stands in for its Verbose
     // announcement just before (`Undo` then `Undo: nothing to undo`), so
     // that 1000 Undos with nothing left are one line, counted, as err's are.
-    if (newest(p)) |last| if (!followerRead(p, last.seq) and std.mem.startsWith(u8, last.text, "msg ")) {
-        const rest = last.text["msg ".len..];
-        const sp = std.mem.indexOfScalar(u8, rest, ' ') orelse rest.len;
-        const word = rest[@min(sp + 1, rest.len)..];
-        var who: [16]u8 = undefined;
-        const mine = if (serial == 0) "-" else std.fmt.bufPrint(&who, "{d}", .{serial}) catch "";
-        if (std.mem.eql(u8, rest[0..sp], mine) and word.len > 0 and std.mem.indexOfScalar(u8, word, ' ') == null and
-            text.len > word.len and std.mem.startsWith(u8, text, word) and text[word.len] == ':')
-            p.fs.log.buf.shrinkRetainingCapacity(last.at);
-    };
+    dropAnnouncement(p, serial, text);
     pushCounting(p, (if (serial == 0)
         std.fmt.bufPrint(&buf, "msg - {s}\n", .{text})
     else
@@ -218,8 +209,27 @@ pub fn noteError(p: *Pardes, req: Req, reply: Reply) void {
     pushCounting(p, record);
 }
 
+/// Drops the newest record when it is the Verbose announcement (`msg
+/// <serial> <Word>`) of the builtin whose words `text` are (`Word: ...`):
+/// what the builtin said, or the err its failure logs, takes its place.
+/// Not one a follower has read.
+pub fn dropAnnouncement(p: *Pardes, serial: u32, text: []const u8) void {
+    const last = newest(p) orelse return;
+    if (followerRead(p, last.seq) or !std.mem.startsWith(u8, last.text, "msg ")) return;
+    const rest = last.text["msg ".len..];
+    const sp = std.mem.indexOfScalar(u8, rest, ' ') orelse rest.len;
+    const word = rest[@min(sp + 1, rest.len)..];
+    var who: [16]u8 = undefined;
+    const mine = if (serial == 0) "-" else std.fmt.bufPrint(&who, "{d}", .{serial}) catch "";
+    if (std.mem.eql(u8, rest[0..sp], mine) and word.len > 0 and std.mem.indexOfScalar(u8, word, ' ') == null and
+        text.len > word.len and std.mem.startsWith(u8, text, word) and text[word.len] == ':')
+        p.fs.log.buf.shrinkRetainingCapacity(last.at);
+}
+
 /// Pushes `record`, or, when it repeats the newest record word for word,
-/// counts that one instead: `<record> (x2)`.
+/// counts that one instead: `<record> (x2)`, the count being every time it
+/// was said. One a follower has already read is not rewritten: the repeat
+/// is a new line carrying the running count, `(x3)`.
 fn pushCounting(p: *Pardes, record: []u8) void {
     // A client retrying a write that fails the same way would fill the ring
     // with one line, so a repeat of the newest record is that record counted,
@@ -234,10 +244,10 @@ fn pushCounting(p: *Pardes, record: []u8) void {
             said = said[0..x];
         } else |_| {}
     };
-    if (!std.mem.eql(u8, said, record[0 .. record.len - 1]) or followerRead(p, last.seq)) return pushLog(p, record);
+    if (!std.mem.eql(u8, said, record[0 .. record.len - 1])) return pushLog(p, record);
     var counted: [pardes.Messages.LoggedMessage.cap + 64]u8 = undefined;
     const again = std.fmt.bufPrint(&counted, "{s} (x{d})\n", .{ said, times +| 1 }) catch return;
-    p.fs.log.buf.shrinkRetainingCapacity(last.at);
+    if (!followerRead(p, last.seq)) p.fs.log.buf.shrinkRetainingCapacity(last.at);
     pushLog(p, again);
 }
 
@@ -900,7 +910,7 @@ test "the log records whether or not anyone reads, and an open that follows wait
     }
     try testing.expectEqualStrings(try std.fmt.bufPrint(&expected, "msg {d} same failure\n", .{said_by}), pieced[0..got]);
     p.setMessage(0, "same failure");
-    try testing.expectEqualStrings(try std.fmt.bufPrint(&expected, "msg {d} same failure\n", .{said_by}), rdf.next(p, log, fh, frozen).bytes);
+    try testing.expectEqualStrings(try std.fmt.bufPrint(&expected, "msg {d} same failure (x2)\n", .{said_by}), rdf.next(p, log, fh, frozen).bytes);
 
     // A follower the ring outran hears how much it missed, then carries on.
     var filler: [200]u8 = @splat('x');
@@ -951,19 +961,20 @@ test "a refused or failed write is an err record in the log, saying which file a
     // A write that succeeds says nothing.
     _ = wr(p, Node.of(serial, .addr), "#0");
     try testing.expectEqual(Status.again, call(p, .{ .tag = 5, .op = .read, .node = log, .handle = f, .off = frozen, .size = 4096 }).reply.status);
-    // A follower that has read an err waits on its repeat: a line of its own.
+    // A follower that has read an err waits on its repeat: a line of its
+    // own, with the running count.
     _ = wr(p, Node.of(serial, .addr), "/nowhere/");
     try testing.expectEqualStrings(try std.fmt.bufPrint(&want, "err {d} addr: no match for regexp\n", .{serial}), next.record(p, f, frozen));
     _ = wr(p, Node.of(serial, .addr), "/nowhere/");
-    try testing.expectEqualStrings(try std.fmt.bufPrint(&want, "err {d} addr: no match for regexp\n", .{serial}), next.record(p, f, frozen));
+    try testing.expectEqualStrings(try std.fmt.bufPrint(&want, "err {d} addr: no match for regexp (x2)\n", .{serial}), next.record(p, f, frozen));
     _ = call(p, .{ .tag = 6, .op = .release, .node = log, .handle = f });
 
-    // With the follower gone, repeats are the newest record counted: the
-    // one it read, and three more.
+    // With the follower gone, repeats are the newest record counted on:
+    // its two, and three more.
     for (0..3) |_| _ = wr(p, Node.of(serial, .addr), "/elsewhere/");
     const g = call(p, .{ .tag = 7, .op = .open, .node = log }).reply.handle;
     const text = call(p, .{ .tag = 8, .op = .read, .node = log, .handle = g, .size = 1 << 16 }).bytes;
-    try testing.expect(std.mem.endsWith(u8, text, try std.fmt.bufPrint(&want, "regexp\nerr {d} addr: no match for regexp (x4)\n", .{serial})));
+    try testing.expect(std.mem.endsWith(u8, text, try std.fmt.bufPrint(&want, "regexp\nerr {d} addr: no match for regexp (x5)\n", .{serial})));
     _ = call(p, .{ .tag = 9, .op = .release, .node = log, .handle = g });
 }