diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml index da91851..58572df 100644 --- a/.github/workflows/ci.yml +++ b/.github/workflows/ci.yml @@ -24,11 +24,11 @@ jobs: - name: Checkout uses: actions/checkout@11bd71901bbe5b1630ceea73d27597364c9af683 # v4.2.2 - - name: Set up Node 24 - uses: actions/setup-node@49933ea5288caeca8642d1e84afbd3f7d6820020 # v4.4.0 - with: - node-version: "24" - + # Bun-only on purpose: it runs every step below (lint, tests, pack + # listing), so a Node toolchain here would be dead weight. The one thing a + # Node job would add is the V8/worker_threads side of bggrep's bounded + # matching — verified by hand with `node --test extension/index.test.ts` + # (193 pass, ~20s). Re-run that by hand after touching the bggrep worker. - name: Set up Bun uses: oven-sh/setup-bun@v2 with: @@ -40,19 +40,35 @@ jobs: - name: tsc --noEmit id: tsc run: | - npx tsc --noEmit + bun run lint echo "result=passed" >> "$GITHUB_OUTPUT" - name: Run tests id: tests - run: npm test + run: bun test extension/index.test.ts + # npm, not bun, for THIS step only: the tarball that ships is built by + # `npm publish` (release.yml, OIDC trusted publishing), so the allowlist + # must be checked with the packer that actually produces it. npm is + # preinstalled on the runner — no setup-node, no second toolchain — and + # today both packers emit the same 7 files; that agreement is what this + # step is here to keep true. - name: npm pack --dry-run (files allowlist sanity) id: pack run: | - pack_output=$(npm pack --dry-run 2>&1) + pack_status=0 + pack_output=$(npm pack --dry-run 2>&1) || pack_status=$? echo "$pack_output" - file_count=$(echo "$pack_output" | grep -oP 'total files:\s*\K[0-9]+' || echo "?") + # sed, not grep -oP: no GNU/BusyBox difference to trip over, and the + # casing differs between packers ("total files:" vs "Total files:"). + file_count=$(echo "$pack_output" | sed -n 's/.*[Tt]otal files:[[:space:]]*\([0-9][0-9]*\).*/\1/p' | tail -1) + # npm pack failing, or printing no file count, means the allowlist was + # never actually checked — the greps below cannot fail on it. Treat + # that as a failure instead of a green step reporting "? files". + if [ "$pack_status" -ne 0 ] || [ -z "$file_count" ]; then + echo "::error::npm pack --dry-run failed (exit ${pack_status}) or printed no file count — allowlist NOT verified" + exit 1 + fi echo "file_count=${file_count}" >> "$GITHUB_OUTPUT" # Enforce the allowlist: test files and other non-runtime files must # never ship in the published tarball (they bloat installs and leak diff --git a/.github/workflows/release.yml b/.github/workflows/release.yml index d60b41c..dd33fbf 100644 --- a/.github/workflows/release.yml +++ b/.github/workflows/release.yml @@ -47,6 +47,11 @@ jobs: - name: Checkout uses: actions/checkout@11bd71901bbe5b1630ceea73d27597364c9af683 # v4.2.2 + # npm (Node) on purpose, unlike ci.yml which is bun-only: `bun publish` + # has no OIDC trusted-publishing or provenance support — it authenticates + # with a long-lived NPM_CONFIG_TOKEN — so switching would trade a + # tokenless, attested release for a stored bearer credential. Revisit only + # if Bun ships trusted publishing. - name: Set up Node 24 uses: actions/setup-node@49933ea5288caeca8642d1e84afbd3f7d6820020 # v4.4.0 with: diff --git a/.gitignore b/.gitignore index 845dad5..0164ab6 100644 --- a/.gitignore +++ b/.gitignore @@ -11,3 +11,8 @@ dist/ # Transient agent working files — never committed. .pi/wip/ + +# Local pi-bgrun project config (jobsDir / showCompletedJobs / digest) — per +# contributor, not repo policy: it changes what every bgrun job in this checkout +# does, and a digest command is shell run at wake time. See docs/dogfooding.md. +.pi/pi-bgrun.json diff --git a/README.md b/README.md index e3d4560..d24c1b9 100644 --- a/README.md +++ b/README.md @@ -35,8 +35,8 @@ Restart pi after install so the extension loads. | ------ | --------- | | `bgrun` | Launch a command detached in the background. Optional `name` gives the job a short human-readable label. Returns `started: ` immediately. Wakes the session automatically on completion. | | `bgstatus` | Show job status. With an id: any job's state + exit code. Without: this session's running jobs (finished jobs hidden by default — pass `includeDone: true` or set `showCompletedJobs`). Other sessions' *running* jobs are listed only when `adoptForeignJobs` is enabled; finished foreign logs from the shared dir can also appear when finished jobs are included. | -| `bgtail` | Read the newest lines of a job's log (default 40; it reads the log's **last 2 MB**), **condensed for context**: ANSI escapes stripped, repeated lines collapsed, long lines and total size capped. First read = full last-N tail; repeat reads return **only lines appended since your last read** (delta tailing) — polling a running job never re-pays for lines already seen. Pass `raw: true` for the unprocessed last-N window (still advances the bookmark). | -| `bggrep` | Regex search over the **last 2 MB** of a job's log: line-numbered matches, optional `context` lines, each line pre-truncated to 10 000 chars before matching, results capped (~50 matches, ~8KB) and condensed. Runs inside the extension, so it reaches the configured jobs dir (including a global one) that project-sandboxed tools (`ctx_execute_file`) cannot. Matching runs under a wall-clock budget ([Bounded matching](#bounded-matching)). With no `pattern`, a generic failure-signature default is used (override it — convenience, not guarantee). | +| `bgtail` | Read the newest lines of a job's log (default 40; it reads the log's **last 2 MB** — widen with `bytes`, max 64 MiB), **condensed for context**: ANSI escapes stripped, repeated lines collapsed, long lines and total size capped. First read = full last-N tail; repeat reads return **only lines appended since your last read** (delta tailing) — polling a running job never re-pays for lines already seen. Pass `raw: true` for the unprocessed last-N window (still advances the bookmark). | +| `bggrep` | Regex search over the **last 2 MB** of a job's log (`bytes` widens the window, max 64 MiB): line-numbered matches, optional `context` lines, each line pre-truncated to 10 000 chars before matching, results capped (~50 matches, ~8KB) and condensed. Resolves the job id to the configured jobs dir itself — no log path to reconstruct. `ctx_execute_file` can read the same file (it takes an absolute path; only your Read-deny rules apply), but it needs that path. Matching runs under a wall-clock budget ([Bounded matching](#bounded-matching)). With no `pattern`, a generic failure-signature default is used (override it — convenience, not guarantee). | | `bgclean` | Remove old job logs. **Default scope: this session's jobs only** — other sessions' logs are untouched — and it also drops stale per-project digest markers (`.bgrun-used-*`, `.digest-nudge-*`) in the session's jobs dir (markers are not session data). Pass `all: true` to sweep every shared jobs dir — under the project-local default that is the project's dir plus the machine-global one, while an explicit absolute `jobsDir` is swept alone — and do the same marker sweep across them. Retention: `cleanupDays` config (7 days); `days` must be a positive number (`days: 0` is rejected rather than purging everything). Never removes a running job's log. | ## Slash commands @@ -57,6 +57,7 @@ wake messages) is the agent's workflow. ## Roadmap / not provided +- Deprecated: the machine-global jobs dir (`PI_BGRUN_GLOBAL_DIR`, `~/.pi-bgrun/jobs`) — see [deprecation](#deprecated-machine-global-jobs-dir). Supported until a future major. - `bgkill` — not implemented; to stop a running job, use `kill -- -` (kill the process group — the child is spawned detached). The pid is the last `--`-separated segment of the job id (e.g. `unit-tests-1726680000-12345` → pid `12345`); it is not shown as a separate field in `bgstatus` output. - `bgwait` — not implemented; the wake mechanism makes blocking on a job unnecessary in the normal flow. @@ -65,8 +66,11 @@ wake messages) is the agent's workflow. ```text agent calls bgrun(command: "make test-short", name: "unit-tests") → extension resolves log path: /--.log (default /.pi-bgrun/jobs/ in a repo, else ~/.pi-bgrun/jobs/) - → spawn('sh', ['-c', 'sh -c "$1"; ec=$?; printf "\\n__BGRUN_EXIT__=%d\\n" "$ec"; exit "$ec"', 'bgrun', ''], + → spawn('sh', ['-c', , 'bgrun', ''], { stdio: ['ignore', logFd, logFd], detached: true }).unref() + = the output-ceiling pipeline (see "Log size ceiling"), or the + uncapped one-liner 'sh -c "$1"; ec=$?; printf "\\n__BGRUN_EXIT__=%d\\n" "$ec"; exit "$ec"' + when the ceiling is disabled (maxLogBytes: 0) → records job in-memory + appends a bgrun-job entry to the session → returns "started: " @@ -85,8 +89,9 @@ exit code even after a restart. ## Reading results without flooding context -Two-tier read model — the log file stays complete on disk for deep analysis; -only bounded digests ever enter the conversation: +Two-tier read model — the log file itself stays on disk, capped (see +[log size ceiling](#log-size-ceiling)), for deep analysis; only bounded digests +ever enter the conversation: - **Quick peek:** `bgtail ` — condensed newest lines (ANSI stripped, repeats collapsed, ~2KB/line and ~8KB caps). The first read is the last-40-lines tail; each later @@ -94,21 +99,29 @@ only bounded digests ever enter the conversation: free. The wake message itself already carries the exit code and the log's last line, so many turns need no follow-up read at all. - **Pattern search:** `bggrep [pattern] [context]` — line-numbered matches, - capped and condensed (~50 matches, ~2KB/line, ~8KB); works on global jobs dirs that `ctx_execute_file` - cannot reach. Pass your own pattern when you know the log's format. + capped and condensed (~50 matches, ~2KB/line, ~8KB); takes the job id, so + there is no log path to reconstruct. Searches the **last 2 MB** by default — + pass `bytes` to widen (max 64 MiB), or use `ctx_execute_file` on the path for + whole-file code-based analysis. Pass your own pattern when you know the log's + format. A **wider window costs latency and memory, not context**: the returned + matches stay capped either way. - **Whole-log analysis:** `ctx_execute_file` on the job's log path (reachable when logs are project-local) to extract only failure lines. Never `cat` or - `Read` a full bgrun log. + `Read` a full bgrun log. The sandbox keeps the file's bytes out of context — + only your script's **stdout** enters it — so print aggregates and capped + slices (`fails.slice(0, 40)`), never the content. With a 64 MiB-ceiling log, + an unsliced `console.log(FILE_CONTENT)` is the one way this path becomes the + dump it exists to avoid; use `bgtail`/`bggrep` first, and this third. **Why `bggrep` instead of `bash grep` on the log?** A bash grep's output is uncapped — a retry-storm log can dump thousands of matching lines straight into context, and safety depends on remembering `| head` on every call. -`bggrep` is bounded by design (last 2 MB of the log, per-line 10 000-char -pre-truncation before matching, ~50 matches, ~8KB), takes the job id instead of -a reconstructed log path (no shell-quoting of the regex), reaches the -configured jobs dir (including a global one) that project-sandboxed tools like -`ctx_execute_file` cannot, and reports match counts, line numbers, and -skip markers. Plain `grep` is fine only for a one-off search you know is tiny. +`bggrep` is bounded by design (last 2 MB of the log by default — `bytes` widens +it, max 64 MiB — per-line 10 000-char pre-truncation before matching, ~50 +matches, ~8KB), takes the job id instead of +a reconstructed log path (no shell-quoting of the regex), resolves the job id to the +configured jobs dir itself (no path to reconstruct), and reports match counts, +line numbers, and skip markers. Plain `grep` is fine only for a one-off search you know is tiny. ### Bounded matching @@ -121,6 +134,56 @@ and `bggrep` returns an error — **a runaway pattern fails, it never hangs the session.** Normal patterns and logs finish far inside the budget; worker startup adds a few tens of milliseconds per call. +### Log size ceiling + +stdout+stderr used to go straight to the log file with no write bound, so a +runaway job (`yes`, a spew loop, a pathological build) could fill the disk and +take the machine down. Job logs are now capped (`maxLogBytes` / `PI_BGRUN_MAX_LOG_BYTES`, +default **64 MiB**, `0` = unlimited): + +- The cap keeps the **first** N bytes. There is no portable in-tree way to keep + the tail — a ring buffer needs a helper binary, and rewriting the file breaks + the readers that depend on the exit marker staying last. A job past 64 MiB is + almost always a runaway, so the head is the useful part. +- The ceiling lives **inside the detached process tree**, so it still holds + after pi exits or crashes — it is not a pi-side watchdog. +- The job is **not** killed, and its real exit code is preserved: bytes past the + cap are drained and discarded instead of SIGPIPE'ing the producer into `141`. +- It is **not silent**. The log carries + `__BGRUN_TRUNC__ output truncated: kept the first bytes` on the line + before the exit marker, and the marker line itself carries the flag + (`__BGRUN_EXIT__=0 truncated=67108864`). Both are reserved `__BGRUN_*__` lines + that content readers filter exactly like the exit marker, and readers classify + the notice by that **marker flag**, never by matching text — a command that + echoes a notice-shaped line cannot make its own log look capped, and cannot + get its own output discounted as wrapper bookkeeping either. If the ceiling + could not be installed at all (`mkfifo` unavailable, so the job ran uncapped) + the log says that too — `__BGRUN_NOCAP__ log ceiling unavailable`, with + `nocap=1` in the marker — so "uncapped" is never indistinguishable from + "output was that small". Every surface the agent reads is labelled: the wake's + Stats line gains `log truncated at 64 MiB`, + `bgtail` and `bggrep` append a note and report `truncatedAtBytes` in their + details, and a configured digest scorecard is **skipped** rather than run + against a log that lost its end — summaries and failure lists live at the end, + so its numbers would be confidently wrong. Treat a skipped digest on a capped + job as "unknown", not "no failures". +- Reading a capped log stays readable-whole: the widest `bytes` window is the + ceiling **plus 4 KiB** (not the ceiling itself, which a capped log always + exceeds by its notices and marker), so `bytes: 67108864` still spans the whole + kept log. Windows are additionally limited to their last 500 000 lines — + materializing a 64 MiB window of one-character lines would cost gigabytes of + strings — and when that line bound trims a window, `bgtail`/`bggrep` say so in + the same labelled way instead of silently answering from a subset. +- Maintainer rationale — why a fifo, why the *first* bytes, which alternatives + were measured and rejected: [`docs/log-size-ceiling.md`](docs/log-size-ceiling.md). +- Cost: a capped job runs through one copier process (`perl` where available, + else `dd`/`head`) reading the job through a fifo, plus a bounded drain wait — + a few tens of milliseconds of job startup, no steady-state overhead. The + copier is also what drains the stream past the cap, so the producer is never + SIGPIPE'd. +- Configure `maxLogBytes: 0` for the previous uncapped behavior, e.g. when the + whole log must survive for `ctx_execute_file`. + ## Configuration The jobs dir defaults to `/.pi-bgrun/jobs` when the session cwd is @@ -145,11 +208,18 @@ config file (trusted projects only) ← environment variables**. - User: `~/.pi/agent/pi-bgrun.json` - Project: `/.pi/pi-bgrun.json` +The project file is per-contributor state, not shared policy: it is read only for +a trusted project, it changes what every `bgrun` job in that checkout does, and a +digest entry runs a shell command at wake time. This repo therefore gitignores +its own; [`docs/dogfooding.md`](docs/dogfooding.md) has the setup its maintainers +run locally (completed jobs visible, a scorecard on `bun test` runs). + ```json { "adoptForeignJobs": false, "showCompletedJobs": false, "cleanupDays": 7, + "maxLogBytes": 67108864, "globalAutoClean": true, "jobsDir": "/some/other/dir" } @@ -204,15 +274,51 @@ Rules and migration notes: sweep and `bgclean all` both cover `~/.pi-bgrun/jobs` in addition to the current project's dir. +### Deprecated: machine-global jobs dir + +**Project-scoped logs are the model.** A single shared `~/.pi-bgrun/jobs` was +the old default; it is now **deprecated** and is no longer what any of the docs +lead with. Retirement is staged — nothing breaks today: + +- `PI_BGRUN_GLOBAL_DIR` and the `~/.pi-bgrun/jobs` **default are deprecated**; + they will be removed in a future major. +- **Supported for now:** an existing absolute `jobsDir` / `PI_BGRUN_DIR` keeps + working exactly as before, and a cwd with no project root still falls back to + `~/.pi-bgrun/jobs` (there is nowhere project-scoped to put it, and the + alternative — scattering logs into an arbitrary cwd — is worse). + +Why project-scoped won: + +- **Each checkout owns its logs** — no cross-project clutter, no ambiguous + `bgstatus` scope, and `bgclean` can't reach into another project's runs. +- **Reachable by project-sandboxed analysis** (`ctx_execute_file`, + `ctx_index`): logs live inside the workspace, so whole-log analysis no longer + needs a path outside it. +- **Disposable with the workspace** — delete the checkout, lose its logs. + +What changes for you, if you set a global dir on purpose: + +1. Drop the absolute `jobsDir` / `PI_BGRUN_DIR` from your config to get + `/.pi-bgrun/jobs`. +2. Planned sharing across projects is what you lose: jobs started in one + checkout are no longer visible to a session in another, and + `adoptForeignJobs` only adopts within the same jobs dir. If you need that, + keep the absolute dir — it is supported, merely no longer the recommended + default — and say so upstream if it is load-bearing for you. +3. Old logs in `~/.pi-bgrun/jobs` keep being swept (the orphan sweep and + `bgclean all` cover both dirs under the project-local default). Delete the + dir by hand once its logs are past retention. + Environment variables (same knobs, handy for one-off overrides): | Variable | Default | Description | | --- | --- | --- | | `PI_BGRUN_DIR` | `/.pi-bgrun/jobs` in repos; else `~/.pi-bgrun/jobs` | Override where job logs are stored. An absolute path is used as-is; a **relative** path resolves against the project root (see [project-local logs](#project-local-logs-default-in-repos)), falling back to `~/.pi-bgrun/jobs` when there is no project root. | -| `PI_BGRUN_GLOBAL_DIR` | `~/.pi-bgrun/jobs` | Override the machine-global jobs base — the no-project-root fallback. It is also swept under the project-local default (and is the `jobsDir` itself in the no-project-root fallback); an explicit absolute `jobsDir` is swept alone. A leading `~` or `~/` is expanded to the home dir; `~user` is not. | +| `PI_BGRUN_GLOBAL_DIR` | `~/.pi-bgrun/jobs` | **Deprecated.** Overrides the machine-global jobs base — the fallback used only when the cwd has no project root (see [deprecation](#deprecated-machine-global-jobs-dir)). A leading `~` or `~/` is expanded to the home dir; `~user` is not. | | `PI_BGRUN_FOREIGN_JOBS` | `false` | Adopt other sessions' running jobs into this session's widget and job list. Adopted jobs are polled so they leave the widget when they finish. | | `PI_BGRUN_SHOW_COMPLETED` | `false` | Include finished jobs in `bgstatus` listings by default. | | `PI_BGRUN_CLEANUP_DAYS` | `7` | Log retention for cleanup sweeps and the `bgclean` default. | +| `PI_BGRUN_MAX_LOG_BYTES` | `67108864` (64 MiB) | Byte ceiling for a job's log (stdout+stderr). `0` disables it (unlimited). See [Log size ceiling](#log-size-ceiling). | | `PI_BGRUN_GLOBAL_AUTO_CLEAN` | `true` | Set `0`/`false` to disable the automatic orphan sweep (see below). | | `PI_BGRUN_GREP_TIMEOUT_MS` | `2000` | Wall-clock budget for a `bggrep` match. A caller-supplied regex that exceeds it is aborted (its worker terminated) and reported as an error instead of hanging — see [Bounded matching](#bounded-matching). | | `PI_BGRUN_USER_CONFIG` | `~/.pi/agent/pi-bgrun.json` | Override the user-level config file path (see [Configuration](#configuration)). | diff --git a/docs/dogfooding.md b/docs/dogfooding.md new file mode 100644 index 0000000..d8e4a32 --- /dev/null +++ b/docs/dogfooding.md @@ -0,0 +1,75 @@ +# Dogfooding bgrun in this repo + +This repo's maintainers run pi-bgrun on its own test suite. The setup is a +*personal* project config, not repo policy: `/.pi/pi-bgrun.json` is read +only for a trusted project, it changes what every `bgrun` job in the checkout +does, and one of its keys runs a shell command at wake time. So it is gitignored +here — copy the example below into your own working copy if you want the same. + +```json +{ + "showCompletedJobs": true, + "digest": [ + { + "type": "test", + "match": { "command": "*bun test*" }, + "label": "bun-test", + "command": "grep -E '[0-9]+ (pass|fail)$' \"$1\" | tail -5" + } + ] +} +``` + +## What it does + +- `showCompletedJobs: true` — finished jobs stay in the widget and in + `bgstatus` instead of disappearing (the extension's default is `false`). +- `digest[0]` — a **scorecard**: at wake time, for a job whose `type` is `test` + *and* whose command matches `*bun test*`, the `command` runs with `$1` set to + the job's log path, and its stdout is appended to the wake as + `digest (bun-test): …`. Here that prints the suite's own pass/fail lines. + +`jobsDir` is intentionally absent — `/.pi-bgrun/jobs` is the default in +a repo, and the extension adds it to `.git/info/exclude` so logs never show up in +`git status`. + +## Try it + +Start the suite as a job and let the wake carry the scorecard: + +``` +bgrun(command: "bun test extension/index.test.ts", type: "test", name: "unit-tests") +``` + +The wake then carries the suite's own numbers instead of a summary the agent +has to re-derive: + +``` +finished (exit 0) … +digest (bun-test): 193 pass + 0 fail +``` + +(the scorecard is the digest command's stdout, exactly as printed — two lines +here, because `bun test` prints one per counter). + +Selection rules that make this work: entries *declaring* a `type` are considered +first and only for jobs that declared that type, and an entry's `match` must pass +as well — so `type: "test"` with a command that isn't a `bun test` run falls +through to the type-less/glob pass (and, with no entry there, gets no scorecard). + +## Overriding and unwinding + +Config layers are `defaults ← user ← project ← env`, so an environment variable +beats the file (`PI_BGRUN_SHOW_COMPLETED=0`, `PI_BGRUN_MAX_LOG_BYTES=0`). To drop +the setup, delete `.pi/pi-bgrun.json`; nothing else depends on it. + +## See also + +- README: [Digest scorecard (opt-in)](../README.md#digest-scorecard-opt-in) — the + full selector reference, presets (`go-test`, `jest`, `pytest`, `junit-xml`), and + the `custom`/`output` forms. +- The `digest-config` skill — samples a project's real logs, drafts a digest + command, and validates it against green *and* red runs before writing the file. +- The per-project nudge: until a project has a digest, bgrun mentions the option + once (a `.bgrun-used-` marker in the jobs dir records that it happened). diff --git a/docs/log-size-ceiling.md b/docs/log-size-ceiling.md new file mode 100644 index 0000000..89de06b --- /dev/null +++ b/docs/log-size-ceiling.md @@ -0,0 +1,196 @@ +# Child stdout ceiling: design rationale + +`maxLogBytes` / `PI_BGRUN_MAX_LOG_BYTES` bounds how much of a job's +stdout+stderr reaches its log file. The operator-facing contract is in the +README ([Log size ceiling](../README.md#log-size-ceiling)); this note is the +rationale a maintainer needs *before* changing the wrapper, and the record of +what was measured and rejected. + +## Problem + +The child's stdout+stderr go straight to the log fd +(`spawn("sh", ["-c", wrapper, "bgrun", command], { stdio: ["ignore", logFd, logFd], detached: true })`). +The read side is bounded (`LOG_TAIL_BYTES` for the exit marker, `LOG_READ_BYTES` +for `bgtail`/`bggrep`), but the **write side was unbounded**: a runaway job +(`yes`, a spew loop, a pathological build) fills the disk and can take the +machine down. A secondary effect: `countLogLines` streams the whole file at exit +(bounded memory, unbounded IO). + +## Constraints + +Any fix has to respect these; most of the wrapper's odd shape is one of them. + +1. The cap must live **inside the detached process tree** — pi can exit at any + time, so no parent-side streaming. A watchdog that dies with pi does not keep + the promise. +2. The `__BGRUN_EXIT__` marker must remain the **last non-empty line**. + Completion evidence is the *last* non-blank line only, so a marker that ends + up mid-file is job output that happens to contain the string. A head cap + guarantees this cheaply: the whole capped log is `cap + overhead`, well inside + the 256 KB tail window that finds it. +3. One writer, one offset — two writers into the same file corrupt it. This + includes the exit-code channel, which is why the exit code does **not** travel + through the pipe (a pipeline's `$?` is the reader's). +4. Cap only the redirected stdout/stderr, **never the command's own files**. +5. `maxLogBytes: 0` means unlimited, and takes the legacy wrapper path verbatim — + no fifo, no copier, no notices. + +## The shipped shape + +A fifo plus one copier process, all inside the detached tree: + +```sh +# argv: $1 command, $2 ecfile, $3 fifo, $4 pidfile, $5 truncation-flag file +{ sh -c "$1" 2>&1; ec=$?; ; } >"$3" & # producer; ec out-of-band +{ ; \ + } <"$3" & # cap + flag + drain +wait "$prod"; +rm -f "$2" "$3" "$4" "$5" +printf '\n__BGRUN_EXIT__%d%s\n' "$ec" "$flag" # marker last, flag attached +exit "$ec" +``` + +Points that are load-bearing: + +- **The copier caps, flags, and drains in one process.** `perl` first (unbuffered, + so the live tail is not block-lagged), then `dd iflag=fullblock`, then `head`. + Whatever variant runs, it both writes the kept bytes and consumes the rest, so + the producer is never SIGPIPE'd and the job keeps its real exit code. +- **Completion follows the command, not the stream.** The wrapper waits on the + producer's pid, then allows a short bounded grace (5 × 20 ms) for the copier to + reach EOF. A child the command backgrounded and did not wait for can hold the + fifo open indefinitely; the job must still complete — the stray's output simply + stops being logged, which is what a ceiling is for. +- **The exit code travels out-of-band** (`$2`), so the producer group can capture + it before the pipeline shape gets a say. +- **The flag rides the marker**, not the notice text: `__BGRUN_EXIT__=0 + truncated=67108864`, or `nocap=1` when `mkfifo` failed and the job ran uncapped. + Readers classify by that flag; see "Visibility" below. +- **Staging paths are hardened**: they are `rm -f`'d before use, then written + under `set -C` (noclobber) with `umask 077`, so a planted file or symlink in the + jobs dir cannot be written through. The log itself is opened `0600`, `wx`. +- **`mkfifo` failure degrades loudly**: the job runs uncapped, the log says so + (`__BGRUN_NOCAP__`), and the marker carries `nocap=1`. Losing output is worse + than losing the bound, but "uncapped" must not look like "output was small". + +Accepted price: the log keeps the **first** `cap` bytes, not the tail. There is +no portable in-tree *tail* cap — a ring buffer needs a helper binary, and a +circular/rewritten file breaks every existing reader (marker-at-tail, `bgtail`, +`bggrep`). A job that emits more than 64 MiB is almost always a runaway, so the +head is the useful part. Revisit only if tail retention turns out to matter in +practice. + +## Why not the obvious counters + +Measured on macOS 25.6 with BSD `head`, while the mechanism was being chosen: + +| detection idea | result | +| --- | --- | +| bytes left after `head -c CAP` (`cat \| wc -c`) | **silently 0** whenever the overshoot is smaller than `head`'s read buffer: `CAP=100 N=101` → 0, `CAP=1000 N=1500` → 0, `CAP=8192 N=8193` → 0; only `CAP=65536 N=65537` → 1. `head` over-reads into its buffer and discards the excess. | +| `wc -c bytes +__BGRUN_NOCAP__ log ceiling unavailable (mkfifo failed, so this job ran uncapped) +``` + +- The leading `\n` is required: without it the notice glues onto the last kept + byte, corrupting line counts and `bggrep` line numbers. +- Both prefixes are reserved `__BGRUN_*__` lines, filtered from content readers + exactly like the exit marker, and the *notice identity* is decided by the + marker's flag — never by matching text. A command that echoes a notice-shaped + line therefore cannot make its own log look capped, nor have its own output + discounted as wrapper bookkeeping. +- `countLogLines` drops the whole trailing wrapper block (notice + marker) using + the flag, so "N lines" counts command output only, and the wake's last-line pick + never reports the notice as the job's last output. +- Every agent-facing surface is labelled instead: the wake's Stats line gains + `log truncated at `, `bgtail`/`bggrep` append a note and report + `truncatedAtBytes`, and a configured digest scorecard is **skipped** rather than + scored against a log that lost its end (summaries and failure lists live at the + end, so the numbers would be confidently wrong). + +## Reader bounds + +- A capped log is always slightly **larger** than the cap — notices, marker, and + the separator newlines. So the search-window maximum is the ceiling **plus the + wrapper's overhead** (`readWindowMax()`), not the ceiling itself: clamping to + the ceiling made the documented "widen it to the whole capped log" unreachable. +- A byte window is not a sufficient bound on its own: 64 MiB of one-character + lines is ~33 M line strings, measured at >3 GB of RSS — an OOM on exactly the + log class the ceiling exists for. A scan therefore materializes at most its last + `LOG_SCAN_LINES_MAX` (500 000) lines (~40 MB), and says so when that bit: + `only the last 500,000 lines of that window were searched`. A trimmed window is + never allowed to report a plain "none". +- `countLogLines` takes its tail pread offset from `fstatSync(fd).size` and + refuses to count (returns `null`) past the window bound, so bounding the scan + can never misplace the marker read or drop the count for capped jobs. + +## Config + +- `maxLogBytes` (number, bytes) plus `PI_BGRUN_MAX_LOG_BYTES`; default **64 MiB**, + `0` = unlimited. +- Read at spawn time, so an edit affects the next job only. +- Normalized to an integer in `1 … Number.MAX_SAFE_INTEGER` before it is ever + interpolated into the shell: a fractional value previously truncated to `0` + (= unlimited, silently), and a value above `MAX_SAFE_INTEGER` reached `sh` as + `1e+21`, which the copier rejects while still consuming the stream — i.e. the + log came out empty. + +## Defects already paid for + +Each of these was reproduced before it was fixed, and each has a regression test. +They are listed because they explain why the wrapper is not simpler. + +| symptom | what the shape does now | +| --- | --- | +| `head -c` alone SIGPIPE'd the producer (exit `141`) | copier drains past the cap | +| `mkfifo` unavailable ran uncapped *and silently* | `__BGRUN_NOCAP__` notice + `nocap=1` | +| truncation inferable from printable text | flag in the marker; reserved notice lines | +| `sleep 30 & echo done` produced no wake for 30 s | wait on the command's pid + bounded grace | +| a ceiling of `1e21` emptied the log; `0.5` disabled the cap | integer normalization, floor of 1 | +| the widest window could not cover a capped log | window max = ceiling + overhead | +| a 64 MiB window of tiny lines cost >3 GB of RSS | 500k-line scan bound + labelled note | +| the line bound fired on logs that fit (false caveat) | only report a trim when bytes were actually dropped | +| `countLogLines` bounded its scan by the cap (dropped the count for capped jobs) | bound by the window max; `fstatSync` for the tail offset | +| stale staging files were never swept; sweeping by mtime deleted a *running* job's fifo | sweep by mtime, skipping stems whose `.pid` is a live process | + +## Rejected alternatives + +- **`head -c` without a drain**: producer dies on SIGPIPE (`141`) — hostile to + legitimately verbose builds. +- **pi-side watchdog** (stat running logs, kill and truncate the tail): a soft + bound only while pi lives; the overshoot is write-rate × poll interval, and it + is unbounded if pi died. Keeps the tail, loses the promise. +- **`ulimit -f`**: caps *every* file the job writes (artifacts, downloads) and + kills it (`SIGXFSZ`/`153`). Opt-in material, not a default. +- **Document-and-trim-finished-logs**: no bound at all while the job runs. +- **`dd bs=1 count=CAP` as the front stage**: exact, but one read syscall per + byte (64 MiB = 64 M syscalls) — unusable. +- **`process.execPath` as the reader**: exact count with no coreutils/BSD + variance, but it adds a runtime dependency to the spawn path and still needs + the detached-tree plumbing; the fifo uses only POSIX `sh` + `mkfifo` + a + coreutils/`dd`/`head` copier. + +## Tests + +The suite pins the contract, not the plumbing: exactness at the boundary +(`cap + 1` is capped, exactly `cap` is not), exit-code preservation under +megabytes of overshoot, no staging files left behind, stale staging reclaimed +while a running job's staging survives, the notice unfakeable by job output, +`nocap` visibility, config normalization (`0`, fractional, over-MAX_SAFE), +reader labelling and `truncatedAtBytes`, and the window and line bounds with +their caveats. + +Run with `bun test extension/index.test.ts` (what CI runs) and, by hand, +`node --test extension/index.test.ts` — the second brings the V8/worker_threads +side of `bggrep`'s bounded matching, which Bun does not exercise. diff --git a/extension/index.test.ts b/extension/index.test.ts index cae199d..bd82996 100644 --- a/extension/index.test.ts +++ b/extension/index.test.ts @@ -70,9 +70,18 @@ after(() => { }); // Isolate the machine-global jobs dir for the whole file so tests never read -// from or delete the real ~/.pi-bgrun/jobs. globalJobsDir() reads this per call. -const TEST_GLOBAL_JOBS_DIR = mkTmp("pi-bgrun-global-"); -process.env.PI_BGRUN_GLOBAL_DIR = TEST_GLOBAL_JOBS_DIR; +// from or delete the real ~/.pi-bgrun/jobs. A fake HOME is enough: the extension +// resolves home through its own HOME-first homeDir(), because Bun's +// os.homedir() ignores $HOME. PI_BGRUN_GLOBAL_DIR is left unset so a stray real +// one cannot point tests out of the sandbox. +// The extension resolves home HOME-first (Bun's os.homedir() ignores $HOME), so +// assertions must use the same rule production does — otherwise a suite that +// pins HOME compares against the developer's real home. +const homeDir = () => process.env.HOME || homedir(); +const TEST_FAKE_HOME = mkTmp("pi-bgrun-home-"); +process.env.HOME = TEST_FAKE_HOME; +delete process.env.PI_BGRUN_GLOBAL_DIR; +const TEST_GLOBAL_JOBS_DIR = join(TEST_FAKE_HOME, ".pi-bgrun", "jobs"); // Isolate the user config too: a real ~/.pi/agent/pi-bgrun.json could carry // adoptForeignJobs / digest / globalAutoClean settings that change results. @@ -2317,7 +2326,7 @@ test("resolveJobsDirPath: expands a leading ~ to the home dir (not project-local const scratch = mkTmp("pi-bgrun-scratch-"); try { const r = mod.resolveJobsDirPath("~/.pi-bgrun/jobs", { cwd: scratch }); - assert.equal(r.dir, join(homedir(), ".pi-bgrun", "jobs")); + assert.equal(r.dir, join(homeDir(), ".pi-bgrun", "jobs")); assert.equal(r.projectLocal, false); } finally { rmSync(scratch, { recursive: true, force: true }); @@ -2331,11 +2340,11 @@ test("resolveJobsDirPath: expands only a leading ~ (or ~/) — ~user and embedde mkdirSync(join(proj, ".git"), { recursive: true }); // Bare ~ → home dir (absolute, not project-local). const bare = mod.resolveJobsDirPath("~", { cwd: proj }); - assert.equal(bare.dir, homedir()); + assert.equal(bare.dir, homeDir()); assert.equal(bare.projectLocal, false); // ~/x → join(home, "x"). const sub = mod.resolveJobsDirPath("~/x", { cwd: proj }); - assert.equal(sub.dir, join(homedir(), "x")); + assert.equal(sub.dir, join(homeDir(), "x")); assert.equal(sub.projectLocal, false); // ~user/x is NOT expanded — treated as a relative path under the root. const user = mod.resolveJobsDirPath("~user/x", { cwd: proj }); @@ -2356,7 +2365,7 @@ test("resolveJobsDirPath: PI_BGRUN_GLOBAL_DIR is tilde-expanded", async () => { try { await withEnv("PI_BGRUN_GLOBAL_DIR", "~/.pi-bgrun/jobs", () => { const r = mod.resolveJobsDirPath(undefined, { cwd: scratch }); - assert.equal(r.dir, join(homedir(), ".pi-bgrun", "jobs")); + assert.equal(r.dir, join(homeDir(), ".pi-bgrun", "jobs")); assert.equal(r.projectLocal, false); }); } finally { @@ -2370,7 +2379,7 @@ test("resolveJobsDirPath: without PI_BGRUN_GLOBAL_DIR the global default is ~/.p try { await withEnv("PI_BGRUN_GLOBAL_DIR", undefined, () => { const r = mod.resolveJobsDirPath(undefined, { cwd: scratch }); - assert.equal(r.dir, join(homedir(), ".pi-bgrun", "jobs")); + assert.equal(r.dir, join(homeDir(), ".pi-bgrun", "jobs")); assert.equal(r.projectLocal, false); }); } finally { @@ -3518,9 +3527,11 @@ test("wake message: Stats line (duration + line count) sits between Command: and ); await waitForWakes(wakes, 1); const wake = wakes[0].text; - // Duration (0.0s for an instant job) + the command's OWN line count — the - // appended exit marker and its blank separator are excluded. - assert.match(wake, /Stats: 0\.0s, 1 lines/); + // Stats carries the command's OWN line count — the appended exit marker, + // its blank separator and (when capped) the truncation notice are excluded. + // The duration is asserted by SHAPE only: it depends on machine speed and on + // how many processes the wrapper spawns, so pinning "0.0s" pins the host. + assert.match(wake, /Stats: \d+\.\d+s, 1 lines/); const cmdIdx = wake.indexOf("Command: "); const statsIdx = wake.indexOf("Stats: "); const lastIdx = wake.indexOf("Last output: "); @@ -5914,16 +5925,24 @@ test("bggrep: a pathological regex returns within the budget instead of hanging" const { pi, tools, ctx } = makeFakePi(); await loadExtension(pi); const id = `patho-${Math.floor(Date.now() / 1000)}-${process.pid}`; - // A long run of `a` then `b` is the classic catastrophic-backtracking input - // for `^(a+)+$`. Under Node/V8 this would lock the thread; the worker must - // abort at the 2s budget. Under Bun's engine it completes quickly. - writeFileSync(join(dir, `${id}.log`), "a".repeat(60_000) + "b\n"); + // Classic catastrophic-backtracking input for `^(a+)+$` — and the failing + // character has to sit INSIDE the per-line cap (BGGREP_LINE_CAP = 10 000), + // or the pre-match truncation removes it and the pattern matches instantly + // (measured: a 60 000-char line whose `!` lands past the cap matches in 0ms + // on BOTH engines, which made this test vacuous). + writeFileSync( + join(dir, `${id}.log`), + "a".repeat(9_000) + "!" + "a".repeat(50_000) + "\n", + ); const t0 = Date.now(); const res = await tools .get("bggrep")! .execute("c", { id, pattern: "^(a+)+$" }, undefined, undefined, ctx); const elapsed = Date.now() - t0; assert.ok(elapsed < 5_000, `bounded by the budget (${elapsed}ms)`); + // Engine-dependent by nature: V8 backtracks here and the budget must trip + // (see the abort-path test for that branch); JSC answers in ~250ms without + // backtracking. Both are acceptable — hanging is not. assert.ok( res.isError === true || typeof res.content[0].text === "string", "returns a result (no hang, no throw)", @@ -6029,3 +6048,963 @@ test("bgclean all: a TERMINAL exit marker reclaims a finished log despite a reus rmSync(dir, { recursive: true, force: true }); } }); + +// ── log size ceiling (maxLogBytes) ───────────────────────────────────────── +// +// A job that writes well past the caps used below: 200 numbered lines +// (~6.6 KB) plus a non-zero exit code, so the marker and the exit code are +// exercised through the capped pipeline too. + +const SPEW_LINES = + 'i=0; while [ $i -lt 200 ]; do echo "line-$i-aaaaaaaaaaaaaaaaaaaaaa"; i=$((i+1)); done; exit 3'; + +function startedId(res: { content: { text: string }[] }): string { + return (res.content[0].text as string).match(/^started: ([^\n]+)/)![1]; +} + +test("bgrun: maxLogBytes keeps the first N bytes, notes the truncation, preserves the exit code", async () => { + await withEnv("PI_BGRUN_MAX_LOG_BYTES", "1000", async () => { + await withJobsDir(async (dir, h) => { + const { wakes, tools, ctx } = h; + const res = await tools.get("bgrun")!.execute( + "call-cap-sn", + { command: SPEW_LINES, name: "spew" }, + undefined, + undefined, + ctx, + ); + const id = startedId(res); + await waitForWakes(wakes, 1); + + const log = readFileSync(join(dir, `${id}.log`), "utf8"); + // The wrapped log fd is written by ONE writer at a time, so the notice + // starts exactly at the cap: 1000 bytes of command output, then "\n". + const noticeAt = log.indexOf( + "\n__BGRUN_TRUNC__ output truncated: kept the first 1000 bytes\n", + ); + assert.equal(noticeAt, 1000, "notice follows exactly the capped bytes"); + assert.ok(log.startsWith("line-0-"), "the first bytes are kept"); + assert.ok(!log.includes("line-199-"), "output past the cap was dropped"); + // Marker still last, carrying BOTH the real exit code and the truncation + // flag — the flag is what readers trust, since a command can print any + // notice text but only the last marker counts. + const nonBlank = log.split("\n").filter((l) => l.trim().length > 0); + assert.equal( + nonBlank[nonBlank.length - 1], + "__BGRUN_EXIT__=3 truncated=1000", + ); + assert.match(wakes[0].text, /finished \(exit 3\)/); + }); + }); +}); + +test("bgrun: the truncation notice is not job output — not counted, not the last line", async () => { + await withEnv("PI_BGRUN_MAX_LOG_BYTES", "1000", async () => { + await withJobsDir(async (dir, h) => { + const { wakes, tools, ctx } = h; + const res = await tools.get("bgrun")!.execute( + "call-cap-stats", + { command: SPEW_LINES, name: "spew" }, + undefined, + undefined, + ctx, + ); + const id = startedId(res); + await waitForWakes(wakes, 1); + + const log = readFileSync(join(dir, `${id}.log`), "utf8"); + // Lines the caller can still READ: the capped region. Counting from the + // file (not from the implementation) keeps this honest — a trailing + // partial line is a line, exactly as the counter treats it. + const regionLines = log.slice(0, 1000).split("\n").length; + assert.match(wakes[0].text, new RegExp(`, ${regionLines} lines`)); + assert.match(wakes[0].text, /Last output: line-\d+-a+$/m); + assert.ok( + !wakes[0].text.includes("Last output: __BGRUN_"), + "the notice is never reported as the job's last line", + ); + }); + }); +}); + +test("bgrun: a job that outruns the cap by megabytes still finishes with its own exit code", async () => { + await withEnv("PI_BGRUN_MAX_LOG_BYTES", "1000", async () => { + await withJobsDir(async (dir, h) => { + const { wakes, tools, ctx } = h; + // ~1.3 MB, far more than the pipe buffers between producer and reader — + // the drain must keep the producer alive (no SIGPIPE/141) and the job's + // own exit code must survive the pipeline. + const res = await tools.get("bgrun")!.execute( + "call-cap-flood", + { command: "seq 1 200000; exit 0", name: "flood" }, + undefined, + undefined, + ctx, + ); + const id = startedId(res); + await waitForWakes(wakes, 1); + + const log = readFileSync(join(dir, `${id}.log`), "utf8"); + assert.equal(log.indexOf("\n__BGRUN_TRUNC__ output truncated"), 1000); + assert.match(log, /__BGRUN_EXIT__=0 truncated=1000\n$/); + assert.match(wakes[0].text, /finished \(exit 0\)/); + }); + }); +}); + +test("bgrun: a log at exactly the cap is not called truncated; one byte over is", async () => { + await withEnv("PI_BGRUN_MAX_LOG_BYTES", "4", async () => { + await withJobsDir(async (dir, h) => { + const { wakes, tools, ctx } = h; + const run = async (command: string) => { + const res = await tools.get("bgrun")!.execute( + command, + { command }, + undefined, + undefined, + ctx, + ); + return startedId(res); + }; + + // "abc\n" is exactly 4 bytes — nothing was dropped. + const atCap = await run("printf 'abc\\n'"); + // "abcd\n" is 5 — the trailing newline is the byte that had to go. + const overCap = await run("printf 'abcd\\n'"); + await waitForWakes(wakes, 2); + + const exact = readFileSync(join(dir, `${atCap}.log`), "utf8"); + assert.equal(exact, "abc\n\n__BGRUN_EXIT__=0\n"); + assert.ok(!exact.includes("truncated"), "no notice at the boundary"); + + const over = readFileSync(join(dir, `${overCap}.log`), "utf8"); + assert.ok( + over.includes( + "\n__BGRUN_TRUNC__ output truncated: kept the first 4 bytes\n", + ), + "one byte past the cap is truncated", + ); + assert.match(over, /__BGRUN_EXIT__=0 truncated=4\n$/); + assert.ok(over.startsWith("abcd"), "kept the first 4 bytes"); + }); + }); +}); + +test("bgrun: maxLogBytes 0 leaves the log uncapped", async () => { + await withEnv("PI_BGRUN_MAX_LOG_BYTES", "0", async () => { + await withJobsDir(async (dir, h) => { + const { wakes, tools, ctx } = h; + const res = await tools.get("bgrun")!.execute( + "call-cap-off", + { command: SPEW_LINES, name: "spew" }, + undefined, + undefined, + ctx, + ); + const id = startedId(res); + await waitForWakes(wakes, 1); + + const log = readFileSync(join(dir, `${id}.log`), "utf8"); + assert.ok(log.includes("line-199-"), "the whole output is kept"); + assert.ok(!log.includes("truncated"), "no notice when uncapped"); + assert.match(log, /__BGRUN_EXIT__=3\n$/); + }); + }); +}); + +test("bgrun: a capped job leaves no staging files behind", async () => { + await withEnv("PI_BGRUN_MAX_LOG_BYTES", "1000", async () => { + await withJobsDir(async (dir, h) => { + const { wakes, tools, ctx } = h; + await tools.get("bgrun")!.execute( + "call-cap-staging", + { command: SPEW_LINES, name: "spew" }, + undefined, + undefined, + ctx, + ); + await waitForWakes(wakes, 1); + + // The exit-code, fifo, liveness and truncation-flag files are the + // wrapper's own scratch — it removes them before printing the marker, so + // a wake never leaves a `.tmp-*` in the jobs dir. + const strays = readdirSync(dir).filter((n) => n.startsWith(".tmp-")); + assert.deepEqual(strays, []); + }); + }); +}); + +test("bgclean: stale staging files (.ec/.fifo/.pid/.trunc) are reclaimed, unrelated .tmp-* are not", async () => { + const dir = mkdtempSync(join(tmpdir(), "pi-bgrun-test-")); + process.env.PI_BGRUN_DIR = dir; + try { + const h = makeFakePi(); + await loadExtension(h.pi); + const stale = Date.now() - 30 * 24 * 60 * 60 * 1000; + const ours = [ + ".tmp-spew-1-abcd.ec", + ".tmp-spew-1-abcd.fifo", + ".tmp-spew-1-abcd.pid", + ".tmp-spew-1-abcd.trunc", + ".tmp-spew-1-abcd.log", + ]; + const foreign = ".tmp-someone-else.txt"; + for (const name of [foreign, ...ours]) { + writeFileSync(join(dir, name), ""); + utimesSync(join(dir, name), new Date(stale), new Date(stale)); + } + + await h.tools + .get("bgclean")! + .execute("call-cap-sweep", { days: 7, all: true }, undefined, undefined, h.ctx); + + for (const name of ours) { + assert.ok(!existsSync(join(dir, name)), `${name} reclaimed`); + } + assert.ok(existsSync(join(dir, foreign)), "an unrelated .tmp-* is left alone"); + } finally { + delete process.env.PI_BGRUN_DIR; + rmSync(dir, { recursive: true, force: true }); + } +}); + +test("bgtail/bggrep work on a capped log and only see what was kept", async () => { + await withEnv("PI_BGRUN_MAX_LOG_BYTES", "1000", async () => { + await withJobsDir(async (_dir, h) => { + const { wakes, tools, ctx } = h; + const bgrun = tools.get("bgrun")!; + const bgtail = tools.get("bgtail")!; + const bggrep = tools.get("bggrep")!; + + // "seq 1 400" fills the 1000-byte window exactly through line 277. + const res = await bgrun.execute( + "call-cap-read", + { command: "seq 1 400", name: "seq" }, + undefined, + undefined, + ctx, + ); + const id = startedId(res); + await waitForWakes(wakes, 1); + + const grep1 = await bggrep.execute( + "call-cap-read", + { id, pattern: "^1$" }, + undefined, + undefined, + ctx, + ); + assert.match(grep1.content[0].text as string, /L1: 1/); + + const grep400 = await bggrep.execute( + "call-cap-read", + { id, pattern: "^400$" }, + undefined, + undefined, + ctx, + ); + assert.ok( + !/L\d+: 400/.test(grep400.content[0].text as string), + "output past the cap is not searchable — it was never written", + ); + + const tail = await bgtail.execute( + "call-cap-read", + { id, lines: 3 }, + undefined, + undefined, + ctx, + ); + const tailText = tail.content[0].text as string; + // The last 3 lines of what was KEPT (277 is the cap boundary), followed + // by the truncation label — the wrapper's raw notice line stays filtered. + assert.match( + tailText, + /275\n276\n277\n\n\(log truncated at 1000 bytes/, + ); + assert.ok( + !tailText.includes("[pi-bgrun] output truncated"), + "the raw notice line is not shown as content", + ); + }); + }); +}); + +test("resolveConfig: maxLogBytes accepts 0 (unlimited) and ignores blank or invalid values", async () => { + const mod = await loadModule(); + const envCases: [string | undefined, unknown][] = [ + [undefined, 67108864], + ["0", 0], + ["2048", 2048], + ["", 67108864], // a blank env var must not silently disable the cap + ["nonsense", 67108864], + ["-5", 67108864], + ]; + for (const [value, expected] of envCases) { + await withEnv("PI_BGRUN_MAX_LOG_BYTES", value, () => { + assert.equal( + mod.resolveConfig({ isProjectTrusted: () => false }).maxLogBytes, + expected, + `PI_BGRUN_MAX_LOG_BYTES=${JSON.stringify(value)}`, + ); + }); + } + + // The config-file layer: a non-negative number wins over the default; a + // negative one or a string is ignored rather than trusted. + const cfgFile = join(mkdtempSync(join(tmpdir(), "pi-bgrun-test-")), "user.json"); + try { + for (const [value, expected] of [ + [4096, 4096], + [-1, 67108864], + ["4096", 67108864], + ] as const) { + writeFileSync(cfgFile, JSON.stringify({ maxLogBytes: value })); + await withEnv("PI_BGRUN_USER_CONFIG", cfgFile, () => { + assert.equal( + mod.resolveConfig({ isProjectTrusted: () => false }).maxLogBytes, + expected, + `config maxLogBytes=${JSON.stringify(value)}`, + ); + }); + } + } finally { + rmSync(dirname(cfgFile), { recursive: true, force: true }); + } +}); + +// ── truncation is visible to the agent, not just on disk ─────────────────── + +test("formatBytes / parseCapStatus: the cap comes from the marker, never from printable text", async () => { + const mod = await loadModule(); + assert.equal(mod.formatBytes(900), "900 bytes"); + assert.equal(mod.formatBytes(1000), "1000 bytes"); + assert.equal(mod.formatBytes(1536), "1.5 KiB"); + assert.equal(mod.formatBytes(67108864), "64 MiB"); + + // The wrapper's own marker, last, carries the flag. + assert.deepEqual( + mod.parseCapStatusFromContent( + "out\n\n__BGRUN_TRUNC__ output truncated: kept the first 1000 bytes\n\n__BGRUN_EXIT__=0 truncated=1000\n", + ), + { kind: "truncated", bytes: 1000 }, + ); + assert.equal( + mod.parseTruncationFromContent( + "out\n\n__BGRUN_TRUNC__ output truncated: kept the first 1000 bytes\n\n__BGRUN_EXIT__=0 truncated=1000\n", + ), + 1000, + ); + // A ceiling that could not be installed is reported too, and is NOT a cap. + assert.deepEqual( + mod.parseCapStatusFromContent( + "out\n__BGRUN_NOCAP__ log ceiling unavailable (mkfifo failed, so this job ran uncapped)\n\n__BGRUN_EXIT__=0 nocap=1\n", + ), + { kind: "ceiling-failed" }, + ); + // A running log, a plain marker, and any printable imitation of the notice + // are not evidence of truncation. This is the direction that used to be + // forgeable: the notice used to be believed purely on position + text. + assert.equal( + mod.parseTruncationFromContent( + "__BGRUN_TRUNC__ output truncated: kept the first 1000 bytes\n", + ), + null, + ); + assert.equal(mod.parseTruncationFromContent("boom\n__BGRUN_EXIT__=1\n"), null); + assert.equal( + mod.parseTruncationFromContent("x\n__BGRUN_TRUNC__ output truncated: kept the first 999 bytes\n\n__BGRUN_EXIT__=0\n"), + null, + "a notice without the marker flag is not a cap", + ); + assert.ok(mod.isWrapperLine("__BGRUN_TRUNC__ anything"), "namespace is reserved"); + assert.ok(!mod.isWrapperLine("[pi-bgrun] output truncated"), "old text is job output"); +}); + +test("wake: a capped job says so in the Stats line; an uncapped one does not", async () => { + const run = async (cap: string, command: string) => { + let wake = ""; + await withEnv("PI_BGRUN_MAX_LOG_BYTES", cap, async () => { + await withJobsDir(async (_dir, h) => { + await h.tools + .get("bgrun")! + .execute("call-wake-cap", { command, name: "j" }, undefined, undefined, h.ctx); + await waitForWakes(h.wakes, 1); + wake = h.wakes[0].text; + }); + }); + return wake; + }; + + const capped = await run("1000", SPEW_LINES); + assert.match(capped, /Stats: [\d.]+s, [\d,]+ lines, log truncated at 1000 bytes/); + + const plain = await run("1000000", "printf 'hello\\n'"); + assert.ok( + !plain.includes("log truncated"), + "no truncation claim for a log inside the cap", + ); + assert.match(plain, /Stats: [\d.]+s, 1 lines/); +}); + +test("wake digest: a scorecard is skipped, not misreported, when the log was capped", async () => { + const { dir, proj, home } = setupDigestEnv(); + try { + writeJson(join(proj, ".pi", "pi-bgrun.json"), { + digest: [{ label: "cap", command: "echo digest-ran" }], + }); + + await withEnv("PI_BGRUN_MAX_LOG_BYTES", "1000", async () => { + const capped = await runDigestJob(proj, { + command: SPEW_LINES, + type: "test", + }); + const line = digestLineOf(capped); + assert.ok(line, "the digest line is still present"); + assert.match(line!, /^digest \(cap\): skipped — the log was truncated at 1000 bytes/); + assert.ok( + !capped.includes("digest-ran"), + "the scorecard never ran against a truncated log", + ); + }); + + // Under the cap the scorecard runs exactly as before. + const plain = await runDigestJob(proj, { + command: "printf 'hello\\n'", + type: "test", + }); + assert.match(digestLineOf(plain)!, /^digest \(cap\): digest-ran$/); + } finally { + teardownDigestEnv(dir, proj, home); + } +}); + +test("bgtail/bggrep: a capped log is labelled, and carries truncatedAtBytes", async () => { + await withEnv("PI_BGRUN_MAX_LOG_BYTES", "1000", async () => { + await withJobsDir(async (_dir, h) => { + const { wakes, tools, ctx } = h; + const bgrun = tools.get("bgrun")!; + const bgtail = tools.get("bgtail")!; + const bggrep = tools.get("bggrep")!; + + const res = await bgrun.execute( + "call-read-cap", + { command: "seq 1 400", name: "seq" }, + undefined, + undefined, + ctx, + ); + const id = startedId(res); + await waitForWakes(wakes, 1); + + const tail = await bgtail.execute( + "call-read-cap", + { id, lines: 3 }, + undefined, + undefined, + ctx, + ); + assert.match( + tail.content[0].text as string, + /log truncated at 1000 bytes .*not the run's real end/, + ); + assert.equal(tail.details.truncatedAtBytes, 1000); + + // The dangerous case: failures past the cap look like "no failures". + const none = await bggrep.execute( + "call-read-cap", + { id, pattern: "^400$" }, + undefined, + undefined, + ctx, + ); + assert.match(none.content[0].text as string, /— none/); + assert.match( + none.content[0].text as string, + /output past the cap was never written and was not searched/, + ); + assert.equal(none.details.truncatedAtBytes, 1000); + }); + }); +}); + +test("bgtail/bggrep: no truncation label on an uncapped log", async () => { + await withJobsDir(async (_dir, h) => { + const { wakes, tools, ctx } = h; + const bgrun = tools.get("bgrun")!; + const bgtail = tools.get("bgtail")!; + const bggrep = tools.get("bggrep")!; + + const res = await bgrun.execute( + "call-read-plain", + { command: "printf 'line1\\nline2\\n'", name: "plain" }, + undefined, + undefined, + ctx, + ); + const id = startedId(res); + await waitForWakes(wakes, 1); + + const tail = await bgtail.execute( + "call-read-plain", + { id, lines: 2 }, + undefined, + undefined, + ctx, + ); + assert.ok(!(tail.content[0].text as string).includes("truncated")); + assert.equal(tail.details.truncatedAtBytes, undefined); + + const grep = await bggrep.execute( + "call-read-plain", + { id, pattern: "line1" }, + undefined, + undefined, + ctx, + ); + assert.ok(!(grep.content[0].text as string).includes("truncated")); + assert.equal(grep.details.truncatedAtBytes, undefined); + }); +}); + +test("bgtail/bggrep: a log bigger than the 2 MB read window says it was only partly searched", async () => { + await withJobsDir(async (_dir, h) => { + const { wakes, tools, ctx } = h; + const bgrun = tools.get("bgrun")!; + const bgtail = tools.get("bgtail")!; + const bggrep = tools.get("bggrep")!; + + // ~2.7 MB — past LOG_READ_BYTES, so both readers see only the tail of it. + const res = await bgrun.execute( + "call-window", + { command: "seq 1 400000", name: "big" }, + undefined, + undefined, + ctx, + ); + const id = startedId(res); + await waitForWakes(wakes, 1); + + const tail = await bgtail.execute( + "call-window", + { id, lines: 3 }, + undefined, + undefined, + ctx, + ); + assert.match( + tail.content[0].text as string, + /searched the last 2 MiB of [\d.]+ MiB — the earlier bytes were not searched/, + ); + + // "— none" on a >2 MB log must not read as "no failures anywhere". + const grep = await bggrep.execute( + "call-window", + { id, pattern: "^1$" }, + undefined, + undefined, + ctx, + ); + assert.match(grep.content[0].text as string, /— none/); + assert.match( + grep.content[0].text as string, + /the earlier bytes were not searched/, + ); + }); +}); + +test("bgtail/bggrep: no window caveat on a small log", async () => { + await withJobsDir(async (_dir, h) => { + const { wakes, tools, ctx } = h; + const bgrun = tools.get("bgrun")!; + const res = await bgrun.execute( + "call-window-small", + { command: "printf 'a\\nb\\n'", name: "small" }, + undefined, + undefined, + ctx, + ); + const id = startedId(res); + await waitForWakes(wakes, 1); + + for (const tool of ["bgtail", "bggrep"] as const) { + const out = await tools.get(tool)!.execute( + "call-window-small", + tool === "bgtail" ? { id, lines: 2 } : { id, pattern: "a" }, + undefined, + undefined, + ctx, + ); + assert.ok( + !(out.content[0].text as string).includes("searched the last"), + `${tool}: no window caveat under the read bound`, + ); + } + }); +}); + +test("bggrep/bgtail: `bytes` widens the search window without widening the output", async () => { + await withJobsDir(async (_dir, h) => { + const { wakes, tools, ctx } = h; + const bgrun = tools.get("bgrun")!; + const bggrep = tools.get("bggrep")!; + const bgtail = tools.get("bgtail")!; + + // The marker is written FIRST, then ~2.7 MB of lines — so the default + // 2 MiB window cannot see it, and a widened window can. + const res = await bgrun.execute( + "call-bytes", + { command: "echo EARLY-MARKER; seq 1 400000", name: "wide" }, + undefined, + undefined, + ctx, + ); + const id = startedId(res); + await waitForWakes(wakes, 1); + + const narrow = await bggrep.execute( + "call-bytes", + { id, pattern: "EARLY-MARKER" }, + undefined, + undefined, + ctx, + ); + assert.match(narrow.content[0].text as string, /— none/); + assert.match(narrow.content[0].text as string, /pass a larger `bytes`/); + assert.equal(narrow.details.windowBytes, 2 * 1024 * 1024); + + const wide = await bggrep.execute( + "call-bytes", + { id, pattern: "EARLY-MARKER", bytes: 8 * 1024 * 1024 }, + undefined, + undefined, + ctx, + ); + assert.match(wide.content[0].text as string, /L1: EARLY-MARKER/); + assert.equal(wide.details.windowBytes, 8 * 1024 * 1024); + // The claim that matters: scanning more does NOT mean returning more. + assert.ok( + (wide.content[0].text as string).length < 9000, + "output stays under the condenser cap", + ); + + // A window bigger than any job could write is clamped to the bound in force + // — the ceiling plus the wrapper's overhead, so a capped log is coverable. + const mod = await loadModule(); + const huge = await bggrep.execute( + "call-bytes", + { id, pattern: "EARLY-MARKER", bytes: 1e15 }, + undefined, + undefined, + ctx, + ); + assert.equal(huge.details.windowBytes, mod.readWindowMax()); + + // bgtail: changing the window is a different VIEW, not appended output — + // it must reset to a full tail instead of claiming "+N new lines". + const first = await bgtail.execute( + "call-bytes", + { id, lines: 3 }, + undefined, + undefined, + ctx, + ); + assert.match(first.content[0].text as string, /400000/); + const rewidened = await bgtail.execute( + "call-bytes", + { id, lines: 3, bytes: 8 * 1024 * 1024 }, + undefined, + undefined, + ctx, + ); + assert.match( + rewidened.content[0].text as string, + /search window changed since last read/, + ); + assert.ok( + !rewidened.content[0].text.includes("new lines since last read"), + "no bogus delta after a window change", + ); + }); +}); + +test("clampReadWindow: default, explicit, garbage, and ceiling", async () => { + const mod = await loadModule(); + assert.equal(mod.clampReadWindow(undefined), 2097152); + assert.equal(mod.clampReadWindow(0), 2097152); + assert.equal(mod.clampReadWindow(-1), 2097152); + assert.equal(mod.clampReadWindow(Number.NaN), 2097152); + assert.equal(mod.clampReadWindow("8192"), 2097152); + assert.equal(mod.clampReadWindow(65536), 65536); + assert.equal(mod.clampReadWindow(65536.7), 65536); + // The bound is the ceiling PLUS the wrapper overhead, so the widest window can + // actually cover a log the cap produced. + assert.equal(mod.clampReadWindow(1e12), mod.readWindowMax()); + assert.ok(mod.readWindowMax() > 67108864); +}); + +test("bggrep: the budget terminates a worker that is stuck mid-match (abort path)", async () => { + const mod: any = await loadModule(); + // An input-driven catastrophic pattern cannot test this portably: V8 + // backtracks exponentially where JSC answers in constant time (measured: + // `^(a+)+$` over 100 "a"s + "!" hangs Node past 10s and returns on Bun in + // ~250ms). So the stall is injected instead — a worker body that never + // returns — and the only assertion is that the budget still ends it. That is + // exactly what a runaway regex looks like to the parent thread. + const stall = 'require("node:worker_threads"); for (;;) {}'; + const t0 = Date.now(); + const outcome = await mod.matchLinesWithBudget( + "a", + ["a".repeat(50)], + 10, + 300, + stall, + ); + const elapsed = Date.now() - t0; + assert.equal(outcome.kind, "timeout", "a stuck worker is reported as a timeout"); + assert.ok(elapsed < 3_000, `terminated promptly (${elapsed}ms)`); +}); + +// ── the sync fallback (bggrep without worker_threads) ────────────────────── +// +// Unreachable on Node and Bun, which is exactly why it needs direct tests: the +// path only runs where worker_threads is missing, so a regression would ship +// silently and surface as "bggrep behaves differently in that environment". + +test("bggrep sync fallback: same results as the worker path, including the line cap", async () => { + const mod: any = await loadModule(); + const lines = [ + "pass ok", + "--- FAIL: TestA", + "x".repeat(50) + "NEEDLE", // the only NEEDLE sits past the per-line cap + "--- FAIL: TestB", + "", + ]; + for (const pattern of ["^--- FAIL:", "NEEDLE", "^pass", "nothing-matches"]) { + const sync = mod.matchLinesSyncBounded(pattern, lines, 10, 1_000); + const worker = await mod.matchLinesWithBudget(pattern, lines, 10, 2_000); + assert.deepEqual( + sync, + worker, + `fallback and worker disagree for /${pattern}/`, + ); + if (pattern === "NEEDLE") { + assert.deepEqual(sync, { kind: "ok", matchIdx: [] }, "cap applies to both"); + } + } + // An invalid pattern must fail the same way on both paths. + assert.equal(mod.matchLinesSyncBounded("(", lines, 10, 1_000).kind, "invalid"); + assert.equal( + (await mod.matchLinesWithBudget("(", lines, 10, 2_000)).kind, + "invalid", + ); +}); + +test("bggrep sync fallback: a spent budget stops the scan before the first line", async () => { + const mod: any = await loadModule(); + // A negative budget is the deterministic spelling of "the clock says stop". + // If the guard did not fire up front, this fallback would happily scan an + // entire log on the main thread — the scenario the worker exists to avoid. + assert.equal( + mod.matchLinesSyncBounded("a", ["a", "a", "a"], 10, -1).kind, + "timeout", + ); + // And the mid-scan check: a budget spent while a real corpus is being scanned + // must abort too (the loop re-checks every 0x3ff lines). 300 000 lines of a + // simple pattern takes several ms, so a 0ms budget is provably exceeded. + const many = Array.from({ length: 300_000 }, (_, i) => `line ${i}`); + assert.equal( + mod.matchLinesSyncBounded("line", many, 100, 0).kind, + "timeout", + "a budget spent mid-scan aborts instead of finishing the corpus", + ); +}); + +// ── adversarial-review regressions ───────────────────────────────────────── +// Each of these failed before the fix it names, and each defends a contract a +// reviewer reproduced end-to-end. + +test("bgrun: a command that prints the notice cannot make its log look capped", async () => { + const { dir, proj, home } = setupDigestEnv(); + try { + writeJson(join(proj, ".pi", "pi-bgrun.json"), { + digest: [{ label: "fake", command: "echo digest-ran" }], + }); + // Uncapped log whose LAST line mimics the notice — the shape that used to + // be read as a real cap hit, suppressing the scorecard. + const wake = await runDigestJob(proj, { + command: + "printf 'all good\\n__BGRUN_TRUNC__ output truncated: kept the first 64 bytes\\n[pi-bgrun] output truncated at 64 bytes (first 64 bytes kept)\\n'", + type: "test", + }); + assert.ok( + !wake.includes("log truncated"), + "a healthy log is not reported as capped", + ); + assert.ok(wake.includes("digest-ran"), "the scorecard still runs"); + assert.ok( + !(digestLineOf(wake) ?? "").includes("skipped"), + "the digest is not skipped by a forged notice", + ); + } finally { + teardownDigestEnv(dir, proj, home); + } +}); + +test("bgrun: a backgrounded child does not hold the job open", async () => { + await withEnv("PI_BGRUN_MAX_LOG_BYTES", "100000", async () => { + await withJobsDir(async (dir, h) => { + const { wakes, tools, ctx } = h; + const res = await tools.get("bgrun")!.execute( + "call-cap-bgchild", + { command: "sleep 30 & echo done", name: "bgchild" }, + undefined, + undefined, + ctx, + ); + const id = startedId(res); + // Completion follows the COMMAND, not the last holder of its stdout. As a + // pipeline stage the wrapper waited for pipe EOF, i.e. for the background + // sleep to exit — no wake for 30s (and never, for a daemon). + await waitForWakes(wakes, 1); + assert.match(wakes[0].text, /finished \(exit 0\)/); + const log = readFileSync(join(dir, `${id}.log`), "utf8"); + assert.match(log, /done\n\n__BGRUN_EXIT__=0\n$/); + }); + }); +}); + +test("bgrun: a ceiling above Number.MAX_SAFE_INTEGER still logs the output", async () => { + await withEnv("PI_BGRUN_MAX_LOG_BYTES", "1e21", async () => { + await withJobsDir(async (dir, h) => { + const { wakes, tools, ctx } = h; + const res = await tools.get("bgrun")!.execute( + "call-cap-huge", + { command: "printf 'important-1\\nimportant-2\\n'", name: "huge" }, + undefined, + undefined, + ctx, + ); + const id = startedId(res); + await waitForWakes(wakes, 1); + // Pre-fix the shell literal was "1e+21": `head -c` rejected it and every + // byte of output was discarded while the job still reported success. + const log = readFileSync(join(dir, `${id}.log`), "utf8"); + assert.ok(log.includes("important-1"), "output is kept"); + assert.ok(!log.includes("truncated"), "not reported as capped"); + }); + }); +}); + +test("bgrun: a fractional ceiling caps instead of silently meaning unlimited", async () => { + await withEnv("PI_BGRUN_MAX_LOG_BYTES", "0.5", async () => { + await withJobsDir(async (dir, h) => { + const { wakes, tools, ctx } = h; + const res = await tools.get("bgrun")!.execute( + "call-cap-fraction", + { command: "printf 'abcdefghij'", name: "frac" }, + undefined, + undefined, + ctx, + ); + const id = startedId(res); + await waitForWakes(wakes, 1); + // 0.5 floors to 0, and 0 is documented as unlimited — the cap the user + // asked for would be silently off. It must mean "one byte" instead. + const log = readFileSync(join(dir, `${id}.log`), "utf8"); + assert.ok(log.startsWith("a\n"), `kept one byte: ${JSON.stringify(log)}`); + assert.match(log, /__BGRUN_EXIT__=0 truncated=1\n$/); + }); + }); +}); + +test("readWindowMax: the widest search window can cover a log the ceiling produced", async () => { + const mod = await loadModule(); + for (const cap of ["1048576", "67108864", "134217728"]) { + await withEnv("PI_BGRUN_MAX_LOG_BYTES", cap, async () => { + // A capped log is cap + notice + marker, so a max EQUAL to the cap left + // its first bytes permanently unreadable through bgtail/bggrep. + assert.ok( + mod.readWindowMax() > Number(cap), + `window max must exceed the ceiling in force (${cap})`, + ); + }); + } + await withEnv("PI_BGRUN_MAX_LOG_BYTES", "0", async () => { + assert.ok(mod.readWindowMax() > 67108864, "unlimited keeps a usable bound"); + }); +}); + +test("bgtail/bggrep: a window of very short lines is scan-bounded, and says so", async () => { + await withJobsDir(async (dir, h) => { + // 250k single-character lines: well under the byte window, but the shape a + // capped `yes ''` runaway produces — materializing every line costs GBs. + const id = "shortlines-1-1"; + const body = Array.from({ length: 600_000 }, (_, i) => + i === 0 ? "FIRST-MARKER" : "x", + ).join("\n"); + writeFileSync(join(dir, `${id}.log`), `${body}\n\n__BGRUN_EXIT__=0\n`); + + const grep = await h.tools + .get("bggrep")! + .execute("c", { id, pattern: "FIRST-MARKER" }, undefined, undefined, h.ctx); + const text = grep.content[0].text as string; + assert.match(text, /only the last [\d,]+ lines of that window were searched/); + assert.match(text, /none/, "the trimmed-away head is not silently searched"); + + const tail = await h.tools + .get("bgtail")! + .execute("c2", { id, lines: 3 }, undefined, undefined, h.ctx); + assert.match( + tail.content[0].text as string, + /only the last [\d,]+ lines/, + "bgtail reports the same bound", + ); + }); +}); + +test("bgclean: a running job's staging files survive an aggressive sweep", async () => { + const dir = mkdtempSync(join(tmpdir(), "pi-bgrun-test-")); + process.env.PI_BGRUN_DIR = dir; + markJobsDir(dir); + try { + const stale = new Date(Date.now() - 30 * 24 * 60 * 60 * 1000); + const live = ".tmp-live-1-beef"; + const orphan = ".tmp-dead-1-beef"; + // A live owner (this process) and an ownerless leftover, both as old as the + // cutoff. Age alone used to delete the live job's scratch files mid-run, + // which silently removed its truncation notice and injected a shell error + // into its log. + for (const name of [`${live}.pid`, `${live}.fifo`, `${live}.trunc`, `${orphan}.fifo`]) { + writeFileSync(join(dir, name), ""); + utimesSync(join(dir, name), stale, stale); + } + // Written after the loop: this is the file the sweep trusts for liveness. + writeFileSync(join(dir, `${live}.pid`), `${process.pid}\n`); + utimesSync(join(dir, `${live}.pid`), stale, stale); + + const { pi, tools, ctx } = makeFakePi(); + await loadExtension(pi); + await tools + .get("bgclean")! + .execute( + "call-cap-live-sweep", + { days: 0.0000001, all: true }, + undefined, + undefined, + ctx, + ); + + assert.ok( + existsSync(join(dir, `${live}.fifo`)), + "a running job keeps its staging files", + ); + assert.ok( + !existsSync(join(dir, `${orphan}.fifo`)), + "an orphan's staging files are still reclaimed", + ); + } finally { + delete process.env.PI_BGRUN_DIR; + rmSync(dir, { recursive: true, force: true }); + } +}); diff --git a/extension/index.ts b/extension/index.ts index 1df317b..1de3644 100644 --- a/extension/index.ts +++ b/extension/index.ts @@ -37,6 +37,7 @@ import { appendFileSync, closeSync, existsSync, + fstatSync, readSync, mkdirSync, openSync, @@ -67,20 +68,70 @@ const EXIT_MARKER = "__BGRUN_EXIT__="; const JOBS_DIR_MARKER = ".bgrun-jobs"; // Tail-read caps — avoid whole-file readFileSync on runaway logs. const LOG_TAIL_BYTES = 256 * 1024; // exit marker + last line -const LOG_READ_BYTES = 2 * 1024 * 1024; // bgtail / bggrep +const LOG_READ_BYTES = 2 * 1024 * 1024; // bgtail / bggrep default window const BGGREP_LINE_CAP = 10_000; // per-line match length cap +// Cap on the bytes a job may write to its log (stdout+stderr). Enforced inside +// the detached process tree, so it holds after pi exits. 0 = unlimited. +const DEFAULT_MAX_LOG_BYTES = 64 * 1024 * 1024; +// Above 2^53-1 a Number stringifies in exponential notation ("1e+21"), and the +// wrapper bakes the ceiling into the shell as a literal — `head -c 1e+21` fails +// and every byte of job output is discarded. A ceiling that large means +// "effectively unlimited", so it is clamped to the largest integral literal the +// shell can still parse. +const MAX_MAX_LOG_BYTES = Number.MAX_SAFE_INTEGER; +// Slack added when deriving read/count bounds from a ceiling: the wrapper writes +// its notice and exit marker PAST the capped bytes, so a capped log is slightly +// larger than the cap. A bound equal to the cap leaves the first bytes of every +// capped log unreadable and drops its line count. +const WRAPPER_OVERHEAD_BYTES = 4096; +// Machine-readable flags the wrapper appends to its exit marker. The marker is +// the one line a command cannot forge (only the LAST marker counts, so printing +// one is not evidence of completion) — carrying truncation there makes "the log +// was capped" unforgeable, unlike a printable notice line that job output can +// imitate. +const EXIT_MARKER_TRUNC_FLAG = " truncated="; +const EXIT_MARKER_NOCAP_FLAG = " nocap=1"; +// Human-readable wrapper notices, in the reserved `__BGRUN_` namespace so they +// cannot collide with a command's own output. Readers filter them exactly like +// EXIT_MARKER: wrapper bookkeeping, not job output, so they are never counted as +// content lines or reported as the job's last line. +const TRUNC_NOTICE_PREFIX = "__BGRUN_TRUNC__ output truncated"; +const CAPFAIL_NOTICE_PREFIX = "__BGRUN_NOCAP__ log ceiling unavailable"; +// Line bound for a log scan. A byte window alone is not enough: a capped log of +// very short lines (the classic `yes ''` runaway) holds millions of lines in a +// few MiB, and materializing them as JS strings costs ~100 bytes each — measured +// at >3 GB of RSS for a 64 MiB window, i.e. an OOM on exactly the log class the +// ceiling exists for. 500k lines is ~40 MB of JS strings — a bounded cost that +// still dwarfs anything a real job prints into a window. +// ceiling exists for. Past this many lines only the tail is scanned, and the +// caveat says so. +const LOG_SCAN_LINES_MAX = 500_000; + const DEFAULT_CLEANUP_DAYS = 7; const STALE_POLL_MS = 30_000; // re-check interval for jobs with no live child handle /** Default jobs dir inside a recognizable project root (`.git` or `.pi`). */ const PROJECT_LOCAL_JOBS_REL = ".pi-bgrun/jobs"; +// Files a spawn stages in the jobs dir under one shared +// `.tmp---` stem: the log itself (renamed to `.log` once the +// child pid is known) plus the wrapper's exit-code, fifo, liveness and +// truncation-flag files. Only these exact suffixes are ours — an unrelated +// `.tmp-*` is not. +const STAGING_SUFFIXES = [".log", ".ec", ".fifo", ".pid", ".trunc"]; +// A staging file is only reclaimable once it is clearly nobody's business: the +// owner's liveness file says the wrapper is gone AND the file is older than this +// floor. Without the floor, an aggressive cleanup cutoff (a `bgclean` "clean +// everything" using a tiny positive `days`) can unlink the scratch files of a +// job that started milliseconds ago, before its liveness file exists. +const STAGING_MIN_AGE_MS = 60_000; + // Machine-global jobs dir. Resolved per call (not a module constant) so // PI_BGRUN_GLOBAL_DIR can redirect it — used by tests to stay off the real // ~/.pi-bgrun, and available for setups with a custom home or shared scratch. function globalJobsDir(): string { return expandTilde( - process.env.PI_BGRUN_GLOBAL_DIR || join(homedir(), ".pi-bgrun", "jobs"), + process.env.PI_BGRUN_GLOBAL_DIR || join(homeDir(), ".pi-bgrun", "jobs"), ); } @@ -112,6 +163,71 @@ try { } `; +// Normalize a configured byte ceiling. 0 stays "unlimited"; a positive fraction +// (0.5) becomes 1 rather than flooring to 0, which would silently mean +// "unlimited"; anything above MAX_MAX_LOG_BYTES is clamped so the value always +// renders as a plain integer in the wrapper. +export function normalizeMaxLogBytes(value: unknown): number | undefined { + if (typeof value !== "number" || !Number.isFinite(value) || value < 0) { + return undefined; + } + if (value === 0) return 0; + const floored = Math.floor(value); + if (floored < 1) return 1; + return Math.min(floored, MAX_MAX_LOG_BYTES); +} + +// Upper bound for an explicit search window (bgtail/bggrep `bytes`): the ceiling +// in force plus the wrapper's overhead, so the widest window a caller can ask +// for can actually cover a log the cap produced. An equal-to-cap bound (the +// original constant) left the first bytes of every capped log unreadable while +// the caveat advertised itself as the remedy. +export function readWindowMax(): number { + let cap = DEFAULT_MAX_LOG_BYTES; + try { + const configured = resolveConfig().maxLogBytes; + if (configured > 0) cap = configured; + } catch { + // No resolvable config → the default ceiling. + } + return cap + WRAPPER_OVERHEAD_BYTES; +} + +// Clamp a caller-supplied log search window: absent/garbage/non-positive → +// the default, anything wider than the bound above → the bound (searching past +// what a job could have written is pure cost, and the window is materialized). +export function clampReadWindow(bytes: unknown, max = readWindowMax()): number { + if (typeof bytes !== "number" || !Number.isFinite(bytes) || bytes <= 0) { + return LOG_READ_BYTES; + } + return Math.min(Math.floor(bytes), max); +} + +// Trim a scan window to its last LOG_SCAN_LINES_MAX lines without splitting the +// whole window first: walking the newline positions backwards costs one pass +// over the window and never materializes millions of short strings. Returns the +// text to scan plus whether the line bound (rather than the byte window) decided +// the view, so callers can say so instead of implying the whole window was read. +export function boundScanLines(content: string): { + content: string; + lineBoundHit: boolean; +} { + let end = content.length; + let seen = 0; + while (seen < LOG_SCAN_LINES_MAX) { + const nl = content.lastIndexOf("\n", end - 1); + if (nl === -1) break; + end = nl; + seen++; + } + // "Hit" only when the limit is what stopped the walk AND bytes were actually + // trimmed off the front — running out of newlines means the whole window fits. + const hit = seen === LOG_SCAN_LINES_MAX && end > 0; + return hit + ? { content: content.slice(end + 1), lineBoundHit: true } + : { content, lineBoundHit: false }; +} + // Read at call time so tests (and users) can lower the budget; a non-positive // or non-numeric value falls back to the default. export function bggrepTimeoutMs(): number { @@ -126,7 +242,7 @@ type GrepMatchOutcome = // Bounded between lines only — a single pathological line can still stall. // Used solely when worker_threads is unavailable (never on Node or Bun). -function matchLinesSyncBounded( +export function matchLinesSyncBounded( source: string, lines: string[], cap: number, @@ -150,11 +266,17 @@ function matchLinesSyncBounded( return { kind: "ok", matchIdx: out }; } -async function matchLinesWithBudget( +// Exported, and workerSource-injectable, so a test can prove the ABORT path on +// any engine: pass a worker body that never returns and the budget must still +// yield `{kind: "timeout"}`. Input-driven catastrophic patterns cannot test it +// — engines differ (V8 backtracks exponentially where JSC does not), so the +// only portable assertion is that termination works. +export async function matchLinesWithBudget( source: string, lines: string[], cap: number, budgetMs: number, + workerSource: string = BGGREP_WORKER_SOURCE, ): Promise { let WorkerCtor: typeof import("node:worker_threads").Worker; try { @@ -164,7 +286,7 @@ async function matchLinesWithBudget( } let worker: import("node:worker_threads").Worker; try { - worker = new WorkerCtor(BGGREP_WORKER_SOURCE, { + worker = new WorkerCtor(workerSource, { eval: true, workerData: { source, lines, cap }, }); @@ -269,6 +391,63 @@ export function parseExitFromLogPath(logPath: string): number | null { return parseExitFromContent(slice.content); } +// Wrapper bookkeeping lines — never job output. Every reader filters them, so a +// capped log's last line, line count, tail window and grep results still +// describe the COMMAND's output rather than the wrapper's own bookkeeping. +// The whole `__BGRUN_` namespace is reserved (exit marker + notices), which is +// also what makes a command printing those lines a deliberate forgery rather +// than an accident. +export function isWrapperLine(line: string): boolean { + return line.startsWith("__BGRUN_"); +} + +// What the wrapper recorded about the ceiling, read from the exit marker — the +// last non-empty line, and the only line a command cannot forge: only the LAST +// marker counts, so printing one is not evidence of completion. The flag rides +// on that marker ("__BGRUN_EXIT__=0 truncated=1000"), which is why a command's +// own output can no longer make a healthy log look capped (it used to be read +// from the notice line, whose position and text a command controls). +export type CapStatus = + | { kind: "truncated"; bytes: number } + | { kind: "ceiling-failed" } + | null; + +export function parseCapStatusFromContent(content: string): CapStatus { + const lines = content.split("\n"); + let i = lines.length - 1; + while (i >= 0 && lines[i].trim().length === 0) i--; + if (i < 0) return null; + const marker = lines[i]; + if (!marker.startsWith(EXIT_MARKER)) return null; + const truncated = marker.match(/ truncated=(\d+)/); + if (truncated) return { kind: "truncated", bytes: parseInt(truncated[1], 10) }; + if (marker.includes(EXIT_MARKER_NOCAP_FLAG)) return { kind: "ceiling-failed" }; + return null; +} + +// The byte ceiling a log hit, or null when it was not capped. Thin accessor over +// the marker parse, kept because most callers only care about the number. +export function parseTruncationFromContent(content: string): number | null { + const status = parseCapStatusFromContent(content); + return status?.kind === "truncated" ? status.bytes : null; +} + +// The marker is written within the last few hundred bytes of the log, so the +// standard tail slice decides this — no full read, even at the ceiling. +function readCapStatus(logPath: string): CapStatus { + const slice = readLogSlice(logPath, LOG_TAIL_BYTES); + if (!slice) return null; + return parseCapStatusFromContent(slice.content); +} + +// Compact byte size for the wake and reader notes ("64 MiB", "1.5 KiB", +// "900 bytes"). One decimal is enough: this labels a ceiling, not a quantity. +export function formatBytes(n: number): string { + if (n >= 1024 * 1024) return `${Math.round((n / (1024 * 1024)) * 10) / 10} MiB`; + if (n >= 1024) return `${Math.round((n / 1024) * 10) / 10} KiB`; + return `${n} bytes`; +} + function readLastLogLine(logPath: string, maxLen = 200): string | null { const slice = readLogSlice(logPath, LOG_TAIL_BYTES); if (!slice) return null; @@ -278,7 +457,7 @@ function readLastLogLine(logPath: string, maxLen = 200): string | null { function readLastLineFromContent(content: string, maxLen = 200): string | null { const lines = content.split("\n").filter((l) => l.trim().length > 0); if (lines.length === 0) return null; - const real = lines.filter((l) => !l.startsWith(EXIT_MARKER)); + const real = lines.filter((l) => !isWrapperLine(l)); // No content lines (a marker-only log) → nothing to show. Never fall back to // the exit-marker line — that leaks "__BGRUN_EXIT__=N" into the wake. if (real.length === 0) return null; @@ -482,6 +661,11 @@ interface BgrunConfig { showCompletedJobs: boolean; // Log retention for cleanup (auto-sweeps and the bgclean default). cleanupDays: number; + // Byte ceiling for a job's log (stdout+stderr). A runaway job (`yes`, a spew + // loop) would otherwise fill the disk. The cap keeps the FIRST maxLogBytes + // bytes and appends a truncation notice; the job itself runs to completion + // with its real exit code. 0 = unlimited. Read per job at spawn time. + maxLogBytes: number; // Auto-sweep the shared jobs dirs at session boundaries for orphans — // finished (exit marker or dead pid) logs older than cleanupDays from // sessions that crashed or are never resumed again. Both the machine-global @@ -510,6 +694,7 @@ interface BgrunConfigFile { adoptForeignJobs?: unknown; showCompletedJobs?: unknown; cleanupDays?: unknown; + maxLogBytes?: unknown; globalAutoClean?: unknown; digest?: unknown; } @@ -544,6 +729,122 @@ function readConfigFile(path: string): BgrunConfigFile { return {}; } +// A byte-budget copier that writes as it reads: keep the first $cap bytes of +// stdin on stdout, flag (O_EXCL, 0600) if anything was left over, and drain the +// rest so the producer never gets SIGPIPE. Used as the drain when perl is +// available: `dd` and `head` are the portable choices, but both buffer their +// output — measured: nothing on disk until 4-8 KiB accumulated, so a running +// capped job's log looks stalled for a slow producer, breaking the live-tail +// workflow bgtail documents. perl's sysread/syswrite has no stdio buffering, so +// the first byte lands immediately. The program avoids quotes so it can be +// single-quoted in the wrapper. +const PERL_CAP_COPIER = [ + `use Fcntl;`, + `my $cap = $ARGV[0]; my $flag = $ARGV[1]; my $left = $cap; my $over = 0; my $flagged = 0; my $buf;`, + `while (1) {`, + ` my $n = sysread(STDIN, $buf, 65536);`, + ` last if !defined($n) || $n == 0;`, + ` if ($left > 0) {`, + ` my $take = $n < $left ? $n : $left;`, + ` my $off = 0;`, + ` while ($off < $take) { my $w = syswrite(STDOUT, $buf, $take - $off, $off); last if !defined($w) || $w <= 0; $off += $w; }`, + ` $left -= $off;`, + ` $over = 1 if $n > $take;`, + ` } else { $over = 1; }`, + ` if ($over && !$flagged) { my $fh; if (sysopen($fh, $flag, O_WRONLY | O_CREAT | O_EXCL, 0600)) { close($fh); } $flagged = 1; }`, + `}`, +].join("\n"); + +// ── Job wrapper ───────────────────────────────────────────────────────────── +// +// Every job runs inside a detached `sh -c` tree, so the log ceiling has to live +// there too — it must hold after pi exits. The command is passed as argv ($1), +// never interpolated, or `#`, quotes and heredocs would break. +// +// Capped shape: the command runs as its OWN background job writing into a fifo; +// a drain copies at most `cap` bytes of that into the log and then reports +// whether anything was left over. Two properties drive that structure: +// +// - Completion must follow the COMMAND, not the data flow. As a pipeline stage, +// `wait` would return only when every holder of the pipe's write end closes +// it — and a child the command backgrounded (`server &`, a watcher, a +// daemonized tool) inherited that fd, so the job would never wake while the +// child lived. `wait "$prod"` returns when `sh -c` is reaped; the strays keep +// running, they just stop being logged (which is the point of a ceiling). +// - The drain may outlive the command, so truncation is reported through a flag +// FILE, and the wrapper's exit marker carries the machine-readable flag. A +// notice line in the log is not evidence: a command can print the same text, +// and only the LAST marker counts, so the marker is the one line a command +// cannot forge. +// +// The drain's byte budget is exact only with `dd iflag=fullblock` (each block is +// filled before it counts): plain `dd` counts READS, so a slow writer would +// exhaust the budget without filling the cap. Without `iflag` (most non-GNU +// systems) `head -c` is used instead — exact, but block-buffered, so a running +// job's log lags by up to 8 KiB until the job exits. +// +// If `mkfifo` fails, fall back to the uncapped path: losing output is worse than +// losing the ceiling — but say so, in the log and in the marker. +// +// argv: $1 command, $2 ecfile, $3 fifo, $4 pidfile, $5 truncation flag. +export function cappedWrapper(maxBytes: number): string { + const cap = String(maxBytes); + return [ + `flag=`, + // Staging names are ours: clear any leftover or planted entry first — rm + // unlinks the name and never follows a link — and every write below runs + // under `set -C` (noclobber) so a path that reappears is refused rather than + // written through. umask is scoped to those writes: the command must keep + // its own. + `rm -f "$2" "$3" "$4" "$5" 2>/dev/null`, + `if mkfifo -m 600 "$3" 2>/dev/null && [ -p "$3" ]; then`, + ` ( umask 077; set -C; printf '%d' "$$" >"$4" ) 2>/dev/null || :`, + ` { sh -c "$1" 2>&1; ec=$?; ( umask 077; set -C; printf '%d' "$ec" >"$2" ) 2>/dev/null; } >"$3" &`, + ` prod=$!`, + ` { if command -v perl >/dev/null 2>&1; then`, + // One process: cap + flag + drain, no stdio buffering (see PERL_CAP_COPIER). + ` perl -e '${PERL_CAP_COPIER}' ${cap} "$5"`, + ` elif dd iflag=fullblock bs=1 count=0 /dev/null 2>&1; then`, + // Exact, but block-buffered: the log lags by up to one block while the job + // runs. (Plain `dd` is worse: it counts READS, so a slow writer exhausts the + // budget without filling the cap and later output is dropped.) + ` { dd iflag=fullblock bs=4096 count=$(( ${cap} / 4096 )) 2>/dev/null; dd iflag=fullblock bs=1 count=$(( ${cap} % 4096 )) 2>/dev/null; }`, + ` if [ "$(dd bs=1 count=1 2>/dev/null | wc -c)" -gt 0 ]; then ( umask 077; set -C; : >"$5" ) 2>/dev/null || :; fi`, + ` cat >/dev/null`, + ` else`, + ` head -c ${cap}`, + ` if [ "$(dd bs=1 count=1 2>/dev/null | wc -c)" -gt 0 ]; then ( umask 077; set -C; : >"$5" ) 2>/dev/null || :; fi`, + ` cat >/dev/null`, + ` fi; } <"$3" &`, + ` drain=$!`, + ` wait "$prod"`, + // The command is done. The drain copies unbuffered, so there is nothing to + // flush — this short bounded wait only gives it the moment it needs to + // notice EOF. A child the command backgrounded and did not wait for can hold + // the fifo open indefinitely; the job must complete anyway (and that stray's + // output simply stops being logged, which is what a ceiling is for). Note + // that after the byte budget is spent only the discard stage remains, so + // nothing can be written to the log after these notices. + ` j=0`, + ` while kill -0 "$drain" 2>/dev/null && [ "$j" -lt 5 ]; do sleep 0.02; j=$((j + 1)); done`, + ` ec=$(if [ -f "$2" ]; then cat "$2" 2>/dev/null; fi)`, + ` if [ -e "$5" ]; then`, + ` printf '\\n${TRUNC_NOTICE_PREFIX}: kept the first %s bytes\\n' ${cap}`, + ` flag="${EXIT_MARKER_TRUNC_FLAG}${cap}"`, + ` fi`, + `else`, + ` sh -c "$1" 2>&1`, + ` ec=$?`, + ` printf '\\n${CAPFAIL_NOTICE_PREFIX} (mkfifo failed, so this job ran uncapped)\\n'`, + ` flag="${EXIT_MARKER_NOCAP_FLAG}"`, + `fi`, + `rm -f "$2" "$3" "$4" "$5" 2>/dev/null`, + `[ -n "$ec" ] || ec=-1`, + `printf '\\n%s%d%s\\n' "${EXIT_MARKER}" "$ec" "\${flag}"`, + `exit "$ec"`, + ].join("\n"); +} + // ── Project-local jobs dir ────────────────────────────────────────────────── // // By default, when the session cwd is inside a recognizable project root @@ -579,7 +880,7 @@ function safeRealpath(p: string): string { // to $HOME. Paths are canonicalized so a symlinked $HOME is still recognized. function findProjectRoot( start: string, - home: string = homedir(), + home: string = homeDir(), ): string | undefined { const homeReal = safeRealpath(home); let cur = start; @@ -591,12 +892,20 @@ function findProjectRoot( } } +// The user's home directory, HOME-first. Node's os.homedir() already resolves +// HOME before falling back to the passwd entry, but Bun's ignores HOME — so +// deriving it here keeps `~`, the machine-global jobs dir and the project-root +// exclusion identical under both runtimes (and lets tests pin HOME). +function homeDir(): string { + return process.env.HOME || homedir(); +} + // Expand a leading `~` (bare or `~/...`) to the user's home directory so a // config/env path like `~/.pi-bgrun/jobs` is absolute rather than a relative // path interpreted project-locally. function expandTilde(p: string): string { - if (p === "~") return homedir(); - if (p.startsWith("~/")) return join(homedir(), p.slice(2)); + if (p === "~") return homeDir(); + if (p.startsWith("~/")) return join(homeDir(), p.slice(2)); return p; } @@ -904,17 +1213,18 @@ function normalizeDigestEntry(raw: unknown): DigestEntry | undefined { export function resolveConfig(ctx?: { cwd?: string; isProjectTrusted?: () => boolean; - // Test seam: os.homedir() caches in some runtimes, so tests inject the user - // config path instead of mutating HOME. + // Test seam: an explicit path, immutable for the process. Tests may also + // simply pin HOME — homeDir() honors it under every runtime, unlike Bun's + // os.homedir(). userConfigPath?: string; }): BgrunConfig { // User config: $HOME/.pi/agent/pi-bgrun.json. Overridable by an explicit // test seam (ctx.userConfigPath) and by PI_BGRUN_USER_CONFIG (mirrors the - // PI_BGRUN_DIR escape hatch — mainly for tests, which cannot swap home). + // PI_BGRUN_DIR escape hatch). const user = readConfigFile( ctx?.userConfigPath ?? process.env.PI_BGRUN_USER_CONFIG ?? - join(homedir(), ".pi", "agent", "pi-bgrun.json"), + join(homeDir(), ".pi", "agent", "pi-bgrun.json"), ); let project: BgrunConfigFile = {}; try { @@ -955,6 +1265,20 @@ export function resolveConfig(ctx?: { : undefined; const envDays = Number(process.env.PI_BGRUN_CLEANUP_DAYS); const daysEnv = Number.isFinite(envDays) && envDays > 0 ? envDays : undefined; + // Byte ceiling: unlike cleanupDays, 0 is meaningful ("unlimited"), so it is + // accepted — but a BLANK env var is not, or an empty + // PI_BGRUN_MAX_LOG_BYTES= would silently disable the cap. Normalization also + // keeps the value in a range the wrapper can express: a positive fraction + // becomes 1 (flooring it to 0 would silently mean "unlimited"), and an + // enormous value is clamped instead of stringifying to "1e+21", which the + // shell's `head -c`/`dd` reject — discarding every byte of job output. + const maxBytesFile = normalizeMaxLogBytes(merged.maxLogBytes); + const maxBytesRaw = process.env.PI_BGRUN_MAX_LOG_BYTES; + const maxBytesEnvValue = + maxBytesRaw === undefined || maxBytesRaw.trim() === "" + ? NaN + : Number(maxBytesRaw); + const maxBytesEnv = normalizeMaxLogBytes(maxBytesEnvValue); const { dir: jobsDir, projectLocal: jobsDirProjectLocal } = resolveJobsDirPath(process.env.PI_BGRUN_DIR || dirFile, ctx); // Digest section: accept either the legacy single-object form (normalized to @@ -1001,6 +1325,7 @@ export function resolveConfig(ctx?: { completedFile ?? false, cleanupDays: daysEnv ?? daysFile ?? DEFAULT_CLEANUP_DAYS, + maxLogBytes: maxBytesEnv ?? maxBytesFile ?? DEFAULT_MAX_LOG_BYTES, globalAutoClean: parseBoolEnv(process.env.PI_BGRUN_GLOBAL_AUTO_CLEAN) ?? globalCleanFile ?? @@ -1089,6 +1414,23 @@ interface BgStatusDetails { export default function (pi: ExtensionAPI) { const jobs = new Map(); + // bgtail's delta-tailing bookmarks: one entry per job id ever tailed, holding + // the high-water mark of what the caller has already had the opportunity to + // see. Declared here, ahead of the cleanup helpers, so removing a log can + // evict its bookmark. TAIL_BOOKMARK_CAP bounds the rest — cleanup only evicts + // jobs whose log it removed, and a long session that tails many job ids + // (foreign ones are never cleaned here) would otherwise grow it forever. + const TAIL_BOOKMARK_CAP = 1_000; + // A bookmark is the high-water mark of what the caller has seen PLUS the + // search window it was seen through: the same log read through a wider window + // is a different view, not newly appended output. + type TailBookmark = { + lines: number; + bytes: number; + first: string; + window: number; + }; + const tailBookmarks = new Map(); // Poller for stale job records — anything running with no live ChildProcess // handle (adopted foreign jobs + jobs reconstructed from transcript entries // after a restart). No exit event exists for those, so their logs/pids are @@ -1139,19 +1481,29 @@ export default function (pi: ExtensionAPI) { return null; } try { + // fstat, not the scan's own progress: the tail pread below is positioned + // by the REAL file size, so bounding the scan can never misplace it. + const size = fstatSync(fd).size; + if (size === 0) return 0; + // readWindowMax, not the cap: a capped log is cap + notice + marker, so a + // bound EQUAL to the cap would omit the line count for every capped job — + // exactly where magnitude matters most. + if (size > readWindowMax()) return null; const buf = Buffer.alloc(64 * 1024); let newlines = 0; - let size = 0; + let seen = 0; let bytesRead = 0; do { bytesRead = readSync(fd, buf, 0, buf.length, null); if (bytesRead <= 0) break; - size += bytesRead; + seen += bytesRead; for (let i = 0; i < bytesRead; i++) { if (buf[i] === 0x0a) newlines++; } } while (bytesRead === buf.length); - if (size === 0) return 0; + // A log that changed size mid-scan (rotated, or appended by a resumed + // job) would produce a count that matches neither state. + if (seen !== size) return null; // One bounded pread of the tail for the final-byte + exit-marker check. const tailLen = Math.min(size, 512); const tail = Buffer.alloc(tailLen); @@ -1159,20 +1511,39 @@ export default function (pi: ExtensionAPI) { const tailText = tail.toString("latin1"); const endsWithNewline = tailText.charCodeAt(tailText.length - 1) === 0x0a; let count = newlines + (endsWithNewline ? 0 : 1); - // The wrapper appends "\n\n" — those newlines are not - // command output. Drop the marker line, plus the blank separator when the - // output already ended in a newline. + // The wrapper appends "\n\n" — and, when it had to + // drop output or could not install the ceiling, "\n\n" before + // that. Those newlines are not command output, so drop the whole trailing + // wrapper block, including its leading separator when the output already + // ended in a newline. WHICH notice precedes the marker is decided by the + // marker's own flags, not by matching notice text: a command that prints + // the phrase must not have its line discounted as wrapper bookkeeping. const markerAt = tailText.lastIndexOf("\n" + EXIT_MARKER); if (markerAt === 0) { // The file is only the wrapper's "\n\n" — no command output. return 0; } if (markerAt !== -1) { + const afterMarker = tailText.slice(markerAt + 1); + const markerEnd = afterMarker.indexOf("\n"); + const markerLine = + markerEnd === -1 ? afterMarker : afterMarker.slice(0, markerEnd); + const noticePrefix = markerLine.includes(EXIT_MARKER_NOCAP_FLAG) + ? CAPFAIL_NOTICE_PREFIX + : markerLine.includes(EXIT_MARKER_TRUNC_FLAG) + ? TRUNC_NOTICE_PREFIX + : null; + const noticeAt = noticePrefix + ? tailText.lastIndexOf("\n" + noticePrefix) + : -1; + const blockStart = + noticeAt !== -1 && noticeAt < markerAt ? noticeAt : markerAt; let extra = 0; - for (let i = markerAt + 1; i < tailText.length; i++) { + for (let i = blockStart + 1; i < tailText.length; i++) { if (tailText.charCodeAt(i) === 0x0a) extra++; } - if (markerAt > 0 && tailText.charCodeAt(markerAt - 1) === 0x0a) extra++; + if (blockStart > 0 && tailText.charCodeAt(blockStart - 1) === 0x0a) + extra++; count = Math.max(0, count - extra); } return count; @@ -1213,10 +1584,25 @@ export default function (pi: ExtensionAPI) { // ── Cleanup ─────────────────────────────────────────────────────────────── - // Sweep stale per-project digest markers (.bgrun-used-*, .digest-nudge-*). - // They aren't session-scoped, so they'd otherwise accumulate one per project - // forever; a project that runs bgrun again re-writes its usage marker at - // spawn, so removing a stale one can at most re-enable one future nudge. + // Is the wrapper that owns this staging stem still running? It records its + // own pid next to its scratch files, so liveness is exact for a job started by + // ANY session sharing this jobs dir — unlike a log, whose protection needs the + // pid in the file name. + function stagingOwnerAlive(pidPath: string): boolean { + try { + const pid = parseInt(readFileSync(pidPath, "utf8").trim(), 10); + return Number.isFinite(pid) && isRunningPid(pid); + } catch { + // No liveness record (or unreadable) → treat as an orphan's leftovers. + return false; + } + } + + // Sweep stale per-project digest markers (.bgrun-used-*, .digest-nudge-*) and + // orphaned staging files. Markers aren't session-scoped, so they'd otherwise + // accumulate one per project forever; a project that runs bgrun again + // re-writes its usage marker at spawn, so removing a stale one can at most + // re-enable one future nudge. function sweepStaleMarkers(jobsDir: string, cutoff: number): void { let names: string[]; try { @@ -1224,18 +1610,31 @@ export default function (pi: ExtensionAPI) { } catch { return; } + // Staging files are only reclaimable when nobody owns them. Age alone used + // to delete a RUNNING job's fifo/flag — the wrapper's scratch files live for + // the whole job, so any aggressive cutoff killed them mid-run, silently + // removing the truncation notice and injecting a shell error into the log. + const stagingCutoff = Math.max(cutoff, Date.now() - STAGING_MIN_AGE_MS); for (const name of names) { + const isStaging = + name.startsWith(".tmp-") && + STAGING_SUFFIXES.some((suffix) => name.endsWith(suffix)); if ( + !isStaging && !name.startsWith(".bgrun-used-") && - !name.startsWith(".digest-nudge-") && - // Only OUR staging files (`.tmp---.log`), never an - // unrelated `.tmp-*` that happens to live in the dir. - !(name.startsWith(".tmp-") && name.endsWith(".log")) + !name.startsWith(".digest-nudge-") ) continue; try { const markerPath = join(jobsDir, name); - if (statSync(markerPath).mtimeMs > cutoff) continue; + const mtimeMs = statSync(markerPath).mtimeMs; + if (isStaging) { + if (mtimeMs > stagingCutoff) continue; + const stem = name.replace(/\.[a-z]+$/, ""); + if (stagingOwnerAlive(join(jobsDir, `${stem}.pid`))) continue; + } else if (mtimeMs > cutoff) { + continue; + } unlinkSync(markerPath); } catch { // ignore @@ -1287,6 +1686,9 @@ export default function (pi: ExtensionAPI) { try { unlinkSync(entry.logPath); result.removed++; + // The log is gone: its delta bookmark would otherwise pin a stale + // high-water mark (and a Map slot) for the life of the session. + tailBookmarks.delete(entry.id); } catch { // ignore } @@ -1326,6 +1728,7 @@ export default function (pi: ExtensionAPI) { // (and its ExtensionContext) for the life of the process. if (rec.exitedAt !== undefined && rec.exitedAt < cutoff) { jobs.delete(rec.id); + tailBookmarks.delete(rec.id); } continue; } @@ -1337,6 +1740,7 @@ export default function (pi: ExtensionAPI) { unlinkSync(rec.logPath); result.removed++; jobs.delete(rec.id); + tailBookmarks.delete(rec.id); } catch { // ignore } @@ -1745,10 +2149,8 @@ export default function (pi: ExtensionAPI) { // log fd must exist before spawn. Create at a temp path, rename after spawn. // randomBytes (not Math.random) plus O_EXCL: the temp name is not // guessable and a pre-planted symlink cannot be truncated through. - const tmpPath = join( - jobsDir, - `.tmp-${slug}-${ts}-${randomBytes(4).toString("hex")}.log`, - ); + const stem = `.tmp-${slug}-${ts}-${randomBytes(4).toString("hex")}`; + const tmpPath = join(jobsDir, `${stem}.log`); let logFd: number | undefined; let logPath = tmpPath; try { @@ -1761,11 +2163,37 @@ export default function (pi: ExtensionAPI) { } try { // Pass command as argv — interpolation breaks on #, quotes, heredocs. - const wrapper = `sh -c "$1"; ec=$?; printf '\\n${EXIT_MARKER}%d\\n' "$ec"; exit "$ec"`; - const child = spawn("sh", ["-c", wrapper, "bgrun", command], { - stdio: ["ignore", logFd, logFd], - detached: true, - }); + // maxLogBytes 0 means "unlimited": keep the pre-ceiling wrapper exactly + // (a zero-byte ceiling is meaningless, so it cannot be routed through + // the capped path). + const capped = cfg.maxLogBytes > 0; + const wrapper = capped + ? cappedWrapper(cfg.maxLogBytes) + : `sh -c "$1"; ec=$?; printf '\\n${EXIT_MARKER}%d\\n' "$ec"; exit "$ec"`; + const child = spawn( + "sh", + capped + ? [ + "-c", + wrapper, + "bgrun", + command, + join(jobsDir, `${stem}.ec`), + join(jobsDir, `${stem}.fifo`), + // Liveness, so a cleanup sweep can tell a running job's scratch + // files from an orphan's instead of judging them by age alone. + join(jobsDir, `${stem}.pid`), + // Truncation flag: written by the drain when bytes were left + // over. A file, not the drain's exit status, because the drain + // may still be running when the wrapper prints. + join(jobsDir, `${stem}.trunc`), + ] + : ["-c", wrapper, "bgrun", command], + { + stdio: ["ignore", logFd, logFd], + detached: true, + }, + ); child.unref(); const childPid = child.pid ?? -1; @@ -1887,6 +2315,18 @@ export default function (pi: ExtensionAPI) { const statsParts = [formatDuration(rec.exitedAt - rec.started)]; if (logLines !== null) statsParts.push(`${logLines.toLocaleString("en-US")} lines`); + // The cap is the one fact that changes what the others MEAN: the line + // count, the last line and any digest describe only the bytes that + // were kept. Say so in the line the agent reads first. A ceiling that + // could not be installed is the opposite case — the log is complete + // but unbounded — and that must not be silent either. + const capStatus = readCapStatus(logPath); + const truncatedAt = + capStatus?.kind === "truncated" ? capStatus.bytes : null; + if (truncatedAt !== null) + statsParts.push(`log truncated at ${formatBytes(truncatedAt)}`); + else if (capStatus?.kind === "ceiling-failed") + statsParts.push("no log ceiling (command ran uncapped)"); // Persist the done-state entry. pi.appendEntry("bgrun-job", { @@ -1926,9 +2366,21 @@ export default function (pi: ExtensionAPI) { }; const selected = selectDigestEntry(digestEntries, digestTarget); if (selected) { - const raw = await runDigestCommand(selected.command, logPath); - const text = raw === undefined ? undefined : capDigestOutput(raw); - if (text) digestBlock = { label: selected.label, text }; + if (truncatedAt !== null) { + // A scorecard reads the log's END (summary lines, failure + // lists) — exactly what a head cap drops. Its numbers would be + // confidently wrong, so report why it was skipped instead. + digestBlock = { + label: selected.label, + text: + `skipped — the log was truncated at ${formatBytes(truncatedAt)} ` + + "and this scorecard reads the log's end, which the cap dropped", + }; + } else { + const raw = await runDigestCommand(selected.command, logPath); + const text = raw === undefined ? undefined : capDigestOutput(raw); + if (text) digestBlock = { label: selected.label, text }; + } } else if (digestEntries?.length) { // Configured but nothing selected — otherwise silent. Surface the // job's type/name plus the configured types, once per distinct @@ -2249,13 +2701,17 @@ export default function (pi: ExtensionAPI) { // for lines already seen. Deliberately-skipped prefix lines are never // replayed as "new". raw: true keeps the verbatim last-N window (no delta // header) but still advances the bookmark. A shrunken log (rotated/replaced) - // resets to a full tail. Bookmarks are in-memory only — a session restart - // starts fresh with a full tail. - - const tailBookmarks = new Map< - string, - { lines: number; bytes: number; first: string } - >(); + // resets to a full tail. Bookmarks are in-memory only (see tailBookmarks + // above) — a session restart starts fresh with a full tail. + + // Record a bookmark, evicting the oldest entry once the map is full. Cleanup + // drops bookmarks when it removes a log; this bounds the rest. + function rememberTail(id: string, bookmark: TailBookmark): void { + tailBookmarks.set(id, bookmark); + if (tailBookmarks.size <= TAIL_BOOKMARK_CAP) return; + const oldest = tailBookmarks.keys().next().value; + if (oldest !== undefined && oldest !== id) tailBookmarks.delete(oldest); + } // Resolve a job's log path and read its bounded slice, single-sourcing the // "in-memory record first, then the configured jobs dir" rule shared by @@ -2265,14 +2721,15 @@ export default function (pi: ExtensionAPI) { function resolveLogForJob( id: string, tool: string, - ctx?: ExtensionContext, + ctx: ExtensionContext | undefined, + window: number, ): | { logPath: string; content: string; size: number } | { logPath: string; errorText: string; notFound: boolean } { validateJobId(id, tool); const logPath = jobs.get(id)?.logPath ?? join(resolveConfig(ctx).jobsDir, `${id}.log`); - const slice = readLogSlice(logPath, LOG_READ_BYTES); + const slice = readLogSlice(logPath, window); if (!slice) { return { logPath, @@ -2286,7 +2743,7 @@ export default function (pi: ExtensionAPI) { // Shared by the bgtail tool (agent-facing) and the /bgtail slash command // (human-facing). async function bgtailCore( - params: { id: string; lines?: number; raw?: boolean }, + params: { id: string; lines?: number; raw?: boolean; bytes?: number }, ctx?: ExtensionContext, ): Promise<{ content: { type: "text"; text: string }[]; @@ -2298,7 +2755,8 @@ export default function (pi: ExtensionAPI) { // tool schema, and lines < 1 would corrupt slicing (slice(-0) = whole log). const lines = Math.max(1, Math.floor(linesParam)); if (!id) throw new Error("bgtail: id is required"); - const resolved = resolveLogForJob(id, "bgtail", ctx); + const readWindow = clampReadWindow(params.bytes); + const resolved = resolveLogForJob(id, "bgtail", ctx, readWindow); if ("errorText" in resolved) { return { content: [{ type: "text", text: resolved.errorText }], @@ -2311,49 +2769,91 @@ export default function (pi: ExtensionAPI) { }; } const { logPath, content, size } = resolved; - // Content lines only: the exit marker and blanks are filtered BEFORE the - // window is sliced, so "last N lines" means the last N content lines - // (matching pre-delta behavior) and bookmarks count content lines. + // The cap dropped bytes off the END, so every "last N lines" view below is + // the end of what was KEPT. Flag it in the output, or a mid-run line reads + // as the job's final word — and in the details, for callers that parse them. + const truncatedAt = parseTruncationFromContent(content); + const capNote = + truncatedAt === null + ? "" + : `\n\n(log truncated at ${formatBytes(truncatedAt)} — lines past the cap were never written, so this is not the run's real end)`; + const truncDetails = + truncatedAt === null ? {} : { truncatedAtBytes: truncatedAt }; + // Tail reads are bounded at LOG_READ_BYTES, so on a log past that window + // every view above is the end of a slice — say so, or "not in the output" + // reads as "not in the log". The advertised maximum is the ceiling actually + // in force plus the wrapper's overhead, so it can cover a capped log + // (a max equal to the cap left its first bytes permanently unreadable). + const windowNote = + size > readWindow + ? `\n\n(searched the last ${formatBytes(readWindow)} of ${formatBytes(size)} — the earlier bytes were not searched; pass a larger \`bytes\` (max ${formatBytes(readWindowMax())}) or use ctx_execute_file on the log path)` + : ""; + // Content lines only: wrapper bookkeeping (exit marker, truncation notice) + // and blanks are filtered BEFORE the window is sliced, so "last N lines" + // means the last N content lines (matching pre-delta behavior) and + // bookmarks count content lines. + // boundScanLines first: a window of very short lines (the `yes ''` runaway + // the ceiling exists for) is millions of lines in a few MiB, and splitting + // it all costs gigabytes of RSS on the host's main thread. // /\r?\n/ keeps CRLF logs from leaving a stray \r on every line. - const rawLines = content + const scan = boundScanLines(content); + const lineNote = scan.lineBoundHit + ? `\n\n(and only the last ${LOG_SCAN_LINES_MAX.toLocaleString("en-US")} lines of that window were scanned)` + : ""; + const rawLines = scan.content .split(/\r?\n/) - .filter((l) => !l.startsWith(EXIT_MARKER) && l.trim().length > 0); + .filter((l) => !isWrapperLine(l) && l.trim().length > 0); const total = rawLines.length; const first = rawLines[0]?.slice(0, 200) ?? ""; const prev = tailBookmarks.get(id); + // Same log, different window: a wider view would look like pages of "new" + // lines that were only never looked at before, so reset the delta. It also + // moves the window's first line, so it must be tested BEFORE the + // replacement heuristic below — otherwise a widened read misreports the log + // as replaced. + const windowChanged = prev !== undefined && prev.window !== readWindow; // Append-only logs never mutate earlier lines, so a changed first // content line means the log was replaced or rotated — reset to a full // tail. Catches same-size replacements the shrink checks cannot see. // (A previously-empty log growing content is growth, not replacement.) const replaced = - prev !== undefined && prev.lines > 0 && prev.first !== first; + prev !== undefined && + !windowChanged && + prev.lines > 0 && + prev.first !== first; const shrank = prev !== undefined && (prev.lines > total || prev.bytes > size); let window: string[]; let header: string | undefined; let newLines: number | undefined; - if (raw || prev === undefined || shrank || replaced) { - // Full tail: first read, raw mode, or a shrunken/replaced log (reset). + if (raw || prev === undefined || shrank || replaced || windowChanged) { + // Full tail: first read, raw mode, a shrunken/replaced log, or a changed + // search window (all resets). window = rawLines.slice(-lines); - if (!raw && (shrank || replaced)) { + if (!raw) { header = shrank ? "log shrank since last read — showing full tail" - : "log was replaced since last read — showing full tail"; + : replaced + ? "log was replaced since last read — showing full tail" + : windowChanged + ? "search window changed since last read — showing full tail" + : undefined; } } else { const fresh = rawLines.slice(prev.lines); newLines = fresh.length; if (fresh.length === 0) { - tailBookmarks.set(id, { + rememberTail(id, { lines: total, bytes: size, first, + window: readWindow, }); return { content: [ { type: "text", - text: `(no new lines since last read — log at ${total} line${total === 1 ? "" : "s"})`, + text: `(no new lines since last read — log at ${total} line${total === 1 ? "" : "s"})${capNote}${windowNote}${lineNote}`, }, ], details: { @@ -2364,6 +2864,8 @@ export default function (pi: ExtensionAPI) { condensed: true, newLines: 0, totalLines: total, + windowBytes: readWindow, + ...truncDetails, }, }; } @@ -2372,10 +2874,11 @@ export default function (pi: ExtensionAPI) { `+${fresh.length} new line${fresh.length === 1 ? "" : "s"} since last read — ` + `log at ${total} lines${fresh.length > lines ? ` (showing last ${lines})` : ""}`; } - tailBookmarks.set(id, { + rememberTail(id, { lines: total, bytes: size, first, + window: readWindow, }); const shown = window; const { text, truncated } = condenseLogLines(shown, { raw }); @@ -2385,7 +2888,12 @@ export default function (pi: ExtensionAPI) { const notes = truncated.length > 0 ? `\n\n(${truncated.join("; ")})` : ""; const head = header ? `${header}\n` : ""; return { - content: [{ type: "text", text: head + body + notes }], + content: [ + { + type: "text", + text: head + body + notes + capNote + windowNote + lineNote, + }, + ], details: { id, linesShown: shown.length, @@ -2394,6 +2902,8 @@ export default function (pi: ExtensionAPI) { condensed: !raw, ...(newLines === undefined ? {} : { newLines, totalLines: total }), ...(truncated.length > 0 ? { condenserNotes: truncated } : {}), + windowBytes: readWindow, + ...truncDetails, }, }; } @@ -2402,7 +2912,7 @@ export default function (pi: ExtensionAPI) { name: "bgtail", label: "Tail Background Log", description: - "Read the newest lines of a background job's log, condensed for context: ANSI escapes stripped, repeated lines collapsed, long lines truncated, output capped (~8KB). Strips the exit-marker line. The first read returns the last N lines (default 40); REPEAT reads return only lines appended since your last read (delta tailing) — polling a running job never re-pays for the same lines. raw: true returns the unprocessed last-N window. A shrunken or replaced log resets to a full tail. For pattern search use bggrep; for whole-log analysis, ctx_execute_file on the log path.", + "Read the newest lines of a background job's log, condensed for context: ANSI escapes stripped, repeated lines collapsed, long lines truncated, output capped (~8KB). Strips the exit-marker line. The first read returns the last N lines (default 40); REPEAT reads return only lines appended since your last read (delta tailing) — polling a running job never re-pays for the same lines. raw: true returns the unprocessed last-N window. A shrunken, replaced, or differently-windowed log resets to a full tail. Reads only the log's last 2 MiB by default (`bytes` widens it, max 64 MiB) and says so when the log is bigger. For pattern search use bggrep; for whole-log analysis, ctx_execute_file on the log path.", promptSnippet: "Read the last N lines of a bgrun job's log", parameters: Type.Object({ id: Type.String({ @@ -2420,6 +2930,13 @@ export default function (pi: ExtensionAPI) { "Skip condensing (ANSI strip, collapse, caps) and return raw text", }), ), + bytes: Type.Optional( + Type.Number({ + description: + "Search window in bytes (default 2097152 = 2 MiB; capped at the configured log ceiling plus the wrapper's overhead — 67108864 = 64 MiB by default). Widening affects how much is SCANNED (and what the scan costs in CPU and memory) — the returned text stays capped.", + minimum: 1, + }), + ), }), async execute(_toolCallId, params, _signal, _onUpdate, ctx) { return bgtailCore(params, ctx); @@ -2428,18 +2945,19 @@ export default function (pi: ExtensionAPI) { // ── bggrep: pattern search over a job's log, capped for context ─────────── // - // The sandboxed whole-log path (ctx_execute_file) is confined to the - // project root, which a global jobs dir sits outside of — bggrep runs - // inside the extension with native fs access, so it reaches the configured - // jobs dir (including a global one). Matches are line-numbered (grep -n style), + // bggrep runs inside the extension, so it resolves the job id to the + // configured jobs dir itself (no path to reconstruct) and needs no shell + // quoting for the regex; ctx_execute_file can read the same file, but you + // must hand it the absolute path. Matches are line-numbered (grep -n style), // optionally with context lines, capped at MAX_GREP_MATCHES, and run // through the same condenser as bgtail so a search can never flood context. const MAX_GREP_MATCHES = 50; async function bggrepCore( - params: { id: string; pattern?: string; context?: number }, + params: { id: string; pattern?: string; context?: number; bytes?: number }, ctx?: ExtensionContext, + ): Promise<{ content: { type: "text"; text: string }[]; details: Record; @@ -2461,7 +2979,8 @@ export default function (pi: ExtensionAPI) { ); } // Record-first, same as bgtail — correct across config changes. - const resolved = resolveLogForJob(id, "bggrep", ctx); + const readWindow = clampReadWindow(params.bytes); + const resolved = resolveLogForJob(id, "bggrep", ctx, readWindow); if ("errorText" in resolved) { return { content: [{ type: "text", text: resolved.errorText }], @@ -2474,13 +2993,39 @@ export default function (pi: ExtensionAPI) { isError: true, }; } - const { logPath, content } = resolved; + const { logPath, content, size } = resolved; + // A capped log is missing its END, and "no matches" is exactly what a + // failure pattern looks like when the failures were past the cap — so the + // note belongs next to the count, not just in the details. + const truncatedAt = parseTruncationFromContent(content); + const truncNote = + truncatedAt === null + ? "" + : `\n\n(log truncated at ${formatBytes(truncatedAt)} — output past the cap was never written and was not searched)`; + const truncDetails = + truncatedAt === null ? {} : { truncatedAtBytes: truncatedAt }; + // Same window caveat as bgtail: the search covers only the last `window` + // bytes, so a miss on a bigger log means "not in the searched slice". The + // advertised maximum is the ceiling in force plus the wrapper's overhead, so + // it can cover a capped log. + const windowNote = + size > readWindow + ? `\n\n(searched the last ${formatBytes(readWindow)} of ${formatBytes(size)} — the earlier bytes were not searched; pass a larger \`bytes\` (max ${formatBytes(readWindowMax())}) or use ctx_execute_file on the log path)` + : ""; + // Bound the LINE count before splitting: a window of very short lines is + // millions of lines in a few MiB, and materializing them costs ~100 bytes + // each (>3 GB measured for a 64 MiB window) — on the main thread, in the + // very log class the ceiling exists for. The caveat says when it bit. + const scan = boundScanLines(content); + const lineNote = scan.lineBoundHit + ? `\n\n(and only the last ${LOG_SCAN_LINES_MAX.toLocaleString("en-US")} lines of that window were searched)` + : ""; // /\r?\n/ normalizes CRLF (a trailing \r would break $-anchored patterns // and leak into output); blank lines are KEPT so L numbers match the // file. A trailing empty split element is dropped; "" yields zero lines. - const split = content === "" ? [] : content.split(/\r?\n/); + const split = scan.content === "" ? [] : scan.content.split(/\r?\n/); if (split.length > 0 && split[split.length - 1] === "") split.pop(); - const rawLines = split.filter((l) => !l.startsWith(EXIT_MARKER)); + const rawLines = split.filter((l) => !isWrapperLine(l)); // Match under a wall-clock budget in a worker: a caller-supplied regex can // backtrack catastrophically and would otherwise hang the main thread with // no way to interrupt it. @@ -2515,6 +3060,8 @@ export default function (pi: ExtensionAPI) { notFound: false, pattern: source, timedOut: true, + windowBytes: readWindow, + ...truncDetails, }, isError: true, }; @@ -2525,13 +3072,17 @@ export default function (pi: ExtensionAPI) { `in ${rawLines.length} line${rawLines.length === 1 ? "" : "s"}`; if (matchIdx.length === 0) { return { - content: [{ type: "text", text: `${header} — none` }], + content: [ + { type: "text", text: `${header} — none${truncNote}${windowNote}${lineNote}` }, + ], details: { id, matches: 0, linesSearched: rawLines.length, logPath, notFound: false, + windowBytes: readWindow, + ...truncDetails, }, }; } @@ -2561,7 +3112,12 @@ export default function (pi: ExtensionAPI) { ? ` — showing first ${MAX_GREP_MATCHES}; ${matchIdx.length - MAX_GREP_MATCHES} more not shown` : ""; return { - content: [{ type: "text", text: `${header}${capNote}\n${text}${notes}` }], + content: [ + { + type: "text", + text: `${header}${capNote}\n${text}${notes}${truncNote}${windowNote}${lineNote}`, + }, + ], details: { id, matches: matchIdx.length, @@ -2570,6 +3126,8 @@ export default function (pi: ExtensionAPI) { notFound: false, pattern: source, capped, + windowBytes: readWindow, + ...truncDetails, }, }; } @@ -2578,7 +3136,7 @@ export default function (pi: ExtensionAPI) { name: "bggrep", label: "Grep Background Log", description: - "Search the last 2 MB of a background job's log with a regex (each line is pre-truncated to 10k chars before matching); returns only matching lines with line numbers (optional context lines), capped (~50 matches, ~8KB) and condensed. Matching runs under a wall-clock budget (default 2s, PI_BGRUN_GREP_TIMEOUT_MS), so a runaway regex fails instead of hanging. Runs inside the extension, so it reaches the configured jobs dir (including a global one) that project-sandboxed tools (ctx_execute_file) cannot reach. Pass your own pattern whenever you know the log's format; with no pattern a generic failure-signature default is used (a convenience only — not a guarantee).", + "Search the tail of a background job's log with a regex — the last 2 MiB by default, widen with `bytes` (each line is pre-truncated to 10k chars before matching); returns only matching lines with line numbers (optional context lines), capped (~50 matches, ~8KB) and condensed. Matching runs under a wall-clock budget (default 2s, PI_BGRUN_GREP_TIMEOUT_MS), so a runaway regex fails instead of hanging. Resolves the job id to the configured jobs dir itself, so there is no log path to reconstruct; ctx_execute_file can read the same file, but needs the absolute path. Pass your own pattern whenever you know the log's format; with no pattern a generic failure-signature default is used (a convenience only — not a guarantee).", promptSnippet: "Search a bgrun job's log for a pattern", promptGuidelines: [ "Never search a bgrun log with the bash tool — uncapped output can flood context, and it needs manual log-path reconstruction and regex shell-quoting; bggrep is bounded by design.", @@ -2602,6 +3160,13 @@ export default function (pi: ExtensionAPI) { minimum: 0, }), ), + bytes: Type.Optional( + Type.Number({ + description: + "Search window in bytes (default 2097152 = 2 MiB; capped at the configured log ceiling plus the wrapper's overhead — 67108864 = 64 MiB by default). Widening affects how much is SCANNED (and what the scan costs in CPU and memory) — the returned matches stay capped (~50 matches, ~8KB).", + minimum: 1, + }), + ), }), async execute(_toolCallId, params, _signal, _onUpdate, ctx) { return bggrepCore(params, ctx); diff --git a/skill/run-bg/SKILL.md b/skill/run-bg/SKILL.md index 074e920..0908ae2 100644 --- a/skill/run-bg/SKILL.md +++ b/skill/run-bg/SKILL.md @@ -50,7 +50,8 @@ no polling. - `done exit=` → failure; analyze the log. - `running` but the job should have finished long ago → likely crashed (the process died without writing the exit marker). Analyze the log with - `bggrep` (any jobs dir) or `ctx_execute_file` (project-local logs only). + `bggrep` (any jobs dir, last 2 MB) or `ctx_execute_file` on the absolute path + (whole file — needed for logs bigger than 2 MB). ### Reading results without flooding context @@ -62,15 +63,18 @@ usually answers "what failed" without any follow-up read. `bgtail` stays the positional-peek tool for everything else. - **Quick peek (≤40 lines):** call `bgtail` with the job id and `lines: 40` — strips the `__BGRUN_EXIT__` marker. The first read returns the last-40 tail; repeat reads return only lines appended since your last read (delta tailing) — polling a running job is nearly free. -- **Failure extraction:** `bggrep(, "pattern")` — line-numbered matches with optional context lines, capped and condensed. Reaches the configured jobs dir (including a global one) that project-sandboxed `ctx_execute_file` cannot (it runs inside the extension). Pass your own pattern whenever you know the tool's output format; the default only catches common failure signatures. -- **Whole-log failure analysis:** `ctx_execute_file` on the log path — **project-local - `jobsDir` only** (e.g. `.pi-bgrun/jobs` in `pi-bgrun.json`). The default global - dir (`~/.pi-bgrun/jobs`) is outside the project sandbox; use `bggrep` there instead. - Copy the `log:` path from `bgrun`'s `started:` line (do not use `~` — it may not expand). +- **Failure extraction:** `bggrep(, "pattern")` — line-numbered matches with optional context lines, capped and condensed. Resolves the job id to the configured jobs dir itself — no path to reconstruct. (`ctx_execute_file` can read the same file given its absolute path.) Searches the last 2 MiB by default; `bytes: 67108864` widens it to the whole capped log — more scanning costs latency and memory, **not context**, since the returned matches stay capped. Pass your own pattern whenever you know the tool's output format; the default only catches common failure signatures. +- **Whole-log failure analysis:** `ctx_execute_file` on the log's **absolute + path**. Unlike `bgtail`/`bggrep` (bounded to the last 2 MB), this reads the + whole file — the only way to cover a log bigger than 2 MB, e.g. one that hit + the size ceiling. Copy the `log:` path from `bgrun`'s `started:` line and + expand `~` yourself (it is not expanded for you; the tool takes an absolute + path or one relative to the project root). Otherwise it is an ordinary tool + call: your normal Read-deny rules still apply. ```javascript ctx_execute_file( - path: "/.pi-bgrun/jobs/.log", + path: "/Users/me/project/.pi-bgrun/jobs/.log", language: "javascript", code: "const L=FILE_CONTENT.split('\\n'); \ const fails=L.filter(l=>/(--- FAIL|FAIL|panic:|Error:)/.test(l)); \ @@ -90,8 +94,7 @@ positional-peek tool for everything else. ~8KB, plus a wall-clock match budget so a runaway regex errors instead of hanging). - It takes the job id — no log-path reconstruction, no shell-quoting of the - regex — and reaches the configured jobs dir (including a global one) that - project-sandboxed `ctx_execute_file` cannot. + regex, and no reliance on the agent getting `~` expansion right. - Output is self-describing: match count, line numbers, `…[N skipped]…` gap markers, `— none` for no-match. @@ -100,6 +103,24 @@ Plain `grep` via bash is fine only for a one-off search you know is tiny. **Never `cat`, `Read`, `bash cat`, or `bash grep` a full bgrun log.** Always `bgtail`, `bggrep`, or (for project-local logs) `ctx_execute_file`. +**Order of preference, cheapest first: `bgtail` → `bggrep` → `ctx_execute_file`.** +Reach for the sandbox only when you need something a regex over lines cannot +express — totals, dedup, grouping, joining the log against another file. + +`ctx_execute_file` is not itself a context dump: the file's bytes never enter +context, only your script's **stdout** does ("raw content never leaves"). So the +cost is exactly what you print — which makes `console.log(FILE_CONTENT)` (or +`print(open(path).read())`, or a big unbounded slice) the one way a whole-log +analysis turns into a context dump, and a capped-by-default 64 MiB log makes +that expensive rather than merely rude. Aggregate, then cap what you print: + +- print counts / grouped summaries / the first N matches — not the content; +- keep a `.slice(0, 40)` / `[:40]` on anything you echo; +- for many different questions about one big log, index it once (`ctx_index`) + and `ctx_search` it, instead of re-scanning the file per call; +- `bgtail` with a larger `lines`, or a tighter `bggrep` pattern, is usually the + cheaper answer to "I need to see more". + ## After a pi restart or session switch - The live wake does not survive a pi restart or a `/resume` to a different session @@ -116,8 +137,27 @@ Plain `grep` via bash is fine only for a one-off search you know is tiny. - Call the tools; never hand-roll `nohup … &` inline. - One job = one id. Multiple concurrent jobs are fine — each has its own log. -- Logs default to `/.pi-bgrun/jobs` in a repo (else `~/.pi-bgrun/jobs`; - override with `PI_BGRUN_DIR` or `jobsDir`). Project-local dirs are +- Job logs are capped by default (`maxLogBytes` / `PI_BGRUN_MAX_LOG_BYTES`, + 64 MiB; `0` = unlimited) and the cap keeps the **first** bytes. A log that + ends with `__BGRUN_TRUNC__ output truncated: kept the first bytes` (or + `__BGRUN_NOCAP__ log ceiling unavailable`, when the ceiling could not be + installed and the job ran uncapped) hit that ceiling: output past it was dropped, not lost to a failure — the job + still ran to completion with its real exit code, and readers (`bgtail`, + `bggrep`, the wake's line count/last line) filter the notice out. The wake's + Stats line, `bgtail` and `bggrep` all say when a log was capped (and report + `truncatedAtBytes` in their details), and a configured digest scorecard is + skipped rather than scored against an incomplete log — so on a capped job, + read a missing digest as "unknown", **not** as "no failures", and do not + re-run the command to see the missing tail; raise the ceiling if you need the + whole log. The flag lives in the exit marker (`__BGRUN_EXIT__=0 + truncated=`, or `nocap=1`), never in printable text — the `__BGRUN_*__` + lines are reserved, so a notice-looking line printed by the command itself is + content, not a signal. A search window is also limited to its last + 500 000 lines: when that bites, `bgtail`/`bggrep` say so — a "none" from a + trimmed window means the head was not searched. +- Logs default to `/.pi-bgrun/jobs` in a repo — project-scoped is the + model (`~/.pi-bgrun/jobs` is a deprecated fallback for a cwd with no project + root; an absolute `PI_BGRUN_DIR`/`jobsDir` still works but is legacy). Project-local dirs are auto-ignored via `.git/info/exclude`, which keeps `git status` clean; the logs stay reachable for project-sandboxed analysis tools like `ctx_execute_file` because they live inside the project.