From e297fe6707fe0fbeadc6d90911ec3e3e00c9560a Mon Sep 17 00:00:00 2001 From: SiddarthAA Date: Sun, 16 Aug 2026 18:37:39 +0530 Subject: [PATCH 1/3] fix(telemetry): stop the dashboard's PostHog client stranding and duplicating its own events MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Four options on the posthog-node client each disabled a different part of the library's delivery machinery. Together they turned a slow network into lost events, duplicated events, and `Error while flushing PostHog` in the terminal `failproofai audit` runs the dashboard in. The injected `resilientFetch` was the root. It retried 5 times over ~40s and then returned a synthetic 200 so the library would never log a network error. It could not work: posthog-node does not merely hand its abort signal to an injected fetch, it *races* that fetch against its own `requestTimeout` (`Promise.race([fetchPromise, deadline])`) precisely because an injected fetch may ignore the signal — which ours did, by stripping it. A ~40s budget racing a 5s deadline can never return in time, so the synthetic 200 was unreachable, the console.error it existed to prevent fired anyway at 5s, and the retries ran on detached from a client that had already given up. That 200 was also the wrong answer on its merits: posthog-node deliberately does NOT dequeue a batch that failed with a network error, so reporting success is what would have made it discard events that never arrived. `fetchRetryCount: 0` left that wrapper as the only thing retrying, at the wrong layer. `requestTimeout: 5000` was half the library's own default. `flushInterval: 0` is falsy and disables the flush timer outright — the one that actually stranded events, since the batch retained after a network error then had nothing scheduled to resend it and sat in an in-memory queue until an unrelated later event triggered a flush. Measured against a server that answers correctly but takes 6s, the old options delivered the event 4 times and logged 2 flush errors; the new ones deliver it once with nothing logged. `flushAt: 1` stays: volume is a handful of events per process and the queue is memory-only, so immediate send is the best defense against process death. The exit drain is now idempotent, since `beforeExit` re-fires whenever a handler schedules async work. No event, trigger or property changed — all 73 call sites fire as before. Tests: __tests__/lib/telemetry-delivery.test.ts asserts delivery against the real library over a real socket (gunzipping the batch body, without which a green test means nothing). The existing suite mocks posthog-node wholesale, which is what let this live in the tree. Also pins two facts rather than fixing them: posthog-node overwrites `$lib` on the server path, so `product` is the attribution that survives; and the opt-out still sends nothing. Co-Authored-By: Claude Opus 5 (1M context) --- CHANGELOG.md | 10 + __tests__/lib/telemetry-delivery.test.ts | 272 +++++++++++++++++++++++ __tests__/lib/telemetry.test.ts | 24 +- lib/telemetry.ts | 85 +++---- src/hooks/hook-telemetry.ts | 5 +- 5 files changed, 351 insertions(+), 45 deletions(-) create mode 100644 __tests__/lib/telemetry-delivery.test.ts diff --git a/CHANGELOG.md b/CHANGELOG.md index be54a525..7b20644f 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,5 +1,15 @@ # Changelog +## 1.0.1-beta.1 — 2026-08-16 + +### Fixes + +- **Stop the dashboard server's telemetry from stranding its own events, and stop it printing `Error while flushing PostHog` while doing it.** Four options on the `posthog-node` client each disabled a different part of the library's delivery machinery, and together they turned a slow network into lost events plus a stack trace in the user's terminal — the one `failproofai audit` starts, where `launch()`'s log filter only strips the Server Action skew block. The injected `resilientFetch` was the root of it: it retried five times over ~40s and then returned a synthetic `200` so the library would never log a network error, but posthog-node does not merely hand its abort signal to an injected fetch, it **races that fetch against its own `requestTimeout`** (`Promise.race([fetchPromise, deadline])`) precisely because an injected fetch may ignore the signal — which ours did, by stripping it. A ~40s budget racing a 5s deadline can never return in time, so the synthetic `200` was unreachable code, the `console.error` it existed to prevent fired anyway at 5s, and the retries ran on detached from a client that had already given up. Worse, that `200` was the wrong answer even when it did land: posthog-node deliberately does NOT dequeue a batch that failed with a network error, so reporting success is what would have made it discard events that never arrived. The wrapper is gone; plain global fetch is what the library expects. `fetchRetryCount` was `0`, leaving that wrapper as the only thing retrying, at the wrong layer — the library retries inside a single flush, knows which errors are retryable, and keeps its queue coherent while doing it. `requestTimeout` was `5000`, half the library's own default, so every attempt had half the room. And `flushInterval` was `0`, which is falsy and therefore disables the flush timer outright — that is the one that actually stranded events, because the batch posthog-node retains after a network error then had nothing scheduled to resend it and sat in an in-memory queue (`PostHogMemoryStorage`, so nothing survives the process) until some unrelated later event happened to trigger a flush. `flushAt: 1` is unchanged and deliberate: volume is a handful of events per process, batching buys nothing, and sending immediately is the best defense a memory-only queue has against the process dying. Measured against a server that answers correctly but takes 6s — a slow network, not an outage — the old options delivered the event **four times** and logged two flush errors, because the wrapper re-POSTed the same batch on each of its own retries while the library still held its retained copy; the new ones deliver it **once**, with nothing logged. The exit drain is now idempotent, since `beforeExit` re-fires every time a handler schedules async work and an unguarded one started a fresh 30s `shutdown()` on each pass. **No event, trigger or property changed** — all 73 call sites across the three dispatchers fire exactly as before. + +- Cover telemetry delivery against the real `posthog-node` and a real socket, in `__tests__/lib/telemetry-delivery.test.ts`. The existing suite mocks the library wholesale, and that mock is what let the above live in the tree: the constructor was called with the right *shape*, so it passed while events were being stranded. The new tests assert on bytes that arrived over a socket — including gunzipping the batch body, without which a green test means nothing, since posthog-node gzips it and a raw read silently parses as "no events delivered". They pin that a captured event reaches `/batch/` with its properties intact, that a transient 500 is retried and still delivered, that a successful flush logs no error, and — for the hook dispatcher carrying the other 37 call sites — that `trackHookEvent` reaches `/capture/` and that `flushHookTelemetry` lands events the caller never awaited. Two facts they nail down rather than fix: posthog-node **overwrites `$lib`** with its own name on the server path, so `trackEvent`'s `"failproofai"` never lands and `product` is the attribution that actually survives (the raw-fetch hook dispatcher has no SDK to overwrite it, so its `"failproofai-hooks"` does); and the opt-out still sends nothing. + +- Correct a comment in `hook-telemetry.ts` claiming `isTelemetryEnabled()` is memoised. `lib/telemetry-enabled.ts` documents at length that it is resolved fresh on every call, deliberately — an opt-out a long-lived process ignores until restart is not an opt-out — so the comment described the exact optimisation that file rejects. + ## 1.0.1-beta.0 — 2026-08-14 ### Features diff --git a/__tests__/lib/telemetry-delivery.test.ts b/__tests__/lib/telemetry-delivery.test.ts new file mode 100644 index 00000000..0bc436f2 --- /dev/null +++ b/__tests__/lib/telemetry-delivery.test.ts @@ -0,0 +1,272 @@ +// @vitest-environment node +/** + * End-to-end delivery tests for lib/telemetry.ts against the REAL posthog-node. + * + * This file exists because `__tests__/lib/telemetry.test.ts` mocks `posthog-node` + * wholesale, and that mock is what let a delivery bug live in the tree: the + * client was configured with an injected `resilientFetch` that retried for ~40s + * against posthog-node's own 5s `requestTimeout` deadline, with `flushInterval: + * 0` disabling the flush timer and `fetchRetryCount: 0` disabling the library's + * retries. Every one of those is invisible to a mock — the constructor was + * called with the right shape, so the mock-based suite passed while real events + * were being stranded in an in-memory queue. + * + * So: no mock of posthog-node here. A local HTTP server stands in for PostHog + * and the assertions are on bytes that actually arrived over a socket. + */ +import { describe, it, expect, beforeEach, afterEach, vi } from "vitest"; +import { createServer, type Server } from "node:http"; +import { gunzipSync } from "node:zlib"; + +vi.mock("@/lib/telemetry-id", () => ({ + getInstanceId: () => "delivery-test-instance", +})); + +import { initTelemetry, trackEvent, shutdownTelemetry } from "@/lib/telemetry"; +import { trackHookEvent, flushHookTelemetry } from "@/src/hooks/hook-telemetry"; + +interface CapturedRequest { + url: string; + body: string; +} + +interface TestServer { + url: string; + server: Server; + received: CapturedRequest[]; + /** Number of requests answered so far, including failed ones. */ + hits: () => number; +} + +/** + * A stand-in for PostHog's ingestion endpoint. `failFirst` makes the first N + * requests answer 500 so a retry can be observed; the body is still recorded so + * a test can prove the retry carried the same payload. + */ +async function startServer(opts: { failFirst?: number } = {}): Promise { + const received: CapturedRequest[] = []; + let hits = 0; + + const server = createServer((req, res) => { + const chunks: Buffer[] = []; + req.on("data", (c) => chunks.push(c)); + req.on("end", () => { + hits++; + // posthog-node gzips the batch body (`content-encoding: gzip`). Reading it + // raw yields binary, which silently parses as "no events delivered" — so + // decompress here rather than letting a green test mean nothing. + const raw = Buffer.concat(chunks); + const body = + req.headers["content-encoding"] === "gzip" + ? gunzipSync(raw).toString("utf-8") + : raw.toString("utf-8"); + received.push({ url: req.url ?? "", body }); + if (opts.failFirst && hits <= opts.failFirst) { + res.writeHead(500, { "Content-Type": "application/json" }).end("{}"); + return; + } + res.writeHead(200, { "Content-Type": "application/json" }).end(JSON.stringify({ status: 1 })); + }); + }); + + return new Promise((done) => { + server.listen(0, "127.0.0.1", () => { + const address = server.address(); + const port = typeof address === "object" && address ? address.port : 0; + done({ url: `http://127.0.0.1:${port}`, server, received, hits: () => hits }); + }); + }); +} + +/** Poll until `predicate` holds or the budget runs out. */ +async function waitFor(predicate: () => boolean, budgetMs: number): Promise { + const deadline = Date.now() + budgetMs; + while (Date.now() < deadline) { + if (predicate()) return; + await new Promise((r) => setTimeout(r, 25)); + } +} + +/** Every event name carried in the batches the server actually received. */ +function deliveredEvents(received: CapturedRequest[]): string[] { + const names: string[] = []; + for (const req of received) { + try { + const parsed = JSON.parse(req.body) as { batch?: Array<{ event?: string }> }; + for (const item of parsed.batch ?? []) { + if (item.event) names.push(item.event); + } + } catch { + // A body we can't parse is not a delivered event; the assertions will say so. + } + } + return names; +} + +describe("lib/telemetry delivery (real posthog-node)", () => { + let ph: TestServer | undefined; + + beforeEach(() => { + globalThis.__FAILPROOFAI_POSTHOG__ = undefined; + // vitest.config.mts sets this globally; delivery is exactly what it suppresses. + delete process.env.FAILPROOFAI_TELEMETRY_DISABLED; + process.env.FAILPROOFAI_POSTHOG_KEY = "phc_delivery_test"; + }); + + afterEach(async () => { + await shutdownTelemetry().catch(() => {}); + globalThis.__FAILPROOFAI_POSTHOG__ = undefined; + delete process.env.FAILPROOFAI_POSTHOG_KEY; + delete process.env.FAILPROOFAI_POSTHOG_HOST; + process.env.FAILPROOFAI_TELEMETRY_DISABLED = "1"; + await new Promise((done) => { + if (!ph) return done(); + ph.server.close(() => done()); + }); + ph = undefined; + }); + + it("delivers a captured event to the ingestion endpoint", async () => { + ph = await startServer(); + process.env.FAILPROOFAI_POSTHOG_HOST = ph.url; + + await initTelemetry(); + trackEvent("app_started", { runtime: "node" }); + + await waitFor(() => deliveredEvents(ph!.received).includes("app_started"), 10_000); + + expect(deliveredEvents(ph.received)).toContain("app_started"); + expect(ph.received.map((r) => r.url)).toContain("/batch/"); + + // The payload is the point — assert the properties survived the trip, not + // just that some request arrived. + const batch = ph.received + .map((r) => JSON.parse(r.body) as { batch?: Array> }) + .flatMap((p) => p.batch ?? []); + const event = batch.find((e) => e.event === "app_started"); + expect(event).toBeDefined(); + expect(event!.distinct_id).toBe("delivery-test-instance"); + expect(event!.properties).toMatchObject({ + runtime: "node", + product: "failproofai-oss", + failproofai_version: expect.any(String), + }); + + // `$lib` is NOT ours on this path, despite trackEvent() setting it to + // "failproofai": posthog-node owns that reserved property and overwrites it + // with its own name and version on every event. (The raw-fetch dispatcher in + // src/hooks/hook-telemetry.ts has no SDK to overwrite it, so its + // "failproofai-hooks" value does survive — the two paths disagree by + // construction.) Attribution that actually holds across both is `product`, + // asserted above; pinned here so nobody "fixes" trackEvent to fight the SDK. + expect((event!.properties as Record).$lib).toBe("posthog-node"); + }, 15_000); + + it("does not log a flush error when delivery succeeds", async () => { + const consoleError = vi.spyOn(console, "error").mockImplementation(() => {}); + ph = await startServer(); + process.env.FAILPROOFAI_POSTHOG_HOST = ph.url; + + await initTelemetry(); + trackEvent("app_started"); + await waitFor(() => deliveredEvents(ph!.received).includes("app_started"), 10_000); + + // posthog-node reports flush failures through a hardcoded console.error + // (`logFlushError`) on a fire-and-forget internal promise — no `.catch()` at + // our call sites can intercept it, so this is the only way to assert it. + const flushErrors = consoleError.mock.calls.filter((c) => + String(c[0]).includes("Error while flushing PostHog"), + ); + expect(flushErrors).toEqual([]); + consoleError.mockRestore(); + }, 15_000); + + it("retries a failed send and still delivers the event", async () => { + // The regression this guards: `fetchRetryCount: 0` meant a single transient + // failure dropped the batch out of the only delivery attempt it would get. + ph = await startServer({ failFirst: 1 }); + process.env.FAILPROOFAI_POSTHOG_HOST = ph.url; + + await initTelemetry(); + trackEvent("app_started"); + + // posthog-node's first retry waits `fetchRetryDelay` (3s), so budget past it. + await waitFor(() => ph!.hits() >= 2, 20_000); + + expect(ph.hits()).toBeGreaterThanOrEqual(2); + // Both the failed attempt and the retry carried the event. + expect(deliveredEvents(ph.received).filter((n) => n === "app_started").length).toBeGreaterThanOrEqual(2); + }, 25_000); +}); + +/** + * The other dispatcher, and the one carrying the most traffic: every hook event + * across all 11 CLIs plus the audit CLI's `cli_audit_*` events (37 call sites) + * goes through `trackHookEvent`. `__tests__/hooks/hook-telemetry.test.ts` covers + * the payload shape against a stubbed global fetch; these assert that bytes + * actually reach a listening socket, which a stub cannot show. + */ +describe("hook-telemetry delivery (real socket)", () => { + let ph: TestServer | undefined; + + beforeEach(() => { + delete process.env.FAILPROOFAI_TELEMETRY_DISABLED; + }); + + afterEach(async () => { + delete process.env.FAILPROOFAI_POSTHOG_HOST; + process.env.FAILPROOFAI_TELEMETRY_DISABLED = "1"; + await new Promise((done) => { + if (!ph) return done(); + ph.server.close(() => done()); + }); + ph = undefined; + }); + + it("delivers an awaited hook event to the capture endpoint", async () => { + ph = await startServer(); + process.env.FAILPROOFAI_POSTHOG_HOST = ph.url; + + await trackHookEvent("hook-instance", "hooks_installed", { count: 1 }); + + expect(ph.received).toHaveLength(1); + expect(ph.received[0].url).toBe("/capture/"); + const body = JSON.parse(ph.received[0].body) as Record; + expect(body.event).toBe("hooks_installed"); + expect(body.distinct_id).toBe("hook-instance"); + expect(body.properties).toMatchObject({ + count: 1, + product: "failproofai-oss", + // Unlike the posthog-node path, no SDK overwrites $lib here, so the + // dispatcher's own tag is what lands. + $lib: "failproofai-hooks", + }); + }, 15_000); + + it("flushHookTelemetry lands events the caller never awaited", async () => { + ph = await startServer(); + process.env.FAILPROOFAI_POSTHOG_HOST = ph.url; + + // The `void trackHookEvent(...)` shape used on the allow path, where no + // trailing await holds the event loop open before process.exit(). This is + // the guarantee flushHookTelemetry exists to provide. + void trackHookEvent("hook-instance", "custom_hooks_loaded", { n: 2 }); + void trackHookEvent("hook-instance", "convention_policies_loaded", { n: 3 }); + + await flushHookTelemetry(); + + const names = ph.received.map((r) => (JSON.parse(r.body) as { event: string }).event); + expect(names.sort()).toEqual(["convention_policies_loaded", "custom_hooks_loaded"]); + }, 15_000); + + it("sends nothing once telemetry is opted out", async () => { + ph = await startServer(); + process.env.FAILPROOFAI_POSTHOG_HOST = ph.url; + process.env.FAILPROOFAI_TELEMETRY_DISABLED = "1"; + + await trackHookEvent("hook-instance", "hooks_installed"); + await flushHookTelemetry(); + + expect(ph.received).toEqual([]); + }, 15_000); +}); diff --git a/__tests__/lib/telemetry.test.ts b/__tests__/lib/telemetry.test.ts index 879fdd05..9df27197 100644 --- a/__tests__/lib/telemetry.test.ts +++ b/__tests__/lib/telemetry.test.ts @@ -77,12 +77,30 @@ describe("lib/telemetry", () => { expect(globalThis.__FAILPROOFAI_POSTHOG__).toBeDefined(); }); - it("passes custom resilientFetch to PostHog constructor", async () => { + // These four assertions are the delivery contract. Each pins a value whose + // previous setting dropped events on the floor — see the comment block in + // lib/telemetry.ts and __tests__/lib/telemetry-delivery.test.ts, which + // proves the same contract end-to-end against the real library. + it("configures PostHog to own retries and keep its flush timer armed", async () => { delete process.env.FAILPROOFAI_TELEMETRY_DISABLED; await initTelemetry(); expect(lastConstructorOpts).toBeDefined(); - expect(lastConstructorOpts!.fetch).toBeTypeOf("function"); - expect(lastConstructorOpts!.fetchRetryCount).toBe(0); + + // No injected fetch. posthog-node races an injected fetch against its own + // `requestTimeout` deadline, so any wrapper here is one budget-inversion + // away from making the deadline unreachable — which is exactly what the + // old `resilientFetch` (5 attempts / ~40s against a 5s deadline) did. + expect(lastConstructorOpts!.fetch).toBeUndefined(); + + // Retries belong to the library, which knows which errors are retryable. + expect(lastConstructorOpts!.fetchRetryCount).toBeGreaterThan(0); + + // 0 is falsy and disables the flush timer outright, stranding the batch + // posthog-node deliberately retains after a network error. + expect(lastConstructorOpts!.flushInterval).toBeGreaterThan(0); + + // Each attempt needs room to finish; the library's own default is 10s. + expect(lastConstructorOpts!.requestTimeout).toBeGreaterThanOrEqual(10_000); }); it("reuses existing client on subsequent calls", async () => { diff --git a/lib/telemetry.ts b/lib/telemetry.ts index 702d37ea..677f3964 100644 --- a/lib/telemetry.ts +++ b/lib/telemetry.ts @@ -38,41 +38,6 @@ interface PostHogOptions { requestTimeout?: number; fetchRetryCount?: number; fetchRetryDelay?: number; - fetch?: (url: string, options: Record) => Promise; -} - -/** - * Wraps native fetch with retry logic and silent failure for non-critical telemetry. - * Prevents posthog-node's internal console.error from firing on network errors. - */ -async function resilientFetch( - url: string, - options: Record, -): Promise { - const MAX_ATTEMPTS = 5; - const BASE_DELAY_MS = 1000; - const TIMEOUT_MS = 5000; - - for (let attempt = 1; attempt <= MAX_ATTEMPTS; attempt++) { - try { - const { signal: _, ...rest } = options; - const res = await fetch(url, { - ...(rest as RequestInit), - signal: AbortSignal.timeout(TIMEOUT_MS), - }); - if (res.ok) return res; - // Non-2xx (e.g. 502) — treat like a transient failure and retry - } catch { - // Network error (ETIMEDOUT, etc.) — retry - } - if (attempt < MAX_ATTEMPTS) { - const delay = Math.min(BASE_DELAY_MS * 2 ** (attempt - 1), 8000); - await new Promise((r) => setTimeout(r, delay)); - } - } - // All attempts failed — return fake OK so PostHog doesn't log errors. - // This is anonymous telemetry; silently dropping events is acceptable. - return new Response("{}", { status: 200 }); } /** @@ -101,17 +66,57 @@ export async function initTelemetry(): Promise { await import("posthog-node"); const apiKey = process.env.FAILPROOFAI_POSTHOG_KEY ?? DEFAULT_API_KEY; const host = process.env.FAILPROOFAI_POSTHOG_HOST ?? DEFAULT_HOST; + // Delivery-critical options. Every one of these was previously set to a + // value that lost events; see __tests__/lib/telemetry-delivery.test.ts, + // which pins the contract against the REAL library rather than a mock. + // + // No custom `fetch`. There used to be a `resilientFetch` wrapper here that + // retried five times over ~40s and then returned a synthetic 200 so + // posthog-node would never log a network error. It could not work: the + // library does not merely hand its abort signal to an injected fetch, it + // *races* that fetch against its own `requestTimeout` deadline + // (`Promise.race([fetchPromise, deadline])`) precisely because an injected + // fetch may ignore the signal — which ours did, by stripping it. With a + // ~40s budget racing a 5s deadline the wrapper could never return in time, + // so the synthetic 200 was unreachable, the `console.error` it existed to + // prevent fired anyway, and its retries ran on detached from the client that + // had already given up. Plain global fetch is what the library expects. + // + // `fetchRetryCount` was 0, which disabled retries entirely and left the + // wrapper above as the only thing retrying — the wrong layer. The library + // retries inside a single flush, knows which errors are retryable, and + // keeps its queue coherent while doing it. + // + // `flushInterval` was 0, which is falsy and therefore disables the flush + // timer completely. That is the one that actually stranded events: on a + // network error posthog-node deliberately does NOT dequeue the batch (it + // treats the failure as transient and keeps it for a later attempt), so + // with no timer armed those retained events had nothing scheduled to + // resend them and sat in memory until an unrelated later event happened to + // trigger a flush. + // + // `flushAt: 1` is deliberate and stays. Volume here is a handful of events + // per process, so batching buys nothing, and posthog-node's queue is + // memory-only (`PostHogMemoryStorage`) — anything still queued when the + // process dies is gone. Sending immediately is the best available defense. globalThis.__FAILPROOFAI_POSTHOG__ = new mod.PostHog(apiKey, { host, flushAt: 1, - flushInterval: 0, - requestTimeout: 5000, - fetchRetryCount: 0, - fetch: resilientFetch, + flushInterval: 10_000, + requestTimeout: 10_000, + fetchRetryCount: 3, + fetchRetryDelay: 3_000, }); - // Flush pending events when the process exits + // Flush pending events when the process exits. This drain is the last line + // of defense for the memory-only queue, so it must not fight itself: + // `beforeExit` re-fires every time a handler schedules more async work, and + // an unguarded handler starts a fresh `shutdown()` — each with its own 30s + // budget — on every one of those passes. + let draining = false; const onExit = () => { + if (draining) return; + draining = true; globalThis.__FAILPROOFAI_POSTHOG__?.shutdown().catch(() => {}); }; process.on("beforeExit", onExit); diff --git a/src/hooks/hook-telemetry.ts b/src/hooks/hook-telemetry.ts index 36c549c7..61288861 100644 --- a/src/hooks/hook-telemetry.ts +++ b/src/hooks/hook-telemetry.ts @@ -59,8 +59,9 @@ export async function trackHookEvent( properties?: Record, ): Promise { // Honours the config file as well as the env var — the env var alone cannot - // reach a system-scope daemon. Memoised, so this stays off the hook path's - // latency budget. See lib/telemetry-enabled.ts. + // reach a system-scope daemon. Resolved fresh on every call, NOT memoised: + // an opt-out a long-lived process ignores until restart is not an opt-out. + // See lib/telemetry-enabled.ts for why that cost is affordable here. if (!isTelemetryEnabled()) return; const p = sendEvent(distinctId, event, properties); From 929f98bf3f53e973b832a7eb42e54fd824de7e8b Mon Sep 17 00:00:00 2001 From: SiddarthAA Date: Sun, 16 Aug 2026 18:54:32 +0530 Subject: [PATCH 2/3] docs(audit): cut `audit --help` to a description and one usage block MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit It had grown to four sections and forty lines: a USAGE block that also carried the headless entry point, a separate SCHEDULING block, a WHAT IT DOES block re-describing the same scan, and a paragraph about which config file the flags write — an implementation detail of the CLI agreeing with the dashboard, not something to read while looking for a flag. Now two lines saying what the command is, then one aligned USAGE block with the five things a person can type. Each keeps its own usage: --schedule still names its optional day count, the 1-90 range and --email. The local-only promise survives, moved into the description where it reads as part of what the command is rather than as a footnote. --scheduled is dropped from the listing. It is not a flag anybody types but the second entry point the daemon spawns, and advertising a machine-facing flag one letter from --schedule is how somebody starts a full scan meaning to configure one. It still works and still refuses every argument it always refused. HELP becomes helpText(), because the command names are coloured through c(), which reads colorOn() at call time — a module-level string would bake in whatever the TTY looked like at import. Padding is measured on the raw command string, since the ANSI bytes occupy no columns; a test pins that in both colour modes, along with the 80-column fit and the presence of every command. No behaviour changed. All five commands verified dispatching against a temp FAILPROOFAI_HOME, and the output verified identical through dist/cli.mjs. Co-Authored-By: Claude Opus 5 (1M context) --- CHANGELOG.md | 2 + __tests__/audit/audit-cli-help.test.ts | 92 ++++++++++++++++++++ src/audit/cli.ts | 113 ++++++++++++++----------- 3 files changed, 158 insertions(+), 49 deletions(-) create mode 100644 __tests__/audit/audit-cli-help.test.ts diff --git a/CHANGELOG.md b/CHANGELOG.md index 7b20644f..6205859e 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -8,6 +8,8 @@ - Cover telemetry delivery against the real `posthog-node` and a real socket, in `__tests__/lib/telemetry-delivery.test.ts`. The existing suite mocks the library wholesale, and that mock is what let the above live in the tree: the constructor was called with the right *shape*, so it passed while events were being stranded. The new tests assert on bytes that arrived over a socket — including gunzipping the batch body, without which a green test means nothing, since posthog-node gzips it and a raw read silently parses as "no events delivered". They pin that a captured event reaches `/batch/` with its properties intact, that a transient 500 is retried and still delivered, that a successful flush logs no error, and — for the hook dispatcher carrying the other 37 call sites — that `trackHookEvent` reaches `/capture/` and that `flushHookTelemetry` lands events the caller never awaited. Two facts they nail down rather than fix: posthog-node **overwrites `$lib`** with its own name on the server path, so `trackEvent`'s `"failproofai"` never lands and `product` is the attribution that actually survives (the raw-fetch hook dispatcher has no SDK to overwrite it, so its `"failproofai-hooks"` does); and the opt-out still sends nothing. +- Cut `failproofai audit --help` down to what somebody actually needs to read: two lines saying what the command is, then one aligned USAGE block listing the five things a person can type. It had grown to four sections and forty lines — a `USAGE` block that also carried the headless entry point, a separate `SCHEDULING` block, a `WHAT IT DOES` block re-describing the same scan, and a paragraph about which config file the flags write, which is an implementation detail of the CLI agreeing with the dashboard rather than something to tell a reader at the moment they are looking for a flag. Every command keeps its own usage — `--schedule` still names its optional day count, its 1–90 range, and `--email` — and the local-only promise survives, moved into the second line where it reads as part of what the command IS. `--scheduled` is deliberately dropped from the listing: it is not a flag anybody types but the second entry point the daemon spawns, and advertising a machine-facing flag one letter away from `--schedule` is how somebody starts a full scan meaning to configure one. It still works and still refuses every argument it always refused. Command names are brand teal through the same `colorOn()` gate as the rest of the CLI, so piped output stays plain, and every line fits 80 columns. No behaviour changed — all five commands dispatch exactly as before, verified against a temp home. + - Correct a comment in `hook-telemetry.ts` claiming `isTelemetryEnabled()` is memoised. `lib/telemetry-enabled.ts` documents at length that it is resolved fresh on every call, deliberately — an opt-out a long-lived process ignores until restart is not an opt-out — so the comment described the exact optimisation that file rejects. ## 1.0.1-beta.0 — 2026-08-14 diff --git a/__tests__/audit/audit-cli-help.test.ts b/__tests__/audit/audit-cli-help.test.ts new file mode 100644 index 00000000..d2062cd8 --- /dev/null +++ b/__tests__/audit/audit-cli-help.test.ts @@ -0,0 +1,92 @@ +// @vitest-environment node +/** + * `failproofai audit --help`. + * + * Two things worth pinning. The obvious one is that every command a person can + * type is listed — a scheduling flag that exists and is undiscoverable is the + * same to a user as one that does not exist. + * + * The subtle one is the ALIGNMENT. The description column is produced by + * padding against the raw command string, because `c()` wraps it in ANSI escape + * bytes that occupy no terminal columns — pad against the coloured string and + * every row shifts left by the width of an escape sequence, but only when + * colour is on, which is never how the output is read in CI. So the width + * assertions below run in BOTH modes. + */ +import { describe, it, expect, afterEach } from "vitest"; +import { helpText } from "../../src/audit/cli"; + +/** Strip ANSI so a rendered line can be measured in terminal columns. */ +const plain = (s: string): string => s.replace(/\[[0-9;]*m/g, ""); + +describe("audit --help", () => { + const originalEnv = { ...process.env }; + + afterEach(() => { + process.env = { ...originalEnv }; + }); + + function render(color: boolean): string { + if (color) { + process.env.FORCE_COLOR = "1"; + delete process.env.NO_COLOR; + } else { + process.env.NO_COLOR = "1"; + delete process.env.FORCE_COLOR; + } + return helpText(); + } + + it("lists every command a person can type", () => { + const text = plain(render(false)); + for (const command of [ + "failproofai audit", + "failproofai audit --schedule [days]", + "failproofai audit --no-schedule", + "failproofai audit --status", + "failproofai audit -h, --help", + ]) { + expect(text).toContain(command); + } + // --email modifies --schedule rather than standing alone, so it is named in + // that entry rather than given a row of its own. + expect(text).toContain("--email
"); + }); + + it("omits --scheduled, which the daemon spawns and nobody types", () => { + // One letter from `--schedule` and it starts a full scan instead of + // configuring one. It still works; it is just not advertised beside it. + expect(plain(render(false))).not.toContain("--scheduled"); + }); + + it("keeps the local-only promise the docs also make", () => { + expect(plain(render(false))).toMatch(/runs on this machine/i); + }); + + it.each([true, false])("aligns and fits 80 columns with color=%s", (color) => { + const lines = plain(render(color)).split("\n"); + + for (const line of lines) { + expect(line.length).toBeLessThanOrEqual(80); + } + + // Every command row and every continuation line shares one description + // column. Derive it from the first row rather than restating the constant, + // so this fails on drift instead of being updated to match it. + const first = lines.find((l) => l.includes("failproofai audit ")); + expect(first).toBeDefined(); + const descCol = first!.indexOf("Scan your session history"); + expect(descCol).toBeGreaterThan(0); + + const continuations = lines.filter( + (l) => l.startsWith(" ".repeat(descCol)) && l.trim().length > 0, + ); + // The rows carry six continuation lines between them. A floor rather than + // an exact count, so reworded copy does not fail this — but a regression in + // the padding math moves them off `descCol` entirely and drops it to zero. + expect(continuations.length).toBeGreaterThanOrEqual(6); + for (const line of continuations) { + expect(line[descCol]).not.toBe(" "); + } + }); +}); diff --git a/src/audit/cli.ts b/src/audit/cli.ts index 0ec2c68b..d4fb136f 100644 --- a/src/audit/cli.ts +++ b/src/audit/cli.ts @@ -2,8 +2,11 @@ * `failproofai audit` — run a local audit of your agent-CLI history, then open * the dashboard to view it. * - * failproofai audit Scan, then launch the dashboard at /audit. - * failproofai audit --help Show usage. + * failproofai audit Scan, then launch the dashboard at /audit. + * failproofai audit --schedule Put scans on a timer and mail the findings. + * failproofai audit --no-schedule Stop the timer. + * failproofai audit --status What this machine is scheduled to do. + * failproofai audit -h, --help Show usage. * * `runAudit()` is a pure local function (no network, no account). We run it, * render the same four progress stages the dashboard's RunProgress shows, @@ -11,9 +14,10 @@ * the bundled dashboard server and open the browser to /audit — which renders * instantly from that cache. * - * No arguments yet — a bare `failproofai audit` does a full scan (all CLIs, all - * history). Flags (--since, --cli, --project, --port, --no-open) are easy - * follow-ups against `RunAuditOptions`. + * A bare `failproofai audit` does a full scan (all CLIs, all history); the + * scheduling flags above write config and never scan. Scan-shaping flags + * (--since, --cli, --project, --port, --no-open) are easy follow-ups against + * `RunAuditOptions`. * * `--scheduled` is the one exception, and it is not a flag on the interactive * command so much as a second entry point sharing its name: it runs the same @@ -58,49 +62,60 @@ export const AUDIT_STAGES: ReadonlyArray<{ label: string; detail: string }> = [ { label: "aggregating results", detail: "counting hits, ranking by frequency" }, ]; -const HELP = ` -failproofai audit — audit your AI agent's behavior, then open the dashboard - -USAGE - failproofai audit Scan your agent-CLI session history for risky and - wasteful patterns, then open the audit dashboard. - failproofai audit --help Show this help. - - failproofai audit --scheduled - Headless run: scan, refresh the dashboard's cached - result, print one line, exit. No browser, no - server. This is what a scheduled audit runs; exit - 75 means another audit already had the lock. - -SCHEDULING - failproofai audit --schedule [days] [--email you@yourdomain.com] - Scan on a timer in the background (default 7 days, - 1-90), and email you when a scan finds something - harmful. Signs you in the first time — the report - has to go somewhere. Pass --email to answer that - up front and go straight to entering the code. - failproofai audit --no-schedule - Stop scanning on a timer. Leaves you signed in. - failproofai audit --status - What this machine is doing: whether scheduling is - on, where reports go, the daemon's state, and when - the next scan is due. - - These write the same ~/.failproofai/config.json the dashboard's settings page - writes, through the same function — so the two are always in step. - -WHAT IT DOES - 1. Scans past sessions from every installed agent CLI (Claude, Codex, Cursor, - Copilot, OpenCode, Pi) — entirely on your machine. - 2. Starts the local dashboard and opens - http://localhost:${DASHBOARD_PORT}/audit with your results. - - A bare "failproofai audit" needs no account, and nothing from your sessions - leaves this machine — anonymous usage counts still apply unless you set - FAILPROOFAI_TELEMETRY_DISABLED=1. Scheduling is the exception: it emails you - what it finds, so it needs an address. - Press Ctrl+C to stop the dashboard server when you're done. -`.trimStart(); +/** Column the description text starts at. The widest command line is 37 wide. */ +const HELP_DESC_COL = 40; + +/** + * `audit --help`. + * + * A function rather than a module-level string because the command names are + * coloured through `c()`, which reads `colorOn()` at CALL time — a const would + * bake in whatever the TTY looked like at import, and this module is imported + * by the bundled CLI long before anyone asks for help. + * + * `--scheduled` is deliberately absent: it is not a flag a person types but a + * second entry point the daemon spawns (see the module header), and listing a + * machine-facing flag one letter away from `--schedule` in the same block is + * how somebody ends up running a 100-second scan when they meant to configure + * one. It still works, and still refuses every argument it always refused. + */ +export function helpText(): string { + const row = (command: string, lines: string[]): string => { + // Padding is measured on the RAW command — `c()` adds escape bytes that + // occupy no columns, so colouring first would misalign every row. + const pad = " ".repeat(Math.max(1, HELP_DESC_COL - 2 - command.length)); + return lines + .map((line, i) => + i === 0 ? ` ${c(CYAN, command)}${pad}${line}` : `${" ".repeat(HELP_DESC_COL)}${line}`, + ) + .join("\n"); + }; + + return [ + `${c(BOLD, "failproofai audit")} — review your agent CLIs for risky and wasteful patterns.`, + c(DIM, "Everything runs on this machine; only a scheduled digest ever leaves it."), + "", + c(BOLD, "USAGE"), + row("failproofai audit", [ + "Scan your session history, then open", + `http://localhost:${DASHBOARD_PORT}/audit`, + ]), + row("failproofai audit --schedule [days]", [ + "Scan on a timer and email the findings.", + "Default 7 days, range 1-90.", + "Signs you in the first time; add", + "--email
to skip a prompt.", + ]), + row("failproofai audit --no-schedule", ["Stop the timer. Leaves you signed in."]), + row("failproofai audit --status", [ + "Whether scheduling is on, where reports", + "go, the daemon's state, and when the", + "next scan is due.", + ]), + row("failproofai audit -h, --help", ["Show this help."]), + "", + ].join("\n"); +} // ── ANSI helpers ──────────────────────────────────────────────────────────── // Colours come from the shared brand palette in hooks/tui.ts, so `audit` reads @@ -498,7 +513,7 @@ export async function runPostSetupAudit(): Promise { export async function runAuditCli(args: string[]): Promise { if (args.includes("--help") || args.includes("-h")) { - process.stdout.write(HELP); + process.stdout.write(helpText()); process.exit(0); } // The headless path, spawned rather than typed. Handled ahead of the From daa250cbfe8f9030ae2cca7e96f1d74191b92fb7 Mon Sep 17 00:00:00 2001 From: SiddarthAA Date: Sun, 16 Aug 2026 18:58:34 +0530 Subject: [PATCH 3/3] docs: reference PR #701 in the changelog entries Co-Authored-By: Claude Opus 5 (1M context) --- CHANGELOG.md | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 6205859e..729a574d 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -4,13 +4,13 @@ ### Fixes -- **Stop the dashboard server's telemetry from stranding its own events, and stop it printing `Error while flushing PostHog` while doing it.** Four options on the `posthog-node` client each disabled a different part of the library's delivery machinery, and together they turned a slow network into lost events plus a stack trace in the user's terminal — the one `failproofai audit` starts, where `launch()`'s log filter only strips the Server Action skew block. The injected `resilientFetch` was the root of it: it retried five times over ~40s and then returned a synthetic `200` so the library would never log a network error, but posthog-node does not merely hand its abort signal to an injected fetch, it **races that fetch against its own `requestTimeout`** (`Promise.race([fetchPromise, deadline])`) precisely because an injected fetch may ignore the signal — which ours did, by stripping it. A ~40s budget racing a 5s deadline can never return in time, so the synthetic `200` was unreachable code, the `console.error` it existed to prevent fired anyway at 5s, and the retries ran on detached from a client that had already given up. Worse, that `200` was the wrong answer even when it did land: posthog-node deliberately does NOT dequeue a batch that failed with a network error, so reporting success is what would have made it discard events that never arrived. The wrapper is gone; plain global fetch is what the library expects. `fetchRetryCount` was `0`, leaving that wrapper as the only thing retrying, at the wrong layer — the library retries inside a single flush, knows which errors are retryable, and keeps its queue coherent while doing it. `requestTimeout` was `5000`, half the library's own default, so every attempt had half the room. And `flushInterval` was `0`, which is falsy and therefore disables the flush timer outright — that is the one that actually stranded events, because the batch posthog-node retains after a network error then had nothing scheduled to resend it and sat in an in-memory queue (`PostHogMemoryStorage`, so nothing survives the process) until some unrelated later event happened to trigger a flush. `flushAt: 1` is unchanged and deliberate: volume is a handful of events per process, batching buys nothing, and sending immediately is the best defense a memory-only queue has against the process dying. Measured against a server that answers correctly but takes 6s — a slow network, not an outage — the old options delivered the event **four times** and logged two flush errors, because the wrapper re-POSTed the same batch on each of its own retries while the library still held its retained copy; the new ones deliver it **once**, with nothing logged. The exit drain is now idempotent, since `beforeExit` re-fires every time a handler schedules async work and an unguarded one started a fresh 30s `shutdown()` on each pass. **No event, trigger or property changed** — all 73 call sites across the three dispatchers fire exactly as before. +- **Stop the dashboard server's telemetry from stranding its own events, and stop it printing `Error while flushing PostHog` while doing it.** Four options on the `posthog-node` client each disabled a different part of the library's delivery machinery, and together they turned a slow network into lost events plus a stack trace in the user's terminal — the one `failproofai audit` starts, where `launch()`'s log filter only strips the Server Action skew block. The injected `resilientFetch` was the root of it: it retried five times over ~40s and then returned a synthetic `200` so the library would never log a network error, but posthog-node does not merely hand its abort signal to an injected fetch, it **races that fetch against its own `requestTimeout`** (`Promise.race([fetchPromise, deadline])`) precisely because an injected fetch may ignore the signal — which ours did, by stripping it. A ~40s budget racing a 5s deadline can never return in time, so the synthetic `200` was unreachable code, the `console.error` it existed to prevent fired anyway at 5s, and the retries ran on detached from a client that had already given up. Worse, that `200` was the wrong answer even when it did land: posthog-node deliberately does NOT dequeue a batch that failed with a network error, so reporting success is what would have made it discard events that never arrived. The wrapper is gone; plain global fetch is what the library expects. `fetchRetryCount` was `0`, leaving that wrapper as the only thing retrying, at the wrong layer — the library retries inside a single flush, knows which errors are retryable, and keeps its queue coherent while doing it. `requestTimeout` was `5000`, half the library's own default, so every attempt had half the room. And `flushInterval` was `0`, which is falsy and therefore disables the flush timer outright — that is the one that actually stranded events, because the batch posthog-node retains after a network error then had nothing scheduled to resend it and sat in an in-memory queue (`PostHogMemoryStorage`, so nothing survives the process) until some unrelated later event happened to trigger a flush. `flushAt: 1` is unchanged and deliberate: volume is a handful of events per process, batching buys nothing, and sending immediately is the best defense a memory-only queue has against the process dying. Measured against a server that answers correctly but takes 6s — a slow network, not an outage — the old options delivered the event **four times** and logged two flush errors, because the wrapper re-POSTed the same batch on each of its own retries while the library still held its retained copy; the new ones deliver it **once**, with nothing logged. The exit drain is now idempotent, since `beforeExit` re-fires every time a handler schedules async work and an unguarded one started a fresh 30s `shutdown()` on each pass. **No event, trigger or property changed** — all 73 call sites across the three dispatchers fire exactly as before. (#701) -- Cover telemetry delivery against the real `posthog-node` and a real socket, in `__tests__/lib/telemetry-delivery.test.ts`. The existing suite mocks the library wholesale, and that mock is what let the above live in the tree: the constructor was called with the right *shape*, so it passed while events were being stranded. The new tests assert on bytes that arrived over a socket — including gunzipping the batch body, without which a green test means nothing, since posthog-node gzips it and a raw read silently parses as "no events delivered". They pin that a captured event reaches `/batch/` with its properties intact, that a transient 500 is retried and still delivered, that a successful flush logs no error, and — for the hook dispatcher carrying the other 37 call sites — that `trackHookEvent` reaches `/capture/` and that `flushHookTelemetry` lands events the caller never awaited. Two facts they nail down rather than fix: posthog-node **overwrites `$lib`** with its own name on the server path, so `trackEvent`'s `"failproofai"` never lands and `product` is the attribution that actually survives (the raw-fetch hook dispatcher has no SDK to overwrite it, so its `"failproofai-hooks"` does); and the opt-out still sends nothing. +- Cover telemetry delivery against the real `posthog-node` and a real socket, in `__tests__/lib/telemetry-delivery.test.ts`. The existing suite mocks the library wholesale, and that mock is what let the above live in the tree: the constructor was called with the right *shape*, so it passed while events were being stranded. The new tests assert on bytes that arrived over a socket — including gunzipping the batch body, without which a green test means nothing, since posthog-node gzips it and a raw read silently parses as "no events delivered". They pin that a captured event reaches `/batch/` with its properties intact, that a transient 500 is retried and still delivered, that a successful flush logs no error, and — for the hook dispatcher carrying the other 37 call sites — that `trackHookEvent` reaches `/capture/` and that `flushHookTelemetry` lands events the caller never awaited. Two facts they nail down rather than fix: posthog-node **overwrites `$lib`** with its own name on the server path, so `trackEvent`'s `"failproofai"` never lands and `product` is the attribution that actually survives (the raw-fetch hook dispatcher has no SDK to overwrite it, so its `"failproofai-hooks"` does); and the opt-out still sends nothing. (#701) -- Cut `failproofai audit --help` down to what somebody actually needs to read: two lines saying what the command is, then one aligned USAGE block listing the five things a person can type. It had grown to four sections and forty lines — a `USAGE` block that also carried the headless entry point, a separate `SCHEDULING` block, a `WHAT IT DOES` block re-describing the same scan, and a paragraph about which config file the flags write, which is an implementation detail of the CLI agreeing with the dashboard rather than something to tell a reader at the moment they are looking for a flag. Every command keeps its own usage — `--schedule` still names its optional day count, its 1–90 range, and `--email` — and the local-only promise survives, moved into the second line where it reads as part of what the command IS. `--scheduled` is deliberately dropped from the listing: it is not a flag anybody types but the second entry point the daemon spawns, and advertising a machine-facing flag one letter away from `--schedule` is how somebody starts a full scan meaning to configure one. It still works and still refuses every argument it always refused. Command names are brand teal through the same `colorOn()` gate as the rest of the CLI, so piped output stays plain, and every line fits 80 columns. No behaviour changed — all five commands dispatch exactly as before, verified against a temp home. +- Cut `failproofai audit --help` down to what somebody actually needs to read: two lines saying what the command is, then one aligned USAGE block listing the five things a person can type. It had grown to four sections and forty lines — a `USAGE` block that also carried the headless entry point, a separate `SCHEDULING` block, a `WHAT IT DOES` block re-describing the same scan, and a paragraph about which config file the flags write, which is an implementation detail of the CLI agreeing with the dashboard rather than something to tell a reader at the moment they are looking for a flag. Every command keeps its own usage — `--schedule` still names its optional day count, its 1–90 range, and `--email` — and the local-only promise survives, moved into the second line where it reads as part of what the command IS. `--scheduled` is deliberately dropped from the listing: it is not a flag anybody types but the second entry point the daemon spawns, and advertising a machine-facing flag one letter away from `--schedule` is how somebody starts a full scan meaning to configure one. It still works and still refuses every argument it always refused. Command names are brand teal through the same `colorOn()` gate as the rest of the CLI, so piped output stays plain, and every line fits 80 columns. No behaviour changed — all five commands dispatch exactly as before, verified against a temp home. (#701) -- Correct a comment in `hook-telemetry.ts` claiming `isTelemetryEnabled()` is memoised. `lib/telemetry-enabled.ts` documents at length that it is resolved fresh on every call, deliberately — an opt-out a long-lived process ignores until restart is not an opt-out — so the comment described the exact optimisation that file rejects. +- Correct a comment in `hook-telemetry.ts` claiming `isTelemetryEnabled()` is memoised. `lib/telemetry-enabled.ts` documents at length that it is resolved fresh on every call, deliberately — an opt-out a long-lived process ignores until restart is not an opt-out — so the comment described the exact optimisation that file rejects. (#701) ## 1.0.1-beta.0 — 2026-08-14