diff options
| author | Adam Malczewski <[email protected]> | 2026-06-06 22:52:48 +0900 |
|---|---|---|
| committer | Adam Malczewski <[email protected]> | 2026-06-06 22:52:48 +0900 |
| commit | 3e95b26ee2928c40db581bed4c138d3fa842b753 (patch) | |
| tree | f9500ab4d75934fb6c0a3863db4c63b29e1b4444 /packages/transport-http/src | |
| parent | 219cf053fad4e48b22590d3178438bf5d67d04e3 (diff) | |
| download | dispatch-3e95b26ee2928c40db581bed4c138d3fa842b753.tar.gz dispatch-3e95b26ee2928c40db581bed4c138d3fa842b753.zip | |
feat(transport-http,transport-ws): structured edge logging (close coverage gap #2)
Both HTTP + WS transport edges now emit structured logs via the injected
logger (D7-compliant: no per-AgentEvent/chat.delta frame logging). Verified
live — the journal contains the edge records.
- transport-ws: connection open/close (debug), chat.send accepted (info),
surface-op + malformed-chat.send (warn), abort-on-close (debug). +4 bun tests.
Correctly scoped extensionId=transport-ws (owns its Bun.serve).
- transport-http: /chat accepted (info) / 400 (warn) / turn-failure (error),
GET /conversations read (info), /models + store failure (error). +4 vitest.
Known follow-up: transport-http edge logs are attributed to '__host__' (not
'transport-http') because host-bin runs the HTTP server via createServer(getHostAPI())
rather than the extension owning its Bun.serve. Logs are captured + correlated;
only the per-extension filter is mis-scoped. Tracked in tasks.md.
typecheck clean, 498 vitest + 84 bun, biome clean.
Diffstat (limited to 'packages/transport-http/src')
| -rw-r--r-- | packages/transport-http/src/app.test.ts | 150 | ||||
| -rw-r--r-- | packages/transport-http/src/app.ts | 62 | ||||
| -rw-r--r-- | packages/transport-http/src/extension.ts | 2 |
3 files changed, 205 insertions, 9 deletions
diff --git a/packages/transport-http/src/app.test.ts b/packages/transport-http/src/app.test.ts index f4707bc..2adf4db 100644 --- a/packages/transport-http/src/app.test.ts +++ b/packages/transport-http/src/app.test.ts @@ -1,8 +1,50 @@ -import type { AgentEvent, StoredChunk } from "@dispatch/kernel"; +import type { AgentEvent, Logger, StoredChunk } from "@dispatch/kernel"; import { describe, expect, it } from "vitest"; import { createApp } from "./app.js"; import type { ConversationStore, CredentialStore, SessionOrchestrator } from "./seam.js"; +interface CapturedLog { + readonly level: "debug" | "info" | "warn" | "error"; + readonly msg: string; + readonly attrs?: Record<string, unknown>; +} + +function createFakeLogger(): Logger & { readonly records: readonly CapturedLog[] } { + const records: CapturedLog[] = []; + return { + get records() { + return records; + }, + debug(msg, attrs) { + records.push({ level: "debug", msg, ...(attrs ? { attrs } : {}) }); + }, + info(msg, attrs) { + records.push({ level: "info", msg, ...(attrs ? { attrs } : {}) }); + }, + warn(msg, attrs) { + records.push({ level: "warn", msg, ...(attrs ? { attrs } : {}) }); + }, + error(msg, attrs) { + records.push({ level: "error", msg, ...(attrs ? { attrs } : {}) }); + }, + child() { + return createFakeLogger(); + }, + span() { + return { + id: "fake-span", + log: createFakeLogger(), + setAttributes() {}, + addLink() {}, + child() { + return this; + }, + end() {}, + }; + }, + }; +} + function createFakeConversationStore( store: Map<string, StoredChunk[]> = new Map(), ): ConversationStore { @@ -75,12 +117,15 @@ function createThrowingCredentialStore(error: Error): CredentialStore { }; } +const noopLogger = createFakeLogger(); + describe("GET /health", () => { it("returns ok", async () => { const app = createApp({ conversationStore: createFakeConversationStore(), orchestrator: createFakeOrchestrator([]), credentialStore: createFakeCredentialStore([]), + logger: noopLogger, }); const res = await app.request("/health"); expect(res.status).toBe(200); @@ -95,6 +140,7 @@ describe("GET /models", () => { conversationStore: createFakeConversationStore(), orchestrator: createFakeOrchestrator([]), credentialStore: createFakeCredentialStore(["opencode/m1", "openai/gpt-4"]), + logger: noopLogger, }); const res = await app.request("/models"); expect(res.status).toBe(200); @@ -107,6 +153,7 @@ describe("GET /models", () => { conversationStore: createFakeConversationStore(), orchestrator: createFakeOrchestrator([]), credentialStore: createFakeCredentialStore([]), + logger: noopLogger, }); const res = await app.request("/models"); expect(res.status).toBe(200); @@ -119,6 +166,7 @@ describe("GET /models", () => { conversationStore: createFakeConversationStore(), orchestrator: createFakeOrchestrator([]), credentialStore: createThrowingCredentialStore(new Error("db down")), + logger: noopLogger, }); const res = await app.request("/models"); expect(res.status).toBe(502); @@ -133,6 +181,7 @@ describe("POST /chat", () => { conversationStore: createFakeConversationStore(), orchestrator: createFakeOrchestrator([]), credentialStore: createFakeCredentialStore([]), + logger: noopLogger, }); const res = await app.request("/chat", { method: "POST", @@ -415,3 +464,102 @@ describe("GET /conversations/:id", () => { expect(res.status).toBe(400); }); }); + +describe("POST /chat logging", () => { + it("POST /chat logs an info line when a request is accepted", async () => { + const logger = createFakeLogger(); + const app = createApp({ + conversationStore: createFakeConversationStore(), + orchestrator: createFakeOrchestrator([ + { type: "done", conversationId: "conv1", turnId: "turn1", reason: "stop" }, + ]), + credentialStore: createFakeCredentialStore([]), + logger, + }); + + await app.request("/chat", { + method: "POST", + headers: { "Content-Type": "application/json" }, + body: JSON.stringify({ + message: "hi", + conversationId: "conv1", + model: "opencode/m1", + cwd: "/tmp", + }), + }); + + const infoLogs = logger.records.filter((r) => r.level === "info"); + expect(infoLogs).toHaveLength(1); + expect(infoLogs[0]?.msg).toBe("chat: request accepted"); + expect(infoLogs[0]?.attrs?.conversationId).toBe("conv1"); + expect(infoLogs[0]?.attrs?.hasModel).toBe(true); + expect(infoLogs[0]?.attrs?.hasCwd).toBe(true); + }); + + it("POST /chat logs a warn on a malformed body (400)", async () => { + const logger = createFakeLogger(); + const app = createApp({ + conversationStore: createFakeConversationStore(), + orchestrator: createFakeOrchestrator([]), + credentialStore: createFakeCredentialStore([]), + logger, + }); + + await app.request("/chat", { + method: "POST", + headers: { "Content-Type": "application/json" }, + body: "not json", + }); + + const warnLogs = logger.records.filter((r) => r.level === "warn"); + expect(warnLogs.length).toBeGreaterThanOrEqual(1); + expect(warnLogs[0]?.msg).toBe("chat: invalid JSON body"); + }); + + it("POST /chat logs an error when the turn fails", async () => { + const logger = createFakeLogger(); + const app = createApp({ + conversationStore: createFakeConversationStore(), + orchestrator: createThrowingOrchestrator(new Error("boom")), + credentialStore: createFakeCredentialStore([]), + logger, + }); + + await app.request("/chat", { + method: "POST", + headers: { "Content-Type": "application/json" }, + body: JSON.stringify({ message: "hi", conversationId: "conv1" }), + }); + + const errorLogs = logger.records.filter((r) => r.level === "error"); + expect(errorLogs).toHaveLength(1); + expect(errorLogs[0]?.msg).toBe("chat: turn failed"); + expect(errorLogs[0]?.attrs?.err).toBeInstanceOf(Error); + }); +}); + +describe("GET /conversations/:id logging", () => { + it("GET /conversations/:id logs the read (conversationId + sinceSeq + count)", async () => { + const logger = createFakeLogger(); + const sampleChunks: StoredChunk[] = [ + { seq: 1, role: "user", chunk: { type: "text", text: "hello" } }, + { seq: 2, role: "assistant", chunk: { type: "text", text: "hi there" } }, + ]; + const store = new Map<string, StoredChunk[]>([["conv1", sampleChunks]]); + const app = createApp({ + conversationStore: createFakeConversationStore(store), + orchestrator: createFakeOrchestrator([]), + credentialStore: createFakeCredentialStore([]), + logger, + }); + + await app.request("/conversations/conv1?sinceSeq=0"); + + const infoLogs = logger.records.filter((r) => r.level === "info"); + expect(infoLogs).toHaveLength(1); + expect(infoLogs[0]?.msg).toBe("conversations: read"); + expect(infoLogs[0]?.attrs?.conversationId).toBe("conv1"); + expect(infoLogs[0]?.attrs?.sinceSeq).toBe(0); + expect(infoLogs[0]?.attrs?.count).toBe(2); + }); +}); diff --git a/packages/transport-http/src/app.ts b/packages/transport-http/src/app.ts index 5f63683..bd9db4e 100644 --- a/packages/transport-http/src/app.ts +++ b/packages/transport-http/src/app.ts @@ -1,4 +1,4 @@ -import type { AgentEvent } from "@dispatch/kernel"; +import type { AgentEvent, Logger } from "@dispatch/kernel"; import type { ConversationHistoryResponse, ModelsResponse } from "@dispatch/transport-contract"; import { Hono } from "hono"; import { @@ -14,11 +14,35 @@ export interface CreateServerOptions { readonly conversationStore: ConversationStore; readonly orchestrator: SessionOrchestrator; readonly credentialStore: CredentialStore; + readonly logger?: Logger; readonly generateId?: () => string; } +const noopLogger: Logger = { + debug() {}, + info() {}, + warn() {}, + error() {}, + child() { + return noopLogger; + }, + span() { + return { + id: "noop-span", + log: noopLogger, + setAttributes() {}, + addLink() {}, + child() { + return this; + }, + end() {}, + }; + }, +}; + export function createApp(opts: CreateServerOptions): Hono { const app = new Hono(); + const log = opts.logger ?? noopLogger; const generateId = opts.generateId ?? (() => crypto.randomUUID()); app.get("/health", (c) => c.json({ ok: true })); @@ -27,14 +51,28 @@ export function createApp(opts: CreateServerOptions): Hono { const conversationId = c.req.param("id"); const sinceSeqResult = parseSinceSeq(c.req.query("sinceSeq")); if (isSinceSeqError(sinceSeqResult)) { + log.warn("conversations: invalid sinceSeq", { + conversationId, + error: sinceSeqResult.error, + }); return c.json({ error: sinceSeqResult.error }, 400); } - const chunks = await opts.conversationStore.loadSince(conversationId, sinceSeqResult); - const latestSeq = - chunks.length > 0 ? (chunks[chunks.length - 1]?.seq ?? sinceSeqResult) : sinceSeqResult; - const body: ConversationHistoryResponse = { chunks, latestSeq }; - return c.json(body, 200); + try { + const chunks = await opts.conversationStore.loadSince(conversationId, sinceSeqResult); + const latestSeq = + chunks.length > 0 ? (chunks[chunks.length - 1]?.seq ?? sinceSeqResult) : sinceSeqResult; + log.info("conversations: read", { + conversationId, + sinceSeq: sinceSeqResult, + count: chunks.length, + }); + const body: ConversationHistoryResponse = { chunks, latestSeq }; + return c.json(body, 200); + } catch (err) { + log.error("conversations: store failure", { err }); + return c.json({ error: "Failed to load conversation" }, 500); + } }); app.get("/models", async (c) => { @@ -42,7 +80,8 @@ export function createApp(opts: CreateServerOptions): Hono { const models = await opts.credentialStore.listCatalog(); const body: ModelsResponse = { models }; return c.json(body, 200); - } catch { + } catch (err) { + log.error("models: failed to retrieve catalog", { err }); return c.json({ error: "Failed to retrieve model catalog" }, 502); } }); @@ -52,15 +91,23 @@ export function createApp(opts: CreateServerOptions): Hono { try { body = await c.req.json(); } catch { + log.warn("chat: invalid JSON body"); return c.json({ error: "Invalid JSON body" }, 400); } const result = parseChatBody(body, generateId); if (isParseError(result)) { + log.warn("chat: validation failed", { reason: result.error }); return c.json({ error: result.error }, 400); } const { conversationId, message, model, cwd } = result; + log.info("chat: request accepted", { + conversationId, + hasModel: model !== undefined, + hasCwd: cwd !== undefined, + }); + const events: AgentEvent[] = []; let resolveStream: () => void; const streamReady = new Promise<void>((resolve) => { @@ -83,6 +130,7 @@ export function createApp(opts: CreateServerOptions): Hono { resolveStream(); }) .catch((err) => { + log.error("chat: turn failed", { err }); events.push({ type: "error", conversationId, diff --git a/packages/transport-http/src/extension.ts b/packages/transport-http/src/extension.ts index ba45f9d..dda722e 100644 --- a/packages/transport-http/src/extension.ts +++ b/packages/transport-http/src/extension.ts @@ -27,7 +27,7 @@ export function createServer(host: HostAPI, _opts?: CreateServerOptions): Hono { const conversationStore = host.getService(conversationStoreHandle); const orchestrator = host.getService(sessionOrchestratorHandle); const credentialStore = host.getService(credentialStoreHandle); - return createApp({ conversationStore, orchestrator, credentialStore }); + return createApp({ conversationStore, orchestrator, credentialStore, logger: host.logger }); } export const extension: Extension = { |
