Let a failed remote delivery leave a trace on the host

GraphcodeKit/Sources/Domain/DialLog.swift

@@ -12,8 +12,14 @@ import Foundation
 /// decisions, but they die with the scrollback.
 ///
 /// Bounded before every append: past `maxBytes` the file is trimmed to its last
-/// `keptLines` lines (~5000 lines is roughly 400 KB of these), so a reconnect loop
-/// that waits all night cannot eat a disk.
+/// `keptLines` lines, so a reconnect loop that waits all night cannot eat a disk.
+///
+/// That bound is a *line-count* trim standing in for a byte budget, which only holds
+/// while a line stays under `maxBytes / keptLines` — 209 bytes. A longer one breaks it
+/// permanently: the trim keeps 5000 lines, 5000 long lines are still over `maxBytes`,
+/// so every later append by every loop on the host re-reads and rewrites the whole file
+/// and never gets under. Anything writing a variable-length field here must size it
+/// against that budget rather than pick a number.
 public enum DialLog {
   public static let maxBytes = 1_048_576
   public static let keptLines = 5000
@@ -25,13 +31,48 @@ public enum DialLog {
   /// format, which is fine for the values this codebase passes (session names are
   /// `graphcode-<uuid>`, the rest are literals here) and would not be for user text.
   public static func fragment(session: String, dial: String, event: String) -> String {
+    "{ mkdir -p \"$HOME/.graphcode\"; " + trimFragment
+      + "printf '%s \(session) \(dial) \(event)\\n' \"$(date -u +%Y-%m-%dT%H:%M:%SZ)\" "
+      + ">> \(logExpression); } 2>/dev/null || true"
+  }
+
+  /// The bound, as both fragments run it: trim to the last `keptLines` when the file has
+  /// grown past `maxBytes`.
+  ///
+  /// The scratch file is per-process (`$$`). It used to be a fixed `dials.log.tmp`, which
+  /// is a race every loop on a host shares: two dials trimming at once both redirect into
+  /// the same name and both `mv` it, and the second `mv` publishes a file the first was
+  /// still writing — measured at 40 concurrent fragments, a 5000-line log came out with
+  /// 34 lines, which is the launch history gone. It was survivable only because trimming
+  /// was rare; a per-process name makes each writer's file its own and the `mv` that
+  /// publishes it atomic.
+  private static var trimFragment: String {
     let log = logExpression
-    return "{ mkdir -p \"$HOME/.graphcode\"; "
-      + "gc_dl=$(wc -c < \(log) 2>/dev/null || echo 0); "
+    return "gc_dl=$(wc -c < \(log) 2>/dev/null || echo 0); "
       + "[ \"${gc_dl:-0}\" -gt \(maxBytes) ] "
-      + "&& { tail -n \(keptLines) \(log) > \(log).tmp && mv \(log).tmp \(log); }; "
-      + "printf '%s \(session) \(dial) \(event)\\n' \"$(date -u +%Y-%m-%dT%H:%M:%SZ)\" "
-      + ">> \(log); } 2>/dev/null || true"
+      + "&& { tail -n \(keptLines) \(log) > \(log).$$.tmp "
+      + "&& mv \(log).$$.tmp \(log); }; "
+  }
+
+  /// `fragment`, with the contents of a shell variable appended as a trailing detail —
+  /// for the one caller that has something to say beyond which branch it took: a failed
+  /// delivery, whose whole problem was leaving no trace of *why*.
+  ///
+  /// The value rides as a `printf` **argument** rather than inside the format, unlike
+  /// `session`, `dial` and `event`. Those are literals this codebase controls; this one
+  /// is an error message from a remote python, and a `%s` or a stray backslash in it
+  /// would otherwise reformat the line it is being written to. Callers are responsible
+  /// for flattening newlines out of the variable first — the log is one line per entry,
+  /// and every reader of it splits on them.
+  /// Callers are also responsible for keeping the value inside the per-line budget the
+  /// trim depends on — see `RemoteGraphAccess.errorDetailBytes`, which derives its size
+  /// from `maxBytes / keptLines` for exactly that reason.
+  public static func fragment(
+    session: String, dial: String, event: String, detailVariable: String
+  ) -> String {
+    "{ mkdir -p \"$HOME/.graphcode\"; " + trimFragment
+      + "printf '%s \(session) \(dial) \(event) %s\\n' \"$(date -u +%Y-%m-%dT%H:%M:%SZ)\" "
+      + "\"$\(detailVariable)\" >> \(logExpression); } 2>/dev/null || true"
   }
 
   /// The same line from Swift, for the launches the daemon decides locally rather than

GraphcodeKit/Sources/Sessions/RemoteGraphAccess.swift

@@ -103,9 +103,17 @@ public enum RemoteGraphAccess {
   /// host, or `nil` when there's nothing to send. One `python3 -c` with a base64 JSON
   /// manifest rather than heredocs or scp: a single argument survives every quoting
   /// layer between here and the remote shell, needs no extra ssh round-trip, and
-  /// content can't collide with a delimiter. Neutered with `|| true` because delivery
-  /// must never block the launch it precedes — a session without its briefing is the
-  /// old behaviour, which works.
+  /// content can't collide with a delimiter. Neutered because delivery must never block
+  /// the launch it precedes — a session without its briefing is the old behaviour, which
+  /// works.
+  ///
+  /// **Neutered is not silent.** It used to be: the fragment ended `>/dev/null 2>&1
+  /// || true`, and when `f6b8af41` left the embedded python with an unbalanced `exec(`,
+  /// every delivery raised `SyntaxError` and threw the evidence away. Remote hosts got
+  /// nothing at all for five days and no machine on either end held a word about it.
+  /// Failure is still non-fatal here, but its stderr now reaches the host's own dial log
+  /// as `delivery install failed <reason>`, which is the difference between a five-day
+  /// mystery and a one-line answer.
   ///
   /// `receipt` is a path and content written **after** every manifest entry has landed,
   /// as proof that the whole delivery succeeded.
@@ -165,10 +173,57 @@ public enum RemoteGraphAccess {
       + "len(sys.argv)>2 and open(os.path.expanduser(sys.argv[2]),'w').write(sys.argv[3])"
     var argv = ["python3", "-c", program, json.base64EncodedString()]
     if let receipt { argv += [receipt.path, receipt.content] }
-    return argv.map(RemoteProjectLocation.shellQuoted).joined(separator: " ")
-      + " >/dev/null 2>&1" + (neutered ? " || true" : "")
+    let install = argv.map(RemoteProjectLocation.shellQuoted).joined(separator: " ")
+    // stderr into a variable, stdout to `/dev/null` — `2>&1 >/dev/null` in that order,
+    // so the substitution keeps the diagnosis and drops the noise.
+    return "gc_di_err=$(\(install) 2>&1 >/dev/null); gc_di_rc=$?; "
+      + "if [ \"$gc_di_rc\" -ne 0 ]; then "
+      + "gc_di_err=$(printf '%s' \"$gc_di_err\" | tr -d '\\r' | tr '\\n\\t' '  ' "
+      + "| tail -c \(errorDetailBytes)); "
+      // A byte-wise `tail` lands mid-character sooner or later, and one orphan
+      // continuation byte makes `grep` and `sed` fail on the *whole* log under a UTF-8
+      // locale — every other dial on the host hidden by the line meant to explain one.
+      // `iconv -c` drops the partial character; where it doesn't exist (musl, busybox —
+      // it lives in glibc's libc-bin) the fallback strips high bytes outright, which
+      // costs a non-ASCII path its accents and keeps the log readable, which is the
+      // property that matters.
+      + "gc_di_err=$(printf '%s' \"$gc_di_err\" | iconv -c -f UTF-8 -t UTF-8 2>/dev/null "
+      + "|| printf '%s' \"$gc_di_err\" | LC_ALL=C tr -d '\\200-\\377'); "
+      + "[ -n \"$gc_di_err\" ] || gc_di_err=\"rc=$gc_di_rc\"; "
+      + DialLog.fragment(
+        session: "delivery", dial: "install", event: "failed", detailVariable: "gc_di_err")
+      + "; fi; "
+      + (neutered ? "true" : "[ \"$gc_di_rc\" -eq 0 ]")
   }
 
+  /// How much of a failed delivery's stderr reaches the dial log — the **last** bytes,
+  /// not the first. A python traceback opens with frames and interpreter paths and ends
+  /// with the line that names the fault, so keeping the head throws away the answer:
+  /// measured, `NotADirectoryError` fell outside the first 400 bytes of the very failure
+  /// this was written to explain.
+  ///
+  /// The size is **derived, not chosen**, and `DialLogBoundTests` locks it: `DialLog`
+  /// trims by keeping its last `keptLines` lines, so a line longer than
+  /// `maxBytes / keptLines` breaks its own bound — the trim can never get the file back
+  /// under `maxBytes`, and from then on every append by every loop on the host re-reads
+  /// and rewrites the whole thing. At 400 bytes it did exactly that: 5000 × 445 = 2.2 MB
+  /// against a 1 MB cap. Deriving it means raising `keptLines` can never silently
+  /// reintroduce that, and what is left still carries the part that names the fault.
+  static let errorDetailBytes =
+    DialLog.maxBytes / DialLog.keptLines - dialLineOverhead
+
+  /// The fixed part of a delivery-failure line **as it lands on disk** — timestamp, the
+  /// three literal fields, the spaces between them, and the newline that terminates it.
+  ///
+  /// The terminator is the point. `wc -c`, which is what the trim measures the file
+  /// with, counts it; the first version of this budget did not, so a line computed as
+  /// exactly 209 bytes was 210 on disk and 5000 of them came to 1,050,000 against a
+  /// 1,048,576 cap — the same permanent-trim bug this constant exists to prevent,
+  /// reintroduced by one byte. Writing the literal with its `\n` keeps the two
+  /// measurements the same measurement.
+  static let dialLineOverhead =
+    "2026-09-20T21:38:23Z delivery install failed \n".utf8.count
+
   /// Installs bridge state through the SSH command's stdin. Only the byte count and
   /// SHA-256 digest appear in the remote command; the capability-bearing JSON never
   /// appears in argv, shell history, or a process listing.

graphcode/Tests/DialLogBoundTests.swift

@@ -0,0 +1,65 @@
+import Foundation
+import Testing
+
+@testable import GraphcodeKit
+
+/// The dial log's bound, and the one property every writer to it owes.
+///
+/// `DialLog` trims by keeping the last `keptLines` lines once the file passes
+/// `maxBytes` — a line-count trim standing in for a byte budget. It holds only while a
+/// line stays under `maxBytes / keptLines`. A longer one breaks it *permanently*: the
+/// trim keeps 5000 lines, 5000 long lines are still over the cap, so every later append
+/// by every loop on that host re-reads and rewrites the whole file and never gets under.
+///
+/// A delivery-failure line shipped at 445 bytes against a 209-byte budget and did
+/// exactly that — 2.2 MB of log that no trim could shrink. These lock the arithmetic so
+/// raising `keptLines`, renaming a field, or adding a longer detail breaks here first.
+@Suite
+struct DialLogBoundTests {
+  /// What one line may cost if `keptLines` of them must fit inside `maxBytes`.
+  private var perLineBudget: Int { DialLog.maxBytes / DialLog.keptLines }
+
+  @Test
+  func aFailureLineFitsTheBudgetItsOwnTrimDependsOn() {
+    let worstCase = RemoteGraphAccess.dialLineOverhead + RemoteGraphAccess.errorDetailBytes
+    #expect(worstCase <= perLineBudget)
+    #expect(DialLog.keptLines * worstCase <= DialLog.maxBytes)
+    // Derived rather than chosen, so the two can never drift apart.
+    #expect(
+      RemoteGraphAccess.errorDetailBytes == perLineBudget - RemoteGraphAccess.dialLineOverhead)
+  }
+
+  @Test
+  func theOverheadMatchesTheLineItBudgetsFor() {
+    // The overhead constant is a measured string; if the fragment's fields change, the
+    // budget must move with them rather than stay a stale number. The `\n` is part of
+    // the measurement, not decoration — `wc -c`, which the trim measures the file with,
+    // counts it, and leaving it out here is precisely how a 210-byte line passed a
+    // 209-byte bound.
+    let rendered = "2026-09-20T21:38:23Z delivery install failed \n"
+    #expect(RemoteGraphAccess.dialLineOverhead == rendered.utf8.count)
+    let fragment = DialLog.fragment(
+      session: "delivery", dial: "install", event: "failed", detailVariable: "gc_di_err")
+    #expect(fragment.contains("delivery install failed %s"))
+  }
+
+  @Test
+  func whatIsLeftStillCarriesTheNameOfTheFault() {
+    // A budget that fits the trim is worth nothing if it cannot hold a real diagnosis.
+    let real =
+      "NotADirectoryError: [Errno 20] Not a directory: "
+      + "'/home/dev/blocker/nested/PROMPT.md'"
+    #expect(real.utf8.count <= RemoteGraphAccess.errorDetailBytes)
+    #expect("SyntaxError: invalid syntax".utf8.count <= RemoteGraphAccess.errorDetailBytes)
+  }
+
+  @Test
+  func theTrimScratchFileIsPerProcess() {
+    // A fixed `dials.log.tmp` is a race every loop on a host shares: two dials trimming
+    // at once both redirect into one name and both `mv` it, publishing a half-written
+    // file. Measured at 40 concurrent fragments, a 5000-line log came out with 34.
+    let fragment = DialLog.fragment(session: "graphcode-x", dial: "ensure", event: "fresh")
+    #expect(fragment.contains(".$$.tmp"))
+    #expect(!fragment.contains("dials.log\".tmp"))
+  }
+}

graphcode/Tests/RemoteInstallerExecutionTests.swift

@@ -114,4 +114,111 @@ struct RemoteInstallerExecutionTests {
       RemoteGraphAccess.installerScript(files: [doomed: "goal"], neutered: false))
     #expect(try run(reporting, home: home) != 0)
   }
+
+  @Test(.enabled(if: hasPython3))
+  func aFailedDeliveryLeavesItsReasonInTheHostsDialLog() throws {
+    // Silence is what cost five days: the installer raised SyntaxError into /dev/null,
+    // so neither machine held a word about why every remote host was empty. Non-fatal
+    // is right; traceless is not.
+    let home = try scratchHome()
+    defer { try? FileManager.default.removeItem(at: home) }
+    let blocker = home.appendingPathComponent("blocker")
+    try "x".write(to: blocker, atomically: true, encoding: .utf8)
+    let script = try #require(
+      RemoteGraphAccess.installerScript(files: ["~/blocker/nested/PROMPT.md": "goal"]))
+
+    #expect(try run(script, home: home) == 0)
+
+    let log = home.appendingPathComponent(".graphcode/dials.log")
+    let entry = try #require(try? String(contentsOf: log, encoding: .utf8))
+    #expect(entry.contains("delivery install failed"))
+    // The python's own words, not just that something went wrong.
+    #expect(entry.contains("NotADirectoryError") || entry.contains("Errno 20"))
+    // One line per entry, or every reader that splits on newlines mis-parses the log.
+    #expect(entry.split(separator: "\n").count == 1)
+  }
+
+  @Test(.enabled(if: hasPython3))
+  func aLoggedFailureLeavesTheWholeLogValidUTF8() throws {
+    // The detail is cut to a byte budget, and a byte cut lands mid-character sooner or
+    // later. One orphan continuation byte is not a cosmetic blemish: it makes `grep` and
+    // `sed` fail on the *entire* file under a UTF-8 locale, so a feature written to make
+    // one failure legible would hide every dial on the host instead.
+    let home = try scratchHome()
+    defer { try? FileManager.default.removeItem(at: home) }
+    // A path whose non-ASCII characters run right through the tail boundary.
+    let deep = "~/" + String(repeating: "é", count: 400) + "/PROMPT.md"
+    let script = try #require(RemoteGraphAccess.installerScript(files: [deep: "goal"]))
+    // Something to lose: an ordinary dial entry written before the failure.
+    _ = try run(
+      DialLog.fragment(session: "graphcode-x", dial: "ensure", event: "fresh"), home: home)
+
+    #expect(try run(script, home: home) == 0)
+
+    let log = home.appendingPathComponent(".graphcode/dials.log")
+    let bytes = try #require(try? Data(contentsOf: log))
+    #expect(String(data: bytes, encoding: .utf8) != nil, "dial log is not valid UTF-8")
+    // The earlier entry must still be findable by the tools anyone would reach for.
+    #expect(try run("grep -q 'ensure fresh' \(log.path)", home: home) == 0)
+  }
+
+  @Test(.enabled(if: hasPython3))
+  func aLoggedFailureLineFitsTheTrimBudgetOnDisk() throws {
+    // Measured from the file, not recomputed. `DialLogBoundTests` checks the arithmetic,
+    // and arithmetic is exactly how this went wrong: the first budget left out the
+    // trailing newline, the test that was written to lock it left the newline out the
+    // same way, and a 210-byte line passed a 209-byte bound. Whatever the emitted
+    // fragment really writes has to fit, terminator and all.
+    let home = try scratchHome()
+    defer { try? FileManager.default.removeItem(at: home) }
+    // A deep path, so the traceback is far longer than the budget and the cut is real.
+    let deep = "~/blocker/" + String(repeating: "nested/", count: 40) + "PROMPT.md"
+    let blocker = home.appendingPathComponent("blocker")
+    try "x".write(to: blocker, atomically: true, encoding: .utf8)
+    let script = try #require(RemoteGraphAccess.installerScript(files: [deep: "goal"]))
+
+    #expect(try run(script, home: home) == 0)
+
+    let log = home.appendingPathComponent(".graphcode/dials.log")
+    let written = try #require(try? Data(contentsOf: log))
+    #expect(!written.isEmpty)
+    #expect(written.count <= DialLog.maxBytes / DialLog.keptLines, "line is \(written.count) bytes")
+    // And `keptLines` of them really do fit under the cap the trim measures against.
+    #expect(DialLog.keptLines * written.count <= DialLog.maxBytes)
+  }
+
+  @Test(.enabled(if: hasPython3))
+  func aFailureWithNoStderrStillRecordsItsExitCode() throws {
+    // A killed installer — an OOM on a small box against a 105 KB argv — exits non-zero
+    // with nothing on stderr. The one datum always available must not be dropped.
+    let home = try scratchHome()
+    defer { try? FileManager.default.removeItem(at: home) }
+    let install = try #require(
+      RemoteGraphAccess.installerScript(files: [RemoteGraphAccess.cliInstallPath: "shim"]))
+    // Replace the python with a silent failure, keeping the reporting tail intact.
+    let silent = install.replacingOccurrences(
+      of: "gc_di_err=$(", with: "gc_di_err=$(sh -c 'exit 137' && ")
+
+    #expect(try run(silent, home: home) == 0)
+
+    let entry = try #require(
+      try? String(
+        contentsOf: home.appendingPathComponent(".graphcode/dials.log"), encoding: .utf8))
+    #expect(entry.contains("delivery install failed rc=137"))
+  }
+
+  @Test(.enabled(if: hasPython3))
+  func aSucceedingDeliveryWritesNoDialLogNoise() throws {
+    // The sweep dials every host every minute. A line per healthy delivery would bury
+    // the one that matters under the ones that don't.
+    let home = try scratchHome()
+    defer { try? FileManager.default.removeItem(at: home) }
+    let script = try #require(
+      RemoteGraphAccess.installerScript(files: [RemoteGraphAccess.cliInstallPath: "shim"]))
+
+    #expect(try run(script, home: home) == 0)
+    #expect(
+      !FileManager.default.fileExists(
+        atPath: home.appendingPathComponent(".graphcode/dials.log").path))
+  }
 }