mirror of
https://github.com/Routstr/routstrd.git
synced 2026-10-05 12:28:23 +00:00
docs: link pi sessions to request/response logs
Adds docs/linking-sessions-to-request-logs.md and a bun mapper (scripts/link-session-logs.ts, run via `bun run link-logs`) that joins a pi session transcript to the daemon's request/response logs. An assistant message stores the upstream response id as `message.responseId`, and that same id appears verbatim in the response log's SSE `chunk.text`, so the join is exact (no keyword/timestamp heuristics). Request and response logs already share one id (`requests/<id>.json` <-> `responses/<id>.jsonl`).
This commit is contained in:
@@ -0,0 +1,177 @@
|
|||||||
|
# Linking pi sessions to request/response logs
|
||||||
|
|
||||||
|
When `requestResponseLogging` is enabled, the daemon records every proxied
|
||||||
|
upstream call as two files that share one id:
|
||||||
|
|
||||||
|
- `requests/<id>.json` — method, url, baseUrl, redacted headers, request body
|
||||||
|
- `responses/<id>.jsonl` — one JSON event per line: `response_start`, `chunk`,
|
||||||
|
`end` / `error`
|
||||||
|
|
||||||
|
The `id` is minted in `src/daemon/request-response-log-sink.ts` (`makeId()`):
|
||||||
|
the request's arrival time with `:`/`.` swapped for `-`, plus 8 hex chars, e.g.
|
||||||
|
`2026-09-30T09-22-35-288Z-60c8e8cf`. The request's `id` and the response's
|
||||||
|
`requestLogId` are the same string, so **the request and response logs are
|
||||||
|
paired by filename stem** and never need matching against each other.
|
||||||
|
|
||||||
|
Separately, pi records its own transcript per working directory. The two are
|
||||||
|
written by different processes, so the session has no log id and the logs have
|
||||||
|
no session id. This document explains the two keys that recover the link
|
||||||
|
exactly, and how to run the mapper on redtop.
|
||||||
|
|
||||||
|
## TL;DR
|
||||||
|
|
||||||
|
```bash
|
||||||
|
# on redtop
|
||||||
|
bun scripts/link-session-logs.ts <session.jsonl> /home/user/.routstrd/reqRes
|
||||||
|
```
|
||||||
|
|
||||||
|
Every assistant turn prints the response log it produced. The request log is
|
||||||
|
the same stem under `requests/`.
|
||||||
|
|
||||||
|
## Where the data lives
|
||||||
|
|
||||||
|
| | redtop (`ssh redtop`) | default |
|
||||||
|
| --- | --- | --- |
|
||||||
|
| request/response logs | `/home/user/.routstrd/reqRes` | `~/.routstrd/request-response-logs` |
|
||||||
|
| log root on disk | `requestResponseLogging.dir` in `~/.routstrd/config.json` | `REQUEST_RESPONSE_LOGS_DIR` (`src/utils/config.ts`) |
|
||||||
|
| pi sessions | `/home/user/.pi/agent/sessions/--<cwd>--/*.jsonl` | `~/.pi/agent/sessions/…` |
|
||||||
|
| pi provider config | `/home/user/.pi/agent/models.json` (`providers.routstr`) | `~/.pi/agent/models.json` |
|
||||||
|
|
||||||
|
On redtop the log root is set explicitly:
|
||||||
|
|
||||||
|
```jsonc
|
||||||
|
// ~/.routstrd/config.json
|
||||||
|
"requestResponseLogging": { "enabled": true, "dir": "/home/user/.routstrd/reqRes" }
|
||||||
|
```
|
||||||
|
|
||||||
|
pi reaches the daemon through the `routstr` provider that
|
||||||
|
`routstrd clients add pi-agent` writes into `models.json`
|
||||||
|
(`src/integrations/pi.ts`, `configPath: ~/.pi/agent/models.json`). So the
|
||||||
|
sessions and the logs on redtop are two views of the *same* traffic.
|
||||||
|
|
||||||
|
Logs are stored uncompressed on redtop (`requests/*.json`,
|
||||||
|
`responses/*.jsonl`). Elsewhere they may be brotli-compressed (`.jsonl.br`);
|
||||||
|
the mapper handles both.
|
||||||
|
|
||||||
|
## The join keys
|
||||||
|
|
||||||
|
### 1. `responseId` ⇄ response stream id (primary, exact)
|
||||||
|
|
||||||
|
Each assistant message in a pi session stores the upstream response id:
|
||||||
|
|
||||||
|
```jsonc
|
||||||
|
// session .jsonl
|
||||||
|
{ "type": "message",
|
||||||
|
"timestamp": "2026-09-30T09:22:36.852Z",
|
||||||
|
"message": { "role": "assistant", "provider": "routstr",
|
||||||
|
"responseId": "chatcmpl-b5e868d7b747dd8be5a2fbc0b1313507", … } }
|
||||||
|
```
|
||||||
|
|
||||||
|
The response log replays the raw upstream SSE stream inside its `chunk` events,
|
||||||
|
so the same id appears verbatim:
|
||||||
|
|
||||||
|
```jsonc
|
||||||
|
// responses/<id>.jsonl
|
||||||
|
{ "requestLogId": "2026-09-30T09-22-35-288Z-60c8e8cf", "type": "chunk",
|
||||||
|
"text": "data: {\"id\":\"chatcmpl-b5e868d7b747dd8be5a2fbc0b1313507\", …}\n\n" }
|
||||||
|
```
|
||||||
|
|
||||||
|
The id prefix depends on which upstream provider answered — `chatcmpl-…` for
|
||||||
|
Venice, `gen-…` for OpenRouter — but it is always present and always identical
|
||||||
|
to `responseId`. Match on `chunk.text`, never on the raw file: the SSE text is
|
||||||
|
JSON-escaped in the log, so `grep '"id":"'` misses it.
|
||||||
|
|
||||||
|
### 2. request ⇄ response (exact, by id)
|
||||||
|
|
||||||
|
`requests/<id>.json` and `responses/<id>.jsonl` share the filename stem
|
||||||
|
(`id` == `requestLogId`). A response hit therefore yields its request for free.
|
||||||
|
|
||||||
|
### 3. trigger timestamp ≈ request timestamp (secondary)
|
||||||
|
|
||||||
|
The request log's `timestamp` is when the daemon received the call, which is
|
||||||
|
the instant pi fired it — within ~10–30 ms of the *triggering* session message
|
||||||
|
(the user turn or tool result), and within a few ms of the assistant record's
|
||||||
|
epoch-ms `message.timestamp`. Useful as a sanity check or fallback, but not
|
||||||
|
needed once key 1 works.
|
||||||
|
|
||||||
|
## Running the mapper
|
||||||
|
|
||||||
|
The mapper is `scripts/link-session-logs.ts` (bun, no extra deps):
|
||||||
|
|
||||||
|
```bash
|
||||||
|
bun run link-logs -- <session.jsonl> [logsDir] [--all] [--json]
|
||||||
|
```
|
||||||
|
|
||||||
|
- `logsDir` defaults to `$ROUTSTRD_LOG_DIR`, else `~/.routstrd/request-response-logs`.
|
||||||
|
- `--all` scans every response log instead of only the session's UTC day (use
|
||||||
|
when a session spans midnight or logs were rotated).
|
||||||
|
- `--json` prints a machine-readable table with both the `requests/` and
|
||||||
|
`responses/` paths per turn.
|
||||||
|
|
||||||
|
On redtop the script must exist in the redtop checkout. Copy it over now (or
|
||||||
|
`git pull` once the change is pushed):
|
||||||
|
|
||||||
|
```bash
|
||||||
|
scp scripts/link-session-logs.ts \
|
||||||
|
redtop:~/projects/routstr_main/routstrd/scripts/
|
||||||
|
```
|
||||||
|
|
||||||
|
`bun` is on `PATH` in an interactive fish session on redtop (`~/.bun/bin`);
|
||||||
|
from a non-interactive shell, add it explicitly:
|
||||||
|
|
||||||
|
```bash
|
||||||
|
ssh redtop 'export PATH=$HOME/.bun/bin:$PATH; \
|
||||||
|
bun ~/projects/routstr_main/routstrd/scripts/link-session-logs.ts \
|
||||||
|
~/.pi/agent/sessions/--home-user-projects-routstr_main-routstr-core--/<session>.jsonl \
|
||||||
|
~/.routstrd/reqRes'
|
||||||
|
```
|
||||||
|
|
||||||
|
To work from the Mac against redtop's logs, either run it there over SSH (as
|
||||||
|
above) or pull the logs first:
|
||||||
|
|
||||||
|
```bash
|
||||||
|
rsync -a redtop:/home/user/.routstrd/reqRes/ ~/.routstrd/reqRes-redtop/
|
||||||
|
bun scripts/link-session-logs.ts <session.jsonl> ~/.routstrd/reqRes-redtop
|
||||||
|
```
|
||||||
|
|
||||||
|
### Finding the session for a given directory
|
||||||
|
|
||||||
|
pi slugs the message's `cwd` into the session directory name by dropping the
|
||||||
|
leading `/` and replacing the rest with `-`, wrapped in `--`:
|
||||||
|
|
||||||
|
```
|
||||||
|
/home/user/projects/routstr_main/routstr-core
|
||||||
|
-> ~/.pi/agent/sessions/--home-user-projects-routstr_main-routstr-core--/
|
||||||
|
```
|
||||||
|
|
||||||
|
Pick the file you want inside that directory (or `ls -t … | head -1` for the
|
||||||
|
latest).
|
||||||
|
|
||||||
|
## Verified
|
||||||
|
|
||||||
|
Against this repo's own history the link is 1:1 and exact:
|
||||||
|
|
||||||
|
- `2026-09-30T09-21-41-962Z_01a0f19e…jsonl` → **12/12** assistant turns matched
|
||||||
|
(provider: Venice, `chatcmpl-…`).
|
||||||
|
- `2026-09-15T19-49-27-933Z_01a0a69e…jsonl` → **8/8** (OpenRouter, `gen-…`).
|
||||||
|
- `2026-08-16T10-51-25-080Z_01a00a32…jsonl` → 51 of 55 turns carry a
|
||||||
|
`responseId`; all 51 matched (compressed `.br` logs).
|
||||||
|
- On redtop, `2026-10-01T07-55-38-825Z_01a0f676…jsonl` → **2/2**.
|
||||||
|
|
||||||
|
## Caveats
|
||||||
|
|
||||||
|
- **Retries and aborted calls leave orphan logs.** A single assistant turn can
|
||||||
|
produce more than one request/response pair (transient `scp`-style failures,
|
||||||
|
provider retries), and some logs belong to sessions outside the one you are
|
||||||
|
looking at. Drive the join from the session, never assume the counts match.
|
||||||
|
- **No `responseId` = no exact link.** The key exists in modern pi session
|
||||||
|
files (see the `2026-06-*` / `2026-08-*` sessions above). If a session omits
|
||||||
|
it, fall back to the trigger-timestamp window.
|
||||||
|
- **Don't match on the system/developer prompt.** The session stores it as
|
||||||
|
`sections` (preamble + project context); the request log stores it as one
|
||||||
|
flattened `developer` message. They are not byte-identical.
|
||||||
|
- **Content can quote an id.** Tool output that happens to contain an id string
|
||||||
|
can make a stem look like it matches an unrelated turn. The mapper only reads
|
||||||
|
`chunk.text`, which is model output, keeping this rare.
|
||||||
|
- **Logging may start mid-history.** If `requestResponseLogging` was enabled
|
||||||
|
after a session began, earlier turns simply have no logs.
|
||||||
@@ -24,6 +24,7 @@
|
|||||||
"lint": "tsc --noEmit",
|
"lint": "tsc --noEmit",
|
||||||
"test": "bun test",
|
"test": "bun test",
|
||||||
"smoke": "scripts/smoke/chat-completions.sh",
|
"smoke": "scripts/smoke/chat-completions.sh",
|
||||||
|
"link-logs": "bun scripts/link-session-logs.ts",
|
||||||
"build": "bun build src/index.ts --target=bun --outfile=dist/index.js --external better-sqlite3 && bun build src/daemon/index.ts --target=bun --outfile=dist/daemon/index.js --external better-sqlite3",
|
"build": "bun build src/index.ts --target=bun --outfile=dist/index.js --external better-sqlite3 && bun build src/daemon/index.ts --target=bun --outfile=dist/daemon/index.js --external better-sqlite3",
|
||||||
"build:binary": "bun build --compile --no-compile-autoload-dotenv --no-compile-autoload-bunfig src/index.ts --outfile=dist/routstrd",
|
"build:binary": "bun build --compile --no-compile-autoload-dotenv --no-compile-autoload-bunfig src/index.ts --outfile=dist/routstrd",
|
||||||
"prepublishOnly": "bun run build"
|
"prepublishOnly": "bun run build"
|
||||||
|
|||||||
@@ -0,0 +1,176 @@
|
|||||||
|
#!/usr/bin/env bun
|
||||||
|
/**
|
||||||
|
* link-session-logs.ts — map a pi session transcript to the routstrd
|
||||||
|
* request/response logs it produced.
|
||||||
|
*
|
||||||
|
* When `requestResponseLogging` is enabled the daemon writes one
|
||||||
|
* `requests/<id>.json` and one `responses/<id>.jsonl` per proxied upstream
|
||||||
|
* call. A pi session (see `routstrd clients add pi-agent`) records the same
|
||||||
|
* calls in its own transcript, under `~/.pi/agent/sessions/<cwd-slug>/*.jsonl`.
|
||||||
|
*
|
||||||
|
* The two are written by different processes, so there is no session id on the
|
||||||
|
* log side and no log id on the session side — but each assistant message in
|
||||||
|
* the session stores the upstream response id (`message.responseId`), and that
|
||||||
|
* same id appears verbatim inside the response log's SSE chunks. The request
|
||||||
|
* and response logs then share one id (`requests/<id>.json` ↔
|
||||||
|
* `responses/<id>.jsonl`, `id` == `requestLogId`), so a response hit yields the
|
||||||
|
* request too.
|
||||||
|
*
|
||||||
|
* Usage:
|
||||||
|
* bun scripts/link-session-logs.ts <session.jsonl> [logsDir] [--all] [--json]
|
||||||
|
*
|
||||||
|
* logsDir Request/response log root. Defaults to $ROUTSTRD_LOG_DIR, else
|
||||||
|
* ~/.routstrd/request-response-logs. On redtop it is
|
||||||
|
* /home/user/.routstrd/reqRes (see requestResponseLogging.dir).
|
||||||
|
* --all Scan every response log instead of only the session's UTC day
|
||||||
|
* (slower; use when a session spans midnight or logs were rotated).
|
||||||
|
* --json Emit machine-readable JSON instead of a table.
|
||||||
|
*/
|
||||||
|
import { readFileSync, readdirSync, existsSync } from "node:fs";
|
||||||
|
import { homedir } from "node:os";
|
||||||
|
import { basename, join } from "node:path";
|
||||||
|
import { brotliDecompressSync } from "node:zlib";
|
||||||
|
|
||||||
|
const ID_RE = /"id"\s*:\s*"([^"]+)"/g;
|
||||||
|
|
||||||
|
interface Turn {
|
||||||
|
/** ISO timestamp of the assistant message (also when the request fired). */
|
||||||
|
timestamp: string;
|
||||||
|
responseId?: string;
|
||||||
|
model?: string;
|
||||||
|
}
|
||||||
|
|
||||||
|
function readMaybeCompressed(path: string): string {
|
||||||
|
const buf = readFileSync(path);
|
||||||
|
if (!path.endsWith(".br")) return buf.toString("utf8");
|
||||||
|
try {
|
||||||
|
return brotliDecompressSync(buf).toString("utf8");
|
||||||
|
} catch {
|
||||||
|
return buf.toString("utf8");
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
|
/** Upstream generation ids emitted inside a response log's SSE chunks. */
|
||||||
|
function responseIds(path: string): Set<string> {
|
||||||
|
const ids = new Set<string>();
|
||||||
|
for (const line of readMaybeCompressed(path).split("\n")) {
|
||||||
|
if (!line.trim()) continue;
|
||||||
|
let event: { type?: string; text?: string };
|
||||||
|
try {
|
||||||
|
event = JSON.parse(line);
|
||||||
|
} catch {
|
||||||
|
continue;
|
||||||
|
}
|
||||||
|
if (event.type !== "chunk" || typeof event.text !== "string") continue;
|
||||||
|
for (const match of event.text.matchAll(ID_RE)) ids.add(match[1]!);
|
||||||
|
}
|
||||||
|
return ids;
|
||||||
|
}
|
||||||
|
|
||||||
|
function assistantTurns(sessionPath: string): Turn[] {
|
||||||
|
const turns: Turn[] = [];
|
||||||
|
for (const line of readFileSync(sessionPath, "utf8").split("\n")) {
|
||||||
|
if (!line.trim()) continue;
|
||||||
|
let record: { type?: string; timestamp?: string; message?: { role?: string; responseId?: string; responseModel?: string } };
|
||||||
|
try {
|
||||||
|
record = JSON.parse(line);
|
||||||
|
} catch {
|
||||||
|
continue;
|
||||||
|
}
|
||||||
|
if (record.type !== "message" || record.message?.role !== "assistant") continue;
|
||||||
|
turns.push({
|
||||||
|
timestamp: record.timestamp ?? "",
|
||||||
|
responseId: record.message.responseId,
|
||||||
|
model: record.message.responseModel,
|
||||||
|
});
|
||||||
|
}
|
||||||
|
return turns;
|
||||||
|
}
|
||||||
|
|
||||||
|
/** Strip the `.jsonl` / `.jsonl.br` suffix to recover the log id (stem). */
|
||||||
|
function stemOf(file: string): string {
|
||||||
|
return file.replace(/\.jsonl(\.br)?$/, "");
|
||||||
|
}
|
||||||
|
|
||||||
|
function main(): void {
|
||||||
|
const args = process.argv.slice(2);
|
||||||
|
const flags = new Set(args.filter((a) => a.startsWith("--")));
|
||||||
|
const positional = args.filter((a) => !a.startsWith("--"));
|
||||||
|
const [sessionPath, logsArg] = positional;
|
||||||
|
|
||||||
|
if (!sessionPath) {
|
||||||
|
console.error("usage: bun scripts/link-session-logs.ts <session.jsonl> [logsDir] [--all] [--json]");
|
||||||
|
process.exit(2);
|
||||||
|
}
|
||||||
|
|
||||||
|
const logsDir =
|
||||||
|
logsArg || process.env.ROUTSTRD_LOG_DIR || join(homedir(), ".routstrd", "request-response-logs");
|
||||||
|
const responsesDir = join(logsDir, "responses");
|
||||||
|
const requestsDir = join(logsDir, "requests");
|
||||||
|
if (!existsSync(responsesDir)) {
|
||||||
|
console.error(`no responses directory at ${responsesDir}`);
|
||||||
|
process.exit(2);
|
||||||
|
}
|
||||||
|
|
||||||
|
const day = basename(sessionPath).slice(0, 10); // YYYY-MM-DD
|
||||||
|
const candidates = readdirSync(responsesDir).filter(
|
||||||
|
(file) => file.endsWith(".jsonl") || file.endsWith(".jsonl.br"),
|
||||||
|
);
|
||||||
|
const scanned = flags.has("--all") ? candidates : candidates.filter((file) => file.startsWith(day));
|
||||||
|
|
||||||
|
// responseId -> response log stem(s). Usually one; retries or quoted ids can
|
||||||
|
// make a stem appear more than once, so keep every hit.
|
||||||
|
const byResponseId = new Map<string, string[]>();
|
||||||
|
for (const file of scanned) {
|
||||||
|
const stem = stemOf(file);
|
||||||
|
for (const id of responseIds(join(responsesDir, file))) {
|
||||||
|
const hits = byResponseId.get(id) ?? [];
|
||||||
|
if (!hits.includes(stem)) hits.push(stem);
|
||||||
|
byResponseId.set(id, hits);
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
|
const turns = assistantTurns(sessionPath);
|
||||||
|
const rows = turns.map((turn) => {
|
||||||
|
const stems = turn.responseId ? (byResponseId.get(turn.responseId) ?? []) : [];
|
||||||
|
return {
|
||||||
|
timestamp: turn.timestamp,
|
||||||
|
responseId: turn.responseId ?? null,
|
||||||
|
model: turn.model ?? null,
|
||||||
|
responseLogs: stems.map((stem) => join(responsesDir, `${stem}.jsonl`)),
|
||||||
|
requestLogs: stems.map((stem) => {
|
||||||
|
const plain = join(requestsDir, `${stem}.json`);
|
||||||
|
return existsSync(plain) ? plain : join(requestsDir, `${stem}.json.br`);
|
||||||
|
}),
|
||||||
|
matched: stems.length > 0,
|
||||||
|
};
|
||||||
|
});
|
||||||
|
|
||||||
|
if (flags.has("--json")) {
|
||||||
|
console.log(JSON.stringify(rows, null, 2));
|
||||||
|
return;
|
||||||
|
}
|
||||||
|
|
||||||
|
const matched = rows.filter((r) => r.matched).length;
|
||||||
|
console.log(`session : ${sessionPath}`);
|
||||||
|
console.log(`logs : ${logsDir}`);
|
||||||
|
console.log(`scanned : ${scanned.length} response log(s)${flags.has("--all") ? " (all)" : ` for ${day}`}`);
|
||||||
|
console.log(`turns : ${rows.length} assistant message(s), ${matched} matched\n`);
|
||||||
|
|
||||||
|
const width = Math.max(...rows.map((r) => (r.responseId ?? "—").length), 10);
|
||||||
|
for (const row of rows) {
|
||||||
|
const id = (row.responseId ?? "—").padEnd(width);
|
||||||
|
const hit = row.matched ? row.responseLogs[0]!.replace(`${logsDir}/`, "") : "NO MATCH";
|
||||||
|
console.log(` ${row.timestamp} ${id} ${hit}`);
|
||||||
|
}
|
||||||
|
|
||||||
|
const unmatched = rows.filter((r) => !r.matched);
|
||||||
|
if (unmatched.length > 0) {
|
||||||
|
console.log(
|
||||||
|
`\n${unmatched.length} unmatched turn(s). If the session spans midnight or the logs were` +
|
||||||
|
` rotated, re-run with --all. Pre-responseId pi versions cannot be matched this way.`,
|
||||||
|
);
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
|
main();
|
||||||
Reference in New Issue
Block a user