Debugging logs: where they live, how to filter, how to group

Debugging logs: where they live, how to filter, how to group

Where logs live

~/.stapler-squad/logs/:

File	What it is
staplersquad.log	Current live log, JSON-lines (one slog record per line: time, level, msg, plus arbitrary key/value fields).
staplersquad-<timestamp>.log.gz	Rotated log segments (lumberjack). Same JSON-lines format, gzipped.
service.log / service.log.old	Raw stdout/stderr of the systemd/launchd-managed service — startup banners, panics that happen before logging is initialized, and anything written outside the log package. Check here first for crash-on-boot issues the structured log never saw.
debug-snapshot-*.json	One-off diagnostic dumps (goroutine/heap snapshots), not part of the regular log stream — see docs/how-to/profile-lockups.md.

The path above is the shared/default location only. A named instance (STAPLER_SQUAD_INSTANCE=<name>) or workspace mode (STAPLER_SQUAD_WORKSPACE_MODE=true or a SwitchDatabase-set workspace preference) logs elsewhere instead — see docs/reference/state-isolation.md for the full priority list. If ~/.stapler-squad/logs/staplersquad.log looks stale despite the service clearly being active, that’s why: check service.log’s startup banner for the Global log: <path> line, which always names the file actually being written to for that run.

Every line is a flat JSON object — pull specific fields with jq rather than grepping text:

jq -r 'select(.level=="ERROR")' ~/.stapler-squad/logs/staplersquad.log
jq -r 'select(.session=="my-session-title")' ~/.stapler-squad/logs/staplersquad.log

Note: the backlog/triage/review call sites (server/services/backlog_service_triage.go, server/services/backlog_service_trigger_triage.go, session/backlog_lifecycle.go, session/backlog_lifecycle_triage.go) used to log through the older log.InfoLog()/ErrorLog().Printf(...) API, which wrote a plain [pid-...] LEVEL:timestamp file:line: [Tag] message key=val ... line — not a JSON object, so jq silently skipped it. These four files were migrated to the structured API (2026-09-15); tools/lint/nolegacylog now fails the build if a legacy call is reintroduced into any of them. If you find a line from one of these files that jq can’t see, it’s a regression — file a bug rather than reaching for grep as the permanent workaround.

Browser (client) logs

The web UI ships console.warn, console.error, window.onerror and unhandled rejections to POST /api/client-logs (web-app/src/lib/telemetry/clientLogShipper.ts, mounted in Providers.tsx). They land in the same staplersquad.log, interleaved with server records, tagged source=client with window (the ?window= id), url, user_agent and, for errors, stack:

jq -r 'select(.source=="client")' ~/.stapler-squad/workspaces/<hash>/logs/staplersquad.log
jq -r 'select(.source=="client" and .window=="c76c8d49")' <log>

console.log/info are deliberately not shipped (the terminal code logs on every resize). The endpoint caps a request at 256 KB / 100 entries and the server at 600 entries per minute total, returning 429 beyond that; the browser re-queues a failed batch (max 200 buffered).

Retention

Rotation is lumberjack: 50 MB per segment, gzip, at most 100 segments or 14 days. Before 2026-10-15 the default was 10 MB x 5 segments, which at ~11 MB/hour kept about 4.5 hours of history. Existing config.json files holding exactly the old triple (10/5/30) are upgraded on load; any other values are treated as deliberate and kept.

Filtering logs for one backlog/triage session

Every TriggerTriage/TriggerReReview/BacklogLifecycle log line carries an item and/or session field with the item ID / headless-triage-<uuid> / headless-re-review-<uuid> session ID shown in the backlog item’s Sessions list in the web UI:

jq -r 'select(.session=="headless-triage-34925c72-c4de-4036-8a17-249d25b7aab2")' ~/.stapler-squad/logs/staplersquad.log
jq -r 'select(.item=="<item-id>")' ~/.stapler-squad/logs/staplersquad.log

Plain grep on the same ID still works too (and is the only option for any file that hasn’t been migrated yet, or across gzipped rotated segments):

grep "headless-triage-34925c72-c4de-4036-8a17-249d25b7aab2" ~/.stapler-squad/logs/staplersquad.log
# or, across rotated segments too:
grep -h "<item-id-or-session-id>" ~/.stapler-squad/logs/staplersquad.log ~/.stapler-squad/logs/*.log.gz 2>/dev/null

This is the fastest way to answer “why did this triage/review fail” — it shows the start line, the raw LLM output on a parse failure (also durably saved under ~/.stapler-squad/headless-failures/, and linked from the backlog item detail page’s failure notice once end_reason is set — see classifyHeadlessCallError and the parse-failure branch in server/services/backlog_service_trigger_triage.go), and any reconcileOrphanedTriageItems/AutoRespawnTriage follow-up lines for the same item, all in one pass — no need to correlate timestamps by hand.

Log levels: global and per-package

Logging goes through the log/ package (slog-based). There are two independent controls:

Global runtime level

• Default: INFO (set in log/log.go’s init()), for both console and file.
• Change at runtime with no restart via the debug API:

  curl -X POST localhost:8543/api/debug/log-level -d '{"level":"DEBUG"}'
  curl localhost:8543/api/debug/log-level   # read current level

• In code: log.SetRuntimeLevel(log.DEBUG) / log.GetRuntimeLevel().

Per-package level overrides (log4j/logback-style hierarchy)

Flipping the global level to DEBUG floods the log with every package’s debug output — usually you only want it for the one package you’re chasing a bug in. log/package_level.go implements the same hierarchical-override model Java logging frameworks use: set a level on a package path, and it applies to that package and everything under it, unless a more specific sub-path has its own override.

At startup, via the STAPLER_SQUAD_LOG_LEVELS env var — a comma-separated list of package=level pairs, paths relative to the module root:

STAPLER_SQUAD_LOG_LEVELS="session/tmux=debug,server/services=warn" ./stapler-squad

At runtime, via the debug API:

# Turn on DEBUG for one package without touching the global level
curl -X POST localhost:8543/api/debug/log-level/packages \
  -d '{"package":"session/tmux","level":"DEBUG"}'

# See what's currently overridden
curl localhost:8543/api/debug/log-level/packages

# Remove an override (falls back to the global level, or a less-specific
# ancestor override — e.g. clearing "session/tmux" while "session" has its
# own override falls back to that)
curl -X DELETE localhost:8543/api/debug/log-level/packages -d '{"package":"session/tmux"}'

In code: log.SetPackageLevel("session/tmux", log.DEBUG), log.ClearPackageLevel(...), log.GetPackageLevels().

How resolution works: every log.Info/Warn/Error/Debug call site resolves its own package from the call site’s program counter (not the message text), so no call-site changes are needed to benefit from this — existing code “just works” once an override is set for its package. See log.PackageForPC(pc) if you want to check how a given call site classifies.

Why this exists: before this, the only lever was one global level — there was no way to see session/tmux‘s debug output without also getting server/services’ (or worse, every websocket handler’s) at the same time.

Reducing log volume: what to check before adding a new log line

A 2026-08-25 audit of ~/.stapler-squad/logs/staplersquad.log found 6 messages accounted for ~84% of all 35,865 lines in the file. The pattern in every case was the same: a message that’s genuinely useful once (state transition, backpressure warning) logged at Info/Warn on every occurrence of an underlying poll/retry loop, forever. Before adding a log line inside anything that runs on a ticker, in a retry loop, or per-item in a bulk operation, ask:

1. Does this repeat for state that hasn’t changed? session/health.go’s SessionHealthChecker reloads every instance from storage every ~15s; session/instance_serialization.go’s worktree-missing detection used to re-fire its Warn on every single reload for the same already-paused session, forever, because the correction was never persisted back to storage. Fixed by de-duplicating per session title (loggedMissingWorktree in that file) — but the actual root cause (state drift between the DB and the in-memory correction never being persisted) is still open; the dedup only stops the log spam.
2. Is this the expected/success path, not an error? session/tmux/tmux.go’s "tmux session doesn't exist, no need to kill" fired 8,000+ times at Info for what is a completely benign, expected outcome — downgraded to Debug.
3. Is this per-item inside a bulk save/load, meant as a debug trace? session/storage.go’s "SaveInstances: converting instance" logged at Info for every single instance on every save — downgraded to Debug.
4. Is this backpressure that fires per-dropped-item under sustained load? session/tokens/store.go and session/artifacts/store.go logged a Warn for every single dropped item when their parse queues were full — under sustained backpressure this is thousands of nearly-identical lines that don’t add information past the first one. Rate-limited to log every 100th drop with a running total (dropLogInterval) instead.
5. Does this fire on every coalesced batch/frame during normal streaming? session/streamhub/hub.go’s onBatchFlush logged at Info on every flush — up to ~50×/sec per actively-streaming session. Downgraded to Debug; the per-flush metric (recordBatchFlushFramesCoalesced) already captures this for OpenTelemetry/Datadog without a log line per flush.

If you’re not sure whether a call site you’re about to add will be hot, grep for its enclosing function’s callers and check whether any of them are a time.NewTicker/for { select {...} } loop — tools/lint/hotpolllog already catches one specific shape of this (a legacy-logger .Printf call directly inside a select case inside a for loop) but doesn’t catch slog-style log.Info(...) calls or loops that call out to a helper containing the log call, so it isn’t a substitute for actually checking.

Grouping/deduplicating logs (Datadog-style pattern clustering)

For ad hoc investigation, scripts/log-group.sh clusters log lines into patterns the way Datadog’s Log Patterns view does: group by (level, message), with dynamic substrings (UUIDs, filesystem paths, embedded JSON blobs, bare numbers) normalized out, so structurally identical messages collapse into one row even on the rare call site that interpolates a value directly into the message text instead of passing it as a separate field.

scripts/log-group.sh                              # top 30 patterns, live log
scripts/log-group.sh -n 50                         # top 50
scripts/log-group.sh -l warn                       # only WARN-level
scripts/log-group.sh ~/.stapler-squad/logs/*.log.gz  # across rotated segments
journalctl --user -u stapler-squad -o cat | scripts/log-group.sh -

Most call sites in this codebase already log a fixed message string with values in separate JSON fields (the slog convention: log.Info("msg", "key", val)), which is why a simple jq -r '.msg' | sort | uniq -c | sort -rn gets you 90% of the way there for a quick check — reach for log-group.sh when you need the normalization (a message with an embedded JSON blob or path baked into the text) or level filtering.

Metrics as an alternative to log volume

Before adding a log line to track something that happens frequently (a counter, a rate, a distribution), check whether it belongs as an OpenTelemetry metric instead — see docs/how-to/enable-opentelemetry.md. The onBatchFlush case above is the template: recordBatchFlushFramesCoalesced already exports this as a metric, so the log line was pure duplication once downgraded off the default-visible path.

Diagnosing parked triage items (end_reason = 'other')

classifyHeadlessCallError buckets every headless triage/review failure it can’t recognize as other. For those, the Go error text is persisted (first 500 runes of err.Error()) in item_sessions.error_detail, so you no longer need the log to have survived rotation. It holds only the Go error chain — raw subprocess output is in the failure_capture_path file instead. The same text appears in the stuck-state context (triage session … ended (other: <error_detail>) …), the item’s Sessions panel failure notice, and ItemSession.error_detail (proto field 27).

Find other failures and group by shared cause (a common prefix across many items in one batch points at infrastructure, not the items). <config-dir> is where your instance keeps state — see docs/reference/state-isolation.md:

sqlite3 <config-dir>/sessions.db \
  "SELECT error_detail, COUNT(*) FROM item_sessions
   WHERE end_reason='other' AND error_detail != ''
   GROUP BY substr(error_detail,1,60) ORDER BY COUNT(*) DESC;"

Find items parked at the retry cap (the same rows the per-item “Auto-triage paused” notification refers to):

sqlite3 <config-dir>/sessions.db \
  "SELECT item_id, remediation_attempts, context FROM backlog_stuck_states
   WHERE reason='orphaned_triage' AND resolved_at IS NULL AND remediation_attempts >= 5;"

When 3 or more items park within 10 minutes, a “Multiple auto-triage retries exhausted” notification fires in addition to the per-item ones — treat it as a signal to look for a shared cause before resetting anything.

Once the cause is fixed, reset the batch with the BulkResetStuckRemediation RPC (reason = STUCK_REASON_ORPHANED_TRIAGE, only_parked defaults to true), or reset one item with ResetStuckRemediation. Rows with an error_detail from before this field existed are empty; only failures after it shipped are recoverable this way.