Skip to content
Open
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
13 changes: 11 additions & 2 deletions backend/CLAUDE.md
Original file line number Diff line number Diff line change
Expand Up @@ -53,8 +53,17 @@ thin: it proxies OpenAI requests with the server-held API key and writes study l
static root doesn't exist. Cache rules: `no-store` for `.html`/`manifest.xml`
(they reference content-hashed bundles by name), `immutable` for hashed assets.
- **Telemetry** (`src/posthog.ts`): optional PostHog error capture; a no-op when
`POSTHOG_PROJECT_TOKEN` is unset. `deletePosthogPerson` (used by both erasure
paths) hits the PostHog *management* API and needs `POSTHOG_PERSONAL_API_KEY` +
`POSTHOG_PROJECT_TOKEN` is unset. **Nothing here may be awaited on the request
path.** `posthogMiddleware` used to `await posthog.flush()` after every request;
`flush()` rejects on any non-2xx, so when the ingestion host started returning 526
every request 500'd (and, because flushes serialize, hung) — health probe included,
which failed a deploy. Ingestion is now left to posthog-node's background batching,
with retries/timeouts capped so a dead host costs seconds rather than ~49s; the tail
is drained by `shutdownPosthog()` on SIGTERM. `/api/ping` is deliberately not
captured. `POSTHOG_HOST` defaults to PostHog US **directly** — the
`e.thoughtful-ai.com` reverse proxy is for the browser SDK (ad blockers) and only
adds a failure mode server-side. `deletePosthogPerson` (used by both erasure paths)
hits the PostHog *management* API and needs `POSTHOG_PERSONAL_API_KEY` +
`POSTHOG_PROJECT_ID`; without them it warns and no-ops.
- **Tool launcher** (`src/toolGrants.ts`): the handoff grant flow for launching
external writing tools from the sidebar (see `docs/tool-launcher-plan.md`, Phase 1).
Expand Down
3 changes: 2 additions & 1 deletion backend/README.md
Original file line number Diff line number Diff line change
Expand Up @@ -42,6 +42,7 @@ Listens on `5000` in Docker (`PORT=5000`).
`OPENAI_API_KEY`, `OPENAI_DEMO_API_KEY` (pays for sessionless/demo requests),
`LOG_SECRET` (gates the log-viewer endpoints + `/api/usage_summary`), `DATA_DIR` (root
for `app.db` + `logs/`), `PORT` (default 8000), `DEBUG`, `POSTHOG_PROJECT_TOKEN`,
`POSTHOG_HOST`, `LOG_DIR` (overrides just the logs subdir). Auth (Better Auth) adds
`POSTHOG_HOST` (defaults to `https://us.i.posthog.com`; the server does not go through
the browser-SDK reverse proxy), `LOG_DIR` (overrides just the logs subdir). Auth (Better Auth) adds
`BETTER_AUTH_ENABLED`, `BETTER_AUTH_SECRET`, `GOOGLE_CLIENT_ID`, `GOOGLE_CLIENT_SECRET`,
and related vars — see [CLAUDE.md](CLAUDE.md) for the full list.
135 changes: 135 additions & 0 deletions backend/src/__tests__/posthog.test.ts
Original file line number Diff line number Diff line change
@@ -0,0 +1,135 @@
import { createServer, type Server } from 'node:http';
import type { AddressInfo } from 'node:net';
import { afterAll, beforeAll, beforeEach, describe, expect, it, vi } from 'vitest';

/**
* Regression test for the outage where a failing PostHog ingestion host took the
* whole backend down: posthogMiddleware used to `await posthog.flush()` after every
* request, and flush() rejects on any non-2xx from the host. A transient 526 from
* the analytics reverse proxy therefore turned every request — including the k8s
* health probe — into a 500, and the deploy never went ready.
*
* Telemetry must stay strictly off the request's critical path: it may not decide a
* response's status, and it may not add to its latency.
*
* The bad host here is a real local HTTP server rather than a mocked `fetch`:
* posthog-node resolves the global fetch once when *it* is imported, which is
* outside Vitest's module registry, so a `vi.stubGlobal('fetch', …)` in this file
* may never be the one it calls.
*/

let server: Server;
let hostUrl: string;
/** Swapped per test to make the ingestion host fail in a particular way. */
let handle: (respond: (status: number) => void) => void;
/**
* Bodies of the batches the fake PostHog received. Assertions match on the event
* names inside them rather than counting requests: a client from an earlier test
* can still have a chained flush in flight, so only the contents identify who sent
* what.
*/
let batches: string[] = [];

beforeAll(async () => {
server = createServer((req, res) => {
let body = '';
req.on('data', (chunk) => {
body += chunk;
});
req.on('end', () => {
batches.push(body);
handle((status) => res.writeHead(status).end('error'));
});
});
await new Promise<void>((resolve) => server.listen(0, '127.0.0.1', resolve));
hostUrl = `http://127.0.0.1:${(server.address() as AddressInfo).port}`;
});

afterAll(async () => {
await new Promise((resolve) => server.close(resolve));
});

// posthog.ts builds its client from the environment at module load, so each test
// stubs the env, resets the module registry, and re-imports.
async function loadApp(route: string) {
vi.stubEnv('POSTHOG_PROJECT_TOKEN', 'phc_test_token');
vi.stubEnv('DISABLE_POSTHOG', '');
vi.stubEnv('POSTHOG_HOST', hostUrl);
vi.resetModules();

const { posthogMiddleware } = await import('../posthog.js');
const { Hono } = await import('hono');
const app = new Hono();
app.use('*', posthogMiddleware);
app.get(route, (c) => c.json({ ok: true }));
return app;
}

// posthog-node batches: it only sends once flushAt (20) events are queued, so a run
// of requests is what provokes an ingestion attempt at all.
const OVER_FLUSH_AT = 25;

beforeEach(() => {
batches = [];
handle = (respond) => respond(526); // what the reverse proxy was returning
});

describe('posthogMiddleware with a failing PostHog host', () => {
it('serves requests normally while ingestion 526s', async () => {
const app = await loadApp('/api/thing');

for (let i = 0; i < OVER_FLUSH_AT; i++) {
const res = await app.request('/api/thing');
expect(res.status).toBe(200);
expect(await res.json()).toEqual({ ok: true });
}

// The failing ingestion really was attempted — otherwise this test would
// pass just as well with telemetry silently doing nothing.
await vi.waitFor(() =>
expect(batches.some((b) => b.includes('GET /api/thing'))).toBe(true),
);
});

it('does not make requests wait on a hung ingestion host', async () => {
handle = () => {
/* accept the connection, never respond */
};
const app = await loadApp('/api/thing');

const started = Date.now();
for (let i = 0; i < OVER_FLUSH_AT; i++) {
expect((await app.request('/api/thing')).status).toBe(200);
}
// The client's own requestTimeout is 3s; the old await-flush middleware
// would have blocked for at least that long before failing the request.
expect(Date.now() - started).toBeLessThan(1000);
});

it('does not capture health-probe requests', async () => {
const app = await loadApp('/api/ping');

for (let i = 0; i < OVER_FLUSH_AT; i++) {
expect((await app.request('/api/ping')).status).toBe(200);
}
// Well past flushAt with nothing queued, so no probe ever reaches PostHog.
await new Promise((r) => setTimeout(r, 100));
expect(batches.filter((b) => b.includes('/api/ping'))).toEqual([]);
});
});

describe('captureException with a failing PostHog host', () => {
it('resolves promptly instead of throwing or hanging', async () => {
handle = () => {
/* accept the connection, never respond */
};
vi.stubEnv('POSTHOG_PROJECT_TOKEN', 'phc_test_token');
vi.stubEnv('POSTHOG_HOST', hostUrl);
vi.resetModules();
const { captureException } = await import('../posthog.js');

const started = Date.now();
await captureException(new Error('boom'));
expect(Date.now() - started).toBeLessThan(1000);
});
});
46 changes: 38 additions & 8 deletions backend/src/posthog.ts
Original file line number Diff line number Diff line change
Expand Up @@ -2,8 +2,11 @@ import { createMiddleware } from 'hono/factory';
import { PostHog } from 'posthog-node';

const token = (process.env.POSTHOG_PROJECT_TOKEN ?? '').trim() || "placeholder-token";
// Defaults to PostHog US directly, NOT the e.thoughtful-ai.com reverse proxy: the
// server has no ad-blocker to evade (that's only worth it for the browser SDK), so
// the proxy added a hop that could — and did — fail on its own.
// Strip any trailing slash so building management-API URLs (deletePosthogPerson)
// can't produce a double slash — the shipped POSTHOG_HOST default ends in '/', and
// can't produce a double slash — an explicitly-set POSTHOG_HOST may end in '/', and
// many reverse proxies 404 on `//api/...`.
const host =
((process.env.POSTHOG_HOST ?? '').trim() || 'https://us.i.posthog.com').replace(
Expand All @@ -13,15 +16,40 @@ const host =

const shouldDisablePosthog = token === "placeholder-token" || process.env.DISABLE_POSTHOG === '1';

const posthog = new PostHog(token, { host, disabled: shouldDisablePosthog });
const posthog = new PostHog(token, {
host,
disabled: shouldDisablePosthog,
// Telemetry must never be able to hold a request (or the whole process) open.
// posthog-node's defaults are 10s per attempt x 4 attempts with 3s between them
// — ~49s of hanging per flush when the ingestion host is down. Ingestion is
// fire-and-forget analytics, so cap it at a few seconds and let the batch drop.
requestTimeout: 3000,
fetchRetryCount: 1,
fetchRetryDelay: 1000,
});

export const posthogMiddleware = createMiddleware(async (c, next) => {
posthog.capture({
distinctId: 'server',
event: `${c.req.method} ${c.req.path}`,
});
// Health probes are not product analytics: they'd add a queue entry (and a
// distinct event name) every few seconds forever.
if (c.req.path !== '/api/ping') {
try {
posthog.capture({
distinctId: 'server',
event: `${c.req.method} ${c.req.path}`,
});
} catch {
// Never let telemetry break the request path.
}
}
await next();
await posthog.flush();
// Deliberately NOT `await posthog.flush()`. That made every request wait on —
// and 500 on — a PostHog ingestion failure: flush() rejects on any non-2xx,
// the rejection propagated out of this middleware into app.onError, and
// because flush() serializes behind the previous flush the latency compounded
// across concurrent requests. A transient 526 from the analytics host thereby
// took the whole backend down, health probe included. posthog-node already
// flushes in the background (batches of 20, or every 10s) and swallows its own
// errors there; shutdownPosthog() drains the tail on SIGTERM.
});

export async function captureException(
Expand All @@ -31,7 +59,9 @@ export async function captureException(
try {
const err = error instanceof Error ? error : new Error(String(error));
posthog.captureException(err, undefined, properties);
await posthog.flush();
// No flush() here either — see posthogMiddleware. The background flush
// timer sends this within ~10s without putting the ingestion host on the
// critical path of an error response.
} catch {
// Never let error tracking break the request path.
}
Expand Down
4 changes: 3 additions & 1 deletion docker-compose-prod.yml
Original file line number Diff line number Diff line change
Expand Up @@ -11,7 +11,9 @@ services:
# on OpenAI's side. Unset => sessionless requests are refused. See openaiProxy.ts.
- OPENAI_DEMO_API_KEY=${OPENAI_DEMO_API_KEY:-}
- POSTHOG_PROJECT_TOKEN=${POSTHOG_PROJECT_TOKEN:-}
- POSTHOG_HOST=${POSTHOG_HOST:-https://e.thoughtful-ai.com/}
# Straight to PostHog US — see docker-compose.yml for why the backend does
# not go through the e.thoughtful-ai.com reverse proxy.
- POSTHOG_HOST=${POSTHOG_HOST:-https://us.i.posthog.com}
# Management API (personal key + project id) — required for "delete my data"
# to purge a user's PostHog person/events. Unset => deletion no-ops with a
# warning (see deletePosthogPerson). Verified post-deploy in issue #517.
Expand Down
6 changes: 5 additions & 1 deletion docker-compose.yml
Original file line number Diff line number Diff line change
Expand Up @@ -19,7 +19,11 @@ services:
- OPENAI_DEMO_API_KEY=${OPENAI_DEMO_API_KEY:-}
- LOG_SECRET=${LOG_SECRET}
- POSTHOG_PROJECT_TOKEN=${POSTHOG_PROJECT_TOKEN:-}
- POSTHOG_HOST=${POSTHOG_HOST:-https://e.thoughtful-ai.com/}
# Server-side ingestion goes straight to PostHog US, not the
# e.thoughtful-ai.com reverse proxy. The proxy exists to get past browser ad
# blockers, which is irrelevant here, and it added a hop whose outage (a
# Cloudflare 526) used to take the backend down with it.
- POSTHOG_HOST=${POSTHOG_HOST:-https://us.i.posthog.com}
# Management API (personal key + project id) — required for "delete my data"
# to purge a user's PostHog person/events. Unset => deletion no-ops with a
# warning (see deletePosthogPerson).
Expand Down
Loading