Back to Semaphore

Debug Logging — Stage 1: Selective Debug Filter

AGENTS/tasks/2026-06-07-debug-log-1.md

2.19.75.6 KB
Original Source

Debug Logging — Stage 1: Selective Debug Filter

Date: 2026-06-07 Plan: AGENTS/plans/2_19/debug-log.md Status: ✅ Done

This is stage 1 of 2. It implements the selective debug-log filter mechanism (Node.js-debug-style namespaces). Stage 2 — adding the actual diagnostic debug log statements across subsystems — is a separate task.

Goal

Let operators turn on debug logs for specific subsystems only, controlled by the environment variable SEMAPHORE_DEBUG_FILTER (or the --debug-filter flag), mirroring the Node.js debug library. Namespaces map to the existing context field already attached via log.WithFields().

Key rule (per the updated plan): the filter only acts on DEBUG-level entries and only when the log level is already DEBUG. It never raises the level itself; if the level is above DEBUG, the filter is inert.

What was implemented

New package pkg/debuglog

  • pkg/debuglog/filter.goFilter type + Parse(spec).

    • Tokens separated by commas/whitespace.
    • * is a wildcard (compiled to an anchored regexp; all other characters matched literally via regexp.QuoteMeta).
    • Leading - marks an exclusion; exclusions always win over includes.
    • Enabled(ns) = matches ≥1 include and no exclude.
    • Active() reports whether any pattern was configured.
    • Context-less entries (namespace "") are naturally only matched by an explicit *, so a narrow filter like runner keeps legacy context-less log.Debug calls quiet.
  • pkg/debuglog/formatter.goFilteringFormatter (wraps the existing logrus.Formatter) + NewFilteringFormatter(inner, filter).

    • For DebugLevel entries whose context namespace is not enabled, Format returns (nil, nil) → logrus writes zero bytes (verified by test: not even a newline).
    • All non-debug entries pass through to the inner formatter untouched.
    • Nil Inner falls back to logrus.TextFormatter; nil Filter suppresses all debug.

Wiring cli/cmd/root.go

  • Added debugFilter to persistentFlags.
  • Added persistent flag --debug-filter.
  • Refactored PersistentPreRun so it no longer early-returns when the log level is unset (that would have skipped the filter); it now sets the level if provided, then calls initDebugFilter().
  • New initDebugFilter():
    • Resolves spec from --debug-filter, falling back to SEMAPHORE_DEBUG_FILTER.
    • Returns early (no-op) when the spec is empty or log.GetLevel() < log.DebugLevel.
    • Otherwise wraps the current standard-logger formatter with FilteringFormatter and prints Debug filter active: <spec>.
  • No global variables introduced (per project code style) — the filter lives inside the formatter instance handed to logrus.

Tests

  • pkg/debuglog/filter_test.go — table-driven: exact match, multiple includes, space-separated, * global, task_* prefix, middle wildcard, exclusions (*,-task_pool, *,-task_*), exclude-only, dot-is-literal, empty spec, and context-less ("") handling.
  • pkg/debuglog/formatter_test.go — end-to-end through a real logrus.Logger at DEBUG level into a bytes.Buffer: suppresses non-matching debug, passes matching debug, never touches Info/Warn/Error, context-less behavior, nil filter, and an assertion that a suppressed entry writes 0 bytes.

Behavior matrix

SEMAPHORE_LOG_LEVELSEMAPHORE_DEBUG_FILTERResult
unset / INFOunsetNo debug output (unchanged).
unset / INFOrunnerFilter inert (level not DEBUG). No debug output.
DEBUGunsetAll debug output (unchanged).
DEBUGrunnerOnly runner debug entries print.
DEBUG*,-dbAll debug except namespace db.

Usage

bash
SEMAPHORE_LOG_LEVEL=DEBUG SEMAPHORE_DEBUG_FILTER=runner semaphore server
SEMAPHORE_LOG_LEVEL=DEBUG SEMAPHORE_DEBUG_FILTER='task_*' semaphore server
SEMAPHORE_LOG_LEVEL=DEBUG SEMAPHORE_DEBUG_FILTER='*,-db' semaphore server
# or via flags:
semaphore server --log-level DEBUG --debug-filter 'runner,git'

Verification

go build ./cli/... ./pkg/debuglog/      # ok
go test ./pkg/debuglog/ -v -count=1     # PASS (all cases)
gofmt -l pkg/debuglog/ cli/cmd/root.go  # clean
go vet ./pkg/debuglog/ ./cli/cmd/       # clean

Known limitations / follow-ups

  • Syslog filtering — implemented via debuglog.FilteringHook in cli/cmd/syslog.go (addSyslogHook wraps both the standard and RFC 5424 hooks). Syslog output now respects the same SEMAPHORE_DEBUG_FILTER / --debug-filter spec as stdout.
  • Filtering happens at format time, so suppressed debug entries are still constructed (cheap, but not free). Acceptable since it only runs at DEBUG level.

Files changed

  • pkg/debuglog/filter.go (new)
  • pkg/debuglog/formatter.go (new)
  • pkg/debuglog/filter_test.go (new)
  • pkg/debuglog/formatter_test.go (new)
  • cli/cmd/root.go (modified: flag + initDebugFilter)

Next: Stage 2

Add log.WithFields(log.Fields{"context": "<ns>", ...}).Debug(...) statements across the high-value subsystems listed in the plan (runner, task_pool, task_runner, git, terraform, session/ldap, schedule, db, ha), never logging secrets.