Persist Telegram getUpdates offset + append courier.log across restarts
Second spam cause: the poller's getUpdates offset (tg-client last-update-id) was in-memory only, so every fresh poller child (leader restart, /mcp reconnect, watchdog respawn, crash) restarted at offset 0 and re-fetched Telegram's ~24h unconfirmed backlog. The leader acked each re-delivered inbound message -> an outbound Telegram storm. The io.sgl async-log fix stopped the crash-loop trigger but not this: any restart still re-delivered.
- poller: persist last-update-id to <relay-dir>/../telegram-offset, reload on child start, re-save after each tick. Cold start / missing / corrupt offset silently DRAINS the pre-existing backlog (advances past it without delivering) so deploying the fix does not itself fire one last storm. - poller: honor COURIERTELEGRAMAPIURL on the poll path. make-tg-bot hard-coded api.telegram.org, so the poller always hit real Telegram and could not be reproduced off-device; build the bot's tg-client directly with the override (send path already did this). - main: open the --log <path> target in APPEND mode. Production launches with --log, which the stdlib log-configure-from-args! truncated on every restart, wiping each spam episode's evidence. - test: offset persistence round-trip + cold-start signals (59 pass). - repro: off-device mock (mocktelegram.py) + captured evidence.
repro/.gitignore | 4 ++++
repro/evidence-2026-07-01.md | 69 +++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
repro/mock_telegram.py | 162 ++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
src/courier/main.sgl | 30 +++++++++++++++++++++++++++++-
src/courier/poller.sgl | 126 ++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++----
test/test-poller-offset.sgl | 88 ++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
6 files changed, 474 insertions(+), 5 deletions(-)repro/.gitignoreadded
run/*.out*.err__pycache__/repro/evidence-2026-07-01.mdadded
# Off-device repro evidence — courier second spam cause (2026-07-01)All runs used a LOCAL mock (`mock_telegram.py`) via COURIER_TELEGRAM_API_URL.NOTHING reached real Telegram. Mock models Telegram's getUpdates offsetsemantics (offset N confirms/drops updates < N) and records every request.Binaries:- FIXED: build/dev/bin/courier (branch fix/courier-log-persist-repro)- CONTROL: master + api-url-only change (isolates the offset-persistence fix)## Deliverable 1 — --log now APPENDS across restarts (was: truncate)```2026-07-01T13:50:34Z [INFO] Courier starting mode=leader relay=none telegram=not configured2026-07-01T13:50:34Z [INFO] MCP server ready name=courier--- courier restart ---2026-07-01T13:50:36Z [INFO] Courier starting mode=leader relay=none telegram=not configured2026-07-01T13:50:36Z [INFO] MCP server ready name=courier--- courier restart ---2026-07-01T13:50:38Z [INFO] Courier starting mode=leader relay=none telegram=not configured2026-07-01T13:50:38Z [INFO] MCP server ready name=courier```3x 'Courier starting' + 2x restart markers => full history preserved.## SECOND CAUSE — BEFORE (pre-fix control): backlog delivered + re-deliveredCold start with a 2-update backlog. Each delivered message = one inbound theleader would ACK = one outbound Telegram send => storm.```control RUN 1 (cold start) stdout events:{"type":"hello","pid":3748}{"type":"heartbeat"}{"type":"message","text":"BACKLOG-1","sender":"daviwil","sender_id":"42","chat_id":"1001"}{"type":"message","text":"BACKLOG-2","sender":"daviwil","sender_id":"42","chat_id":"1001"}{"type":"heartbeat"}{"type":"heartbeat"}{"type":"heartbeat"}{"type":"heartbeat"}control RUN 1 stderr (no offset persistence, no drain):2026-07-01T13:49:48Z [INFO] Telegram poller child started pid=3748control RUN 2 (restart, backlog still pending) -> RE-DELIVERS:{"type":"message","text":"BACKLOG-1","sender":"daviwil","sender_id":"42","chat_id":"1001"}{"type":"message","text":"BACKLOG-2","sender":"daviwil","sender_id":"42","chat_id":"1001"}```## SECOND CAUSE — AFTER (fixed): drain on cold start, deliver-once, no re-delivery```RUN 1 (cold start, 2-update backlog) stdout events:{"type":"hello","pid":30027}{"type":"heartbeat"}{"type":"heartbeat"}{"type":"heartbeat"}{"type":"heartbeat"}{"type":"heartbeat"}{"type":"heartbeat"}{"type":"heartbeat"}RUN 1 stderr:2026-07-01T13:44:45Z [INFO] Cold start: drained Telegram backlog (not delivered) count=2 offset=3RUN 2 (restart; 1 NEW update injected) -> delivers NEW once:{"type":"message","text":"NEW-live-msg","sender":"daviwil","sender_id":"42","chat_id":"1001"}2026-07-01T13:44:51Z [INFO] Restored Telegram getUpdates offset offset=3RUN 3 (restart, no new updates) -> NO re-delivery:message events: 02026-07-01T13:44:57Z [INFO] Restored Telegram getUpdates offset offset=4```repro/mock_telegram.pyadded
#!/usr/bin/env python3"""Mock Telegram Bot API for OFF-DEVICE courier repro.Models the two semantics that matter for the getUpdates-backlog spam bug: * getUpdates(offset=N) CONFIRMS (drops) every pending update with update_id < N, then returns the remaining pending updates. A call with no offset (or offset 0) confirms nothing and returns the whole backlog -- exactly how a fresh poller (offset reset to 0) re-fetches Telegram's ~24h backlog. * sendMessage records the outbound and returns ok. Nothing here ever reaches real Telegram; the point is to COUNT would-be sends.Every request is appended to <logdir>/requests.log so the driver canassert on re-delivery. Control endpoints (not part of the Telegram API)let the driver seed and inject updates: POST /_seed body: {"updates":[{...},...]} replace the backlog POST /_add body: {"text":"...","sender_id":"..","chat_id":".."} append one update GET /_stats {"delivered":[ids], "sends":N}Usage: mock_telegram.py <port> <logdir>"""import jsonimport sysimport osimport threadingfrom http.server import BaseHTTPRequestHandler, ThreadingHTTPServerPORT = int(sys.argv[1])LOGDIR = sys.argv[2]os.makedirs(LOGDIR, exist_ok=True)REQ_LOG = os.path.join(LOGDIR, "requests.log")SEND_LOG = os.path.join(LOGDIR, "sends.log")LOCK = threading.Lock()STATE = { "updates": [], # pending updates (list of dicts with update_id) "next_id": 1, # next update_id to assign via _add "getupdates": 0, # count of getUpdates calls "sends": 0, # count of sendMessage calls "delivered_ids": [], # update_ids the mock RETURNED to a poller (per call)}def logline(path, msg): with open(path, "a") as f: f.write(msg + "\n") f.flush()def make_update(update_id, text, sender_id="42", chat_id="1001"): return { "update_id": update_id, "message": { "message_id": update_id, "date": 1000000 + update_id, "text": text, "from": {"id": int(sender_id), "is_bot": False, "first_name": "David", "username": "daviwil"}, "chat": {"id": int(chat_id), "type": "private"}, }, }class Handler(BaseHTTPRequestHandler): def log_message(self, *a): pass # silence default stderr logging def _body(self): n = int(self.headers.get("Content-Length", 0)) raw = self.rfile.read(n) if n else b"" try: return json.loads(raw) if raw else {} except Exception: return {} def _reply(self, obj, code=200): data = json.dumps(obj).encode() self.send_response(code) self.send_header("Content-Type", "application/json") self.send_header("Content-Length", str(len(data))) self.end_headers() self.wfile.write(data) def do_GET(self): if self.path == "/_stats": with LOCK: self._reply({"delivered": STATE["delivered_ids"], "sends": STATE["sends"], "getupdates": STATE["getupdates"], "pending": [u["update_id"] for u in STATE["updates"]]}) return self._reply({"ok": False, "description": "not found"}, 404) def do_POST(self): body = self._body() path = self.path # ---- control endpoints ---- if path == "/_seed": with LOCK: STATE["updates"] = list(body.get("updates", [])) STATE["next_id"] = (max([u["update_id"] for u in STATE["updates"]], default=0) + 1) STATE["getupdates"] = 0 STATE["sends"] = 0 STATE["delivered_ids"] = [] self._reply({"ok": True}) return if path == "/_add": with LOCK: uid = STATE["next_id"] STATE["next_id"] += 1 STATE["updates"].append(make_update( uid, body.get("text", "msg"), body.get("sender_id", "42"), body.get("chat_id", "1001"))) self._reply({"ok": True, "update_id": uid}) return # ---- Telegram Bot API ---- # path looks like /bot<token>/<method> method = path.rsplit("/", 1)[-1] if method == "getUpdates": offset = body.get("offset", 0) or 0 with LOCK: STATE["getupdates"] += 1 if offset > 0: # Confirm: drop everything below the offset. STATE["updates"] = [u for u in STATE["updates"] if u["update_id"] >= offset] result = list(STATE["updates"]) ids = [u["update_id"] for u in result] STATE["delivered_ids"].append({"offset": offset, "returned": ids}) logline(REQ_LOG, f"getUpdates offset={offset} -> returned={ids}") self._reply({"ok": True, "result": result}) return if method == "sendMessage": chat_id = body.get("chat_id") text = body.get("text", "") with LOCK: STATE["sends"] += 1 n = STATE["sends"] logline(SEND_LOG, f"#{n} sendMessage chat_id={chat_id} text={text!r}") logline(REQ_LOG, f"sendMessage chat_id={chat_id} text={text!r}") self._reply({"ok": True, "result": { "message_id": 9000 + n, "date": 1, "chat": {"id": chat_id, "type": "private"}, "text": text}}) return # Any other Telegram method (getMe, etc.) -> generic ok. logline(REQ_LOG, f"{method} (generic-ok)") self._reply({"ok": True, "result": {}})if __name__ == "__main__": logline(REQ_LOG, f"--- mock start on :{PORT} ---") srv = ThreadingHTTPServer(("127.0.0.1", PORT), Handler) srv.serve_forever()src/courier/main.sglmodified
((string=? (car rest) flag) #t) (else (loop (cdr rest)))))) ;; Value following a CLI flag (e.g. the path after --log), or #f. (define (find-cli-value flag) (let loop ((rest (cdr (command-line)))) (cond ((null? rest) #f) ((and (string=? (car rest) flag) (not (null? (cdr rest)))) (cadr rest)) (else (loop (cdr rest)))))) ;; ============================================================ ;; Crash Logging ;; ============================================================ (ensure-directory log-dir) (log-configure! target: (open-log-append! log-path)))) ;; Configure logging from CLI args, opening any --log <path> target ;; in APPEND mode. This is the production path: the leader launches ;; `courier serve --log <dir>/courier.log --log-level trace` ;; (claude-ops launch-server.sh). The stdlib log-configure-from-args! ;; would open that path with open-output-file, TRUNCATING it on every ;; restart -- which is why a spam episode's evidence kept getting ;; wiped. Appending (via open-log-append!, capped at ;; *log-carryover-max*) makes restart behavior observable. When no ;; --log is given, only the level is applied and logging stays on the ;; console/stderr default (matching the stdlib helper's behavior). (define (configure-logging-from-args!) (let ((log-path (find-cli-value "--log")) (log-level (find-cli-value "--log-level"))) (when log-level (log-configure! level: (string->symbol log-level))) (when log-path (ensure-directory (path-dirname log-path)) (log-configure! target: (open-log-append! log-path))))) ;; ============================================================ ;; Entry Point ;; ============================================================ " (sigil " (sigil-version) ")\n")) (exit 0)) (log-configure-from-args!) (configure-logging-from-args!) ;; Telegram poller child mode: run the isolated poll loop and ;; exit. Spawned by the leader's poller supervisor; events gosrc/courier/poller.sglmodified
(define-library (courier poller) (import (sigil core) (sigil io) (sigil fs) (sigil path) (sigil string) (sigil struct) (sigil math) parse-poller-event make-poller-message-event poller-stale? poller-next-restart-delay) poller-next-restart-delay offset-file-path load-persisted-offset save-offset!) (begin ;; ============================================================ (poller-emit-line! *heartbeat-line*) (loop (- remaining *heartbeat-slice*))))) ;; ============================================================ ;; Child: getUpdates offset persistence ;; ============================================================ ;; ;; The getUpdates offset (the tg-client last-update-id) is otherwise ;; in-memory only. A fresh child -- leader restart, /mcp reconnect, ;; watchdog respawn, or crash -- starts at offset 0, so getUpdates ;; re-returns Telegram's entire ~24h unconfirmed backlog. Each ;; re-delivered inbound message is re-injected to the leader, which ;; acks every one (the two-message telegram-ack protocol) -> an ;; outbound Telegram storm. This was the SECOND spam cause: the ;; io.sgl async-log fix stopped the crash-LOOP that triggered ;; restarts, but ANY restart re-delivered. Persisting the offset ;; across restarts makes each inbound delivered exactly once. ;; Where the offset lives: next to courier.log, keyed off the relay ;; dir so a poller child and the leader agree on the location. (define (offset-file-path) (path-join (path-dirname (default-relay-dir)) "telegram-offset")) ;; Persisted offset, or #f when the file is absent, unreadable, or ;; not a positive integer. #f means "cold start" -> drain, don't ;; deliver, the pre-existing backlog. (define (load-persisted-offset) (let ((path (offset-file-path))) (and (file-exists? path) (guard (e (else #f)) (let ((n (string->number (string-trim (read-file-string path))))) (and (integer? n) (> n 0) n)))))) ;; Persist the offset. Best-effort: a failed write only risks a ;; bounded re-delivery on the next restart, never a crash. (define (save-offset! n) (guard (e (else #f)) (ensure-directory (path-dirname (offset-file-path))) (write-file-string (offset-file-path) (number->string n)))) ;; Cold start: advance the offset past every currently-pending ;; update WITHOUT delivering any of them, so deploying ;; offset-persistence does not itself fire one last storm from the ;; backlog that already accumulated with no saved offset. Retries ;; through transient errors -- we must not fall through to the ;; delivery loop with the backlog still pending. Heartbeats keep the ;; supervisor from killing the child while draining. Returns the ;; count drained (for logging). (define (drain-backlog! bot) (let ((client (tg-bot-client bot))) (let loop ((backoff *error-backoff-initial*) (total 0)) (poller-emit-line! *heartbeat-line*) (when (poller-parent-gone?) (exit 0)) (let* ((result (guard (e (else (log-error (format "Backlog drain error: ~a" e)) 'error)) (tg-get-updates client timeout: 0))) (updates (cond ((eq? result 'error) 'error) ((array? result) (array->list result)) (else '())))) (cond ;; Transient failure: back off and retry (still not ;; delivering); heartbeats emitted by poller-sleep/heartbeat. ((eq? updates 'error) (poller-sleep/heartbeat backoff) (loop (min (* backoff 2) *error-backoff-max*) total)) ;; Backlog fully drained. ((null? updates) total) ;; Advance past this batch (no dispatch) and continue. (else (for-each (lambda (raw) (let ((update (dict->tg-update raw))) (set-tg-client-last-update-id! client (+ (tg-update-update-id update) 1)))) updates) (loop *error-backoff-initial* (+ total (length updates))))))))) ;; Restore the saved offset, or silently drain the backlog on a cold ;; start, before the delivery loop begins. (define (initialize-offset! bot) (let ((saved (load-persisted-offset))) (if saved (begin (set-tg-client-last-update-id! (tg-bot-client bot) saved) (log-info "Restored Telegram getUpdates offset" offset: saved)) (let ((drained (drain-backlog! bot))) (let ((offset (tg-client-last-update-id (tg-bot-client bot)))) (save-offset! offset) (log-info "Cold start: drained Telegram backlog (not delivered)" count: drained offset: offset)))))) ;;; Entry point for `courier --telegram-poller`. ;;; ;;; Polls Telegram synchronously and forwards allowed messages to (: courier-config? -> void?) (let* ((token (courier-config-telegram-token config)) (allowed (courier-config-allowed-senders config)) (bot (make-tg-bot token: token request-timeout: *poll-request-timeout* connect-timeout: *poll-connect-timeout*))) ;; Honor COURIER_TELEGRAM_API_URL for the poll path too. The ;; send path (telegram.sgl) already redirects via config, but ;; make-tg-bot hard-codes api.telegram.org -- so before this, ;; the poller ALWAYS hit real Telegram, and there was no way ;; to reproduce/verify inbound polling off-device against a ;; mock. Build the bot's client directly with the override. (api-url (or (courier-config-telegram-api-url config) "https://api.telegram.org")) (bot (tg-bot client: (tg-client token: token api-url: api-url request-timeout: *poll-request-timeout* connect-timeout: *poll-connect-timeout*)))) (poller-emit-line! (json-encode `((type . "hello") (pid . ,(process-id))))) (log-info "Telegram poller child started" pid: (process-id)) ;; Restore the getUpdates offset (or drain the backlog on a cold ;; start) BEFORE polling, so a restart never re-delivers the ;; ~24h Telegram backlog. See the offset-persistence section. (initialize-offset! bot) (let loop ((backoff *error-backoff-initial*)) ;; Heartbeat IMMEDIATELY BEFORE the (blocking) poll so the ;; supervisor's liveness window resets right at the start of #f)) (tg-bot-tick bot) #t))) ;; Persist the (possibly advanced) offset after a successful ;; tick so the next child resumes exactly here -- a delivered ;; message is confirmed by the next getUpdates offset and is ;; never re-delivered across a restart. (when ok? (save-offset! (tg-client-last-update-id (tg-bot-client bot)))) ;; Heartbeats are the supervisor's liveness signal -- ;; emitted on errors too: an erroring child is alive and ;; backing off, not wedged.test/test-poller-offset.sgladded
(import (sigil test) (sigil string) (sigil fs) (sigil path) (sigil process) (courier poller));; ============================================================;; getUpdates offset persistence (the second-spam-cause fix);; ============================================================;;;; The poller's getUpdates offset (tg-client last-update-id) must;; survive a process restart, or a fresh child starts at offset 0 and;; re-delivers Telegram's entire ~24h backlog -- the leader then acks;; each re-delivered message, an outbound storm. These tests cover the;; durable-offset primitives: round-trip, and the "cold start" signals;; (missing / non-positive / garbage file) that trigger a silent drain;; instead of delivering a stale backlog.;; Point the relay dir (and thus the offset file) at a fresh temp dir.;; offset-file-path is <dirname(relay-dir)>/telegram-offset.(define (with-temp-offset thunk) (let ((tmp (make-temp-directory))) (setenv! "COURIER_RELAY_DIR" (path-join tmp "relays")) (let ((result (thunk tmp))) (setenv! "COURIER_RELAY_DIR" "") (guard (e (else #f)) (delete-directory tmp)) result)))(test-group "offset-file-path" (test "sits beside the relay dir, not inside it" (with-temp-offset (lambda (tmp) ;; dirname(<tmp>/relays) == <tmp> (assert-equal (path-join tmp "telegram-offset") (offset-file-path))))))(test-group "load-persisted-offset — cold-start signals" (test "missing file -> #f (cold start: drain the backlog)" (with-temp-offset (lambda (tmp) (assert-false (load-persisted-offset))))) (test "garbage file -> #f (corrupt: treat as cold start)" (with-temp-offset (lambda (tmp) (write-file-string (offset-file-path) "not-a-number") (assert-false (load-persisted-offset))))) (test "zero -> #f (offset 0 means no offset -> would re-fetch backlog)" (with-temp-offset (lambda (tmp) (write-file-string (offset-file-path) "0") (assert-false (load-persisted-offset))))) (test "empty file -> #f" (with-temp-offset (lambda (tmp) (write-file-string (offset-file-path) "") (assert-false (load-persisted-offset))))))(test-group "save-offset! / load-persisted-offset round-trip" (test "a saved positive offset reloads exactly" (with-temp-offset (lambda (tmp) (save-offset! 42) (assert-equal 42 (load-persisted-offset))))) (test "re-saving overwrites (offset only advances forward)" (with-temp-offset (lambda (tmp) (save-offset! 42) (save-offset! 100) (assert-equal 100 (load-persisted-offset))))) (test "large update_id round-trips (no precision loss)" (with-temp-offset (lambda (tmp) (save-offset! 999999999) (assert-equal 999999999 (load-persisted-offset))))) (test "trailing whitespace in the file is tolerated" (with-temp-offset (lambda (tmp) (write-file-string (offset-file-path) "57\n") (assert-equal 57 (load-persisted-offset))))))(run-tests)