Fix log pruning that silently never ran, and cover it behaviourally

Message

prune-instance-logs! called three procedures that do not exist in this stdlib: string-prefix?, string-suffix? and sort. The real names are string-starts-with?, string-ends-with? (both subject-first) and list-sort (from (sigil list), which was not imported).

None of that failed the build. The function is wrapped in a guard -- a failure there costs disk, not correctness -- so at runtime the unbound variable was caught and swallowed, and pruning simply never happened. The log files looked entirely correct, because the bug was in what did NOT occur. A source read would have passed it; only asking the binary to prune a directory found it.

Pruning now also runs AFTER the instance opens its own log, so the cap counts this generation and the newest-first ordering can never select the live file for deletion.

Harness case 8 pins the behaviour: 15 stale generations plus a live one are capped to 10 newest, and the non-log neighbours (send-dedup.state, telegram-offset, the old shared courier.log) are left untouched.

Also pinned in the unit suite:

the send-result strings must stay distinguishable from each other and from a bare "Message sent" (that string equality is the whole defect);
claim-token-hash's zero-padding branch, which only executes for 1 token in 16 and would otherwise sit unrun until it failed in production. The expected value is derived independently rather than copied from output.

Suite 111 passed / 0 failed. Harness 38 checks, all passing, with the pre-fix control still producing 4 conflicts and 2 poller children.

Changed

 repro/single_poller_harness.py | 59 +++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
 src/courier/main.sgl           | 19 +++++++++++--------
 test/test-claim.sgl            | 10 ++++++++++
 test/test-telegram.sgl         | 38 ++++++++++++++++++++++++++++++++++++++
 4 files changed, 118 insertions(+), 8 deletions(-)

Diff

repro/single_poller_harness.pymodified

@@ -491,6 +491,63 @@ def case_sigkill(binp, run_dir, a, state_dir):

491

return c

492

493

+494

def case_log_pruning(binp, run_dir):

+495

"""Per-instance logs must not accumulate forever, and must not take

+496

anything else with them.

+497

+498

Worth a behavioural case rather than trusting the source: the pruning

+499

code is wrapped in a guard (a failure there costs disk, not

+500

correctness), and a guard is exactly what hides a defect. The first

+501

version of this function called two procedures that do not exist in

+502

this stdlib; it compiled, it ran, the guard swallowed the unbound

+503

variable, and pruning silently never happened. Nothing about the log

+504

files would have looked wrong.

+505

"""

+506

print("=== 8 LOG PRUNING (bounded, and only OUR files) ===")

+507

d = os.path.join(run_dir, "prune")

+508

os.makedirs(os.path.join(d, "relays"), exist_ok=True)

+509

now = time.time()

+510

fakes = []

+511

for i in range(15):

+512

p = os.path.join(d, f"courier-9{i:04d}.log")

+513

with open(p, "w") as f:

+514

f.write(f"fake generation {i}\n")

+515

# Staggered mtimes, oldest first, so "keep the newest N" is testable.

+516

os.utime(p, (now - (100 - i) * 60, now - (100 - i) * 60))

+517

fakes.append(p)

+518

# Files that are NOT instance logs must survive untouched.

+519

bystanders = {

+520

os.path.join(d, "send-dedup.state"): "1 abc\n",

+521

os.path.join(d, "telegram-offset"): "12345",

+522

os.path.join(d, "courier.log"): "the old shared log\n",

+523

os.path.join(d, "courier-notes.txt"): "not a log\n",

+524

}

+525

for p, content in bystanders.items():

+526

with open(p, "w") as f:

+527

f.write(content)

+528

+529

c = Courier(binp, d, "prune-a")

+530

c.initialize()

+531

time.sleep(2)

+532

remaining = sorted(n for n in os.listdir(d)

+533

if n.startswith("courier-") and n.endswith(".log"))

+534

check("instance logs are capped at 10", len(remaining) == 10,

+535

f"{len(remaining)} remain: {remaining}")

+536

check("the instance's own log survived pruning",

+537

f"courier-{c.pid}.log" in remaining, f"{remaining}")

+538

check("the OLDEST fakes are the ones removed",

+539

os.path.basename(fakes[0]) not in remaining

+540

and os.path.basename(fakes[14]) in remaining,

+541

f"{remaining}")

+542

survived = [os.path.basename(p) for p in bystanders if os.path.exists(p)]

+543

check("non-log files (dedup state, offset) are untouched",

+544

len(survived) == len(bystanders),

+545

f"survived={survived} of {[os.path.basename(p) for p in bystanders]}")

+546

c.close_stdin()

+547

time.sleep(1)

+548

c.kill()

+549

+550

551

EXPECTED_DRY_RUN = ("Message NOT sent: COURIER_DISABLE_TELEGRAM_SEND is set "

552

"(dry-run, nothing delivered).")

553

@@ -606,6 +663,8 @@ def main():

663

inst.kill()

664

instances = []

665

+666

case_log_pruning(args.bin, run_dir)

+667

668

dry_dir, text = case_dry_run(args.bin, run_dir)

669

case_gag_does_not_poison(args.bin, run_dir, dry_dir, text)

670

src/courier/main.sglmodified

@@ -8,6 +8,7 @@

(define-library (courier main)

(import (sigil core)

(sigil string)

+11

(sigil list)

(sigil io)

(sigil dotenv)

(sigil async)

@@ -99,14 +100,14 @@

100

(guard (e (else #f))

101

(let* ((entries (or (directory-list log-dir) '()))

102

(logs (filter (lambda (n)

−102

(and (string-prefix? "courier-" n)

−103

(string-suffix? ".log" n)))

+103

(and (string-starts-with? n "courier-")

+104

(string-ends-with? n ".log")))

105

entries))

106

(paths (map (lambda (n) (path-join log-dir n)) logs))

−106

(sorted (sort paths

−107

(lambda (a b)

−108

(> (or (file-mtime a) 0)

−109

(or (file-mtime b) 0))))))

+107

(sorted (list-sort (lambda (a b)

+108

(> (or (file-mtime a) 0)

+109

(or (file-mtime b) 0)))

+110

paths)))

111

(let loop ((rest sorted) (i 0))

112

(unless (null? rest)

113

(when (>= i *log-keep-generations*)

@@ -151,8 +152,10 @@

152

(number->string (process-id))

153

".log"))))

154

(ensure-directory log-dir)

−154

(prune-instance-logs! log-dir)

−155

(log-configure! target: (open-log-append! log-path))))

+155

(log-configure! target: (open-log-append! log-path))

+156

;; AFTER opening ours, so the cap counts this instance's file too and

+157

;; the newest-first ordering can never select it for deletion.

+158

(prune-instance-logs! log-dir)))

159

160

;; Configure logging from CLI args, opening any --log <path> target

161

;; in APPEND mode. This is the production path: the leader launches

test/test-claim.sglmodified

@@ -46,6 +46,16 @@

(claim-token-hash

"9999999999:AAEEFFbbccddeeff00112233445566778899"))))

+49

;; The zero-padding branch only runs for a hash with a leading zero nibble,

+50

;; which is 1 token in 16 -- so it would otherwise sit unexecuted until it

+51

;; failed in production. "tok-pad-2400" hashes to 0x6175bd22d28fede (15 hex

+52

;; digits), which forces it. The expected value is derived independently of

+53

;; this implementation: FNV-1a("tok-pad-2400") padded left to 16 hex digits,

+54

;; first 12 taken.

+55

(test "zero-pads a short hash instead of truncating a different window"

+56

(assert-equal 12 (string-length (claim-token-hash "tok-pad-2400")))

+57

(assert-equal "06175bd22d28" (claim-token-hash "tok-pad-2400")))

+58

;; The token must never be recoverable from anything written to disk.

(test "never embeds the token itself"

(let ((token "123456:SECRETSECRETSECRET"))

test/test-telegram.sglmodified

@@ -104,3 +104,41 @@

104

(assert-equal "2.5 MB" (format-size (quotient (* 5 1024 1024) 2)))))

105

106

(run-tests)

+107

+108

;; ============================================================

+109

;; Send-result strings: a caller must be able to tell delivery

+110

;; from non-delivery by reading the return value

+111

;; ============================================================

+112

;;

+113

;; The dry-run path used to return "Message sent." byte-for-byte, so every

+114

;; gagged send from 2026-07-06 to 2026-08-04 claimed a delivery it had not

+115

;; made -- and mimicked the silent-drop bug it was masking exactly, which

+116

;; made production observation of that bug impossible while the gag was on.

+117

;; These pin the property that failure cost us: the strings must be

+118

;; DISTINGUISHABLE. The end-to-end behaviour (what the MCP tool actually

+119

;; returns, and that a gagged send does not poison a later real one) is

+120

;; proved by repro/repro-single-poller.sh cases 5 and 6.

+121

+122

(test-group "send-result strings"

+123

(test "the dry-run string does not contain a bare 'Message sent'"

+124

(assert-true (not (string-contains? *dry-run-not-sent-message*

+125

"Message sent"))))

+126

+127

(test "the dry-run string does not begin with 'Message sent'"

+128

(assert-true (not (string-starts-with? *dry-run-not-sent-message*

+129

"Message sent"))))

+130

+131

(test "the dry-run string says plainly that nothing was delivered"

+132

(assert-true (string-contains? *dry-run-not-sent-message* "NOT sent"))

+133

(assert-true (string-contains? *dry-run-not-sent-message*

+134

"COURIER_DISABLE_TELEGRAM_SEND")))

+135

+136

(test "the duplicate-suppressed string is not the plain success string"

+137

(assert-true (not (string=? *duplicate-suppressed-message*

+138

"Message sent.")))

+139

(assert-true (string-contains? *duplicate-suppressed-message*

+140

"duplicate suppressed")))

+141

+142

(test "the two non-delivery strings are distinct from each other"

+143

(assert-true (not (string=? *dry-run-not-sent-message*

+144

*duplicate-suppressed-message*)))))