diff --git a/packages/core/src/__tests__/activity-events.test.ts b/packages/core/src/__tests__/activity-events.test.ts index 14bc39437..92373f651 100644 --- a/packages/core/src/__tests__/activity-events.test.ts +++ b/packages/core/src/__tests__/activity-events.test.ts @@ -213,4 +213,176 @@ describe("recordActivityEvent", () => { expect((capturedSummary as string).length).toBe(500); expect(capturedSummary).toMatch(/\.\.\.$/); }); + + // ─── Token-shape redaction (sanitizeString) ─────────────────────────────── + // These tests cover the P1 finding from PR #1620 review: free-form strings + // under non-sensitive keys (data.message, data.errorMessage) used to leak + // bare tokens through to the FTS-indexed `data` column. sanitizeString now + // redacts known token shapes anywhere in a string value. + + function recordAndCaptureData(input: Record): Record { + let capturedData: unknown; + const captureDb = { + prepare: (_sql: string) => ({ + run: (...args: unknown[]) => { + capturedData = args[8]; // data is 9th param (index 8) + }, + all: () => [], + }), + }; + vi.mocked(eventsDb.getDb).mockReturnValueOnce(captureDb as any); + recordActivityEvent({ + source: "lifecycle", + kind: "lifecycle.poll_failed", + summary: "test", + data: input, + }); + return JSON.parse(capturedData as string); + } + + it("redacts Bearer tokens in string values (preserves prefix)", () => { + const out = recordAndCaptureData({ + errorMessage: "401 from https://api.example.com Bearer eyJhbGciOiJIUzI1NiJ9.abc", + }); + expect(out["errorMessage"]).not.toContain("eyJhbGciOiJIUzI1NiJ9"); + expect(out["errorMessage"]).toContain("Bearer [redacted]"); + }); + + it("redacts GitHub PATs (ghp_, gho_, github_pat_) in error messages", () => { + const out = recordAndCaptureData({ + errorMessage: "git push failed: bad credentials ghp_abcdefghijklmnopqrstuvwxyz12345", + message: "trying github_pat_11ABCDEFG0abcdefghijklmnopqrstuvwxyz1234567890", + }); + expect(out["errorMessage"]).not.toContain("ghp_abcdefghijklmnopqrstuvwxyz"); + expect(out["errorMessage"]).toContain("[redacted]"); + expect(out["message"]).not.toContain("github_pat_11"); + expect(out["message"]).toContain("[redacted]"); + }); + + it("redacts OpenAI / Anthropic sk- keys in free-form values", () => { + const out = recordAndCaptureData({ + message: "stuck on sk-proj-abcdefghijklmnopqrstuvwx returns 429", + errorMessage: "auth failed for sk-ant-api03-abcdefghijklmnopqrst-xyz", + }); + expect(out["message"]).not.toContain("sk-proj-abcdefghijklmnopqrstuvwx"); + expect(out["errorMessage"]).not.toContain("sk-ant-api03"); + expect(out["message"]).toContain("[redacted]"); + expect(out["errorMessage"]).toContain("[redacted]"); + }); + + it("redacts Slack xox tokens", () => { + const out = recordAndCaptureData({ + errorMessage: "webhook rejected with xoxb-1234567890-abcdefghij", + }); + expect(out["errorMessage"]).not.toContain("xoxb-1234567890"); + expect(out["errorMessage"]).toContain("[redacted]"); + }); + + it("redacts AWS access key IDs (AKIA...)", () => { + const out = recordAndCaptureData({ + errorMessage: "s3 upload failed for AKIAIOSFODNN7EXAMPLE", + }); + expect(out["errorMessage"]).not.toContain("AKIAIOSFODNN7EXAMPLE"); + expect(out["errorMessage"]).toContain("[redacted]"); + }); + + it("redacts JWTs (three base64url segments with eyJ prefix)", () => { + // Build the JWT string at runtime so the literal pattern doesn't appear + // in source (gitleaks pre-commit hook flags real-shaped JWT literals). + const jwt = "ey" + "JTESTHEADERabcde" + "." + "TESTPAYLOADabcdef" + "." + "TESTSIGNATUREabc"; + const out = recordAndCaptureData({ message: `token=${jwt} expired` }); + expect(out["message"]).not.toContain("JTESTHEADERabcde"); + expect(out["message"]).toContain("[redacted]"); + }); + + it("redacts ENV-style assignments (ALL_CAPS_KEY=value with sensitive suffix)", () => { + const out = recordAndCaptureData({ + message: "agent reported: OPENAI_API_KEY=sk-test-abcdefghijklmnopqr returns 429", + errorMessage: "config: GITHUB_TOKEN=ghp_xyz_invalid + DATABASE_URL=postgres://x", + }); + // The ENV assignment redacts to KEY=[redacted]; the inner sk-/ghp_ also + // matches its own pattern. Either way the secret value is gone. + expect(out["message"]).not.toContain("sk-test-abcdefghijklmnopqr"); + expect(out["errorMessage"]).not.toContain("ghp_xyz_invalid"); + expect(out["message"]).toContain("[redacted]"); + expect(out["errorMessage"]).toContain("[redacted]"); + }); + + it("preserves prose that mentions sensitive words but isn't token-shaped", () => { + // Regression guard for the existing "preserves error messages that mention + // sensitive words in values" behavior — Greptile's earlier finding noted + // this is intentional. Pattern-redaction must not over-match plain prose. + const out = recordAndCaptureData({ + reason: "token expired", + message: "authorization header missing", + detail: "the cookie was rejected", + note: "user pressed cancel on password prompt", + }); + expect(out["reason"]).toBe("token expired"); + expect(out["message"]).toBe("authorization header missing"); + expect(out["detail"]).toBe("the cookie was rejected"); + expect(out["note"]).toBe("user pressed cancel on password prompt"); + }); + + it("caps individual string values at 500 chars (matches sanitizeSummary cap)", () => { + const out = recordAndCaptureData({ + stack: "x".repeat(600), + }); + expect((out["stack"] as string).length).toBe(500); + expect(out["stack"]).toMatch(/\.\.\.$/); + }); + + it("redacts tokens nested in arrays and objects", () => { + const out = recordAndCaptureData({ + attempts: [ + { url: "https://api.x", error: "Bearer eyJhbGciOiJIUzI1NiJ9.payload.sig failed" }, + { url: "https://api.y", error: "ghp_abcdefghijklmnopqrstuvwxyz12345 invalid" }, + ], + }); + const attempts = out["attempts"] as Array>; + expect(attempts[0]!["error"]).toContain("Bearer [redacted]"); + expect(attempts[0]!["error"]).not.toContain("eyJhbGciOiJIUzI1NiJ9"); + expect(attempts[1]!["error"]).toContain("[redacted]"); + expect(attempts[1]!["error"]).not.toContain("ghp_abc"); + }); + + it("REGRESSION: redactCredentialUrls handles pathological input in <100ms (was ReDoS)", () => { + // Replaced the regex-based CREDENTIAL_URL_RE with a linear scan — no + // backtracking possible. Kept as a regression guard in case of regression. + const pathological = "http://".repeat(2000); // ~14KB, ~2000 prefix repetitions, no @ + const start = Date.now(); + const out = recordAndCaptureData({ errorMessage: pathological }); + const elapsed = Date.now() - start; + expect(elapsed).toBeLessThan(100); + expect((out["errorMessage"] as string).length).toBeLessThanOrEqual(500); + }); + + it("REGRESSION: redactCredentialUrls handles >200-char userinfo (P1 from PR #1620 review)", () => { + // The previous CREDENTIAL_URL_RE had {1,200} which let userinfo >200 chars + // pass through unredacted. The linear scan has no length limit. + const longPass = "a".repeat(300); + const input = `https://user:${longPass}@github.com/org/repo.git`; + const out = recordAndCaptureData({ remoteUrl: input }); + const result = out["remoteUrl"] as string; + expect(result).not.toContain(longPass); + expect(result).toContain("[redacted]"); + }); + + it("redactCredentialUrls does not touch URLs without userinfo", () => { + const input = "https://github.com/org/repo.git pushed successfully"; + const out = recordAndCaptureData({ message: input }); + expect(out["message"]).toBe(input); + }); + + it("redactCredentialUrls handles multiple credential URLs in one string", () => { + const input = "remote: https://token123@github.com/a.git origin: https://pass@github.com/b.git"; + const out = recordAndCaptureData({ message: input }); + const result = out["message"] as string; + expect(result).not.toContain("token123"); + expect(result).not.toContain("pass"); + expect(result).toMatch(/\[redacted\]/g); + // Should still contain the host parts + expect(result).toContain("github.com/a.git"); + expect(result).toContain("github.com/b.git"); + }); }); diff --git a/packages/core/src/__tests__/events-fts-integration.test.ts b/packages/core/src/__tests__/events-fts-integration.test.ts index 671ab5214..81f8337ce 100644 --- a/packages/core/src/__tests__/events-fts-integration.test.ts +++ b/packages/core/src/__tests__/events-fts-integration.test.ts @@ -168,4 +168,59 @@ describe("FTS5 integration (real SQLite)", () => { expect(recent.some((e) => e.summary === "new event")).toBe(true); expect(recent.every((e) => e.summary !== "old event")).toBe(true); }); + + // ─── Token-shape redaction regression (PR #1620 P1) ──────────────────────── + // The `data` column is FTS-indexed alongside `summary`. Before this fix, a + // free-form value like `data.errorMessage = "Bearer eyJ..."` would land in + // the events DB unredacted and become searchable. This test drives the full + // pipeline: real recordActivityEvent → real SQLite write → FTS5 trigger → + // both direct SELECT and FTS MATCH must report zero token leakage. + + itIfAvailable("REGRESSION: token-shaped values in data don't survive in stored row or FTS index", () => { + // Sentinels are built dynamically (string concatenation across the prefix + // boundary) so the literal token shapes don't appear in source — gitleaks' + // pre-commit hook would otherwise flag these as real leaked secrets. + const sentinels = { + bearer: "ey" + "JfakeTOKENxyz0abcdefghijklmnop.payload.sig", + ghPat: "gh" + "p_REGRESSIONfakeABCDEFGHIJKLMN1234", + openAi: "sk-" + "proj-REGRESSIONfakeXYZabc123456", + slack: "xox" + "b-9999999999-REGRESSIONfakeABCDE", + aws: "AKIA" + "REGRESSIONFAKE12", // AKIA + 16 alphanumeric per AWS spec + }; + + recordActivityEvent({ + source: "lifecycle", + kind: "lifecycle.poll_failed", + summary: "poll cycle failed", + data: { + // Mirror the real leak vector: free-form text under non-sensitive keys. + errorMessage: `git push failed: 401 Bearer ${sentinels.bearer}`, + message: `agent reported OPENAI_API_KEY=${sentinels.openAi} returns 429`, + nested: { + headers: { url: `https://api.example.com with ${sentinels.ghPat}` }, + attempts: [ + `xoxb webhook rejected: ${sentinels.slack}`, + `s3 PutObject failed for ${sentinels.aws}`, + ], + }, + }, + }); + + // 1. Direct row read — none of the sentinels survive in stored data. + const rows = db + .prepare("SELECT data FROM activity_events WHERE type = 'lifecycle.poll_failed'") + .all() as Array<{ data: string }>; + expect(rows).toHaveLength(1); + const storedData = rows[0]!.data; + for (const sentinel of Object.values(sentinels)) { + expect(storedData).not.toContain(sentinel); + } + expect(storedData).toContain("[redacted]"); + + // 2. FTS MATCH — searching for any sentinel returns zero hits. + for (const [name, sentinel] of Object.entries(sentinels)) { + const matches = searchActivityEvents(sentinel); + expect(matches, `FTS leak for ${name}: '${sentinel}' is searchable`).toHaveLength(0); + } + }); }); diff --git a/packages/core/src/__tests__/lifecycle-manager-instrumentation.test.ts b/packages/core/src/__tests__/lifecycle-manager-instrumentation.test.ts new file mode 100644 index 000000000..70b0b0296 --- /dev/null +++ b/packages/core/src/__tests__/lifecycle-manager-instrumentation.test.ts @@ -0,0 +1,962 @@ +/** + * Tests for activity-event emits added to lifecycle-manager's silent + * failure paths (scm.review_fetch_failed, scm.poll_pr_failed). + * + * Design choices: + * - vi.mock("../activity-events.js") at module scope so the emit calls in + * lifecycle-manager become inspectable via vi.mocked. + * - Reuses createMockSCM/createMockNotifier from test-utils so the SCM/Notifier + * surface stays in sync with the project's existing test patterns. + * - One test per event for the happy "emit fires" path, plus one cross-cutting + * test that proves the lifecycle check completes successfully even if + * recordActivityEvent itself throws (B2 invariant). + * + * Notifier instrumentation is intentionally omitted — the notifier subsystem + * is undergoing larger work and AE evidence there is not currently useful. + */ +import { describe, it, expect, beforeEach, afterEach, vi } from "vitest"; +import type * as ActivityEventsModule from "../activity-events.js"; + +vi.mock("../activity-events.js", async (importOriginal) => { + const original = await importOriginal(); + return { + ...original, + recordActivityEvent: vi.fn(), + }; +}); + +import { recordActivityEvent } from "../activity-events.js"; +import { createLifecycleManager } from "../lifecycle-manager.js"; +import { writeMetadata } from "../metadata.js"; +import type { + OpenCodeSessionManager, + OrchestratorConfig, + PRInfo, + PluginRegistry, + SessionMetadata, +} from "../types.js"; +import { + createMockNotifier, + createMockPlugins, + createMockRegistry, + createMockSCM, + createMockSessionManager, + createTestEnvironment, + makePR, + makeSession, + type MockPlugins, + type TestEnvironment, +} from "./test-utils.js"; + +let env: TestEnvironment; +let plugins: MockPlugins; +let mockSessionManager: OpenCodeSessionManager; +let config: OrchestratorConfig; + +beforeEach(() => { + env = createTestEnvironment(); + plugins = createMockPlugins(); + mockSessionManager = createMockSessionManager(); + config = env.config; + vi.mocked(recordActivityEvent).mockClear(); +}); + +afterEach(() => { + env.cleanup(); +}); + +/** Helper: persist session metadata + register the session with the mock manager. */ +function persistSession( + sessionId: string, + session: ReturnType, + metaOverrides: Record = {}, +) { + const persistedMetadata: Record = { + worktree: "/tmp", + branch: session.branch ?? "main", + status: session.status, + project: "my-app", + runtimeHandle: session.runtimeHandle ?? undefined, + ...metaOverrides, + }; + const persistedStringMetadata = Object.fromEntries( + Object.entries(persistedMetadata).filter( + (entry): entry is [string, string] => typeof entry[1] === "string", + ), + ); + + const enriched = { + ...session, + metadata: { ...session.metadata, ...persistedStringMetadata }, + }; + + vi.mocked(mockSessionManager.get).mockResolvedValue(enriched); + vi.mocked(mockSessionManager.list).mockResolvedValue([enriched]); + writeMetadata(env.sessionsDir, sessionId, persistedMetadata as unknown as SessionMetadata); + return enriched; +} + +function buildLM(registry: PluginRegistry) { + return createLifecycleManager({ config, registry, sessionManager: mockSessionManager }); +} + +function makeMatchingPR(overrides: Partial = {}): PRInfo { + return makePR({ owner: "org", repo: "my-app", ...overrides }); +} + +// --------------------------------------------------------------------------- +// scm.review_fetch_failed +// --------------------------------------------------------------------------- + +describe("scm.review_fetch_failed", () => { + it("records an AE event when scm.getReviewThreads throws during review backlog dispatch", async () => { + const mockSCM = createMockSCM({ + getReviewThreads: vi.fn().mockRejectedValue(new Error("403 forbidden")), + }); + const registry = createMockRegistry({ + runtime: plugins.runtime, + agent: plugins.agent, + scm: mockSCM, + notifier: createMockNotifier(), + }); + + const session = makeSession({ status: "pr_open", pr: makeMatchingPR() }); + persistSession("app-1", session); + + const lm = buildLM(registry); + await lm.check("app-1"); + + const calls = vi.mocked(recordActivityEvent).mock.calls.map((c) => c[0]); + const reviewFailures = calls.filter((c) => c.kind === "scm.review_fetch_failed"); + expect(reviewFailures).toHaveLength(1); + + const ev = reviewFailures[0]!; + expect(ev.source).toBe("scm"); + expect(ev.level).toBe("warn"); + expect(ev.summary).toContain("review fetch failed for PR #42"); + expect(ev.projectId).toBe(session.projectId); + expect(ev.sessionId).toBe(session.id); + expect(ev.data).toMatchObject({ + prNumber: 42, + prUrl: "https://github.com/org/my-app/pull/42", + errorMessage: "403 forbidden", + }); + }); +}); + +// --------------------------------------------------------------------------- +// scm.poll_pr_failed +// --------------------------------------------------------------------------- + +describe("scm.poll_pr_failed", () => { + it("records an AE event when scm.getPRState throws on the cache-miss fallback", async () => { + // Force a cache miss by returning an empty enrichment map, then make + // getPRState throw — exercises the inner try/catch at lifecycle-manager.ts:1053. + const mockSCM = createMockSCM({ + enrichSessionsPRBatch: vi.fn().mockResolvedValue(new Map()), + getPRState: vi.fn().mockRejectedValue(new Error("rate limited")), + }); + const registry = createMockRegistry({ + runtime: plugins.runtime, + agent: plugins.agent, + scm: mockSCM, + notifier: createMockNotifier(), + }); + + const session = makeSession({ status: "pr_open", pr: makeMatchingPR() }); + persistSession("app-1", session); + + const lm = buildLM(registry); + await lm.check("app-1"); + + const calls = vi.mocked(recordActivityEvent).mock.calls.map((c) => c[0]); + const pollFailures = calls.filter((c) => c.kind === "scm.poll_pr_failed"); + expect(pollFailures).toHaveLength(1); + + const ev = pollFailures[0]!; + expect(ev.source).toBe("scm"); + expect(ev.level).toBe("warn"); + expect(ev.summary).toContain("getPRState failed for PR #42"); + expect(ev.data).toMatchObject({ + prNumber: 42, + prUrl: "https://github.com/org/my-app/pull/42", + errorMessage: "rate limited", + }); + }); +}); + +// --------------------------------------------------------------------------- +// scm.batch_enrich_failed +// --------------------------------------------------------------------------- + +describe("scm.batch_enrich_failed", () => { + it("records an AE event when scm.enrichSessionsPRBatch throws", async () => { + const mockSCM = createMockSCM({ + enrichSessionsPRBatch: vi.fn().mockRejectedValue(new Error("rate limited")), + }); + const registry = createMockRegistry({ + runtime: plugins.runtime, + agent: plugins.agent, + scm: mockSCM, + notifier: createMockNotifier(), + }); + + const session = makeSession({ status: "pr_open", pr: makeMatchingPR() }); + persistSession("app-1", session); + + const lm = buildLM(registry); + await lm.check("app-1"); + + const calls = vi.mocked(recordActivityEvent).mock.calls.map((c) => c[0]); + const batchFailures = calls.filter((c) => c.kind === "scm.batch_enrich_failed"); + expect(batchFailures.length).toBeGreaterThan(0); + + const ev = batchFailures[0]!; + expect(ev.source).toBe("scm"); + expect(ev.level).toBe("warn"); + expect(ev.summary).toContain("batch_enrich failed"); + expect(ev.data).toMatchObject({ + plugin: "github", + prCount: 1, + errorMessage: "rate limited", + }); + }); +}); + +// --------------------------------------------------------------------------- +// scm.detect_pr_succeeded / scm.detect_pr_failed +// --------------------------------------------------------------------------- + +describe("scm.detect_pr", () => { + it("emits scm.detect_pr_succeeded when scm.detectPR finds a PR for a previously-PR-less session", async () => { + const detectedPR = makeMatchingPR({ number: 99, url: "https://github.com/org/my-app/pull/99" }); + const mockSCM = createMockSCM({ + detectPR: vi.fn().mockResolvedValue(detectedPR), + }); + const registry = createMockRegistry({ + runtime: plugins.runtime, + agent: plugins.agent, + scm: mockSCM, + notifier: createMockNotifier(), + }); + + const session = makeSession({ status: "working" }); + persistSession("app-1", session); + + const lm = buildLM(registry); + await lm.check("app-1"); + + const calls = vi.mocked(recordActivityEvent).mock.calls.map((c) => c[0]); + const events = calls.filter((c) => c.kind === "scm.detect_pr_succeeded"); + expect(events).toHaveLength(1); + expect(events[0]!.data).toMatchObject({ prNumber: 99 }); + }); + + it("emits scm.detect_pr_failed when scm.detectPR throws", async () => { + const mockSCM = createMockSCM({ + detectPR: vi.fn().mockRejectedValue(new Error("403 forbidden")), + }); + const registry = createMockRegistry({ + runtime: plugins.runtime, + agent: plugins.agent, + scm: mockSCM, + notifier: createMockNotifier(), + }); + + const session = makeSession({ status: "working" }); + persistSession("app-1", session); + + const lm = buildLM(registry); + await lm.check("app-1"); + + const calls = vi.mocked(recordActivityEvent).mock.calls.map((c) => c[0]); + const events = calls.filter((c) => c.kind === "scm.detect_pr_failed"); + expect(events).toHaveLength(1); + expect(events[0]!.data).toMatchObject({ errorMessage: "403 forbidden" }); + }); +}); + +// --------------------------------------------------------------------------- +// runtime.probe_failed +// --------------------------------------------------------------------------- + +describe("runtime.probe_failed", () => { + it("records an AE event when runtime.isAlive throws", async () => { + vi.mocked(plugins.runtime.isAlive).mockRejectedValue(new Error("kill -0 EPERM")); + + const registry = createMockRegistry({ + runtime: plugins.runtime, + agent: plugins.agent, + scm: createMockSCM(), + notifier: createMockNotifier(), + }); + + const session = makeSession({ status: "working" }); + persistSession("app-1", session); + + const lm = buildLM(registry); + await lm.check("app-1"); + + const calls = vi.mocked(recordActivityEvent).mock.calls.map((c) => c[0]); + const events = calls.filter((c) => c.kind === "runtime.probe_failed"); + expect(events.length).toBeGreaterThan(0); + expect(events[0]!.source).toBe("runtime"); + expect(events[0]!.data).toMatchObject({ errorMessage: "kill -0 EPERM" }); + }); +}); + +// --------------------------------------------------------------------------- +// agent.activity_probe_failed +// --------------------------------------------------------------------------- + +describe("agent.activity_probe_failed", () => { + it("records an AE event when the activity probing block throws", async () => { + vi.mocked(plugins.agent.getActivityState).mockRejectedValue(new Error("native probe died")); + + const registry = createMockRegistry({ + runtime: plugins.runtime, + agent: plugins.agent, + scm: createMockSCM(), + notifier: createMockNotifier(), + }); + + const session = makeSession({ status: "working" }); + persistSession("app-1", session); + + const lm = buildLM(registry); + await lm.check("app-1"); + + const calls = vi.mocked(recordActivityEvent).mock.calls.map((c) => c[0]); + const events = calls.filter((c) => c.kind === "agent.activity_probe_failed"); + expect(events.length).toBeGreaterThan(0); + expect(events[0]!.source).toBe("agent"); + expect(events[0]!.data).toMatchObject({ errorMessage: "native probe died" }); + }); +}); + +// --------------------------------------------------------------------------- +// agent.process_probe_failed (standalone path) +// --------------------------------------------------------------------------- + +describe("agent.process_probe_failed", () => { + it("records an AE event with where=standalone when isProcessRunning throws on the standalone probe", async () => { + // Drive activity probe to return null + force standalone path: + // - getActivityState resolves null → falls into terminal-output fallback + // - getOutput returns empty → no terminal-fallback isProcessRunning call + // - then standalone isProcessRunning at line ~1132 fires (processProbe still unknown) + vi.mocked(plugins.agent.getActivityState).mockResolvedValue(null); + vi.mocked(plugins.runtime.getOutput).mockResolvedValue(""); + vi.mocked(plugins.agent.isProcessRunning).mockRejectedValue(new Error("ps lookup failed")); + + const registry = createMockRegistry({ + runtime: plugins.runtime, + agent: plugins.agent, + scm: createMockSCM(), + notifier: createMockNotifier(), + }); + + const session = makeSession({ status: "working" }); + persistSession("app-1", session); + + const lm = buildLM(registry); + await lm.check("app-1"); + + const calls = vi.mocked(recordActivityEvent).mock.calls.map((c) => c[0]); + const events = calls.filter((c) => c.kind === "agent.process_probe_failed"); + expect(events.length).toBeGreaterThan(0); + expect(events[0]!.source).toBe("agent"); + expect(events[0]!.data).toMatchObject({ + where: "standalone", + errorMessage: "ps lookup failed", + }); + }); +}); + +// --------------------------------------------------------------------------- +// reaction.escalated / reaction.send_to_agent_failed / reaction.action_succeeded +// --------------------------------------------------------------------------- + +/** Build an SCM mock whose batch enrichment drives the session to ci_failed. */ +function makeCiFailedScm(overrides: Partial[0]> = {}) { + return createMockSCM({ + enrichSessionsPRBatch: vi.fn().mockImplementation(async (prs: PRInfo[]) => { + const result = new Map(); + for (const pr of prs) { + result.set(`${pr.owner}/${pr.repo}#${pr.number}`, { + state: "open", + ciStatus: "failing", + reviewDecision: "none", + mergeable: false, + ciChecks: [{ name: "test", status: "failed" }], + }); + } + return result; + }), + ...overrides, + }); +} + +describe("reaction.action_succeeded", () => { + it("emits AE on successful send-to-agent reaction", async () => { + config.reactions = { + "ci-failed": { auto: true, action: "send-to-agent", message: "fix CI", retries: 5 }, + }; + vi.mocked(mockSessionManager.send).mockResolvedValue(undefined); + + const registry = createMockRegistry({ + runtime: plugins.runtime, + agent: plugins.agent, + scm: makeCiFailedScm(), + notifier: createMockNotifier(), + }); + + const session = makeSession({ status: "pr_open", pr: makeMatchingPR() }); + persistSession("app-1", session); + + const lm = buildLM(registry); + await lm.check("app-1"); + + const calls = vi.mocked(recordActivityEvent).mock.calls.map((c) => c[0]); + const events = calls.filter((c) => c.kind === "reaction.action_succeeded"); + expect(events.length).toBeGreaterThan(0); + + const ev = events[0]!; + expect(ev.source).toBe("reaction"); + expect(ev.data).toMatchObject({ + reactionKey: "ci-failed", + action: "send-to-agent", + }); + }); +}); + +describe("reaction.send_to_agent_failed", () => { + it("emits AE when sessionManager.send throws inside a send-to-agent reaction", async () => { + config.reactions = { + "ci-failed": { auto: true, action: "send-to-agent", message: "fix CI", retries: 5 }, + }; + vi.mocked(mockSessionManager.send).mockRejectedValue(new Error("agent unreachable")); + + const registry = createMockRegistry({ + runtime: plugins.runtime, + agent: plugins.agent, + scm: makeCiFailedScm(), + notifier: createMockNotifier(), + }); + + const session = makeSession({ status: "pr_open", pr: makeMatchingPR() }); + persistSession("app-1", session); + + const lm = buildLM(registry); + await lm.check("app-1"); + + const calls = vi.mocked(recordActivityEvent).mock.calls.map((c) => c[0]); + const events = calls.filter((c) => c.kind === "reaction.send_to_agent_failed"); + expect(events).toHaveLength(1); + expect(events[0]!.data).toMatchObject({ + reactionKey: "ci-failed", + errorMessage: "agent unreachable", + }); + }); +}); + +describe("reaction.escalated", () => { + it("emits AE with escalationCause=max_retries when attempts exceed retries", async () => { + // retries: 0 → first attempt escalates (attempts=1 > 0) + config.reactions = { + "ci-failed": { auto: true, action: "send-to-agent", message: "fix CI", retries: 0, priority: "urgent" }, + }; + vi.mocked(mockSessionManager.send).mockResolvedValue(undefined); + + const registry = createMockRegistry({ + runtime: plugins.runtime, + agent: plugins.agent, + scm: makeCiFailedScm(), + notifier: createMockNotifier(), + }); + + const session = makeSession({ status: "pr_open", pr: makeMatchingPR() }); + persistSession("app-1", session); + + const lm = buildLM(registry); + await lm.check("app-1"); + + const calls = vi.mocked(recordActivityEvent).mock.calls.map((c) => c[0]); + const events = calls.filter((c) => c.kind === "reaction.escalated"); + expect(events).toHaveLength(1); + expect(events[0]!.data).toMatchObject({ + reactionKey: "ci-failed", + attempts: 1, + escalationCause: "max_retries", + }); + }); + + it("REGRESSION: escalationCause=max_attempts when numeric escalateAfter triggers (no retries cfg)", async () => { + // Numeric escalateAfter is an attempt-count gate, not a duration. Without + // `retries`, maxRetries defaults to Infinity, so the max_retries branch + // never fires. The cause must reflect the actual triggering check + // (numeric threshold), not be misattributed to "max_duration" — there + // was no time-based check involved at all. + config.reactions = { + "ci-failed": { + auto: true, + action: "send-to-agent", + message: "fix CI", + escalateAfter: 0, // first attempt: 1 > 0 → escalates immediately + priority: "urgent", + }, + }; + vi.mocked(mockSessionManager.send).mockResolvedValue(undefined); + + const registry = createMockRegistry({ + runtime: plugins.runtime, + agent: plugins.agent, + scm: makeCiFailedScm(), + notifier: createMockNotifier(), + }); + + const session = makeSession({ status: "pr_open", pr: makeMatchingPR() }); + persistSession("app-1", session); + + const lm = buildLM(registry); + await lm.check("app-1"); + + const events = vi + .mocked(recordActivityEvent) + .mock.calls.map((c) => c[0]) + .filter((c) => c.kind === "reaction.escalated"); + expect(events).toHaveLength(1); + expect(events[0]!.data).toMatchObject({ + reactionKey: "ci-failed", + attempts: 1, + escalationCause: "max_attempts", + }); + }); +}); + +// --------------------------------------------------------------------------- +// session.auto_cleanup_{deferred,completed,failed} +// --------------------------------------------------------------------------- + +/** SCM mock whose batch enrichment drives session into MERGED status. */ +function makeMergedScm() { + return createMockSCM({ + getPRState: vi.fn().mockResolvedValue("merged"), + enrichSessionsPRBatch: vi.fn().mockImplementation(async (prs: PRInfo[]) => { + const result = new Map(); + for (const pr of prs) { + result.set(`${pr.owner}/${pr.repo}#${pr.number}`, { + state: "merged", + ciStatus: "none", + reviewDecision: "none", + mergeable: false, + }); + } + return result; + }), + }); +} + +function configWithAutoCleanup(): OrchestratorConfig { + return { + ...config, + lifecycle: { autoCleanupOnMerge: true, mergeCleanupIdleGraceMs: 300_000 }, + }; +} + +describe("session.auto_cleanup_completed", () => { + it("emits AE when sessionManager.kill succeeds after PR merges", async () => { + vi.mocked(mockSessionManager.kill).mockResolvedValue({ + cleaned: true, + alreadyTerminated: false, + }); + + const registry = createMockRegistry({ + runtime: plugins.runtime, + agent: plugins.agent, + scm: makeMergedScm(), + notifier: createMockNotifier(), + }); + + const session = makeSession({ + status: "approved", + pr: makeMatchingPR(), + activity: "idle", + }); + persistSession("app-1", session); + + const lm = createLifecycleManager({ + config: configWithAutoCleanup(), + registry, + sessionManager: mockSessionManager, + }); + await lm.check("app-1"); + + const calls = vi.mocked(recordActivityEvent).mock.calls.map((c) => c[0]); + const events = calls.filter((c) => c.kind === "session.auto_cleanup_completed"); + expect(events).toHaveLength(1); + expect(events[0]!.source).toBe("lifecycle"); + expect(events[0]!.data).toMatchObject({ cleaned: true }); + }); +}); + +describe("session.auto_cleanup_failed", () => { + it("emits AE when sessionManager.kill throws after PR merges", async () => { + vi.mocked(mockSessionManager.kill).mockRejectedValue(new Error("worktree busy")); + + const registry = createMockRegistry({ + runtime: plugins.runtime, + agent: plugins.agent, + scm: makeMergedScm(), + notifier: createMockNotifier(), + }); + + const session = makeSession({ + status: "approved", + pr: makeMatchingPR(), + activity: "idle", + }); + persistSession("app-1", session); + + const lm = createLifecycleManager({ + config: configWithAutoCleanup(), + registry, + sessionManager: mockSessionManager, + }); + await lm.check("app-1"); + + const calls = vi.mocked(recordActivityEvent).mock.calls.map((c) => c[0]); + const events = calls.filter((c) => c.kind === "session.auto_cleanup_failed"); + expect(events).toHaveLength(1); + expect(events[0]!.level).toBe("error"); + expect(events[0]!.data).toMatchObject({ errorMessage: "worktree busy" }); + }); +}); + +// --------------------------------------------------------------------------- +// lifecycle.poll_failed +// --------------------------------------------------------------------------- + +describe("lifecycle.poll_failed", () => { + it("emits AE when sessionManager.list throws inside pollAll", async () => { + vi.useFakeTimers(); + vi.mocked(mockSessionManager.list).mockRejectedValue(new Error("storage unreadable")); + + const registry = createMockRegistry({ + runtime: plugins.runtime, + agent: plugins.agent, + scm: createMockSCM(), + notifier: createMockNotifier(), + }); + + // pollAll only emits per-project poll metrics when scopedProjectId is set. + // Force it via the deps. + const lm = createLifecycleManager({ + config, + registry, + sessionManager: mockSessionManager, + projectId: "my-app", + }); + + try { + lm.start(60_000); + await vi.advanceTimersByTimeAsync(0); + await vi.advanceTimersByTimeAsync(60_000); + + const calls = vi.mocked(recordActivityEvent).mock.calls.map((c) => c[0]); + const events = calls.filter((c) => c.kind === "lifecycle.poll_failed"); + expect(events.length).toBeGreaterThan(0); + expect(events[0]!.level).toBe("error"); + expect(events[0]!.data).toMatchObject({ errorMessage: "storage unreadable" }); + } finally { + lm.stop(); + vi.useRealTimers(); + } + }); + + it("REGRESSION: summary must not interpolate raw error text (credential leak via FTS)", async () => { + // sanitizeSummary only truncates; sanitizeData (which runs on `data`) + // redacts credential URLs. Because activity_events_fts indexes summary, + // any credential interpolated into summary becomes searchable from the DB. + // Lifecycle code must keep summary generic and put error reasons in `data`. + vi.useFakeTimers(); + const credentialUrl = "https://x-oauth-basic:SECRET_TOKEN_xyz123@github.com/foo/bar.git"; + vi.mocked(mockSessionManager.list).mockRejectedValue( + new Error(`fatal: unable to access '${credentialUrl}/'`), + ); + + const registry = createMockRegistry({ + runtime: plugins.runtime, + agent: plugins.agent, + scm: createMockSCM(), + notifier: createMockNotifier(), + }); + + const lm = createLifecycleManager({ + config, + registry, + sessionManager: mockSessionManager, + projectId: "my-app", + }); + + try { + lm.start(60_000); + await vi.advanceTimersByTimeAsync(0); + await vi.advanceTimersByTimeAsync(60_000); + + const events = vi + .mocked(recordActivityEvent) + .mock.calls.map((c) => c[0]) + .filter((c) => c.kind === "lifecycle.poll_failed"); + expect(events.length).toBeGreaterThan(0); + + // Summary stays generic — no secret material. + expect(events[0]!.summary).not.toContain("SECRET_TOKEN"); + expect(events[0]!.summary).not.toContain("x-oauth-basic"); + + // Error reason still surfaces — but only via `data`, where it's sanitized. + expect(events[0]!.data).toMatchObject({ + errorMessage: expect.stringContaining("unable to access"), + }); + } finally { + lm.stop(); + vi.useRealTimers(); + } + }); +}); + +// --------------------------------------------------------------------------- +// detecting.escalated +// --------------------------------------------------------------------------- + +describe("detecting.escalated", () => { + it("emits AE exactly once when detecting transitions to stuck via attempts limit", async () => { + // Drive determineStatus to commit STUCK by failing every probe path, + // and pre-load detectingAttempts to MAX so the next attempt escalates. + vi.mocked(plugins.runtime.isAlive).mockRejectedValue(new Error("probe down")); + vi.mocked(plugins.agent.getActivityState).mockResolvedValue(null); + vi.mocked(plugins.runtime.getOutput).mockResolvedValue(""); + vi.mocked(plugins.agent.isProcessRunning).mockRejectedValue(new Error("ps down")); + + const registry = createMockRegistry({ + runtime: plugins.runtime, + agent: plugins.agent, + scm: createMockSCM(), + notifier: createMockNotifier(), + }); + + const session = makeSession({ status: "detecting" }); + persistSession("app-1", session, { + detectingAttempts: "3", // DETECTING_MAX_ATTEMPTS — next attempt = 4 > 3 → escalates + }); + + const lm = buildLM(registry); + await lm.check("app-1"); + + const calls = vi.mocked(recordActivityEvent).mock.calls.map((c) => c[0]); + const events = calls.filter((c) => c.kind === "detecting.escalated"); + expect(events).toHaveLength(1); + expect(events[0]!.data).toMatchObject({ cause: "max_attempts" }); + + // Idempotency guard: a second poll while still stuck must NOT re-emit. + // The first emit set detectingEscalatedAt in metadata; subsequent polls + // see it non-empty and skip the emit. + vi.mocked(recordActivityEvent).mockClear(); + await lm.check("app-1"); + const repeat = vi.mocked(recordActivityEvent).mock.calls + .map((c) => c[0]) + .filter((c) => c.kind === "detecting.escalated"); + expect(repeat).toHaveLength(0); + }); +}); + +// --------------------------------------------------------------------------- +// report_watcher.triggered +// --------------------------------------------------------------------------- + +describe("report_watcher.triggered", () => { + it("emits AE when the report watcher detects a no_acknowledge trigger", async () => { + vi.useFakeTimers(); + vi.setSystemTime(new Date("2025-01-01T12:00:00.000Z")); + + const registry = createMockRegistry({ + runtime: plugins.runtime, + agent: plugins.agent, + scm: createMockSCM(), + notifier: createMockNotifier(), + }); + + // Session created 20 minutes ago (> default 10min ack timeout) and never reported. + const staleSession = makeSession({ + id: "app-1", + status: "working", + workspacePath: null, + createdAt: new Date("2025-01-01T11:40:00.000Z"), + metadata: { createdAt: "2025-01-01T11:40:00.000Z" }, + }); + persistSession("app-1", staleSession, { createdAt: "2025-01-01T11:40:00.000Z" }); + + const lm = createLifecycleManager({ + config, + registry, + sessionManager: mockSessionManager, + }); + + try { + await lm.check("app-1"); + + const calls = vi.mocked(recordActivityEvent).mock.calls.map((c) => c[0]); + const events = calls.filter((c) => c.kind === "report_watcher.triggered"); + expect(events.length).toBeGreaterThan(0); + expect(events[0]!.source).toBe("report-watcher"); + expect(events[0]!.level).toBe("warn"); + expect(events[0]!.data).toMatchObject({ trigger: "no_acknowledge" }); + } finally { + vi.useRealTimers(); + } + }); + + it("does NOT re-emit while the same trigger persists across polls (one-shot guard)", async () => { + // Regression: we observed 116 identical report_watcher.triggered events + // landing in production over a few hours because the emit was unguarded + // and fired every 30s poll while the trigger stayed active. The fix gates + // the emit on `isNewTrigger` so it fires only on the first poll that + // detects the trigger. + vi.useFakeTimers(); + vi.setSystemTime(new Date("2025-01-01T12:00:00.000Z")); + + const registry = createMockRegistry({ + runtime: plugins.runtime, + agent: plugins.agent, + scm: createMockSCM(), + notifier: createMockNotifier(), + }); + + const staleSession = makeSession({ + id: "app-1", + status: "working", + workspacePath: null, + createdAt: new Date("2025-01-01T11:40:00.000Z"), + metadata: { createdAt: "2025-01-01T11:40:00.000Z" }, + }); + persistSession("app-1", staleSession, { createdAt: "2025-01-01T11:40:00.000Z" }); + + const lm = createLifecycleManager({ + config, + registry, + sessionManager: mockSessionManager, + }); + + try { + // First check — trigger fires fresh, AE event lands. + await lm.check("app-1"); + const firstPass = vi.mocked(recordActivityEvent).mock.calls + .map((c) => c[0]) + .filter((c) => c.kind === "report_watcher.triggered"); + expect(firstPass).toHaveLength(1); + + // Second check — same trigger still active. Must NOT re-emit. + vi.mocked(recordActivityEvent).mockClear(); + await lm.check("app-1"); + const secondPass = vi.mocked(recordActivityEvent).mock.calls + .map((c) => c[0]) + .filter((c) => c.kind === "report_watcher.triggered"); + expect(secondPass).toHaveLength(0); + } finally { + vi.useRealTimers(); + } + }); + + it("REGRESSION: summary must not interpolate auditResult.message (report.note credential leak)", async () => { + // `auditResult.message` for the agent_needs_input trigger embeds the + // free-form `report.note` supplied via `ao report --note "..."`. Since + // sanitizeSummary only truncates and FTS5 indexes summary, a note that + // happens to contain a credential URL becomes persistently searchable + // from the DB. Summary must stay generic; the message stays in `data` + // where sanitizeData redacts credentials. + vi.useFakeTimers(); + vi.setSystemTime(new Date("2025-01-01T12:00:00.000Z")); + + const registry = createMockRegistry({ + runtime: plugins.runtime, + agent: plugins.agent, + scm: createMockSCM(), + notifier: createMockNotifier(), + }); + + // Seed a needs_input report whose note contains a credential URL. + // Per agent-report.ts:560, readAgentReport pulls these out of metadata. + const credentialNote = "stuck on git push https://x-oauth-basic:SECRET_NOTE_TOKEN@github.com/foo/bar.git"; + const blockedSession = makeSession({ + id: "app-1", + status: "working", + workspacePath: null, + createdAt: new Date("2025-01-01T11:55:00.000Z"), + metadata: { createdAt: "2025-01-01T11:55:00.000Z" }, + }); + persistSession("app-1", blockedSession, { + createdAt: "2025-01-01T11:55:00.000Z", + agentReportedState: "needs_input", + agentReportedAt: "2025-01-01T11:58:00.000Z", + agentReportedNote: credentialNote, + }); + + const lm = createLifecycleManager({ + config, + registry, + sessionManager: mockSessionManager, + }); + + try { + await lm.check("app-1"); + + const events = vi + .mocked(recordActivityEvent) + .mock.calls.map((c) => c[0]) + .filter((c) => c.kind === "report_watcher.triggered"); + expect(events.length).toBeGreaterThan(0); + expect(events[0]!.data).toMatchObject({ trigger: "agent_needs_input" }); + + // Summary stays generic — no secret material from report.note. + expect(events[0]!.summary).not.toContain("SECRET_NOTE_TOKEN"); + expect(events[0]!.summary).not.toContain("x-oauth-basic"); + + // The full message still surfaces via `data` where sanitizeData runs. + expect(events[0]!.data).toMatchObject({ + message: expect.stringContaining("Agent needs input"), + }); + } finally { + vi.useRealTimers(); + } + }); +}); + +// --------------------------------------------------------------------------- +// B2 invariant: emits never break the lifecycle flow +// --------------------------------------------------------------------------- + +describe("invariant: recordActivityEvent failures do not break the lifecycle flow", () => { + it("lm.check completes successfully even if recordActivityEvent throws", async () => { + vi.mocked(recordActivityEvent).mockImplementation(() => { + throw new Error("AE went boom"); + }); + + const registry = createMockRegistry({ + runtime: plugins.runtime, + agent: plugins.agent, + scm: createMockSCM({ + getReviewThreads: vi.fn().mockRejectedValue(new Error("review fetch down")), + }), + notifier: createMockNotifier(), + }); + + const session = makeSession({ status: "pr_open", pr: makeMatchingPR() }); + persistSession("app-1", session); + + const lm = buildLM(registry); + // Per gist + B2: lifecycle code MUST NOT depend on recordActivityEvent + // success. If this test fails, a new emit was added without the wrapper + // safety the real recordActivityEvent provides — find the unsafe call site + // and wrap it (or rely on the real impl's internal try/catch). + await expect(lm.check("app-1")).resolves.not.toThrow(); + }); +}); diff --git a/packages/core/src/activity-events.ts b/packages/core/src/activity-events.ts index edff28d67..6065c3d41 100644 --- a/packages/core/src/activity-events.ts +++ b/packages/core/src/activity-events.ts @@ -12,7 +12,16 @@ import { getDb } from "./events-db.js"; // Distinct names to avoid collision with types.ts EventType / EventSource. -export type ActivityEventSource = "lifecycle" | "session-manager" | "api" | "ui"; +export type ActivityEventSource = + | "lifecycle" + | "session-manager" + | "api" + | "ui" + | "scm" + | "runtime" + | "agent" + | "reaction" + | "report-watcher"; export type ActivityEventKind = | "session.spawn_started" @@ -22,7 +31,28 @@ export type ActivityEventKind = | "activity.transition" | "lifecycle.transition" | "ci.failing" - | "review.pending"; + | "review.pending" + // Lifecycle-manager plugin-call failures + | "scm.batch_enrich_failed" + | "scm.detect_pr_succeeded" + | "scm.detect_pr_failed" + | "scm.review_fetch_failed" + | "scm.poll_pr_failed" + | "runtime.probe_failed" + | "agent.process_probe_failed" + | "agent.activity_probe_failed" + // Reaction lifecycle + | "reaction.escalated" + | "reaction.send_to_agent_failed" + | "reaction.action_succeeded" + // Auto-cleanup + poll cycle + | "session.auto_cleanup_deferred" + | "session.auto_cleanup_completed" + | "session.auto_cleanup_failed" + | "lifecycle.poll_failed" + | "detecting.escalated" + // Report watcher + | "report_watcher.triggered"; export type ActivityEventLevel = "debug" | "info" | "warn" | "error"; @@ -74,12 +104,101 @@ function pruneOldEvents(db: ReturnType, cutoff: number): void { // Patterns that indicate sensitive field names const SENSITIVE_KEY_RE = /token|password|secret|authorization|cookie|api[-_]?key/i; -// URL credentials: https://token@host or http://user:pass@host -const CREDENTIAL_URL_RE = /https?:\/\/[^@\s]+@/gi; +// URL credentials: https://token@host or http://user:pass@host. +// Linear scan — find :// then scan forward for the next @ before a path +// separator or whitespace. O(n) worst case, no regex backtracking, no length +// limits. Replaces the previous CREDENTIAL_URL_RE which either ReDoS'd +// (unbounded quantifier) or missed >200-char userinfo (bounded quantifier). +function redactCredentialUrls(input: string): string { + let result = input; + let offset = 0; + while (offset < result.length) { + const proto = result.indexOf("://", offset); + if (proto === -1) break; + // Only match http:// or https:// (case-insensitive, matching old /gi flag) + if (proto < 4) { offset = proto + 3; continue; } + const schemeEnd = result.slice(Math.max(0, proto - 5), proto).toLowerCase(); + if (!schemeEnd.endsWith("http") && !schemeEnd.endsWith("https")) { + offset = proto + 3; + continue; + } + + let cursor = proto + 3; + while (cursor < result.length) { + const ch = result.charCodeAt(cursor); + // Space/control chars or '/' mean no '@' is coming in userinfo + if (ch <= 0x20 || ch === 0x2F) break; + if (ch === 0x40) { + // '@' found — redact everything between :// and @ + // Lowercase the scheme to match the old /gi regex behavior + const before = result.slice(0, proto + 3).toLowerCase(); + const suffix = result.slice(cursor); + result = before + "[redacted]" + suffix; + offset = proto + 3 + "[redacted]".length + 1; + break; + } + cursor++; + } + // No '@' found — not a credential URL, move past this :// + if (cursor >= result.length || result.charCodeAt(cursor) <= 0x20 || result.charCodeAt(cursor) === 0x2F) { + offset = proto + 3; + } + } + return result; +} + +// Per-string-value cap. The whole-data 16 KB cap still applies on top of this; +// truncating individual strings limits blast radius if a pattern below misses a +// new token format and a long error message gets pasted in. +const STRING_VALUE_MAX_CHARS = 500; + +// Token-shape patterns matched against ANY string value, not just keys. +// Order: more-specific first. Replacement strings preserve the prefix where +// the prefix itself is informative (e.g. "Bearer [redacted]" so RCA can still +// see this was a bearer-auth failure). +// +// SENSITIVE_KEY_RE above redacts entire values under sensitive *key* names; +// these patterns redact token-shaped *substrings* anywhere — including under +// keys like `message` and `errorMessage`, which are the leak vector flagged +// in PR #1620 review (data column is FTS5-indexed in events-db.ts). +const TOKEN_PATTERNS: ReadonlyArray = [ + // Bearer auth headers (also catches JWTs prefixed with Bearer) + [/\bBearer\s+[A-Za-z0-9._~+/=-]{12,}\b/gi, "Bearer [redacted]"], + // GitHub Personal Access Tokens — classic (ghp_/gho_/ghu_/ghs_/ghr_) + [/\bgh[pousr]_[A-Za-z0-9_]{20,}\b/g, "[redacted]"], + // GitHub fine-grained PATs + [/\bgithub_pat_[A-Za-z0-9_]{20,}\b/g, "[redacted]"], + // OpenAI / Anthropic sk- keys (incl. sk-proj-, sk-svcacct-, sk-ant-) + [/\bsk-(?:ant-)?(?:proj-|svcacct-)?[A-Za-z0-9_-]{16,}\b/g, "[redacted]"], + // Slack tokens (xoxb-, xoxp-, xoxa-, xoxr-, xoxs-) + [/\bxox[baprs]-[A-Za-z0-9-]{10,}\b/g, "[redacted]"], + // AWS access key IDs (16 trailing chars exactly per AWS spec) + [/\bAKIA[0-9A-Z]{16}\b/g, "[redacted]"], + // JWTs — three base64url segments, eyJ prefix on header + [/\beyJ[A-Za-z0-9_-]{10,}\.[A-Za-z0-9_-]{10,}\.[A-Za-z0-9_-]{10,}\b/g, "[redacted]"], + // ENV-style assignments: MY_API_TOKEN=value, GITHUB_SECRET=..., etc. + // Scoped to ALL_CAPS keys containing a sensitive word so prose like + // "the message=hello" doesn't redact. + [ + /\b([A-Z][A-Z0-9_]*(?:TOKEN|PASSWORD|SECRET|AUTHORIZATION|COOKIE|API_KEY|APIKEY)[A-Z0-9_]*)=([^\s"'`]{6,})/g, + "$1=[redacted]", + ], +]; + +function sanitizeString(value: string): string { + let cleaned = redactCredentialUrls(value); + for (const [pattern, replacement] of TOKEN_PATTERNS) { + cleaned = cleaned.replace(pattern, replacement); + } + if (cleaned.length > STRING_VALUE_MAX_CHARS) { + cleaned = `${cleaned.slice(0, STRING_VALUE_MAX_CHARS - 3)}...`; + } + return cleaned; +} function sanitizeValue(value: unknown, seen: WeakSet): unknown { if (typeof value === "bigint") return value.toString(); - if (typeof value === "string") return value.replace(CREDENTIAL_URL_RE, "https://[redacted]@"); + if (typeof value === "string") return sanitizeString(value); if (value === null || typeof value !== "object") return value; if (seen.has(value)) return "[circular]"; diff --git a/packages/core/src/lifecycle-manager.ts b/packages/core/src/lifecycle-manager.ts index fdb8a3918..3ae00cf27 100644 --- a/packages/core/src/lifecycle-manager.ts +++ b/packages/core/src/lifecycle-manager.ts @@ -627,6 +627,22 @@ export function createLifecycleManager(deps: LifecycleManagerDeps): LifecycleMan level: "warn", data: { plugin: pluginKey, prCount: pluginPRs.length }, }); + recordActivityEvent({ + // Tag with scopedProjectId when the lifecycle worker is project-scoped + // so `ao events list --project ` surfaces this failure. Unscoped + // (multi-project) supervisors leave projectId null because the batch + // crosses project boundaries — RCA there should query without --project. + projectId: scopedProjectId, + source: "scm", + kind: "scm.batch_enrich_failed", + level: "warn", + summary: `batch_enrich failed for ${pluginPRs.length} PR(s)`, + data: { + plugin: pluginKey, + prCount: pluginPRs.length, + errorMessage: errorMsg, + }, + }); } } @@ -660,8 +676,23 @@ export function createLifecycleManager(deps: LifecycleManagerDeps): LifecycleMan session.pr = detectedPR; const sessionsDir = getProjectSessionsDir(session.projectId); updateMetadata(sessionsDir, session.id, { pr: detectedPR.url }); + recordActivityEvent({ + projectId: session.projectId, + sessionId: session.id, + source: "scm", + kind: "scm.detect_pr_succeeded", + summary: `PR #${detectedPR.number} detected`, + data: { + plugin: project.scm.plugin, + prNumber: detectedPR.number, + prUrl: detectedPR.url, + prOwner: detectedPR.owner, + prRepo: detectedPR.repo, + }, + }); } } catch (error) { + const errorMsg = error instanceof Error ? error.message : String(error); observer?.recordOperation?.({ metric: "lifecycle_poll", operation: "scm.detect_pr", @@ -669,9 +700,21 @@ export function createLifecycleManager(deps: LifecycleManagerDeps): LifecycleMan correlationId: createCorrelationId("detect-pr"), projectId: session.projectId, sessionId: session.id, - reason: error instanceof Error ? error.message : String(error), + reason: errorMsg, level: "warn", }); + recordActivityEvent({ + projectId: session.projectId, + sessionId: session.id, + source: "scm", + kind: "scm.detect_pr_failed", + level: "warn", + summary: `detect_pr failed for ${session.id}`, + data: { + plugin: project.scm.plugin, + errorMessage: errorMsg, + }, + }); } } } @@ -897,11 +940,23 @@ export function createLifecycleManager(deps: LifecycleManagerDeps): LifecycleMan lifecycle.runtime.reason = session.runtimeHandle.runtimeName === "tmux" ? "tmux_missing" : "process_missing"; } - } catch { + } catch (err) { lifecycle.runtime.state = "probe_failed"; lifecycle.runtime.reason = "probe_error"; lifecycle.runtime.lastObservedAt = nowIso; runtimeProbe = { state: "unknown", failed: true }; + recordActivityEvent({ + projectId: session.projectId, + sessionId: session.id, + source: "runtime", + kind: "runtime.probe_failed", + level: "warn", + summary: `runtime.isAlive probe failed for ${session.id}`, + data: { + runtimeName: session.runtimeHandle.runtimeName, + errorMessage: err instanceof Error ? err.message : String(err), + }, + }); } } } @@ -1013,17 +1068,42 @@ export function createLifecycleManager(deps: LifecycleManagerDeps): LifecycleMan lifecycle.runtime.reason = "process_missing"; lifecycle.runtime.lastObservedAt = nowIso; } - } catch { + } catch (err) { processProbe = { state: "unknown", failed: true }; + recordActivityEvent({ + projectId: session.projectId, + sessionId: session.id, + source: "agent", + kind: "agent.process_probe_failed", + level: "warn", + summary: `agent.isProcessRunning failed for ${session.id}`, + data: { + agentName, + where: "fallback", + errorMessage: err instanceof Error ? err.message : String(err), + }, + }); } } } else { activitySignal = createActivitySignal("null", { source: "native" }); activityEvidence = formatActivitySignalEvidence(activitySignal); } - } catch { + } catch (err) { activitySignal = createActivitySignal("probe_failure", { source: "native" }); activityEvidence = formatActivitySignalEvidence(activitySignal); + recordActivityEvent({ + projectId: session.projectId, + sessionId: session.id, + source: "agent", + kind: "agent.activity_probe_failed", + level: "warn", + summary: `activity probing failed for ${session.id}`, + data: { + agentName, + errorMessage: err instanceof Error ? err.message : String(err), + }, + }); if ( lifecycle.session.state === "stuck" || lifecycle.session.state === "needs_input" || @@ -1061,8 +1141,21 @@ export function createLifecycleManager(deps: LifecycleManagerDeps): LifecycleMan lifecycle.runtime.reason = "process_missing"; lifecycle.runtime.lastObservedAt = nowIso; } - } catch { + } catch (err) { processProbe = { state: "unknown", failed: true }; + recordActivityEvent({ + projectId: session.projectId, + sessionId: session.id, + source: "agent", + kind: "agent.process_probe_failed", + level: "warn", + summary: `agent.isProcessRunning failed for ${session.id}`, + data: { + agentName, + where: "standalone", + errorMessage: err instanceof Error ? err.message : String(err), + }, + }); } } @@ -1131,8 +1224,23 @@ export function createLifecycleManager(deps: LifecycleManagerDeps): LifecycleMan }), ); } - } catch { - // Best-effort — batch will retry next cycle + } catch (err) { + // Best-effort — batch will retry next cycle. Record AE evidence so + // RCA can answer "why didn't AO transition to merged/closed in time?" + recordActivityEvent({ + projectId: session.projectId, + sessionId: session.id, + source: "scm", + kind: "scm.poll_pr_failed", + level: "warn", + summary: `getPRState failed for PR #${session.pr.number}`, + data: { + plugin: project.scm?.plugin, + prNumber: session.pr.number, + prUrl: session.pr.url, + errorMessage: err instanceof Error ? err.message : String(err), + }, + }); } } catch (error) { observer?.recordOperation?.({ @@ -1294,6 +1402,29 @@ export function createLifecycleManager(deps: LifecycleManagerDeps): LifecycleMan } if (shouldEscalate) { + // Mirror the trigger checks above so the cause matches the gate that + // actually fired. Numeric escalateAfter is an attempt-count gate, not a + // duration; without this distinction it gets misattributed to max_duration. + const escalationCause: "max_retries" | "max_attempts" | "max_duration" = + tracker.attempts > maxRetries + ? "max_retries" + : typeof escalateAfter === "number" && tracker.attempts > escalateAfter + ? "max_attempts" + : "max_duration"; + recordActivityEvent({ + projectId, + sessionId, + source: "reaction", + kind: "reaction.escalated", + level: "warn", + summary: `reaction ${reactionKey} escalated after ${tracker.attempts} attempts`, + data: { + reactionKey, + attempts: tracker.attempts, + durationSinceFirstMs: Date.now() - tracker.firstTriggered.getTime(), + escalationCause, + }, + }); // Escalate to human const context = buildEventContext(session, prEnrichmentCache); const event = createEvent("reaction.escalated", { @@ -1324,7 +1455,14 @@ export function createLifecycleManager(deps: LifecycleManagerDeps): LifecycleMan if (reactionConfig.message) { try { await sessionManager.send(sessionId, reactionConfig.message); - + recordActivityEvent({ + projectId, + sessionId, + source: "reaction", + kind: "reaction.action_succeeded", + summary: `send-to-agent ${reactionKey}`, + data: { reactionKey, action: "send-to-agent", attempts: tracker.attempts }, + }); return { reactionType: reactionKey, success: true, @@ -1332,8 +1470,21 @@ export function createLifecycleManager(deps: LifecycleManagerDeps): LifecycleMan message: reactionConfig.message, escalated: false, }; - } catch { + } catch (err) { // Send failed — allow retry on next poll cycle (don't escalate immediately) + recordActivityEvent({ + projectId, + sessionId, + source: "reaction", + kind: "reaction.send_to_agent_failed", + level: "warn", + summary: `send-to-agent failed for ${sessionId}`, + data: { + reactionKey, + attempts: tracker.attempts, + errorMessage: err instanceof Error ? err.message : String(err), + }, + }); return { reactionType: reactionKey, success: false, @@ -1354,6 +1505,14 @@ export function createLifecycleManager(deps: LifecycleManagerDeps): LifecycleMan data: { reactionKey, context, schemaVersion: 2 }, }); await notifyHuman(event, reactionConfig.priority ?? "info"); + recordActivityEvent({ + projectId, + sessionId, + source: "reaction", + kind: "reaction.action_succeeded", + summary: `notify ${reactionKey}`, + data: { reactionKey, action: "notify", attempts: tracker.attempts }, + }); return { reactionType: reactionKey, success: true, @@ -1373,6 +1532,14 @@ export function createLifecycleManager(deps: LifecycleManagerDeps): LifecycleMan data: { reactionKey, context, schemaVersion: 2 }, }); await notifyHuman(event, "action"); + recordActivityEvent({ + projectId, + sessionId, + source: "reaction", + kind: "reaction.action_succeeded", + summary: `auto-merge ${reactionKey}`, + data: { reactionKey, action: "auto-merge", attempts: tracker.attempts }, + }); return { reactionType: reactionKey, success: true, @@ -1498,8 +1665,23 @@ export function createLifecycleManager(deps: LifecycleManagerDeps): LifecycleMan // Fallback for SCM plugins that don't implement getReviewThreads yet allThreads = await scm.getPendingComments(session.pr); } - } catch { - // Failed to fetch — preserve existing metadata. + } catch (err) { + // Failed to fetch — preserve existing metadata; record AE evidence so + // RCA can answer "why aren't review comments being dispatched?" + recordActivityEvent({ + projectId: session.projectId, + sessionId: session.id, + source: "scm", + kind: "scm.review_fetch_failed", + level: "warn", + summary: `review fetch failed for PR #${session.pr.number}`, + data: { + plugin: project.scm?.plugin, + prNumber: session.pr.number, + prUrl: session.pr.url, + errorMessage: err instanceof Error ? err.message : String(err), + }, + }); // Don't update the throttle timestamp so the next poll retries immediately // instead of being blocked for 2 minutes with the agent left on a bare notification. return; @@ -2016,6 +2198,22 @@ export function createLifecycleManager(deps: LifecycleManagerDeps): LifecycleMan data: { activity, pendingSince, graceMs }, level: "info", }); + recordActivityEvent({ + projectId: session.projectId, + sessionId: session.id, + source: "lifecycle", + kind: "session.auto_cleanup_deferred", + summary: `auto-cleanup deferred for ${session.id}`, + data: { + activity, + // Elapsed wall-time since cleanup was first deferred. NOT a Unix + // timestamp — naming it `pendingSinceMs` was misleading (Greptile). + pendingElapsedMs: Number.isFinite(pendingSinceMs) + ? Date.now() - pendingSinceMs + : null, + graceMs, + }, + }); return; } @@ -2041,6 +2239,19 @@ export function createLifecycleManager(deps: LifecycleManagerDeps): LifecycleMan }, level: "info", }); + recordActivityEvent({ + projectId: session.projectId, + sessionId: session.id, + source: "lifecycle", + kind: "session.auto_cleanup_completed", + summary: `auto-cleanup completed for ${session.id}`, + data: { + cleaned: result.cleaned, + alreadyTerminated: result.alreadyTerminated, + graceElapsed, + activity, + }, + }); states.delete(session.id); } catch (err) { // Leave `merged` status in place so the next poll retries. Preserve the @@ -2048,6 +2259,7 @@ export function createLifecycleManager(deps: LifecycleManagerDeps): LifecycleMan if (!session.metadata["mergedPendingCleanupSince"]) { updateSessionMetadata(session, { mergedPendingCleanupSince: nowIso }); } + const errorMsg = err instanceof Error ? err.message : String(err); observer.recordOperation({ metric: "lifecycle_poll", operation: "lifecycle.merge_cleanup.failed", @@ -2055,9 +2267,18 @@ export function createLifecycleManager(deps: LifecycleManagerDeps): LifecycleMan correlationId, projectId: session.projectId, sessionId: session.id, - reason: err instanceof Error ? err.message : String(err), + reason: errorMsg, level: "warn", }); + recordActivityEvent({ + projectId: session.projectId, + sessionId: session.id, + source: "lifecycle", + kind: "session.auto_cleanup_failed", + level: "error", + summary: `auto-cleanup failed for ${session.id}`, + data: { errorMessage: errorMsg }, + }); } } @@ -2090,6 +2311,27 @@ export function createLifecycleManager(deps: LifecycleManagerDeps): LifecycleMan ? session.metadata["detectingEscalatedAt"] || new Date().toISOString() : ""; + // Emit ONCE per escalation — guarded by detectingEscalatedAt being empty. + // Subsequent polls while session stays stuck have detectingEscalatedAt set + // and won't re-fire (per invariant: don't repeat escalation events). + if (isDetectingEscalated && !session.metadata["detectingEscalatedAt"]) { + const cause: "max_attempts" | "max_duration" = + assessment.detectingAttempts > DETECTING_MAX_ATTEMPTS ? "max_attempts" : "max_duration"; + recordActivityEvent({ + projectId: session.projectId, + sessionId: session.id, + source: "lifecycle", + kind: "detecting.escalated", + level: "warn", + summary: `detecting → stuck via ${cause}`, + data: { + attempts: assessment.detectingAttempts, + cause, + startedAt: nextDetectingStartedAt, + }, + }); + } + const metadataUpdates: Record = {}; if (session.metadata["lifecycleEvidence"] !== nextLifecycleEvidence) { metadataUpdates["lifecycleEvidence"] = nextLifecycleEvidence; @@ -2411,6 +2653,34 @@ export function createLifecycleManager(deps: LifecycleManagerDeps): LifecycleMan }, level: "warn", }); + // Emit ONCE per trigger activation (matches the detecting.escalated guard + // pattern). Without this guard the audit would fire every poll cycle while + // a trigger stays active, producing hundreds of identical events. The + // observer.recordOperation above is unguarded by design (it's a metric); + // the activity-event trail is for actionable evidence, not heartbeat. + if (isNewTrigger) { + recordActivityEvent({ + projectId: session.projectId, + sessionId: session.id, + source: "report-watcher", + kind: "report_watcher.triggered", + level: "warn", + // Trigger is a bounded enum (no_acknowledge | stale_report | + // agent_needs_input); auditResult.message includes free-form + // report.note text from `ao report` and must not land in summary, + // which is FTS-indexed and only truncated by sanitizeSummary. + // Full message stays in `data.message` where sanitizeData redacts + // credential URLs. + summary: `${auditResult.trigger} triggered`, + data: { + trigger: auditResult.trigger, + message: auditResult.message, + timeSinceSpawnMs: auditResult.timeSinceSpawnMs, + timeSinceReportMs: auditResult.timeSinceReportMs, + reportState: auditResult.report?.state, + }, + }); + } // Execute reaction if configured if (isNewTrigger && reactionConfig && reactionConfig.auto !== false) { @@ -2539,6 +2809,22 @@ export function createLifecycleManager(deps: LifecycleManagerDeps): LifecycleMan reason: errorReason, level: "error", }); + recordActivityEvent({ + projectId: scopedProjectId, + source: "lifecycle", + kind: "lifecycle.poll_failed", + level: "error", + // Keep summary generic — sanitizeSummary only truncates, but the FTS + // index covers it. Error text (which can contain credential URLs from + // git/gh subprocess output) is routed through `data` where sanitizeData + // redacts credentials. + summary: "poll cycle failed", + data: { + errorMessage: errorReason, + durationMs: Date.now() - startedAt, + projectScope: scopedProjectId ?? "all", + }, + }); observer.setHealth({ surface: "lifecycle.worker", status: "error",