From 172859286dd0c703302e298b497153e918176a77 Mon Sep 17 00:00:00 2001 From: "posthog[bot]" <206114724+posthog[bot]@users.noreply.github.com> Date: Fri, 19 Jun 2026 10:19:07 +0000 Subject: [PATCH 1/2] fix(agent): observe and unblock silent Slack inbox relay drops Inbox/Slack notifications are posted server-side off the agent relay path, so a silent drop reads to the user as an empty inbox rather than a broken pipe (the reported symptom). This addresses the second, unidentified cause of dropped notifications that #2765 did not fully fix. - Emit stably-named attempt/delivered/dropped telemetry on `relayAgentResponse`, replacing the debug-only logs that swallowed every failure. Drops (relay request failure, no agent message) are now warn-level so they surface in agent logs instead of only as user reports. - Widen `PR_CREATION_RECENCY_MS` from 15 minutes to 24 hours. Notification delivery is gated on attributing a freshly created PR to the run, and the 15-minute window failed closed on any run where the PR surfaced later (multi-turn runs, late/coalesced terminal flushes), so the PR was never attributed and the notification never fired. Generated-By: PostHog Code Task-Id: c18c5b19-a5e4-4c98-95f2-13a68a331e4b --- packages/agent/src/pr-url-detector.test.ts | 15 +++- packages/agent/src/pr-url-detector.ts | 10 ++- .../agent/src/server/agent-server.test.ts | 86 +++++++++++++++++++ packages/agent/src/server/agent-server.ts | 48 +++++++++-- 4 files changed, 148 insertions(+), 11 deletions(-) diff --git a/packages/agent/src/pr-url-detector.test.ts b/packages/agent/src/pr-url-detector.test.ts index 9478ea733..663492455 100644 --- a/packages/agent/src/pr-url-detector.test.ts +++ b/packages/agent/src/pr-url-detector.test.ts @@ -1,5 +1,9 @@ import { describe, expect, it } from "vitest"; -import { findPrUrl, wasCreatedRecently } from "./pr-url-detector"; +import { + findPrUrl, + PR_CREATION_RECENCY_MS, + wasCreatedRecently, +} from "./pr-url-detector"; const PR_URL = "https://github.com/PostHog/posthog.com/pull/17764"; @@ -59,4 +63,13 @@ describe("wasCreatedRecently", () => { it("fails closed on an unparseable createdAt", () => { expect(wasCreatedRecently("not-a-date", now, maxAge)).toBe(false); }); + + it("attributes a PR created earlier in a long multi-turn run with the default window", () => { + // The notification path gates on attribution, so the default window must be + // wide enough that a PR created an hour ago (and only re-surfacing now) is + // still attributed. The old 15-minute default dropped these silently. + const oneHourAgo = new Date(now - 60 * 60 * 1000).toISOString(); + expect(wasCreatedRecently(oneHourAgo, now)).toBe(true); + expect(PR_CREATION_RECENCY_MS).toBeGreaterThan(60 * 60 * 1000); + }); }); diff --git a/packages/agent/src/pr-url-detector.ts b/packages/agent/src/pr-url-detector.ts index d8dc87162..8d5b21664 100644 --- a/packages/agent/src/pr-url-detector.ts +++ b/packages/agent/src/pr-url-detector.ts @@ -2,7 +2,15 @@ const PR_URL_REGEX = /https:\/\/github\.com\/[^/\s"]+\/[^/\s"]+\/pull\/\d+/; // A fixed window (not "since run start") so a PR the agent merely views on a // long run is too old to be mistaken for one it just created. -export const PR_CREATION_RECENCY_MS = 15 * 60 * 1000; +// +// Sized to comfortably cover a real run rather than a single tool call: a PR is +// often created in an early turn and only surfaces again (a summary line, a +// follow-up turn, a coalesced/late terminal flush) much later in the same +// multi-turn run. The old 15-minute window failed closed on exactly those runs, +// so the PR was never attributed and the Slack inbox notification — which is +// gated on attribution — silently never fired. A day is wide enough for any +// realistic run while still excluding genuinely stale PRs the agent only views. +export const PR_CREATION_RECENCY_MS = 24 * 60 * 60 * 1000; export function findPrUrl(text: string): string | null { return text.match(PR_URL_REGEX)?.[0] ?? null; diff --git a/packages/agent/src/server/agent-server.test.ts b/packages/agent/src/server/agent-server.test.ts index e7030e7b1..2e070896a 100644 --- a/packages/agent/src/server/agent-server.test.ts +++ b/packages/agent/src/server/agent-server.test.ts @@ -1293,6 +1293,92 @@ describe("AgentServer HTTP Mode", () => { }); }); + describe("Slack inbox relay telemetry", () => { + const payload: JwtPayload = { + task_id: "t", + run_id: "r", + team_id: 1, + user_id: 1, + distinct_id: "d", + mode: "interactive", + }; + + type FakeLogger = { + info: ReturnType; + warn: ReturnType; + error: ReturnType; + debug: ReturnType; + }; + + type RelayTestServer = { + relayAgentResponse(p: JwtPayload): Promise; + session: unknown; + questionRelayedToSlack: boolean; + posthogAPI: { relayMessage: ReturnType }; + logger: FakeLogger; + }; + + const setup = (opts: { + message?: string; + relayMessage?: ReturnType; + flush?: ReturnType; + }): RelayTestServer => { + const s = createServer() as unknown as RelayTestServer; + s.logger = { info: vi.fn(), warn: vi.fn(), error: vi.fn(), debug: vi.fn() }; + s.posthogAPI = { + relayMessage: opts.relayMessage ?? vi.fn(async () => {}), + }; + s.session = { + logWriter: { + flush: opts.flush ?? vi.fn(async () => {}), + getFullAgentResponse: vi.fn(() => opts.message), + isRegistered: vi.fn(() => true), + }, + }; + s.questionRelayedToSlack = false; + return s; + }; + + const outcomesFrom = (mock: ReturnType) => + mock.mock.calls.map((c) => (c[1] as { outcome: string }).outcome); + + it("records attempt then delivered on a successful relay", async () => { + const s = setup({ message: "hello" }); + await s.relayAgentResponse(payload); + expect(s.posthogAPI.relayMessage).toHaveBeenCalledWith("t", "r", "hello"); + expect(outcomesFrom(s.logger.info)).toEqual(["attempt", "delivered"]); + expect(s.logger.warn).not.toHaveBeenCalled(); + }); + + it("records a warn-level dropped event when the relay request throws", async () => { + const relayMessage = vi.fn(async () => { + throw new Error("boom"); + }); + const s = setup({ message: "hello", relayMessage }); + await s.relayAgentResponse(payload); + expect(s.logger.warn).toHaveBeenCalledTimes(1); + const event = s.logger.warn.mock.calls[0][1] as { + outcome: string; + reason: string; + }; + expect(event.outcome).toBe("dropped"); + expect(event.reason).toBe("relay_request_failed"); + }); + + it("records a dropped event when there is no agent message to relay", async () => { + const s = setup({ message: undefined }); + await s.relayAgentResponse(payload); + expect(s.posthogAPI.relayMessage).not.toHaveBeenCalled(); + expect(s.logger.warn).toHaveBeenCalledTimes(1); + const event = s.logger.warn.mock.calls[0][1] as { + outcome: string; + reason: string; + }; + expect(event.outcome).toBe("dropped"); + expect(event.reason).toBe("no_agent_message"); + }); + }); + describe("buildCloudSystemPrompt", () => { it("returns review-first prompt for existing PRs on non-Slack runs", () => { const s = createServer(); diff --git a/packages/agent/src/server/agent-server.ts b/packages/agent/src/server/agent-server.ts index 5b01dc996..eb05b6914 100644 --- a/packages/agent/src/server/agent-server.ts +++ b/packages/agent/src/server/agent-server.ts @@ -14,6 +14,7 @@ import { import { type ServerType, serve } from "@hono/node-server"; import { execGh } from "@posthog/git/gh"; import { getCurrentBranch } from "@posthog/git/queries"; +import { serializeError } from "@posthog/shared"; import { Hono } from "hono"; import { z } from "zod"; import packageJson from "../../package.json" with { type: "json" }; @@ -2279,21 +2280,26 @@ ${signedCommitInstructions} return; } + // Inbox/Slack notifications are posted server-side off this relay, so a + // silent drop here reads to the user as an empty inbox rather than a broken + // pipe. Emit attempt/outcome telemetry at a visible severity (not debug) so + // drops surface in agent logs instead of only as user reports. + this.recordRelayTelemetry("attempt", payload); + try { await this.session.logWriter.flush(payload.run_id, { coalesce: true }); } catch (error) { - this.logger.debug("Failed to flush logs before Slack relay", { + this.logger.warn("Failed to flush logs before Slack relay", { taskId: payload.task_id, runId: payload.run_id, - error, + error: serializeError(error), }); } const message = this.session.logWriter.getFullAgentResponse(payload.run_id); if (!message) { - this.logger.debug("No agent message found for Slack relay", { - taskId: payload.task_id, - runId: payload.run_id, + this.recordRelayTelemetry("dropped", payload, { + reason: "no_agent_message", sessionRegistered: this.session.logWriter.isRegistered(payload.run_id), }); return; @@ -2305,15 +2311,39 @@ ${signedCommitInstructions} payload.run_id, message, ); + this.recordRelayTelemetry("delivered", payload); } catch (error) { - this.logger.debug("Failed to relay initial agent response to Slack", { - taskId: payload.task_id, - runId: payload.run_id, - error, + this.recordRelayTelemetry("dropped", payload, { + reason: "relay_request_failed", + error: serializeError(error), }); } } + // A single, stably-named telemetry shape for the Slack/inbox relay path so the + // full attempt -> delivered/dropped funnel is queryable in agent logs. Drops + // are warn-level (always emitted, even with debug off) because a swallowed + // failure here is invisible to the user — the exact silent-drop class of bug + // this records. `attempt`/`delivered` are info so the funnel stays complete. + private recordRelayTelemetry( + outcome: "attempt" | "delivered" | "dropped", + payload: JwtPayload, + extra: Record = {}, + ): void { + const event = { + telemetry: "slack_inbox_relay", + outcome, + taskId: payload.task_id, + runId: payload.run_id, + ...extra, + }; + if (outcome === "dropped") { + this.logger.warn("Slack inbox relay dropped", event); + } else { + this.logger.info("Slack inbox relay", event); + } + } + private relaySlackQuestion( payload: JwtPayload, toolMeta: Record | null | undefined, From cd04536f5c3e6c214eef06cc9242b3b1d5f1a29c Mon Sep 17 00:00:00 2001 From: "posthog[bot]" <206114724+posthog[bot]@users.noreply.github.com> Date: Fri, 19 Jun 2026 10:47:29 +0000 Subject: [PATCH 2/2] fix(agent): biome format + address Greptile review on relay telemetry - Fix the failing `quality` check: run biome formatter on the relay telemetry test (the line that broke `biome ci`). - Keep flush failures inside the `slack_inbox_relay` telemetry shape via a new `flush_failed` outcome, and tag the subsequent `no_agent_message` drop with `flushFailed` so a cascaded drop's root cause stays queryable instead of reading as a bare drop (Greptile issue 2). - Express the three relay funnel cases as a parameterised `it.each` table per the project's test convention; keep the flush-cascade case separate since its setup/assertions differ (Greptile issue 1). Generated-By: PostHog Code Task-Id: c18c5b19-a5e4-4c98-95f2-13a68a331e4b --- .../agent/src/server/agent-server.test.ts | 103 +++++++++++++----- packages/agent/src/server/agent-server.ts | 24 ++-- 2 files changed, 89 insertions(+), 38 deletions(-) diff --git a/packages/agent/src/server/agent-server.test.ts b/packages/agent/src/server/agent-server.test.ts index 2e070896a..b880362d9 100644 --- a/packages/agent/src/server/agent-server.test.ts +++ b/packages/agent/src/server/agent-server.test.ts @@ -1324,7 +1324,12 @@ describe("AgentServer HTTP Mode", () => { flush?: ReturnType; }): RelayTestServer => { const s = createServer() as unknown as RelayTestServer; - s.logger = { info: vi.fn(), warn: vi.fn(), error: vi.fn(), debug: vi.fn() }; + s.logger = { + info: vi.fn(), + warn: vi.fn(), + error: vi.fn(), + debug: vi.fn(), + }; s.posthogAPI = { relayMessage: opts.relayMessage ?? vi.fn(async () => {}), }; @@ -1342,40 +1347,80 @@ describe("AgentServer HTTP Mode", () => { const outcomesFrom = (mock: ReturnType) => mock.mock.calls.map((c) => (c[1] as { outcome: string }).outcome); - it("records attempt then delivered on a successful relay", async () => { - const s = setup({ message: "hello" }); - await s.relayAgentResponse(payload); - expect(s.posthogAPI.relayMessage).toHaveBeenCalledWith("t", "r", "hello"); - expect(outcomesFrom(s.logger.info)).toEqual(["attempt", "delivered"]); - expect(s.logger.warn).not.toHaveBeenCalled(); - }); - - it("records a warn-level dropped event when the relay request throws", async () => { - const relayMessage = vi.fn(async () => { - throw new Error("boom"); + const throwingFn = (msg: string) => + vi.fn(async () => { + throw new Error(msg); }); - const s = setup({ message: "hello", relayMessage }); - await s.relayAgentResponse(payload); - expect(s.logger.warn).toHaveBeenCalledTimes(1); - const event = s.logger.warn.mock.calls[0][1] as { - outcome: string; - reason: string; - }; - expect(event.outcome).toBe("dropped"); - expect(event.reason).toBe("relay_request_failed"); - }); - it("records a dropped event when there is no agent message to relay", async () => { - const s = setup({ message: undefined }); + it.each([ + { + name: "records attempt then delivered on a successful relay", + message: "hello" as string | undefined, + relayThrows: false, + relayed: true, + infoOutcomes: ["attempt", "delivered"], + warn: null as { outcome: string; reason: string } | null, + }, + { + name: "records a warn-level dropped event when the relay request throws", + message: "hello" as string | undefined, + relayThrows: true, + relayed: true, + infoOutcomes: ["attempt"], + warn: { outcome: "dropped", reason: "relay_request_failed" }, + }, + { + name: "records a dropped event when there is no agent message to relay", + message: undefined as string | undefined, + relayThrows: false, + relayed: false, + infoOutcomes: ["attempt"], + warn: { outcome: "dropped", reason: "no_agent_message" }, + }, + ])( + "$name", + async ({ message, relayThrows, relayed, infoOutcomes, warn }) => { + const relayMessage = relayThrows + ? throwingFn("boom") + : vi.fn(async () => {}); + const s = setup({ message, relayMessage }); + await s.relayAgentResponse(payload); + + expect(outcomesFrom(s.logger.info)).toEqual(infoOutcomes); + expect(s.posthogAPI.relayMessage).toHaveBeenCalledTimes( + relayed ? 1 : 0, + ); + + if (warn) { + expect(s.logger.warn).toHaveBeenCalledTimes(1); + const event = s.logger.warn.mock.calls[0][1] as { + outcome: string; + reason: string; + }; + expect(event.outcome).toBe(warn.outcome); + expect(event.reason).toBe(warn.reason); + } else { + expect(s.logger.warn).not.toHaveBeenCalled(); + } + }, + ); + + // Separate case: a flush failure that cascades into an empty message must + // keep its root cause inside the telemetry shape (two warns, drop tagged + // flushFailed), so it does not read as a bare `no_agent_message` drop. + it("tags the drop with flushFailed when a flush failure leaves no message", async () => { + const s = setup({ message: undefined, flush: throwingFn("flush boom") }); await s.relayAgentResponse(payload); + expect(s.posthogAPI.relayMessage).not.toHaveBeenCalled(); - expect(s.logger.warn).toHaveBeenCalledTimes(1); - const event = s.logger.warn.mock.calls[0][1] as { - outcome: string; + const warnOutcomes = outcomesFrom(s.logger.warn); + expect(warnOutcomes).toEqual(["flush_failed", "dropped"]); + const dropEvent = s.logger.warn.mock.calls[1][1] as { reason: string; + flushFailed: boolean; }; - expect(event.outcome).toBe("dropped"); - expect(event.reason).toBe("no_agent_message"); + expect(dropEvent.reason).toBe("no_agent_message"); + expect(dropEvent.flushFailed).toBe(true); }); }); diff --git a/packages/agent/src/server/agent-server.ts b/packages/agent/src/server/agent-server.ts index eb05b6914..d2c1b017b 100644 --- a/packages/agent/src/server/agent-server.ts +++ b/packages/agent/src/server/agent-server.ts @@ -2286,12 +2286,16 @@ ${signedCommitInstructions} // drops surface in agent logs instead of only as user reports. this.recordRelayTelemetry("attempt", payload); + let flushFailed = false; try { await this.session.logWriter.flush(payload.run_id, { coalesce: true }); } catch (error) { - this.logger.warn("Failed to flush logs before Slack relay", { - taskId: payload.task_id, - runId: payload.run_id, + // Keep the flush failure inside the queryable telemetry shape: a failed + // flush can leave no coalesced message to relay, and without this the + // resulting drop would read as a bare `no_agent_message` with no upstream + // cause. + flushFailed = true; + this.recordRelayTelemetry("flush_failed", payload, { error: serializeError(error), }); } @@ -2300,6 +2304,7 @@ ${signedCommitInstructions} if (!message) { this.recordRelayTelemetry("dropped", payload, { reason: "no_agent_message", + flushFailed, sessionRegistered: this.session.logWriter.isRegistered(payload.run_id), }); return; @@ -2322,11 +2327,12 @@ ${signedCommitInstructions} // A single, stably-named telemetry shape for the Slack/inbox relay path so the // full attempt -> delivered/dropped funnel is queryable in agent logs. Drops - // are warn-level (always emitted, even with debug off) because a swallowed - // failure here is invisible to the user — the exact silent-drop class of bug - // this records. `attempt`/`delivered` are info so the funnel stays complete. + // and flush failures are warn-level (always emitted, even with debug off) + // because a swallowed failure here is invisible to the user — the exact + // silent-drop class of bug this records. `attempt`/`delivered` are info so the + // funnel stays complete. private recordRelayTelemetry( - outcome: "attempt" | "delivered" | "dropped", + outcome: "attempt" | "delivered" | "dropped" | "flush_failed", payload: JwtPayload, extra: Record = {}, ): void { @@ -2337,8 +2343,8 @@ ${signedCommitInstructions} runId: payload.run_id, ...extra, }; - if (outcome === "dropped") { - this.logger.warn("Slack inbox relay dropped", event); + if (outcome === "dropped" || outcome === "flush_failed") { + this.logger.warn("Slack inbox relay", event); } else { this.logger.info("Slack inbox relay", event); }