Skip to content

fix(logs): persist Alloy positions, release SIGINT handlers and carry every selector in Loki hints - #449

Merged
roodboi merged 4 commits into
nextfrom
wf/g67-loki-followups-2
Oct 24, 2026
Merged

roodboi merged 4 commits into
nextfrom
wf/g67-loki-followups-2

Conversation

@roodboi

@roodboi roodboi commented Oct 23, 2026 •

Copy link
Copy Markdown
Contributor

Follow-ups to #417 (merged into next as 6e173f5) for Loki-backed hack logs.

Root cause

  1. Alloy positions were not persisted. The alloy service in renderGlobalLoggingCompose (src/templates.ts) had no data volume and replaced the image's default command, which carries --storage.path=/var/lib/alloy/data, with run /etc/alloy/config.alloy. Alloy then wrote positions.yml under its default data-alloy/ in the container's writable layer, so every recreated container (hack global down then hack global up) read every retained container log again and could resend entries Loki already held.
  2. SIGINT listeners piled up. lokiTail in src/ui/loki-logs.ts registered process.once("SIGINT", ...) per follow and never removed it on a normal close. A process that follows repeatedly (the TUI, the MCP server) accumulated one listener per follow and hit MaxListenersExceededWarning after ten.
  3. Hints dropped selectors. The empty-snapshot and empty-follow hints repeated only --path, --project, --branch and the positional service. --services, --tail, --profile, --pretty, --json, --query, --since and --until were dropped silently, so the suggested hack logs --compose command showed a different selection.
  4. Weak follow tests. No test proved the tail keeps following after the no-entries notice (adding stop() after notify() survived every test), and the "quiet when an entry arrives before the notice delay" test depended on a 60 ms real timer racing the socket.
  5. Docs stated the wrong reopen condition. docs/architecture.md and the src/templates.ts comment said Alloy reopens an exited container that finished after the last line it shipped. Alloy v1.12.0 runner.go compares State.FinishedAt against target.Last(), the wall-clock second at which Alloy last processed a line from that container.

Fix

  1. The logging compose mounts a named volume alloy-data (GLOBAL_ALLOY_DATA_VOLUME) at /var/lib/alloy/data (GLOBAL_ALLOY_STORAGE_PATH, the directory the official image creates for this) and runs run --storage.path=/var/lib/alloy/data /etc/alloy/config.alloy. hack global down runs docker compose down without -v, so the volume survives a down/up; hack global logs-reset (down -v) removes it together with Loki's data, which is the right pairing.
  2. lokiTail keeps process.once("SIGINT", onSigint) and calls process.off("SIGINT", onSigint) in the socket's close handler. once stays so a second Ctrl-C after the handler ran gets the default action.
  3. src/lib/logs.ts gains LogsCommandSelectors and renderComposeLogsSuggestion, which returns the command plus omitted. The command carries --tail, --profile, --pretty, --json and a single service (a lone --services value becomes the positional). --query, --since, --until and more than one service have no compose equivalent (--compose refuses the Loki-only flags and the CLI takes one positional service), so the notice ends with The compose backend has no equivalent for --services api,www and --since 15m. instead of dropping them. src/commands/project.ts builds the selectors from the parsed options (--tail only when passed) for both the snapshot hint and the follow notice.
  4. noEntriesNotice.schedule?: NoticeScheduler ((fn, afterMs) => cancel) is injectable, defaulting to setTimeout/clearTimeout. src/backends/log-backend.ts now types its noEntriesNotice as LokiLogsParams["noEntriesNotice"] so the option passes through unchanged.
  5. The template comment and docs/architecture.md state the exact condition: on each 5-second tick Alloy inspects the container and reopens its log when State.Running is true or finished.Unix() >= target.Last(), where finished is State.FinishedAt (0 if unparsable) and Last() is set to time.Now() after each processed line, starts at 0 when the target is created, and is not stored in the positions file. So a container that logged its last line and then exited is reopened every 5 s, and so is one Alloy has read no line from since the target was created; a container is left alone only after Alloy read a line from it after it had finished. The docs also note that a position is a whole second and Docker's since includes that second, so the last second Alloy read can be sent again.

Tests

  • tests/loki-short-lived-logs.test.ts: parses the rendered logging compose and asserts the alloy-data:/var/lib/alloy/data mount, the --storage.path command and the top-level volume declaration (next to loki-data and grafana-data); hint tests for --tail/--profile/--pretty/--json and for the omitted --services/--query/--since/--until sentence, for both the snapshot hint and the follow notice; renderComposeLogsSuggestion shape, quoting and omitted list; a hand-driven NoticeScheduler (manualNoticeTimer) drives the "reports once and keeps following afterwards" test (fires the timer, then sends an entry over the still-open socket and asserts it is printed while the follow promise is still pending) and the "stays quiet" test (asserts the timer was cancelled, then fires it); one test keeps the default real timer with a lower bound only; two SIGINT tests: twelve sequential follows leave process.listenerCount("SIGINT") unchanged, and process.emit("SIGINT") closes an open follow with exit 0 and removes the listener.
  • tests/logs-loki-empty-fallback-cli.test.ts (source CLI, stub docker, in-process fake Loki, private HOME): --loki --no-follow --services api,migrate --tail 5 --since 15m --profile jobs migrate hints hack logs --compose --no-follow --tail 5 --profile jobs and names --services api,migrate and --since 15m; a lone --services migrate --json becomes the positional and keeps --json with a start/end NDJSON pair; the follow-notice test now passes --tail 5 and expects it in the suggested command.
  • tests/global-command.test.ts: hack global down runs exactly docker compose -f <logging> down (no -v/--volumes) and hack global up passes no -V/--renew-anon-volumes, so the named volume survives a down/up.

Mutation proof (each mutation applied alone to the committed tree, the named test file run, the file restored):

Mutation Result
alloy-data mount removed from the compose killed, 1 failing (loki-short-lived-logs)
Alloy command without --storage.path killed, 1 failing
top-level alloy-data: volume removed killed, 1 failing
process.off("SIGINT", ...) removed killed, 2 failing
SIGINT handler does nothing killed, 1 failing
stop() added after notify() killed, 1 failing (keeps-following test)
an entry does not cancel the notice timer killed, 1 failing
notice scheduled with 0 instead of afterMs killed, 1 failing
default scheduler never fires killed, 2 failing
hint drops --tail killed, 5 failing (loki-short-lived-logs, logs-loki-empty-fallback-cli)
hint drops --profile killed, 4 failing
hint drops --pretty killed, 1 failing
hint drops --json killed, 3 failing
single service not made positional killed, 9 failing
several services dropped silently killed, 4 failing
--query/--since/--until dropped silently killed, 4 failing
project.ts follow notice passes empty selectors killed, 1 failing (logs-loki-empty-fallback-cli)
project.ts snapshot hint passes empty selectors killed, 4 failing
project.ts drops --tail / --profile / services / --since from the selectors killed, 2 / 1 / 5 / 1 failing
global down passes -v for the logging stack killed, 1 failing (global-command)

Evidence

  • Bun 1.4.2 (mise x bun@1.4.2), bun install --frozen-lockfile; bun.lock unchanged.
  • Local (macOS): bun run --cwd packages/cli typecheck 0 errors; root bun run check (includes privacy:check) passes with only the 34 pre-existing complexity warnings; Biome is clean on every changed file. Focused tests: loki-short-lived-logs (25), logs-loki-empty-fallback-cli (7), global-command, templates, logs-utils, log-backend all pass.
  • bun run docs:cli-reference regenerates docs/reference/cli.md with no diff (no option changed).
  • Alloy behavior read from the v1.12.0 source: internal/component/loki/source/docker/runner.go (finished.Unix() >= t.target.Last() on every targetRestartInterval tick), internal/dockertarget/target.go (last initialised to 0, t.last.Store(time.Now().Unix()) after each line, positions.Put(..., ts.Unix()), Since from the position), docker.go (positions.yml under DataPath), internal/alloycli/cmd_run.go (--storage.path, default data-alloy/) and the image Dockerfile (/var/lib/alloy/data, default CMD with --storage.path). Docker's since inclusivity from moby daemon/logger/loggerutils/logfile.go (msg.Timestamp.Before(since) is skipped).
  • gitleaks 8.30.1 over a git log -p origin/next..HEAD export: no leaks.
  • Full suite: run locally on this Mac, not on the M3. The M3 reports 56G free on /, below the 58 GiB floor the unit must keep, and its m3-ci lock has been held since 01:13 (same disk-guard state that blocked fix(logs): escape Loki selectors once, quiet Alloy info logs and add empty-follow hints #417), so no M3 worktree was created. Instead bun run build:config-compiler && bun run test ran at this head (bccc3b2) under nice -n 15 on the loaded local Mac: 8059 pass, 8 fail. The 8 failures (7 in tests/test-config-compiler.test.ts, 1 in tests/native-compose-file-command.test.ts, several at the 5 s default timeout) are outside this change; rerun serially with --timeout 60000 they pass (39/39 and 20/20).

Gaps

  • No live Alloy container. The volume path and --storage.path flag come from the v1.12.0 Dockerfile and cmd_run.go, not from a running grafana/alloy:v1.12.0 container; the task forbids starting real containers. That a recreated container resumes from the persisted positions is therefore inferred from the source, not observed.
  • The M3 full suite has not run at this head (see Evidence).
  • Existing installs get the volume only after hack global install rewrites ~/.hack/logging/docker-compose.yml and the stack restarts; that first restart still re-reads retained logs once.
  • The Docker API polling cost described in the docs is unchanged; the text is now exact, not smaller.

Refs HACK-1379

🤖 Generated with Claude Code


View with [code]smith Autofix with [code]smith
Need help on this PR? Tag @codesmith-bot with what you need.

… every selector in Loki hints

Follow-ups to #417 for Loki-backed `hack logs` (HACK-1379).

- The global logging compose gives Alloy a named `alloy-data` volume at
  `/var/lib/alloy/data` and repeats `--storage.path` there, so read positions
  survive a recreated container instead of re-reading every retained log.
- `lokiTail` removes its SIGINT listener when the socket closes, so repeated
  follows in one process no longer pile up listeners.
- Empty-snapshot and empty-follow hints carry `--tail`, `--profile`,
  `--pretty`, `--json` and a single service, and name `--services`, `--query`,
  `--since` and `--until` when the compose backend cannot apply them.
- The empty-follow notice timer is injectable; tests drive it by hand and prove
  the tail keeps following after the notice.
- The template comment and docs/architecture.md state Alloy v1.12.0's exact
  reopen condition (`State.Running || finished.Unix() >= target.Last()`).

Refs HACK-1379

Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com>
@linear-code

linear-code Bot commented Oct 23, 2026

Copy link
Copy Markdown

HACK-1379

roodboi and others added 3 commits October 23, 2026 10:53
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
…oll costs

Alloy v1.12.0 reopens an exited container's log when
`finished.Unix() >= target.Last()`. A reopen reads from the position
second, which Docker includes, so it reads the last line again and moves
`Last()` past the finish time. Only a container that never logged a line
is reopened every 5 seconds; one that logged, or whose lines the
positions file covers, is reopened once and then stays closed. Every
discovered container still costs one inspect call per poll.

Refs HACK-1379

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
#405 (HACK-1392) landed its own fix for the Loki follow SIGINT leak: the
handler is installed just before the tail awaits close and removed in a
finally. Keep that version and drop this branch's close-handler removal and
its two SIGINT tests in favour of next's; keep the injectable notice
scheduler, the Alloy positions volume and the selector-carrying hints.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
@roodboi
roodboi marked this pull request as ready for review October 24, 2026 05:48
@roodboi
roodboi merged commit 4c9eb3e into next Oct 24, 2026
16 checks passed
@roodboi
roodboi deleted the wf/g67-loki-followups-2 branch October 24, 2026 05:48
roodboi added a commit that referenced this pull request Oct 24, 2026
…n bound and Loki hint wiring (#478)

Refs HACK-1425. Follow-ups from the verifier reviews of #447 (merged as 686b6b8) and #449
(merged as 4c9eb3e). None of them blocked those PRs.

## Root cause

1. **No test pinned the production drain bound.** Every drain test read
`NATIVE_EXIT_DRAIN_BOUND_MS` itself, or injected a wide value through the `exitDrainBoundMs`
test seam. The held-descendant cases only checked an upper bound (`settled - exited < bound +
margin`). So setting the constant to 250 (or changing the `?? NATIVE_EXIT_DRAIN_BOUND_MS`
default to `?? 250`) passed the whole suite. 2. **Three bound drains had no late-writer case.**
The one-off drain and the two recovery drains (selection and cleanup) use the same code path as
status, read, logs and exec. Only those four had a "closed code written after the reported exit"
case. 3. **Three wiring mutations in `src/commands/project.ts` survived the tests.**
`tests/logs-loki-empty-fallback-cli.test.ts` never passed `--pretty`, `--query` or `--until`
through the CLI. Replacing `pretty: args.options.pretty === true`, or the selectors' `query:
opts.queryOpt` or `until: opts.until`, with a constant did not fail any test. 4. **The `hack
global logs-reset` text was out of date.** The command runs `down -v`, which (since #449) also
deletes the `alloy-data` volume that holds Alloy's read positions. The confirm prompt and the
CLI summary named only Loki and Grafana.

## Fix

- `tests/native-runtime-client.test.ts`
  - New case `the production exit drain bound keeps its documented floor and outlasts a late
  writer`. It checks that `NATIVE_EXIT_DRAIN_BOUND_MS >= 5000` (the documented floor, now
  written in the constant's doc comment) and that the bound is larger than the late-writer delay
  plus a clock tolerance.
  - The held-descendant `exit` cases (read, selection, cleanup) do not pass the seam. They now
  also check `settled - exited >= NATIVE_EXIT_DRAIN_BOUND_MS - 50 ms`, which proves the
  production default is the bound in effect.
  - `LATE_WRITER_SELECTIONS` gains `one-off`, `selection` and `cleanup`.
- `tests/native-project-process.test.ts`: the same lower bound on the foreground graph owner's
  two held-descendant cases. This covers that file's own `?? NATIVE_EXIT_DRAIN_BOUND_MS`
  default.
- `tests/logs-loki-empty-fallback-cli.test.ts` gets two CLI cases. Both use the stub `docker`,
  the fake Loki, and a private HOME via `privateCliEnv`:
  - `--loki --no-follow --pretty migrate`: the hint repeats `--pretty`.
  - `--no-follow --query '<custom LogQL>' --until 1m`: Loki receives the custom query exactly as
  given, and the hint lists `--query '…'` and `--until 1m` as selectors that `--compose` cannot
  apply.
- `src/commands/global.ts`: the summary is now "Wipe Loki, Grafana and Alloy volumes (fresh
  logs, dashboards and Alloy read positions)". The prompt now says it deletes "ALL Loki logs,
  Grafana state and Alloy read positions". `docs/reference/cli.md` was regenerated with `bun run
  docs:cli-reference`. `docs/architecture.md` already described the volume removal, so it is
  unchanged.

There is no production behavior change apart from the logs-reset text and a doc comment.

## Evidence

Mutation runs (each mutation applied on its own and restored from a backup afterward):

| Mutation | Killed by | | --- | --- | | `NATIVE_EXIT_DRAIN_BOUND_MS = 250` | documented-floor
case | | runtime client `selected ?? 250` | read, selection and cleanup held-descendant `exit`
cases | | graph owner `opts.exitDrainBoundMs ?? 250` | `ready` and `early failure` held-
descendant cases | | fixed 250 ms window for `one-off` only | `authored one-off keeps a closed
code written after the reported exit` | | fixed 250 ms window for `recovery-selection` only |
`authored selection keeps a closed code …` | | fixed 250 ms window for `recovery-cleanup` only |
`authored cleanup keeps a closed code …` | | `pretty: args.options.pretty === true` → `false` |
`explicit --loki snapshot hint repeats --pretty` | | selectors `query: opts.queryOpt` →
`undefined` | `explicit --query snapshot hint names --query and --until` | | selectors `until:
opts.until` → `undefined` | `explicit --query snapshot hint names --query and --until` |

Local gates at this head (Bun 1.4.2):
- `bun run check` passed, including `privacy:check`.
- `bun run --cwd packages/cli typecheck` and root `bun run typecheck` reported 0 errors.
- Biome reported no issues on the changed files.
- gitleaks 8.30.1 on the `origin/next..HEAD` patch found no leaks.
- Focused tests: `native-runtime-client`, `native-project-process`, `logs-loki-empty-fallback-
  cli`, `global-command` and `prerequisites-matrix` gave 74 pass, 0 fail.

The full-suite evidence is hosted CI's sharded `test` job at this PR head.

## Gaps

- The new lower-bound checks rely on the wall clock of two processes and a 50 ms tolerance. The
  lower direction does not depend on host load, because a timer cannot fire before its delay, so
  these checks should not add flakiness.
- The new prompt text has no test. `confirmSafe` declines in non-interactive runs
  (`initialValue: false`), so a CLI test cannot see the prompt without a TTY harness. This
  matches the coverage before this PR.
- The pin is a floor (`>=`), not an exact value. Raising the bound still passes, which is
  intended.

🤖 Generated with [Claude Code](https://claude.com/claude-code)
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant