diff --git a/CHANGELOG.md b/CHANGELOG.md index f142953e..dfdb26b5 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -14,6 +14,7 @@ ### Fixes - Make documentation translation publishing atomic: require every locale and cache artifact, pin the Mintlify validator, validate the final overlaid PR tree, and emit the canonical `pt-BR` Mintlify locale while preserving `pt-br` paths. +- Fix hook telemetry being dropped on the common allow path. The binary is short-lived — `bin/failproofai.mjs` calls `process.exit()` the moment `handleHookEvent` returns — so events fired with un-awaited `void trackHookEvent(...)` (`custom_hooks_loaded`, `convention_policies_loaded`, the `*_error` events) were killed mid-flight and never reached PostHog; they only survived when a `deny`/`instruct` decision happened to add a trailing `await`. `hook-telemetry.ts` now tracks every in-flight POST and exposes `flushHookTelemetry()`, which `handleHookEvent` awaits before returning (and `bin`'s hook error path drains on throw), so all fired events are delivered reliably regardless of decision. No change to *which* events fire — allow decisions still send nothing by design. (#515) - Fix the Pi live `pi list` roundtrip e2e tests against pi-coding-agent ≥0.80: newer Pi no longer trusts project-local `.pi/settings.json` by default, so the tests now detect the installed Pi version and pass `pi list --approve` on ≥0.80 (older Pi trusts project settings without the flag and would reject it) to include the project-scope package failproofai's installer writes (previously `pi list` printed "No packages installed." — failing the install roundtrip and making the uninstall roundtrip pass vacuously). Gated behind `detectPiVersion()`, so it only runs where `pi` is installed. (#491) - Fix Antigravity file writes slipping past path/content policies. `ANTIGRAVITY_TOOL_MAP` had best-effort tool names; the real ones (verified against the `agy` binary + live transcripts) are `write_to_file` (not `write_file`), `list_dir` (not `list_directory`), and `find_by_name` (not `find_filepath`), and there was **no** input-key map for file tools — so `write_to_file`'s path (delivered as `TargetFile`) never became `file_path` and `block-env-files` / `block-secrets-write` silently allowed `.env` writes on Antigravity. Corrected the tool names and added `Write`/`Edit`/`Read` input maps (`TargetFile`→`file_path`, `CodeContent`→`content`). Verified live: `agy` now denies a `.env` write. (#508) - Keep informational allow-notes out of the agent-facing hook stdout on events with no additional-context channel (`Stop`, `SubagentStop`, `Session*`, `PreCompact`, …). Previously a *passing* `Stop` emitted its allow-reasons as `{reason}` on stdout, so agents like droid rendered a "…skipping commit check…skipping PR check…" wall on a perfectly fine turn. Those notes now go to stderr + the activity store only; stdout stays clean on channel-less events. (#508) diff --git a/__tests__/hooks/handler.test.ts b/__tests__/hooks/handler.test.ts index 41be695b..2e50c321 100644 --- a/__tests__/hooks/handler.test.ts +++ b/__tests__/hooks/handler.test.ts @@ -36,6 +36,7 @@ vi.mock("../../src/hooks/hook-activity-store", () => ({ vi.mock("../../src/hooks/hook-telemetry", () => ({ trackHookEvent: vi.fn(() => Promise.resolve()), + flushHookTelemetry: vi.fn(() => Promise.resolve()), })); vi.mock("../../lib/telemetry-id", () => ({ @@ -147,6 +148,17 @@ describe("hooks/handler", () => { ); }); + it("flushes pending telemetry before returning, even on the allow path", async () => { + // The allow path fires no awaited event, so without an explicit flush the + // caller's process.exit() would drop un-awaited (`void`) load/error events. + mockStdin(); + const { flushHookTelemetry } = await import("../../src/hooks/hook-telemetry"); + + await handleHookEvent("PreToolUse"); + + expect(flushHookTelemetry).toHaveBeenCalled(); + }); + it("persists deny decision when evaluator returns deny", async () => { const { evaluatePolicies } = await import("../../src/hooks/policy-evaluator"); vi.mocked(evaluatePolicies).mockResolvedValueOnce({ diff --git a/__tests__/hooks/hook-telemetry.test.ts b/__tests__/hooks/hook-telemetry.test.ts index 81a05ecb..071d3705 100644 --- a/__tests__/hooks/hook-telemetry.test.ts +++ b/__tests__/hooks/hook-telemetry.test.ts @@ -5,7 +5,7 @@ * fetch body here guarantees `product: failproofai-oss` is stamped on all of them. */ import { describe, it, expect, vi, beforeEach, afterEach } from "vitest"; -import { trackHookEvent } from "../../src/hooks/hook-telemetry"; +import { trackHookEvent, flushHookTelemetry } from "../../src/hooks/hook-telemetry"; describe("hook-telemetry trackHookEvent", () => { let fetchSpy: ReturnType; @@ -48,3 +48,61 @@ describe("hook-telemetry trackHookEvent", () => { expect(fetchSpy).not.toHaveBeenCalled(); }); }); + +describe("flushHookTelemetry", () => { + let fetchSpy: ReturnType; + const originalEnv = { ...process.env }; + + beforeEach(() => { + delete process.env.FAILPROOFAI_TELEMETRY_DISABLED; + }); + + afterEach(() => { + vi.unstubAllGlobals(); + process.env = { ...originalEnv }; + }); + + it("resolves instantly when nothing is pending", async () => { + fetchSpy = vi.fn().mockResolvedValue(new Response("{}", { status: 200 })); + vi.stubGlobal("fetch", fetchSpy); + await expect(flushHookTelemetry()).resolves.toBeUndefined(); + expect(fetchSpy).not.toHaveBeenCalled(); + }); + + it("awaits an un-awaited (void) event so the POST completes before exit", async () => { + // Control when the fetch settles to prove flush actually waits for it. + let resolveFetch!: (r: Response) => void; + fetchSpy = vi.fn( + () => new Promise((res) => { resolveFetch = res; }), + ); + vi.stubGlobal("fetch", fetchSpy); + + // Fire WITHOUT awaiting — this is exactly how the handler's load/error + // events are sent (`void trackHookEvent(...)`). + void trackHookEvent("inst-id", "custom_hooks_loaded", { n: 1 }); + await Promise.resolve(); // let the pending promise register + expect(fetchSpy).toHaveBeenCalledOnce(); + + let flushed = false; + const flushP = flushHookTelemetry().then(() => { flushed = true; }); + + // Fetch is still in flight → flush must not have resolved yet. + await Promise.resolve(); + expect(flushed).toBe(false); + + // Once the POST settles, flush drains and resolves. + resolveFetch(new Response("{}", { status: 200 })); + await flushP; + expect(flushed).toBe(true); + }); + + it("does not throw when an in-flight POST rejects", async () => { + fetchSpy = vi.fn().mockRejectedValue(new Error("network down")); + vi.stubGlobal("fetch", fetchSpy); + + void trackHookEvent("inst-id", "custom_hooks_loaded"); + await Promise.resolve(); + + await expect(flushHookTelemetry()).resolves.toBeUndefined(); + }); +}); diff --git a/bin/failproofai.mjs b/bin/failproofai.mjs index b7490cc0..9f8bb1f7 100755 --- a/bin/failproofai.mjs +++ b/bin/failproofai.mjs @@ -93,6 +93,8 @@ if (hookIdx >= 0) { try { const { handleHookEvent } = await import("../src/hooks/handler"); const exitCode = await handleHookEvent(eventType, cli); + // handleHookEvent already flushes its own telemetry before returning; this + // is the normal, reliable exit. process.exit(exitCode); } catch (err) { const msg = err instanceof Error ? err.message : String(err); @@ -101,6 +103,13 @@ if (hookIdx >= 0) { cli, error_type: err instanceof Error ? err.name : "unknown", }); + // handleHookEvent threw before its own flush ran, so any events it fired + // with `void trackHookEvent(...)` are still in flight — drain them (plus the + // hook_dispatch_error above) before exiting so they aren't dropped. + try { + const { flushHookTelemetry } = await import("../src/hooks/hook-telemetry"); + await flushHookTelemetry(); + } catch {} console.error(`Unexpected error: ${msg}`); process.exit(2); } diff --git a/src/hooks/handler.ts b/src/hooks/handler.ts index 7ee80770..ab143456 100644 --- a/src/hooks/handler.ts +++ b/src/hooks/handler.ts @@ -33,7 +33,7 @@ import { clearPolicies, registerPolicy } from "./policy-registry"; import { loadAllCustomHooks } from "./custom-hooks-loader"; import type { CustomHook } from "./policy-types"; import { persistHookActivity } from "./hook-activity-store"; -import { trackHookEvent } from "./hook-telemetry"; +import { trackHookEvent, flushHookTelemetry } from "./hook-telemetry"; import { resolveCwd } from "./resolve-cwd"; import { resolvePermissionMode } from "./resolve-permission-mode"; import { resolveTranscriptPath } from "./resolve-transcript-path"; @@ -356,5 +356,11 @@ export async function handleHookEvent( } } + // Await any un-awaited (`void trackHookEvent(...)`) events fired during this + // invocation before returning. The caller (bin/failproofai.mjs) calls + // process.exit() as soon as we return, which would otherwise drop in-flight + // POSTs — notably on the allow path, which has no trailing awaited event. + await flushHookTelemetry(); + return result.exitCode; } diff --git a/src/hooks/hook-telemetry.ts b/src/hooks/hook-telemetry.ts index d4240cb7..59e0a5b1 100644 --- a/src/hooks/hook-telemetry.ts +++ b/src/hooks/hook-telemetry.ts @@ -11,13 +11,23 @@ import { POSTHOG_API_KEY, POSTHOG_PRODUCT } from "../posthog-key"; const API_KEY = POSTHOG_API_KEY; const CAPTURE_URL = "https://us.i.posthog.com/capture/"; -export async function trackHookEvent( +/** + * In-flight telemetry POSTs. The hook binary is short-lived — `bin/failproofai.mjs` + * calls `process.exit()` the moment `handleHookEvent` returns, which kills any + * fetch that a caller fired with `void trackHookEvent(...)` (i.e. did not await). + * We track every send here so `flushHookTelemetry()` can await them all at the + * process-exit boundary, making delivery reliable regardless of whether the + * individual call site awaited. Without this, un-awaited events (custom_hooks_loaded, + * convention_policies_loaded, the *_error events) are dropped on the common + * allow path, since no trailing await holds the event loop open. + */ +const pending = new Set>(); + +async function sendEvent( distinctId: string, event: string, properties?: Record, ): Promise { - if (process.env.FAILPROOFAI_TELEMETRY_DISABLED === "1") return; - const body = JSON.stringify({ api_key: process.env.FAILPROOFAI_POSTHOG_KEY ?? API_KEY, event, @@ -41,3 +51,33 @@ export async function trackHookEvent( // Telemetry is best-effort — never fail the hook } } + +export async function trackHookEvent( + distinctId: string, + event: string, + properties?: Record, +): Promise { + if (process.env.FAILPROOFAI_TELEMETRY_DISABLED === "1") return; + + const p = sendEvent(distinctId, event, properties); + pending.add(p); + // Deregister on settle so the set doesn't grow unbounded in long-lived + // callers (tests, the dashboard server). `sendEvent` never rejects, but + // `.finally` is defensive. + void p.finally(() => pending.delete(p)); + await p; +} + +/** + * Await every in-flight telemetry POST. Call this immediately before + * `process.exit()` on any short-lived path so `void trackHookEvent(...)` events + * are delivered instead of being cut off by the exit. No-op (resolves instantly) + * when nothing is pending. Never throws — `sendEvent` swallows its own errors. + */ +export async function flushHookTelemetry(): Promise { + // Loop in case a settling promise's `.finally` races a newly-added send; + // in practice one pass suffices because no send spawns another. + while (pending.size > 0) { + await Promise.allSettled([...pending]); + } +}