Skip to content
Merged
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
54 changes: 50 additions & 4 deletions README.md
Original file line number Diff line number Diff line change
Expand Up @@ -219,14 +219,60 @@ first miss of each test, which is the one to fix.
`valuePatterns` of the config. Check each one for slow backtracking
before you add it.
- **Sentry.** With `sentryDsn`, each read and write of a recording sends
the metric `roach.recording`. Its attributes are `tenant`, `rule`, `key`,
`run` (the `name` of the run), and `result`: `replayed`, `missed`, or
`written`. Group by `key` and count `run`, and a recording that only one
run uses shows that a value changes on each run.
a span to Sentry. Each proxied request sends a span and metrics. See
[Sentry](#sentry).
- **Certificate authority.** `ca` holds the PEM certificate and key that
clients trust. Keep it across restarts. Host certificates live for 7
days, and the service makes new ones before they expire.

### Sentry

With `sentryDsn`, the service sends metrics and spans to Sentry. It keeps
all traces. Metrics have only attributes with few values: `tenant`, `mode`,
`rule`, `origin`, and `result`. Spans also have `run` (the `name` of the
run) and `key`.

| Metric | Type | Value |
| ------------------------ | ----------------- | ---------------------------------------------------------------------------------------------------------------------------------------------------- |
| `roach.request` | counter | 1 for each proxied request. `result` is the `x-roach` header: `replayed`, `live`, `missed`, or `passthrough`. A `passthrough` request has no `rule`. |
| `roach.request.duration` | distribution (ms) | The time to answer a request that a rule records, by `result`. |
| `roach.recording.write` | counter | Recordings by `rule`. `result` is `written` (the proxy sent them to the store) or `dropped` (their session failed). |

Each proxied request is one trace. Each span has `tenant`, `mode`, and
`run`.

- `roach.run.start`: a new run, with `write` (the run has the write token).
- `roach.request`: one proxied request, named `<method> <origin>`, with
`origin`, `rule`, `result`, and `http.response.status_code`. It contains:
- `roach.key`: the key of the request, with `rule` and `key`.
- `roach.store.read`: a read of a recording, with `key` and `result`:
`hit` or `miss`.
- `roach.upstream`: the live request, with `origin` and
`http.response.status_code`.
- `roach.store.write`: a write of recordings, with `recordings` and
`written`. A session writes when it ends, so this span is usually its
own trace.

Telemetry never has a credential, a body, or the path or query of a URL.
So the service turns off the request data and the HTTP spans of the SDK,
and it adds no trace headers to the requests that it sends.

To see how well the cache works:

- **Hit rate.** Sum `roach.request`, group by `result`, and filter by
`tenant` and `rule`. The hit rate is `replayed / (replayed + live +
missed)`.
- **Misses.** `missed` is a request that failed in `replay` mode. `live`
in `auto` mode is a new recording. When `live` stays high from run to
run, a value in the key changes on each run.
- **Time.** Compare `roach.request.duration` for `live` and `replayed`.
- **Dropped.** `roach.recording.write` with `result:dropped` counts
recordings of failed sessions. The next run sends these requests live
again.
- **Changing keys.** Search spans for `span.op:roach.key`, group by
`key`, and count the runs. A key that only one run uses shows that a
value changes on each run.

### Limits

- Runs live in memory in one process. A restart ends the open runs, and
Expand Down
110 changes: 95 additions & 15 deletions src/recorder.ts
Original file line number Diff line number Diff line change
Expand Up @@ -14,7 +14,8 @@
* its session ended follows the result of that session. A request outside
* a session is written at once.
*
* The recorder never writes a known credential (`secrets.ts`).
* The recorder never writes a known credential (`secrets.ts`). It reports
* spans and metrics through the `Telemetry` hooks of `service.ts`.
*/
import type { IncomingHttpHeaders } from "node:http";
import { keyRequest, type KeyedRequest } from "./request-key.ts";
Expand Down Expand Up @@ -56,6 +57,29 @@ export interface ProxyResponse {
/** Where the response to a recorded request came from. */
export type ResponseSource = "live" | "missed" | "replayed";

/** The attributes of a span or a metric. */
type Attributes = Record<string, string | number | boolean>;

/**
* Hooks that report spans and metrics. `service.ts` gives hooks that send
* them to Sentry, so this file and `server.ts` do not load the SDK. An
* attribute must never hold a credential, a body, or the path or query of
* a URL.
*/
export interface Telemetry {
/** Run `fn` in a span. The span ends when `fn` returns or settles. */
span<T>(
options: { op: string; name?: string; attributes?: Attributes },
fn: () => T,
): T;
/** Add attributes to the active span. */
annotate(attributes: Attributes): void;
/** Add `value` to the counter `name`. */
count(name: string, value: number, attributes: Attributes): void;
/** Add a time in milliseconds to the distribution `name`. */
time(name: string, ms: number, attributes: Attributes): void;
}

interface Session {
name: string;
/** New recordings, by key. */
Expand Down Expand Up @@ -142,6 +166,7 @@ export interface RecorderConfig {
rules: RecordingRule[];
/** Credentials to redact, in addition to the ones that it learns. */
secrets?: string[];
telemetry: Telemetry;
}

/** Create the recorder of one run, with the store of its recordings. */
Expand All @@ -152,6 +177,7 @@ export function createRecorder(config: RecorderConfig, store: RecordingStore) {
}
}
let session: Session | undefined;
const { telemetry } = config;
const secrets = createSecrets(config.secrets);
const stats: RecordingStats = {
counts: Object.fromEntries(
Expand All @@ -165,8 +191,27 @@ export function createRecorder(config: RecorderConfig, store: RecordingStore) {
discarded: 0,
passthrough: {},
};
/** Count recordings by rule in `roach.recording.write`. */
const countRecordings = (keys: string[], result: "dropped" | "written") => {
const byRule = new Map<string, number>();
for (const key of keys) {
const rule = key.slice(0, key.indexOf("/"));
byRule.set(rule, (byRule.get(rule) ?? 0) + 1);
}
for (const [rule, value] of byRule) {
telemetry.count("roach.recording.write", value, { rule, result });
}
};
const write = async (recordings: Array<[string, Recording]>) => {
stats.written += await store.write(recordings);
countRecordings(
recordings.map(([key]) => key),
"written",
);
};
const drop = (keys: string[]) => {
stats.discarded += keys.length;
countRecordings(keys, "dropped");
};

const record = async (
Expand All @@ -177,7 +222,7 @@ export function createRecorder(config: RecorderConfig, store: RecordingStore) {
if (owner && owner.passed === undefined) {
owner.recorded.set(key, recording);
} else if (owner?.passed === false) {
stats.discarded += 1;
drop([key]);
} else {
await write([[key, recording]]);
}
Expand All @@ -201,7 +246,7 @@ export function createRecorder(config: RecorderConfig, store: RecordingStore) {
session = undefined;
ended.passed = passed;
if (passed) await write([...ended.recorded]);
else stats.discarded += ended.recorded.size;
else drop([...ended.recorded.keys()]);
return ended.missed;
};

Expand All @@ -216,6 +261,8 @@ export function createRecorder(config: RecorderConfig, store: RecordingStore) {
countPassthrough(origin: string, headers: IncomingHttpHeaders): void {
secrets.learn(headers);
stats.passthrough[origin] = (stats.passthrough[origin] ?? 0) + 1;
telemetry.annotate({ result: "passthrough" });
telemetry.count("roach.request", 1, { origin, result: "passthrough" });
},

/**
Expand All @@ -228,19 +275,30 @@ export function createRecorder(config: RecorderConfig, store: RecordingStore) {
request: ProxyRequest,
sendLive: () => Promise<ProxyResponse>,
): Promise<ProxyResponse & { source: ResponseSource }> {
const started = performance.now();
const origin = request.url.origin;
// A request belongs to the session that was open when it started.
const owner = session;
const counts = stats.counts[rule.name]!;
secrets.learn(request.headers);
const keyed = keyRequest(
rule,
{
method: request.method,
url: request.url.href,
headers: request.headers,
body: request.body.toString("utf8"),
telemetry.annotate({ rule: rule.name });
const { keyed, key } = telemetry.span(
{ op: "roach.key", attributes: { rule: rule.name } },
() => {
const result = keyRequest(
rule,
{
method: request.method,
url: request.url.href,
headers: request.headers,
body: request.body.toString("utf8"),
},
owner?.known,
);
const name = recordingKey(rule.name, result.key);
telemetry.annotate({ key: name });
return { keyed: result, key: name };
},
owner?.known,
);
if (owner) {
for (const [name, list] of keyed.values) {
Expand All @@ -249,12 +307,22 @@ export function createRecorder(config: RecorderConfig, store: RecordingStore) {
}
}
}
const key = recordingKey(rule.name, keyed.key);
const report = (result: ResponseSource) => {
const attributes = { rule: rule.name, origin, result };
telemetry.annotate({ result });
telemetry.count("roach.request", 1, attributes);
telemetry.time(
"roach.request.duration",
performance.now() - started,
attributes,
);
};

if (config.mode !== "record") {
const recording = await store.read(key);
if (recording) {
counts.replayed += 1;
report("replayed");
return {
...fromRecording(recording, keyed.values),
source: "replayed",
Expand All @@ -264,6 +332,7 @@ export function createRecorder(config: RecorderConfig, store: RecordingStore) {
if (config.mode === "replay") {
counts.missed += 1;
if (owner) owner.missed += 1;
report("missed");
return {
status: 412,
headers: { "content-type": "text/plain" },
Expand All @@ -276,18 +345,29 @@ export function createRecorder(config: RecorderConfig, store: RecordingStore) {
}

counts.live += 1;
const live = await telemetry.span(
{
op: "roach.upstream",
name: `${request.method} ${origin}`,
attributes: { origin, "http.request.method": request.method },
},
async () => {
const response = await sendLive();
telemetry.annotate({ "http.response.status_code": response.status });
return response;
},
);
// The client gets the redacted response too, so a live run and a
// replay give the same body.
const recording = JSON.parse(
secrets.redact(
JSON.stringify(
toRecording(request, keyed, owner?.name, await sendLive()),
),
JSON.stringify(toRecording(request, keyed, owner?.name, live)),
),
) as Recording;
if (!isTemporaryStatus(recording.response.status)) {
await record(owner, key, recording);
}
report("live");
return { ...fromRecording(recording, keyed.values), source: "live" };
},

Expand Down
27 changes: 22 additions & 5 deletions src/server.ts
Original file line number Diff line number Diff line change
Expand Up @@ -20,7 +20,7 @@ import https from "node:https";
import { isIP, type Socket } from "node:net";
import tls from "node:tls";
import type { CertificateAuthority } from "./certificates.ts";
import type { ProxyRequest, Recorder } from "./recorder.ts";
import type { ProxyRequest, Recorder, Telemetry } from "./recorder.ts";

/** The path prefix of the control API. */
export const CONTROL_PATH = "/__roach";
Expand Down Expand Up @@ -289,6 +289,8 @@ export interface ProxyTarget {
replayOnly?: boolean;
/** Set when the target stops. Its tunnels then refuse new requests. */
closed?: boolean;
/** Gets a span for each proxied request. */
telemetry: Telemetry;
}

/** A target, or the HTTP status that refuses the request. */
Expand Down Expand Up @@ -345,17 +347,32 @@ function serveProxied(
outgoing.end("Roach: this run has ended\n");
return;
}
proxyRequest(target, incoming, outgoing, tunnelOrigin).catch(
(error: unknown) => {
// Only the origin: the path and query can hold a credential.
const origin = tunnelOrigin ?? URL.parse(incoming.url ?? "")?.origin;
const method = incoming.method ?? "GET";
target.telemetry
.span(
{
op: "roach.request",
name: `${method} ${origin}`,
attributes: { origin: String(origin), "http.request.method": method },
},
async () => {
await proxyRequest(target, incoming, outgoing, tunnelOrigin);
target.telemetry.annotate({
"http.response.status_code": outgoing.statusCode,
});
},
)
.catch((error: unknown) => {
if (!outgoing.headersSent) {
const status = (error as { status?: number }).status ?? 502;
outgoing.writeHead(status, { "content-type": "text/plain" });
}
outgoing.end(
`Roach error: ${error instanceof Error ? error.message : String(error)}\n`,
);
},
);
});
}

/**
Expand Down
Loading
Loading