diff --git a/sdks/typescript/packages/client/src/__tests__/debug-logger.test.ts b/sdks/typescript/packages/client/src/__tests__/debug-logger.test.ts new file mode 100644 index 0000000000..df123af528 --- /dev/null +++ b/sdks/typescript/packages/client/src/__tests__/debug-logger.test.ts @@ -0,0 +1,330 @@ +import { describe, it, expect, vi, beforeEach, afterEach } from "vitest"; +import { DebugLogger, createDebugLogger } from "@/debug-logger"; +import { resolveAgentDebugConfig, ResolvedAgentDebugConfig } from "@/agent/types"; + +describe("resolveAgentDebugConfig", () => { + it("undefined -> all fields false", () => { + const result = resolveAgentDebugConfig(undefined); + expect(result).toEqual({ + enabled: false, + events: false, + lifecycle: false, + verbose: false, + }); + }); + + it("false -> all fields false", () => { + const result = resolveAgentDebugConfig(false); + expect(result).toEqual({ + enabled: false, + events: false, + lifecycle: false, + verbose: false, + }); + }); + + it("true -> all fields true", () => { + const result = resolveAgentDebugConfig(true); + expect(result).toEqual({ + enabled: true, + events: true, + lifecycle: true, + verbose: true, + }); + }); + + it("{} -> events true, lifecycle true, verbose false, enabled true", () => { + const result = resolveAgentDebugConfig({}); + expect(result).toEqual({ + enabled: true, + events: true, + lifecycle: true, + verbose: false, + }); + }); + + it("{ events: true } -> events true, lifecycle true (default), verbose false", () => { + const result = resolveAgentDebugConfig({ events: true }); + expect(result).toEqual({ + enabled: true, + events: true, + lifecycle: true, + verbose: false, + }); + }); + + it("{ events: false } -> events false, lifecycle true, verbose false", () => { + const result = resolveAgentDebugConfig({ events: false }); + expect(result).toEqual({ + enabled: true, + events: false, + lifecycle: true, + verbose: false, + }); + }); + + it("{ lifecycle: false } -> events true, lifecycle false, verbose false", () => { + const result = resolveAgentDebugConfig({ lifecycle: false }); + expect(result).toEqual({ + enabled: true, + events: true, + lifecycle: false, + verbose: false, + }); + }); + + it("{ verbose: true } -> events true, lifecycle true, verbose true", () => { + const result = resolveAgentDebugConfig({ verbose: true }); + expect(result).toEqual({ + enabled: true, + events: true, + lifecycle: true, + verbose: true, + }); + }); + + it("{ events: false, lifecycle: false } -> enabled false", () => { + const result = resolveAgentDebugConfig({ + events: false, + lifecycle: false, + }); + expect(result).toEqual({ + enabled: false, + events: false, + lifecycle: false, + verbose: false, + }); + }); + + it("{ events: false, lifecycle: false, verbose: true } -> enabled false (verbose alone doesn't enable)", () => { + const result = resolveAgentDebugConfig({ + events: false, + lifecycle: false, + verbose: true, + }); + expect(result).toEqual({ + enabled: false, + events: false, + lifecycle: false, + verbose: true, + }); + }); + + it("{ events: true, lifecycle: false, verbose: true } -> enabled true", () => { + const result = resolveAgentDebugConfig({ + events: true, + lifecycle: false, + verbose: true, + }); + expect(result).toEqual({ + enabled: true, + events: true, + lifecycle: false, + verbose: true, + }); + }); +}); + +describe("createDebugLogger", () => { + it("returns undefined when config has enabled: false", () => { + const config: ResolvedAgentDebugConfig = { + enabled: false, + events: false, + lifecycle: false, + verbose: false, + }; + expect(createDebugLogger(config)).toBeUndefined(); + }); + + it("returns DebugLogger instance when config has enabled: true", () => { + const config: ResolvedAgentDebugConfig = { + enabled: true, + events: true, + lifecycle: true, + verbose: false, + }; + const logger = createDebugLogger(config); + expect(logger).toBeInstanceOf(DebugLogger); + }); +}); + +describe("DebugLogger.event()", () => { + let debugSpy: ReturnType; + + beforeEach(() => { + debugSpy = vi.spyOn(console, "debug").mockImplementation(() => {}); + }); + + afterEach(() => { + vi.restoreAllMocks(); + }); + + it("does NOT call console.debug when events is disabled", () => { + const logger = new DebugLogger({ + enabled: true, + events: false, + lifecycle: true, + verbose: false, + }); + logger.event("PREFIX", "some label", { foo: "bar" }); + expect(debugSpy).not.toHaveBeenCalled(); + }); + + it("calls console.debug with [PREFIX] label and JSON.stringify(data) when verbose is true", () => { + const logger = new DebugLogger({ + enabled: true, + events: true, + lifecycle: true, + verbose: true, + }); + const data = { type: "TEST", value: 42 }; + logger.event("PREFIX", "some label", data); + expect(debugSpy).toHaveBeenCalledTimes(1); + expect(debugSpy).toHaveBeenCalledWith("[PREFIX] some label", JSON.stringify(data)); + }); + + it("calls console.debug with [PREFIX] label and summary object when verbose is false and summary provided", () => { + const logger = new DebugLogger({ + enabled: true, + events: true, + lifecycle: true, + verbose: false, + }); + const data = { type: "TEST", value: 42, bigPayload: "lots of data" }; + const summary = { type: "TEST" }; + logger.event("PREFIX", "some label", data, summary); + expect(debugSpy).toHaveBeenCalledTimes(1); + expect(debugSpy).toHaveBeenCalledWith("[PREFIX] some label", summary); + }); + + it("calls console.debug with [PREFIX] label and raw data when verbose is false and no summary provided", () => { + const logger = new DebugLogger({ + enabled: true, + events: true, + lifecycle: true, + verbose: false, + }); + const data = { type: "TEST", value: 42 }; + logger.event("PREFIX", "some label", data); + expect(debugSpy).toHaveBeenCalledTimes(1); + expect(debugSpy).toHaveBeenCalledWith("[PREFIX] some label", data); + }); + + it("handles string data correctly in verbose mode (no double-stringify)", () => { + const logger = new DebugLogger({ + enabled: true, + events: true, + lifecycle: true, + verbose: true, + }); + const data = "just a string"; + logger.event("PREFIX", "some label", data); + expect(debugSpy).toHaveBeenCalledTimes(1); + // String data should be passed directly, not JSON.stringify'd + expect(debugSpy).toHaveBeenCalledWith("[PREFIX] some label", "just a string"); + }); +}); + +describe("DebugLogger.lifecycle()", () => { + let debugSpy: ReturnType; + + beforeEach(() => { + debugSpy = vi.spyOn(console, "debug").mockImplementation(() => {}); + }); + + afterEach(() => { + vi.restoreAllMocks(); + }); + + it("does NOT call console.debug when lifecycle is disabled", () => { + const logger = new DebugLogger({ + enabled: true, + events: true, + lifecycle: false, + verbose: false, + }); + logger.lifecycle("PREFIX", "some label", { key: "value" }); + expect(debugSpy).not.toHaveBeenCalled(); + }); + + it("calls console.debug with [PREFIX] label and data when data provided", () => { + const logger = new DebugLogger({ + enabled: true, + events: true, + lifecycle: true, + verbose: false, + }); + const data = { agentId: "agent-1", threadId: "thread-1" }; + logger.lifecycle("PREFIX", "some label", data); + expect(debugSpy).toHaveBeenCalledTimes(1); + expect(debugSpy).toHaveBeenCalledWith("[PREFIX] some label", data); + }); + + it("calls console.debug with [PREFIX] label only when no data provided", () => { + const logger = new DebugLogger({ + enabled: true, + events: true, + lifecycle: true, + verbose: false, + }); + logger.lifecycle("PREFIX", "some label"); + expect(debugSpy).toHaveBeenCalledTimes(1); + expect(debugSpy).toHaveBeenCalledWith("[PREFIX] some label"); + }); +}); + +describe("DebugLogger getters", () => { + it("enabled returns config.enabled", () => { + const logger = new DebugLogger({ + enabled: true, + events: false, + lifecycle: false, + verbose: false, + }); + expect(logger.enabled).toBe(true); + + const logger2 = new DebugLogger({ + enabled: false, + events: false, + lifecycle: false, + verbose: false, + }); + expect(logger2.enabled).toBe(false); + }); + + it("eventsEnabled returns config.events", () => { + const logger = new DebugLogger({ + enabled: true, + events: true, + lifecycle: false, + verbose: false, + }); + expect(logger.eventsEnabled).toBe(true); + + const logger2 = new DebugLogger({ + enabled: true, + events: false, + lifecycle: true, + verbose: false, + }); + expect(logger2.eventsEnabled).toBe(false); + }); + + it("lifecycleEnabled returns config.lifecycle", () => { + const logger = new DebugLogger({ + enabled: true, + events: false, + lifecycle: true, + verbose: false, + }); + expect(logger.lifecycleEnabled).toBe(true); + + const logger2 = new DebugLogger({ + enabled: true, + events: true, + lifecycle: false, + verbose: false, + }); + expect(logger2.lifecycleEnabled).toBe(false); + }); +}); diff --git a/sdks/typescript/packages/client/src/agent/__tests__/agent-debug.test.ts b/sdks/typescript/packages/client/src/agent/__tests__/agent-debug.test.ts new file mode 100644 index 0000000000..f4a7753f1f --- /dev/null +++ b/sdks/typescript/packages/client/src/agent/__tests__/agent-debug.test.ts @@ -0,0 +1,347 @@ +import { describe, it, expect, vi, beforeEach, afterEach } from "vitest"; +import { AbstractAgent } from "../agent"; +import { DebugLogger } from "@/debug-logger"; +import { + BaseEvent, + EventType, + RunAgentInput, + RunStartedEvent, + RunFinishedEvent, + RunErrorEvent, + TextMessageStartEvent, + TextMessageContentEvent, + TextMessageEndEvent, +} from "@ag-ui/core"; +import { Observable, of, Subject } from "rxjs"; + +// Mock uuid module +vi.mock("uuid", () => ({ + v4: vi.fn().mockReturnValue("mock-uuid"), +})); + +// Mock utils +vi.mock("@/utils", async () => { + const actual = await vi.importActual("@/utils"); + return { + ...actual, + structuredClone_: (obj: any) => { + if (obj === undefined) return undefined; + const jsonString = JSON.stringify(obj); + if (jsonString === undefined || jsonString === "undefined") return undefined; + return JSON.parse(jsonString); + }, + }; +}); + +class TestAgent extends AbstractAgent { + private eventsToEmit: BaseEvent[] = []; + + setEventsToEmit(events: BaseEvent[]) { + this.eventsToEmit = events; + } + + run(input: RunAgentInput): Observable { + return of(...this.eventsToEmit); + } +} + +class ErrorTestAgent extends AbstractAgent { + run(input: RunAgentInput): Observable { + return new Observable((subscriber) => { + subscriber.next({ + type: EventType.RUN_STARTED, + threadId: "thread-1", + runId: "run-1", + } as RunStartedEvent); + subscriber.next({ + type: EventType.RUN_ERROR, + message: "Something went wrong", + code: "test-error", + } as RunErrorEvent); + subscriber.complete(); + }); + } +} + +describe("Agent construction debug config", () => { + it("debug: undefined -> debugLogger is undefined", () => { + const agent = new TestAgent({ debug: undefined }); + expect(agent.debugLogger).toBeUndefined(); + }); + + it("debug: false -> debugLogger is undefined", () => { + const agent = new TestAgent({ debug: false }); + expect(agent.debugLogger).toBeUndefined(); + }); + + it("debug: true -> debugLogger is DebugLogger instance, all config true", () => { + const agent = new TestAgent({ debug: true }); + expect(agent.debugLogger).toBeInstanceOf(DebugLogger); + expect(agent.debug).toEqual({ + enabled: true, + events: true, + lifecycle: true, + verbose: true, + }); + }); + + it("debug: { events: true } -> debugLogger is DebugLogger instance with correct config", () => { + const agent = new TestAgent({ debug: { events: true } }); + expect(agent.debugLogger).toBeInstanceOf(DebugLogger); + expect(agent.debug).toEqual({ + enabled: true, + events: true, + lifecycle: true, + verbose: false, + }); + }); +}); + +describe("Agent run lifecycle logging", () => { + let debugSpy: ReturnType; + + beforeEach(() => { + debugSpy = vi.spyOn(console, "debug").mockImplementation(() => {}); + }); + + afterEach(() => { + vi.restoreAllMocks(); + }); + + it("with debug: true, logs [LIFECYCLE] Run started: with agentId and threadId", async () => { + const agent = new TestAgent({ + agentId: "test-agent", + threadId: "thread-1", + debug: true, + }); + agent.setEventsToEmit([ + { + type: EventType.RUN_STARTED, + threadId: "thread-1", + runId: "run-1", + } as RunStartedEvent, + { + type: EventType.RUN_FINISHED, + threadId: "thread-1", + runId: "run-1", + } as RunFinishedEvent, + ]); + + await agent.runAgent(); + + const startedCalls = debugSpy.mock.calls.filter( + (call) => typeof call[0] === "string" && call[0] === "[LIFECYCLE] Run started:", + ); + expect(startedCalls.length).toBe(1); + expect(startedCalls[0][1]).toMatchObject({ + agentId: "test-agent", + threadId: "thread-1", + }); + }); + + it("with debug: true, logs [LIFECYCLE] Run finished: with agentId and threadId", async () => { + const agent = new TestAgent({ + agentId: "test-agent", + threadId: "thread-1", + debug: true, + }); + agent.setEventsToEmit([ + { + type: EventType.RUN_STARTED, + threadId: "thread-1", + runId: "run-1", + } as RunStartedEvent, + { + type: EventType.RUN_FINISHED, + threadId: "thread-1", + runId: "run-1", + } as RunFinishedEvent, + ]); + + await agent.runAgent(); + + const finishedCalls = debugSpy.mock.calls.filter( + (call) => typeof call[0] === "string" && call[0] === "[LIFECYCLE] Run finished:", + ); + expect(finishedCalls.length).toBe(1); + expect(finishedCalls[0][1]).toMatchObject({ + agentId: "test-agent", + threadId: "thread-1", + }); + }); + + it("with debug: false, no lifecycle logs", async () => { + const agent = new TestAgent({ + agentId: "test-agent", + threadId: "thread-1", + debug: false, + }); + agent.setEventsToEmit([ + { + type: EventType.RUN_STARTED, + threadId: "thread-1", + runId: "run-1", + } as RunStartedEvent, + { + type: EventType.RUN_FINISHED, + threadId: "thread-1", + runId: "run-1", + } as RunFinishedEvent, + ]); + + await agent.runAgent(); + + const lifecycleCalls = debugSpy.mock.calls.filter( + (call) => typeof call[0] === "string" && call[0].startsWith("[LIFECYCLE]"), + ); + expect(lifecycleCalls.length).toBe(0); + }); + + it("with { lifecycle: false, events: true }, no lifecycle logs but event logs present", async () => { + const agent = new TestAgent({ + agentId: "test-agent", + threadId: "thread-1", + debug: { lifecycle: false, events: true }, + }); + agent.setEventsToEmit([ + { + type: EventType.RUN_STARTED, + threadId: "thread-1", + runId: "run-1", + } as RunStartedEvent, + { + type: EventType.RUN_FINISHED, + threadId: "thread-1", + runId: "run-1", + } as RunFinishedEvent, + ]); + + await agent.runAgent(); + + const lifecycleCalls = debugSpy.mock.calls.filter( + (call) => typeof call[0] === "string" && call[0].startsWith("[LIFECYCLE]"), + ); + expect(lifecycleCalls.length).toBe(0); + + // Should still have event-level logs from verify, apply, etc. + const eventCalls = debugSpy.mock.calls.filter( + (call) => + typeof call[0] === "string" && + (call[0].startsWith("[VERIFY]") || call[0].startsWith("[APPLY]")), + ); + expect(eventCalls.length).toBeGreaterThan(0); + }); +}); + +describe("Agent run error logging", () => { + let debugSpy: ReturnType; + + beforeEach(() => { + debugSpy = vi.spyOn(console, "debug").mockImplementation(() => {}); + // Suppress console.error from the error handler + vi.spyOn(console, "error").mockImplementation(() => {}); + }); + + afterEach(() => { + vi.restoreAllMocks(); + }); + + it("logs [LIFECYCLE] Run errored: with agentId and error message on error", async () => { + const agent = new TestAgent({ + agentId: "test-agent", + threadId: "thread-1", + debug: true, + }); + + // Make the agent emit an error via run() + const errorAgent = agent as any; + errorAgent.run = () => { + return new Observable((subscriber: any) => { + subscriber.error(new Error("Something went wrong")); + }); + }; + + try { + await agent.runAgent(); + } catch { + // Expected + } + + const errorCalls = debugSpy.mock.calls.filter( + (call) => typeof call[0] === "string" && call[0] === "[LIFECYCLE] Run errored:", + ); + expect(errorCalls.length).toBe(1); + expect(errorCalls[0][1]).toMatchObject({ + agentId: "test-agent", + error: "Something went wrong", + }); + }); +}); + +describe("Agent pipeline integration", () => { + let debugSpy: ReturnType; + + beforeEach(() => { + debugSpy = vi.spyOn(console, "debug").mockImplementation(() => {}); + }); + + afterEach(() => { + vi.restoreAllMocks(); + }); + + it("with debug: true, the full pipeline produces logs from ALL stages", async () => { + const agent = new TestAgent({ + agentId: "test-agent", + threadId: "thread-1", + debug: true, + }); + agent.setEventsToEmit([ + { + type: EventType.RUN_STARTED, + threadId: "thread-1", + runId: "run-1", + } as RunStartedEvent, + { + type: EventType.TEXT_MESSAGE_START, + messageId: "msg-1", + role: "assistant", + } as TextMessageStartEvent, + { + type: EventType.TEXT_MESSAGE_CONTENT, + messageId: "msg-1", + delta: "Hello", + } as TextMessageContentEvent, + { + type: EventType.TEXT_MESSAGE_END, + messageId: "msg-1", + } as TextMessageEndEvent, + { + type: EventType.RUN_FINISHED, + threadId: "thread-1", + runId: "run-1", + } as RunFinishedEvent, + ]); + + await agent.runAgent(); + + const allDebugCalls = debugSpy.mock.calls; + + // Check that we have LIFECYCLE logs + const lifecycleCalls = allDebugCalls.filter( + (call) => typeof call[0] === "string" && call[0].startsWith("[LIFECYCLE]"), + ); + expect(lifecycleCalls.length).toBeGreaterThan(0); + + // Check that we have VERIFY logs (each event passes through verify) + const verifyCalls = allDebugCalls.filter( + (call) => typeof call[0] === "string" && call[0].startsWith("[VERIFY]"), + ); + expect(verifyCalls.length).toBeGreaterThan(0); + + // Check that we have APPLY logs (each event passes through apply) + const applyCalls = allDebugCalls.filter( + (call) => typeof call[0] === "string" && call[0].startsWith("[APPLY]"), + ); + expect(applyCalls.length).toBeGreaterThan(0); + }); +}); diff --git a/sdks/typescript/packages/client/src/agent/__tests__/http.test.ts b/sdks/typescript/packages/client/src/agent/__tests__/http.test.ts index b8a454b1a3..3ff75c96b3 100644 --- a/sdks/typescript/packages/client/src/agent/__tests__/http.test.ts +++ b/sdks/typescript/packages/client/src/agent/__tests__/http.test.ts @@ -175,8 +175,9 @@ describe("HttpAgent", () => { // Execute the run function agent.run(input); - // Verify that transformHttpEventStream was called with the mock observable - expect(transformHttpEventStream).toHaveBeenCalledWith(mockObservable); + // Verify that transformHttpEventStream was called with the mock observable and debugLogger + // When debug is off (default), createDebugLogger returns undefined + expect(transformHttpEventStream).toHaveBeenCalledWith(mockObservable, undefined); }); it("should process HTTP response data end-to-end", async () => { diff --git a/sdks/typescript/packages/client/src/agent/agent.ts b/sdks/typescript/packages/client/src/agent/agent.ts index 8c32d899ed..80a7fc1358 100644 --- a/sdks/typescript/packages/client/src/agent/agent.ts +++ b/sdks/typescript/packages/client/src/agent/agent.ts @@ -9,7 +9,13 @@ import { AgentCapabilities, } from "@ag-ui/core"; -import { AgentConfig, RunAgentParameters } from "./types"; +import { + AgentConfig, + RunAgentParameters, + ResolvedAgentDebugConfig, + resolveAgentDebugConfig, +} from "./types"; +import { DebugLogger, createDebugLogger } from "@/debug-logger"; import { v4 as uuidv4 } from "uuid"; import { structuredClone_ } from "@/utils"; import { compareVersions } from "compare-versions"; @@ -44,7 +50,8 @@ export abstract class AbstractAgent { public threadId: string; public messages: Message[]; public state: State; - public debug: boolean = false; + public debug: ResolvedAgentDebugConfig; + private _debugLogger: DebugLogger | undefined; public subscribers: AgentSubscriber[] = []; public isRunning: boolean = false; private middlewares: Middleware[] = []; @@ -56,6 +63,20 @@ export abstract class AbstractAgent { return packageJson.version; } + get debugLogger(): DebugLogger | undefined { + return this._debugLogger; + } + + set debugLogger(value: DebugLogger | boolean | undefined) { + if (typeof value === "boolean") { + this._debugLogger = value + ? createDebugLogger(resolveAgentDebugConfig(true)) + : undefined; + } else { + this._debugLogger = value; + } + } + constructor({ agentId, description, @@ -69,7 +90,8 @@ export abstract class AbstractAgent { this.threadId = threadId ?? uuidv4(); this.messages = structuredClone_(initialMessages ?? []); this.state = structuredClone_(initialState ?? {}); - this.debug = debug ?? false; + this.debug = resolveAgentDebugConfig(debug); + this.debugLogger = createDebugLogger(this.debug); if (compareVersions(this.maxVersion, "0.0.39") <= 0) { this.middlewares.unshift(new BackwardCompatibility_0_0_39()); @@ -115,6 +137,12 @@ export abstract class AbstractAgent { this.isRunning = true; this.agentId = this.agentId ?? uuidv4(); const input = this.prepareRunAgentInput(parameters); + + this.debugLogger?.lifecycle("LIFECYCLE", "Run started:", { + agentId: this.agentId, + threadId: this.threadId, + }); + let result: any = undefined; const currentMessageIds = new Set(this.messages.map((message) => message.id)); @@ -160,17 +188,25 @@ export abstract class AbstractAgent { return chainedAgent.run(input); }, - transformChunks(this.debug), - verifyEvents(this.debug), + transformChunks(this.debugLogger), + verifyEvents(this.debugLogger), // Stop processing immediately when this run is detached (source$) => source$.pipe(takeUntil(this.activeRunDetach$!)), (source$) => this.apply(input, source$, subscribers), (source$) => this.processApplyEvents(input, source$, subscribers), catchError((error) => { + this.debugLogger?.lifecycle("LIFECYCLE", "Run errored:", { + agentId: this.agentId, + error: error instanceof Error ? error.message : String(error), + }); this.isRunning = false; return this.onError(input, error, subscribers); }), finalize(() => { + this.debugLogger?.lifecycle("LIFECYCLE", "Run finished:", { + agentId: this.agentId, + threadId: this.threadId, + }); this.isRunning = false; void this.onFinalize(input, subscribers); resolveActiveRunCompletion?.(); @@ -225,8 +261,8 @@ export abstract class AbstractAgent { const pipeline = pipe( () => defer(() => this.connect(input)), - transformChunks(this.debug), - verifyEvents(this.debug), + transformChunks(this.debugLogger), + verifyEvents(this.debugLogger), // Stop processing immediately when this run is detached (source$) => source$.pipe(takeUntil(this.activeRunDetach$!)), (source$) => this.apply(input, source$, subscribers), @@ -277,7 +313,7 @@ export abstract class AbstractAgent { events$: Observable, subscribers: AgentSubscriber[], ): Observable { - return defaultApplyEvents(input, events$, this, subscribers); + return defaultApplyEvents(input, events$, this, subscribers, this.debugLogger); } protected processApplyEvents( @@ -462,6 +498,7 @@ export abstract class AbstractAgent { cloned.messages = structuredClone_(this.messages); cloned.state = structuredClone_(this.state); cloned.debug = this.debug; + cloned.debugLogger = this.debugLogger; cloned.isRunning = this.isRunning; cloned.subscribers = [...this.subscribers]; cloned.middlewares = [...this.middlewares]; @@ -618,15 +655,13 @@ export abstract class AbstractAgent { })(); return runObservable.pipe( - transformChunks(this.debug), - verifyEvents(this.debug), + transformChunks(this.debugLogger), + verifyEvents(this.debugLogger), convertToLegacyEvents(this.threadId, input.runId, this.agentId), (events$: Observable) => { return events$.pipe( map((event) => { - if (this.debug) { - console.debug("[LEGACY]:", JSON.stringify(event)); - } + this.debugLogger?.event("LEGACY", "Event:", event, { type: event.type }); return event; }), ); diff --git a/sdks/typescript/packages/client/src/agent/http.ts b/sdks/typescript/packages/client/src/agent/http.ts index f9d9c30029..4238957b80 100644 --- a/sdks/typescript/packages/client/src/agent/http.ts +++ b/sdks/typescript/packages/client/src/agent/http.ts @@ -56,7 +56,7 @@ export class HttpAgent extends AbstractAgent { run(input: RunAgentInput): Observable { const httpEvents = runHttpRequest(this.url, this.requestInit(input)); - return transformHttpEventStream(httpEvents); + return transformHttpEventStream(httpEvents, this.debugLogger); } public clone(): HttpAgent { diff --git a/sdks/typescript/packages/client/src/agent/index.ts b/sdks/typescript/packages/client/src/agent/index.ts index 046bfa90bb..b47f424ca9 100644 --- a/sdks/typescript/packages/client/src/agent/index.ts +++ b/sdks/typescript/packages/client/src/agent/index.ts @@ -1,5 +1,13 @@ export { AbstractAgent } from "./agent"; export type { RunAgentResult } from "./agent"; export { HttpAgent } from "./http"; -export type { AgentConfig, HttpAgentConfig, RunAgentParameters } from "./types"; +export type { + AgentConfig, + HttpAgentConfig, + RunAgentParameters, + AgentDebugConfig, + ResolvedAgentDebugConfig, +} from "./types"; +export { resolveAgentDebugConfig } from "./types"; export type { AgentSubscriber, AgentStateMutation, AgentSubscriberParams } from "./subscriber"; +export { DebugLogger, createDebugLogger } from "../debug-logger"; diff --git a/sdks/typescript/packages/client/src/agent/types.ts b/sdks/typescript/packages/client/src/agent/types.ts index 65f9682815..d85a95500e 100644 --- a/sdks/typescript/packages/client/src/agent/types.ts +++ b/sdks/typescript/packages/client/src/agent/types.ts @@ -1,12 +1,42 @@ import { Message, RunAgentInput, State } from "@ag-ui/core"; +/** Normalized debug configuration for the AG-UI agent. */ +export interface ResolvedAgentDebugConfig { + enabled: boolean; + events: boolean; + lifecycle: boolean; + verbose: boolean; +} + +/** Debug input — boolean shorthand or granular config. */ +export type AgentDebugConfig = + | boolean + | { + events?: boolean; + lifecycle?: boolean; + verbose?: boolean; + }; + +/** Resolves an AgentDebugConfig into a normalized ResolvedAgentDebugConfig. */ +export function resolveAgentDebugConfig( + debug: AgentDebugConfig | undefined, +): ResolvedAgentDebugConfig { + if (!debug) return { enabled: false, events: false, lifecycle: false, verbose: false }; + if (debug === true) return { enabled: true, events: true, lifecycle: true, verbose: true }; + + const events = debug.events ?? true; + const lifecycle = debug.lifecycle ?? true; + const verbose = debug.verbose ?? false; + return { enabled: events || lifecycle, events, lifecycle, verbose }; +} + export interface AgentConfig { agentId?: string; description?: string; threadId?: string; initialMessages?: Message[]; initialState?: State; - debug?: boolean; + debug?: AgentDebugConfig; } export interface HttpAgentConfig extends AgentConfig { diff --git a/sdks/typescript/packages/client/src/apply/__tests__/apply-debug.test.ts b/sdks/typescript/packages/client/src/apply/__tests__/apply-debug.test.ts new file mode 100644 index 0000000000..6c588b188c --- /dev/null +++ b/sdks/typescript/packages/client/src/apply/__tests__/apply-debug.test.ts @@ -0,0 +1,184 @@ +import { describe, it, expect, vi, beforeEach, afterEach } from "vitest"; +import { Subject, firstValueFrom } from "rxjs"; +import { toArray } from "rxjs/operators"; +import { + BaseEvent, + EventType, + Message, + RunStartedEvent, + TextMessageStartEvent, + TextMessageContentEvent, + TextMessageEndEvent, + RunFinishedEvent, + RunAgentInput, +} from "@ag-ui/core"; +import { defaultApplyEvents } from "../default"; +import { AbstractAgent } from "@/agent"; +import { createDebugLogger, DebugLogger } from "@/debug-logger"; +import { AgentSubscriber } from "@/agent/subscriber"; + +const createAgent = (messages: Message[] = []) => + ({ + messages: messages.map((message) => ({ ...message })), + state: {}, + }) as unknown as AbstractAgent; + +const createInput = (): RunAgentInput => ({ + messages: [], + state: {}, + threadId: "test-thread", + runId: "test-run", + tools: [], + context: [], +}); + +describe("defaultApplyEvents debug logging", () => { + let debugSpy: ReturnType; + + beforeEach(() => { + debugSpy = vi.spyOn(console, "debug").mockImplementation(() => {}); + }); + + afterEach(() => { + vi.restoreAllMocks(); + }); + + it("no debug logs when logger is undefined", async () => { + const events$ = new Subject(); + const input = createInput(); + const agent = createAgent(); + const result$ = defaultApplyEvents(input, events$, agent, [], undefined); + const stateUpdatesPromise = firstValueFrom(result$.pipe(toArray())); + + events$.next({ type: EventType.RUN_STARTED } as RunStartedEvent); + events$.next({ + type: EventType.TEXT_MESSAGE_START, + messageId: "msg-1", + role: "assistant", + } as TextMessageStartEvent); + events$.next({ + type: EventType.TEXT_MESSAGE_END, + messageId: "msg-1", + } as TextMessageEndEvent); + events$.next({ + type: EventType.RUN_FINISHED, + } as RunFinishedEvent); + + await new Promise((resolve) => setTimeout(resolve, 10)); + events$.complete(); + await stateUpdatesPromise; + + expect(debugSpy).not.toHaveBeenCalled(); + }); + + it("event applied log: [APPLY] Event applied: with type and subscriber count (summary mode)", async () => { + const logger = createDebugLogger({ + enabled: true, + events: true, + lifecycle: true, + verbose: false, + })!; + + const events$ = new Subject(); + const input = createInput(); + const agent = createAgent(); + const subscribers: AgentSubscriber[] = [{}]; // One empty subscriber + const result$ = defaultApplyEvents(input, events$, agent, subscribers, logger); + const stateUpdatesPromise = firstValueFrom(result$.pipe(toArray())); + + events$.next({ type: EventType.RUN_STARTED } as RunStartedEvent); + events$.next({ + type: EventType.TEXT_MESSAGE_START, + messageId: "msg-1", + role: "assistant", + } as TextMessageStartEvent); + + await new Promise((resolve) => setTimeout(resolve, 10)); + events$.complete(); + await stateUpdatesPromise; + + const appliedCalls = debugSpy.mock.calls.filter( + (call) => typeof call[0] === "string" && call[0] === "[APPLY] Event applied:", + ); + + // Both events should be "applied" + expect(appliedCalls.length).toBe(2); + expect(appliedCalls[0][1]).toEqual({ + type: EventType.RUN_STARTED, + subscribers: 1, + }); + expect(appliedCalls[1][1]).toEqual({ + type: EventType.TEXT_MESSAGE_START, + subscribers: 1, + }); + }); + + it("event applied log with verbose: full JSON payload", async () => { + const logger = createDebugLogger({ + enabled: true, + events: true, + lifecycle: true, + verbose: true, + })!; + + const events$ = new Subject(); + const input = createInput(); + const agent = createAgent(); + const result$ = defaultApplyEvents(input, events$, agent, [], logger); + const stateUpdatesPromise = firstValueFrom(result$.pipe(toArray())); + + events$.next({ type: EventType.RUN_STARTED } as RunStartedEvent); + + await new Promise((resolve) => setTimeout(resolve, 10)); + events$.complete(); + await stateUpdatesPromise; + + const appliedCalls = debugSpy.mock.calls.filter( + (call) => typeof call[0] === "string" && call[0] === "[APPLY] Event applied:", + ); + + expect(appliedCalls.length).toBe(1); + // In verbose mode, should be JSON string + expect(typeof appliedCalls[0][1]).toBe("string"); + const parsed = JSON.parse(appliedCalls[0][1]); + expect(parsed.type).toBe(EventType.RUN_STARTED); + }); + + it("event dropped log: [APPLY] Event dropped: with type and reason when subscriber calls stopPropagation", async () => { + const logger = createDebugLogger({ + enabled: true, + events: true, + lifecycle: true, + verbose: false, + })!; + + const events$ = new Subject(); + const input = createInput(); + const agent = createAgent(); + const subscribers: AgentSubscriber[] = [ + { + onEvent: () => { + return { stopPropagation: true }; + }, + }, + ]; + const result$ = defaultApplyEvents(input, events$, agent, subscribers, logger); + const stateUpdatesPromise = firstValueFrom(result$.pipe(toArray())); + + events$.next({ type: EventType.RUN_STARTED } as RunStartedEvent); + + await new Promise((resolve) => setTimeout(resolve, 10)); + events$.complete(); + await stateUpdatesPromise; + + const droppedCalls = debugSpy.mock.calls.filter( + (call) => typeof call[0] === "string" && call[0] === "[APPLY] Event dropped:", + ); + + expect(droppedCalls.length).toBe(1); + expect(droppedCalls[0][1]).toEqual({ + type: EventType.RUN_STARTED, + reason: "stopPropagation by subscriber", + }); + }); +}); diff --git a/sdks/typescript/packages/client/src/apply/default.ts b/sdks/typescript/packages/client/src/apply/default.ts index 291e7658ee..c668e845f4 100644 --- a/sdks/typescript/packages/client/src/apply/default.ts +++ b/sdks/typescript/packages/client/src/apply/default.ts @@ -48,13 +48,16 @@ import type { Observable } from "rxjs"; import { concatMap, defaultIfEmpty, mergeAll, mergeMap } from "rxjs/operators"; import untruncateJson from "untruncate-json"; import { structuredClone_ } from "../utils"; +import type { DebugLogger } from "@/debug-logger"; export const defaultApplyEvents = ( input: RunAgentInput, events$: Observable, agent: AbstractAgent, subscribers: AgentSubscriber[], + debugLogger?: DebugLogger | false | null, ): Observable => { + const log = debugLogger || undefined; let messages = structuredClone_(agent.messages); let state = structuredClone_(input.state); let currentMutation: AgentStateMutation = {}; @@ -90,6 +93,18 @@ export const defaultApplyEvents = ( ); applyMutation(mutation); + if (mutation.stopPropagation === true) { + log?.event("APPLY", "Event dropped:", event, { + type: event.type, + reason: "stopPropagation by subscriber", + }); + } else { + log?.event("APPLY", "Event applied:", event, { + type: event.type, + subscribers: subscribers.length, + }); + } + if (mutation.stopPropagation === true) { return emitUpdates(); } diff --git a/sdks/typescript/packages/client/src/chunks/__tests__/transform-debug.test.ts b/sdks/typescript/packages/client/src/chunks/__tests__/transform-debug.test.ts new file mode 100644 index 0000000000..09d5e8e507 --- /dev/null +++ b/sdks/typescript/packages/client/src/chunks/__tests__/transform-debug.test.ts @@ -0,0 +1,281 @@ +import { describe, it, expect, vi, beforeEach, afterEach } from "vitest"; +import { of, concat, firstValueFrom } from "rxjs"; +import { toArray } from "rxjs/operators"; +import { transformChunks } from "../transform"; +import { createDebugLogger, DebugLogger } from "@/debug-logger"; +import { + BaseEvent, + EventType, + TextMessageChunkEvent, + ToolCallChunkEvent, + ReasoningMessageChunkEvent, + RunFinishedEvent, +} from "@ag-ui/core"; + +describe("transformChunks debug logging", () => { + let debugSpy: ReturnType; + + beforeEach(() => { + debugSpy = vi.spyOn(console, "debug").mockImplementation(() => {}); + }); + + afterEach(() => { + vi.restoreAllMocks(); + }); + + const closeEvent: RunFinishedEvent = { + type: EventType.RUN_FINISHED, + threadId: "thread-1", + runId: "run-1", + }; + + describe("when debugLogger is falsy", () => { + it("no console.debug calls when debugLogger is undefined", async () => { + const chunk: TextMessageChunkEvent = { + type: EventType.TEXT_MESSAGE_CHUNK, + messageId: "msg-1", + delta: "Hello", + }; + const events$ = concat(of(chunk as BaseEvent), of(closeEvent as BaseEvent)); + await firstValueFrom(transformChunks(undefined)(events$).pipe(toArray())); + expect(debugSpy).not.toHaveBeenCalled(); + }); + + it("no console.debug calls when debugLogger is false", async () => { + const chunk: TextMessageChunkEvent = { + type: EventType.TEXT_MESSAGE_CHUNK, + messageId: "msg-1", + delta: "Hello", + }; + const events$ = concat(of(chunk as BaseEvent), of(closeEvent as BaseEvent)); + await firstValueFrom(transformChunks(false)(events$).pipe(toArray())); + expect(debugSpy).not.toHaveBeenCalled(); + }); + + it("no console.debug calls when debugLogger is null", async () => { + const chunk: TextMessageChunkEvent = { + type: EventType.TEXT_MESSAGE_CHUNK, + messageId: "msg-1", + delta: "Hello", + }; + const events$ = concat(of(chunk as BaseEvent), of(closeEvent as BaseEvent)); + await firstValueFrom(transformChunks(null)(events$).pipe(toArray())); + expect(debugSpy).not.toHaveBeenCalled(); + }); + }); + + describe("when debug events enabled with verbose", () => { + let logger: DebugLogger; + + beforeEach(() => { + logger = createDebugLogger({ + enabled: true, + events: true, + lifecycle: true, + verbose: true, + })!; + }); + + it("TEXT_MESSAGE_CHUNK produces debug logs for TEXT_MESSAGE_START, TEXT_MESSAGE_CONTENT, TEXT_MESSAGE_END with full JSON payloads", async () => { + const chunk: TextMessageChunkEvent = { + type: EventType.TEXT_MESSAGE_CHUNK, + messageId: "msg-1", + delta: "Hello", + }; + const events$ = concat(of(chunk as BaseEvent), of(closeEvent as BaseEvent)); + await firstValueFrom(transformChunks(logger)(events$).pipe(toArray())); + + // Should have logs for: TEXT_MESSAGE_START, TEXT_MESSAGE_CONTENT, TEXT_MESSAGE_END + const transformCalls = debugSpy.mock.calls.filter( + (call) => typeof call[0] === "string" && call[0].startsWith("[TRANSFORM]"), + ); + expect(transformCalls.length).toBe(3); + + expect(transformCalls[0][0]).toBe("[TRANSFORM] TEXT_MESSAGE_START"); + expect(typeof transformCalls[0][1]).toBe("string"); // JSON.stringify in verbose mode + expect(JSON.parse(transformCalls[0][1])).toMatchObject({ + type: EventType.TEXT_MESSAGE_START, + messageId: "msg-1", + }); + + expect(transformCalls[1][0]).toBe("[TRANSFORM] TEXT_MESSAGE_CONTENT"); + expect(typeof transformCalls[1][1]).toBe("string"); + expect(JSON.parse(transformCalls[1][1])).toMatchObject({ + type: EventType.TEXT_MESSAGE_CONTENT, + messageId: "msg-1", + }); + + expect(transformCalls[2][0]).toBe("[TRANSFORM] TEXT_MESSAGE_END"); + expect(typeof transformCalls[2][1]).toBe("string"); + expect(JSON.parse(transformCalls[2][1])).toMatchObject({ + type: EventType.TEXT_MESSAGE_END, + messageId: "msg-1", + }); + }); + + it("TOOL_CALL_CHUNK produces debug logs for TOOL_CALL_START, TOOL_CALL_ARGS, TOOL_CALL_END with full payloads", async () => { + const chunk: ToolCallChunkEvent = { + type: EventType.TOOL_CALL_CHUNK, + toolCallId: "tc-1", + toolCallName: "myTool", + delta: '{"key":"value"}', + }; + const events$ = concat(of(chunk as BaseEvent), of(closeEvent as BaseEvent)); + await firstValueFrom(transformChunks(logger)(events$).pipe(toArray())); + + const transformCalls = debugSpy.mock.calls.filter( + (call) => typeof call[0] === "string" && call[0].startsWith("[TRANSFORM]"), + ); + expect(transformCalls.length).toBe(3); + + expect(transformCalls[0][0]).toBe("[TRANSFORM] TOOL_CALL_START"); + expect(JSON.parse(transformCalls[0][1])).toMatchObject({ + type: EventType.TOOL_CALL_START, + toolCallId: "tc-1", + toolCallName: "myTool", + }); + + expect(transformCalls[1][0]).toBe("[TRANSFORM] TOOL_CALL_ARGS"); + expect(JSON.parse(transformCalls[1][1])).toMatchObject({ + type: EventType.TOOL_CALL_ARGS, + toolCallId: "tc-1", + }); + + expect(transformCalls[2][0]).toBe("[TRANSFORM] TOOL_CALL_END"); + expect(JSON.parse(transformCalls[2][1])).toMatchObject({ + type: EventType.TOOL_CALL_END, + toolCallId: "tc-1", + }); + }); + + it("REASONING_MESSAGE_CHUNK produces corresponding debug logs", async () => { + const chunk: ReasoningMessageChunkEvent = { + type: EventType.REASONING_MESSAGE_CHUNK, + messageId: "rmsg-1", + delta: "thinking...", + }; + const events$ = concat(of(chunk as BaseEvent), of(closeEvent as BaseEvent)); + await firstValueFrom(transformChunks(logger)(events$).pipe(toArray())); + + const transformCalls = debugSpy.mock.calls.filter( + (call) => typeof call[0] === "string" && call[0].startsWith("[TRANSFORM]"), + ); + expect(transformCalls.length).toBe(3); + + expect(transformCalls[0][0]).toBe("[TRANSFORM] REASONING_MESSAGE_START"); + expect(transformCalls[1][0]).toBe("[TRANSFORM] REASONING_MESSAGE_CONTENT"); + expect(transformCalls[2][0]).toBe("[TRANSFORM] REASONING_MESSAGE_END"); + }); + }); + + describe("when debug events enabled without verbose (summary mode)", () => { + let logger: DebugLogger; + + beforeEach(() => { + logger = createDebugLogger({ + enabled: true, + events: true, + lifecycle: true, + verbose: false, + })!; + }); + + it("TEXT_MESSAGE_CHUNK logs include summary with messageId", async () => { + const chunk: TextMessageChunkEvent = { + type: EventType.TEXT_MESSAGE_CHUNK, + messageId: "msg-1", + delta: "Hello", + }; + const events$ = concat(of(chunk as BaseEvent), of(closeEvent as BaseEvent)); + await firstValueFrom(transformChunks(logger)(events$).pipe(toArray())); + + const transformCalls = debugSpy.mock.calls.filter( + (call) => typeof call[0] === "string" && call[0].startsWith("[TRANSFORM]"), + ); + + // In summary mode, the second argument should be the summary object, not a JSON string + expect(transformCalls[0][0]).toBe("[TRANSFORM] TEXT_MESSAGE_START"); + expect(transformCalls[0][1]).toEqual({ messageId: "msg-1" }); + + expect(transformCalls[1][0]).toBe("[TRANSFORM] TEXT_MESSAGE_CONTENT"); + expect(transformCalls[1][1]).toEqual({ messageId: "msg-1" }); + + expect(transformCalls[2][0]).toBe("[TRANSFORM] TEXT_MESSAGE_END"); + expect(transformCalls[2][1]).toEqual({ messageId: "msg-1" }); + }); + + it("TOOL_CALL_CHUNK logs include summary with toolCallId/toolCallName", async () => { + const chunk: ToolCallChunkEvent = { + type: EventType.TOOL_CALL_CHUNK, + toolCallId: "tc-1", + toolCallName: "myTool", + delta: '{"key":"value"}', + }; + const events$ = concat(of(chunk as BaseEvent), of(closeEvent as BaseEvent)); + await firstValueFrom(transformChunks(logger)(events$).pipe(toArray())); + + const transformCalls = debugSpy.mock.calls.filter( + (call) => typeof call[0] === "string" && call[0].startsWith("[TRANSFORM]"), + ); + + expect(transformCalls[0][0]).toBe("[TRANSFORM] TOOL_CALL_START"); + expect(transformCalls[0][1]).toEqual({ + toolCallId: "tc-1", + toolCallName: "myTool", + }); + + expect(transformCalls[1][0]).toBe("[TRANSFORM] TOOL_CALL_ARGS"); + expect(transformCalls[1][1]).toEqual({ toolCallId: "tc-1" }); + + expect(transformCalls[2][0]).toBe("[TRANSFORM] TOOL_CALL_END"); + expect(transformCalls[2][1]).toEqual({ toolCallId: "tc-1" }); + }); + + it("REASONING_MESSAGE_CHUNK logs include summary with messageId", async () => { + const chunk: ReasoningMessageChunkEvent = { + type: EventType.REASONING_MESSAGE_CHUNK, + messageId: "rmsg-1", + delta: "thinking...", + }; + const events$ = concat(of(chunk as BaseEvent), of(closeEvent as BaseEvent)); + await firstValueFrom(transformChunks(logger)(events$).pipe(toArray())); + + const transformCalls = debugSpy.mock.calls.filter( + (call) => typeof call[0] === "string" && call[0].startsWith("[TRANSFORM]"), + ); + + expect(transformCalls[0][0]).toBe("[TRANSFORM] REASONING_MESSAGE_START"); + expect(transformCalls[0][1]).toEqual({ messageId: "rmsg-1" }); + + expect(transformCalls[1][0]).toBe("[TRANSFORM] REASONING_MESSAGE_CONTENT"); + expect(transformCalls[1][1]).toEqual({ messageId: "rmsg-1" }); + + expect(transformCalls[2][0]).toBe("[TRANSFORM] REASONING_MESSAGE_END"); + expect(transformCalls[2][1]).toEqual({ messageId: "rmsg-1" }); + }); + }); + + describe("prefix format", () => { + it("uses [TRANSFORM] prefix", async () => { + const logger = createDebugLogger({ + enabled: true, + events: true, + lifecycle: true, + verbose: false, + })!; + + const chunk: TextMessageChunkEvent = { + type: EventType.TEXT_MESSAGE_CHUNK, + messageId: "msg-1", + delta: "Hello", + }; + const events$ = concat(of(chunk as BaseEvent), of(closeEvent as BaseEvent)); + await firstValueFrom(transformChunks(logger)(events$).pipe(toArray())); + + const allCalls = debugSpy.mock.calls; + for (const call of allCalls) { + expect(call[0]).toMatch(/^\[TRANSFORM\]/); + } + }); + }); +}); diff --git a/sdks/typescript/packages/client/src/chunks/transform.ts b/sdks/typescript/packages/client/src/chunks/transform.ts index 20f9144de3..8a6c73b51d 100644 --- a/sdks/typescript/packages/client/src/chunks/transform.ts +++ b/sdks/typescript/packages/client/src/chunks/transform.ts @@ -15,6 +15,7 @@ import { ReasoningMessageStartEvent, } from "@ag-ui/core"; import { EventType } from "@ag-ui/core"; +import { DebugLogger } from "@/debug-logger"; interface TextMessageFields { messageId: string; @@ -32,8 +33,9 @@ interface ReasoningMessageFields { } export const transformChunks = - (debug: boolean) => + (debugLogger?: DebugLogger | false | null) => (events$: Observable): Observable => { + const log = debugLogger || undefined; let textMessageFields: TextMessageFields | undefined; let toolCallFields: ToolCallFields | undefined; let reasoningMessageFields: ReasoningMessageFields | undefined; @@ -50,9 +52,9 @@ export const transformChunks = mode = undefined; textMessageFields = undefined; - if (debug) { - console.debug("[TRANSFORM]: TEXT_MESSAGE_END", JSON.stringify(event)); - } + log?.event("TRANSFORM", "TEXT_MESSAGE_END", event, { + messageId: event.messageId, + }); return event; }; @@ -68,9 +70,9 @@ export const transformChunks = mode = undefined; toolCallFields = undefined; - if (debug) { - console.debug("[TRANSFORM]: TOOL_CALL_END", JSON.stringify(event)); - } + log?.event("TRANSFORM", "TOOL_CALL_END", event, { + toolCallId: event.toolCallId, + }); return event; }; @@ -86,9 +88,9 @@ export const transformChunks = mode = undefined; reasoningMessageFields = undefined; - if (debug) { - console.debug("[TRANSFORM]: REASONING_MESSAGE_END", JSON.stringify(event)); - } + log?.event("TRANSFORM", "REASONING_MESSAGE_END", event, { + messageId: event.messageId, + }); return event; }; @@ -176,12 +178,9 @@ export const transformChunks = textMessageResult.push(textMessageStartEvent); - if (debug) { - console.debug( - "[TRANSFORM]: TEXT_MESSAGE_START", - JSON.stringify(textMessageStartEvent), - ); - } + log?.event("TRANSFORM", "TEXT_MESSAGE_START", textMessageStartEvent, { + messageId: messageChunkEvent.messageId, + }); } if (messageChunkEvent.delta !== undefined) { @@ -193,12 +192,9 @@ export const transformChunks = textMessageResult.push(textMessageContentEvent); - if (debug) { - console.debug( - "[TRANSFORM]: TEXT_MESSAGE_CONTENT", - JSON.stringify(textMessageContentEvent), - ); - } + log?.event("TRANSFORM", "TEXT_MESSAGE_CONTENT", textMessageContentEvent, { + messageId: textMessageFields!.messageId, + }); } return textMessageResult; @@ -239,9 +235,10 @@ export const transformChunks = toolMessageResult.push(toolCallStartEvent); - if (debug) { - console.debug("[TRANSFORM]: TOOL_CALL_START", JSON.stringify(toolCallStartEvent)); - } + log?.event("TRANSFORM", "TOOL_CALL_START", toolCallStartEvent, { + toolCallId: toolCallChunkEvent.toolCallId, + toolCallName: toolCallChunkEvent.toolCallName, + }); } if (toolCallChunkEvent.delta !== undefined) { @@ -253,9 +250,9 @@ export const transformChunks = toolMessageResult.push(toolCallArgsEvent); - if (debug) { - console.debug("[TRANSFORM]: TOOL_CALL_ARGS", JSON.stringify(toolCallArgsEvent)); - } + log?.event("TRANSFORM", "TOOL_CALL_ARGS", toolCallArgsEvent, { + toolCallId: toolCallFields!.toolCallId, + }); } return toolMessageResult; @@ -290,12 +287,9 @@ export const transformChunks = } as ReasoningMessageStartEvent; reasoningMessageResult.push(reasoningMessageStartEvent); - if (debug) { - console.debug( - "[TRANSFORM]: REASONING_MESSAGE_START", - JSON.stringify(reasoningMessageStartEvent), - ); - } + log?.event("TRANSFORM", "REASONING_MESSAGE_START", reasoningMessageStartEvent, { + messageId: reasoningChunkEvent.messageId, + }); } if (reasoningChunkEvent.delta !== undefined) { @@ -307,12 +301,9 @@ export const transformChunks = reasoningMessageResult.push(reasoningMessageContentEvent); - if (debug) { - console.debug( - "[TRANSFORM]: REASONING_MESSAGE_CONTENT", - JSON.stringify(reasoningMessageContentEvent), - ); - } + log?.event("TRANSFORM", "REASONING_MESSAGE_CONTENT", reasoningMessageContentEvent, { + messageId: reasoningMessageFields!.messageId, + }); } return reasoningMessageResult; diff --git a/sdks/typescript/packages/client/src/debug-logger.ts b/sdks/typescript/packages/client/src/debug-logger.ts new file mode 100644 index 0000000000..cacaca8101 --- /dev/null +++ b/sdks/typescript/packages/client/src/debug-logger.ts @@ -0,0 +1,59 @@ +import { ResolvedAgentDebugConfig } from "@/agent/types"; + +/** + * Centralized debug logger for the AG-UI event pipeline. + * Handles verbose vs summary output based on config. + */ +export class DebugLogger { + constructor(private config: ResolvedAgentDebugConfig) {} + + /** + * Log an event-level debug message. + * Only logs when `config.events` is enabled. + * In verbose mode, logs the full data; otherwise logs the summary. + */ + event(prefix: string, label: string, data: unknown, summary?: Record): void { + if (!this.config.events) return; + if (this.config.verbose) { + console.debug(`[${prefix}] ${label}`, typeof data === "string" ? data : JSON.stringify(data)); + } else { + console.debug(`[${prefix}] ${label}`, summary ?? data); + } + } + + /** + * Log a lifecycle-level debug message. + * Only logs when `config.lifecycle` is enabled. + */ + lifecycle(prefix: string, label: string, data?: Record): void { + if (!this.config.lifecycle) return; + if (data) { + console.debug(`[${prefix}] ${label}`, data); + } else { + console.debug(`[${prefix}] ${label}`); + } + } + + /** Whether event-level logging is enabled. */ + get eventsEnabled(): boolean { + return this.config.events; + } + + /** Whether lifecycle-level logging is enabled. */ + get lifecycleEnabled(): boolean { + return this.config.lifecycle; + } + + /** Whether any logging is enabled. */ + get enabled(): boolean { + return this.config.enabled; + } +} + +/** + * Creates a DebugLogger if debug is enabled, otherwise returns undefined. + * This allows consumers to pass it around cheaply when debug is off. + */ +export function createDebugLogger(config: ResolvedAgentDebugConfig): DebugLogger | undefined { + return config.enabled ? new DebugLogger(config) : undefined; +} diff --git a/sdks/typescript/packages/client/src/transform/__tests__/debug.test.ts b/sdks/typescript/packages/client/src/transform/__tests__/debug.test.ts new file mode 100644 index 0000000000..0a5aa75562 --- /dev/null +++ b/sdks/typescript/packages/client/src/transform/__tests__/debug.test.ts @@ -0,0 +1,254 @@ +import { describe, it, expect, vi, beforeEach, afterEach } from "vitest"; +import { Subject, firstValueFrom } from "rxjs"; +import { take, toArray } from "rxjs/operators"; +import { parseSSEStream } from "../sse"; +import { transformHttpEventStream } from "../http"; +import { createDebugLogger, DebugLogger } from "@/debug-logger"; +import { HttpEvent, HttpEventType } from "../../run/http-request"; +import { EventType } from "@ag-ui/core"; + +describe("parseSSEStream debug logging", () => { + let debugSpy: ReturnType; + + beforeEach(() => { + debugSpy = vi.spyOn(console, "debug").mockImplementation(() => {}); + }); + + afterEach(() => { + vi.restoreAllMocks(); + }); + + const createSSEData = (json: object): HttpEvent => ({ + type: HttpEventType.DATA, + data: new TextEncoder().encode(`data: ${JSON.stringify(json)}\n\n`), + }); + + it("no debug logs when logger is undefined", async () => { + const source$ = new Subject(); + const event$ = parseSSEStream(source$, undefined); + const resultPromise = firstValueFrom(event$.pipe(take(1))); + + source$.next( + createSSEData({ + type: "TEXT_MESSAGE_START", + messageId: "1", + role: "assistant", + }), + ); + + await resultPromise; + expect(debugSpy).not.toHaveBeenCalled(); + }); + + it("with events+verbose: logs full JSON of each parsed SSE event with [SSE] prefix", async () => { + const logger = createDebugLogger({ + enabled: true, + events: true, + lifecycle: true, + verbose: true, + })!; + + const source$ = new Subject(); + const event$ = parseSSEStream(source$, logger); + const resultPromise = firstValueFrom(event$.pipe(take(1))); + + const eventData = { + type: "TEXT_MESSAGE_START", + messageId: "1", + role: "assistant", + }; + source$.next(createSSEData(eventData)); + + await resultPromise; + + const sseCalls = debugSpy.mock.calls.filter( + (call) => typeof call[0] === "string" && call[0].startsWith("[SSE]"), + ); + expect(sseCalls.length).toBe(1); + expect(sseCalls[0][0]).toBe("[SSE] Event received:"); + // In verbose mode, should be JSON string + expect(typeof sseCalls[0][1]).toBe("string"); + const parsed = JSON.parse(sseCalls[0][1]); + expect(parsed).toMatchObject(eventData); + }); + + it("with events only (no verbose): logs { type } summary", async () => { + const logger = createDebugLogger({ + enabled: true, + events: true, + lifecycle: true, + verbose: false, + })!; + + const source$ = new Subject(); + const event$ = parseSSEStream(source$, logger); + const resultPromise = firstValueFrom(event$.pipe(take(1))); + + const eventData = { + type: "TEXT_MESSAGE_START", + messageId: "1", + role: "assistant", + }; + source$.next(createSSEData(eventData)); + + await resultPromise; + + const sseCalls = debugSpy.mock.calls.filter( + (call) => typeof call[0] === "string" && call[0].startsWith("[SSE]"), + ); + expect(sseCalls.length).toBe(1); + expect(sseCalls[0][0]).toBe("[SSE] Event received:"); + // In summary mode, should be the summary object + expect(sseCalls[0][1]).toEqual({ type: "TEXT_MESSAGE_START" }); + }); +}); + +describe("transformHttpEventStream debug logging", () => { + let debugSpy: ReturnType; + + beforeEach(() => { + debugSpy = vi.spyOn(console, "debug").mockImplementation(() => {}); + }); + + afterEach(() => { + vi.restoreAllMocks(); + }); + + const createHeaders = (contentType: string = "text/event-stream"): HttpEvent => { + const headers = new Headers(); + headers.append("Content-Type", contentType); + return { + type: HttpEventType.HEADERS, + status: 200, + headers, + }; + }; + + const createSSEData = (json: object): HttpEvent => ({ + type: HttpEventType.DATA, + data: new TextEncoder().encode(`data: ${JSON.stringify(json)}\n\n`), + }); + + it("no debug logs when logger is undefined", async () => { + const source$ = new Subject(); + const event$ = transformHttpEventStream(source$, undefined); + const resultPromise = firstValueFrom(event$.pipe(take(1))); + + source$.next(createHeaders()); + source$.next( + createSSEData({ + type: EventType.TEXT_MESSAGE_START, + messageId: "1", + role: "assistant", + }), + ); + + await resultPromise; + expect(debugSpy).not.toHaveBeenCalled(); + }); + + it("lifecycle log: [HTTP] Stream format detected: with contentType and parser type", async () => { + const logger = createDebugLogger({ + enabled: true, + events: true, + lifecycle: true, + verbose: false, + })!; + + const source$ = new Subject(); + const event$ = transformHttpEventStream(source$, logger); + const resultPromise = firstValueFrom(event$.pipe(take(1))); + + source$.next(createHeaders("text/event-stream")); + source$.next( + createSSEData({ + type: EventType.TEXT_MESSAGE_START, + messageId: "1", + role: "assistant", + }), + ); + + await resultPromise; + + const lifecycleCalls = debugSpy.mock.calls.filter( + (call) => typeof call[0] === "string" && call[0] === "[HTTP] Stream format detected:", + ); + expect(lifecycleCalls.length).toBe(1); + expect(lifecycleCalls[0][1]).toEqual({ + contentType: "text/event-stream", + parser: "sse", + }); + }); + + it("event validation log: [HTTP] Event validated: with type and valid:true on success", async () => { + const logger = createDebugLogger({ + enabled: true, + events: true, + lifecycle: true, + verbose: false, + })!; + + const source$ = new Subject(); + const event$ = transformHttpEventStream(source$, logger); + const resultPromise = firstValueFrom(event$.pipe(take(1))); + + source$.next(createHeaders()); + source$.next( + createSSEData({ + type: EventType.TEXT_MESSAGE_START, + messageId: "1", + role: "assistant", + }), + ); + + await resultPromise; + + const validatedCalls = debugSpy.mock.calls.filter( + (call) => typeof call[0] === "string" && call[0] === "[HTTP] Event validated:", + ); + expect(validatedCalls.length).toBe(1); + expect(validatedCalls[0][1]).toEqual({ + type: EventType.TEXT_MESSAGE_START, + valid: true, + }); + }); + + it("event invalid log: [HTTP] Event invalid: on schema parse failure", async () => { + expect.assertions(1); + + const logger = createDebugLogger({ + enabled: true, + events: true, + lifecycle: true, + verbose: false, + })!; + + const source$ = new Subject(); + const event$ = transformHttpEventStream(source$, logger); + + // Subscribe to catch the error + event$.subscribe({ + error: () => { + // expected + }, + }); + + source$.next(createHeaders()); + // Send an event with an invalid type to trigger schema parse failure + source$.next( + createSSEData({ + type: "COMPLETELY_INVALID_EVENT_TYPE_THAT_DOES_NOT_EXIST", + data: "bad", + }), + ); + + // Wait for processing + await new Promise((resolve) => setTimeout(resolve, 50)); + + const invalidCalls = debugSpy.mock.calls.filter( + (call) => typeof call[0] === "string" && call[0] === "[HTTP] Event invalid:", + ); + + expect(invalidCalls.length).toBe(1); + }); +}); diff --git a/sdks/typescript/packages/client/src/transform/http.ts b/sdks/typescript/packages/client/src/transform/http.ts index 1dce39327c..567c99ca3e 100644 --- a/sdks/typescript/packages/client/src/transform/http.ts +++ b/sdks/typescript/packages/client/src/transform/http.ts @@ -5,11 +5,16 @@ import { parseSSEStream } from "./sse"; import { parseProtoStream } from "./proto"; import * as proto from "@ag-ui/proto"; import { EventType } from "@ag-ui/core"; +import { DebugLogger } from "@/debug-logger"; /** * Transforms HTTP events into BaseEvents using the appropriate format parser based on content type. */ -export const transformHttpEventStream = (source$: Observable): Observable => { +export const transformHttpEventStream = ( + source$: Observable, + debugLogger?: DebugLogger | false | null, +): Observable => { + const log = debugLogger || undefined; const eventSubject = new Subject(); // Use ReplaySubject to buffer events until we decide on the parser @@ -29,6 +34,11 @@ export const transformHttpEventStream = (source$: Observable): Observ parserInitialized = true; const contentType = event.headers.get("content-type"); + log?.lifecycle("HTTP", "Stream format detected:", { + contentType, + parser: contentType === proto.AGUI_MEDIA_TYPE ? "protobuf" : "sse", + }); + // Choose parser based on content type if (contentType === proto.AGUI_MEDIA_TYPE) { // Use protocol buffer parser @@ -39,12 +49,17 @@ export const transformHttpEventStream = (source$: Observable): Observ }); } else { // Use SSE JSON parser for all other cases - parseSSEStream(bufferSubject).subscribe({ + parseSSEStream(bufferSubject, log).subscribe({ next: (json) => { try { const parsedEvent = EventSchemas.parse(json); + log?.event("HTTP", "Event validated:", parsedEvent, { + type: parsedEvent.type, + valid: true, + }); eventSubject.next(parsedEvent as BaseEvent); } catch (err) { + log?.event("HTTP", "Event invalid:", { json, error: String(err) }); eventSubject.error(err); } }, @@ -59,7 +74,7 @@ export const transformHttpEventStream = (source$: Observable): Observ eventSubject.complete(); return; } - return eventSubject.error(err) + return eventSubject.error(err); }, complete: () => eventSubject.complete(), }); diff --git a/sdks/typescript/packages/client/src/transform/sse.ts b/sdks/typescript/packages/client/src/transform/sse.ts index a5e3550215..8575fd04a8 100644 --- a/sdks/typescript/packages/client/src/transform/sse.ts +++ b/sdks/typescript/packages/client/src/transform/sse.ts @@ -1,5 +1,6 @@ import { Observable, Subject } from "rxjs"; import { HttpEvent, HttpEventType } from "../run/http-request"; +import { DebugLogger } from "@/debug-logger"; /** * Parses a stream of HTTP events into a stream of JSON objects using Server-Sent Events (SSE) format. @@ -9,7 +10,11 @@ import { HttpEvent, HttpEventType } from "../run/http-request"; * - Multi-line data events are supported and joined * - Non-data fields (event, id, retry) are ignored */ -export const parseSSEStream = (source$: Observable): Observable => { +export const parseSSEStream = ( + source$: Observable, + debugLogger?: DebugLogger | false | null, +): Observable => { + const log = debugLogger || undefined; const jsonSubject = new Subject(); // Create TextDecoder with stream option set to true to handle split UTF-8 characters const decoder = new TextDecoder("utf-8", { fatal: false }); @@ -52,10 +57,10 @@ export const parseSSEStream = (source$: Observable): Observable /** * Helper function to process an SSE event. * Extracts and joins data lines, then parses the result as JSON. - * + * * Follows the SSE spec by processing lines starting with 'data:', * ignoring a single space if it is present after the colon. - * + * * @param eventText The raw event text to process */ function processSSEEvent(eventText: string) { @@ -75,6 +80,7 @@ export const parseSSEStream = (source$: Observable): Observable // Join multi-line data and parse JSON const jsonStr = dataLines.join("\n"); const json = JSON.parse(jsonStr); + log?.event("SSE", "Event received:", json, { type: json.type }); jsonSubject.next(json); } catch (err) { jsonSubject.error(err); diff --git a/sdks/typescript/packages/client/src/verify/__tests__/verify-debug.test.ts b/sdks/typescript/packages/client/src/verify/__tests__/verify-debug.test.ts new file mode 100644 index 0000000000..e255811373 --- /dev/null +++ b/sdks/typescript/packages/client/src/verify/__tests__/verify-debug.test.ts @@ -0,0 +1,200 @@ +import { describe, it, expect, vi, beforeEach, afterEach } from "vitest"; +import { Subject, firstValueFrom } from "rxjs"; +import { toArray } from "rxjs/operators"; +import { verifyEvents } from "../verify"; +import { createDebugLogger, DebugLogger } from "@/debug-logger"; +import { + BaseEvent, + EventType, + RunStartedEvent, + TextMessageStartEvent, + TextMessageContentEvent, + TextMessageEndEvent, + RunFinishedEvent, +} from "@ag-ui/core"; + +describe("verifyEvents debug logging", () => { + let debugSpy: ReturnType; + + beforeEach(() => { + debugSpy = vi.spyOn(console, "debug").mockImplementation(() => {}); + }); + + afterEach(() => { + vi.restoreAllMocks(); + }); + + const emitCompleteSequence = (source$: Subject) => { + source$.next({ + type: EventType.RUN_STARTED, + threadId: "thread-1", + runId: "run-1", + } as RunStartedEvent); + source$.next({ + type: EventType.TEXT_MESSAGE_START, + messageId: "msg-1", + role: "assistant", + } as TextMessageStartEvent); + source$.next({ + type: EventType.TEXT_MESSAGE_CONTENT, + messageId: "msg-1", + delta: "Hello", + } as TextMessageContentEvent); + source$.next({ + type: EventType.TEXT_MESSAGE_END, + messageId: "msg-1", + } as TextMessageEndEvent); + source$.next({ + type: EventType.RUN_FINISHED, + threadId: "thread-1", + runId: "run-1", + } as RunFinishedEvent); + source$.complete(); + }; + + describe("when debugLogger is falsy", () => { + it("no console.debug calls when debugLogger is undefined", async () => { + const source$ = new Subject(); + const result$ = verifyEvents(undefined)(source$).pipe(toArray()); + const resultPromise = firstValueFrom(result$); + emitCompleteSequence(source$); + await resultPromise; + expect(debugSpy).not.toHaveBeenCalled(); + }); + + it("no console.debug calls when debugLogger is false", async () => { + const source$ = new Subject(); + const result$ = verifyEvents(false)(source$).pipe(toArray()); + const resultPromise = firstValueFrom(result$); + emitCompleteSequence(source$); + await resultPromise; + expect(debugSpy).not.toHaveBeenCalled(); + }); + + it("no console.debug calls when debugLogger is null", async () => { + const source$ = new Subject(); + const result$ = verifyEvents(null)(source$).pipe(toArray()); + const resultPromise = firstValueFrom(result$); + emitCompleteSequence(source$); + await resultPromise; + expect(debugSpy).not.toHaveBeenCalled(); + }); + }); + + describe("when debug events enabled with verbose", () => { + let logger: DebugLogger; + + beforeEach(() => { + logger = createDebugLogger({ + enabled: true, + events: true, + lifecycle: true, + verbose: true, + })!; + }); + + it("logs full JSON of each event", async () => { + const source$ = new Subject(); + const result$ = verifyEvents(logger)(source$).pipe(toArray()); + const resultPromise = firstValueFrom(result$); + emitCompleteSequence(source$); + const events = await resultPromise; + + const verifyCalls = debugSpy.mock.calls.filter( + (call) => typeof call[0] === "string" && call[0].startsWith("[VERIFY]"), + ); + + // One log per event in the sequence (5 events) + expect(verifyCalls.length).toBe(5); + + // In verbose mode, should get JSON strings + for (const call of verifyCalls) { + expect(typeof call[1]).toBe("string"); + // Should be valid JSON + expect(() => JSON.parse(call[1])).not.toThrow(); + } + }); + }); + + describe("when debug events enabled without verbose", () => { + let logger: DebugLogger; + + beforeEach(() => { + logger = createDebugLogger({ + enabled: true, + events: true, + lifecycle: true, + verbose: false, + })!; + }); + + it("logs only { type } summary", async () => { + const source$ = new Subject(); + const result$ = verifyEvents(logger)(source$).pipe(toArray()); + const resultPromise = firstValueFrom(result$); + emitCompleteSequence(source$); + await resultPromise; + + const verifyCalls = debugSpy.mock.calls.filter( + (call) => typeof call[0] === "string" && call[0].startsWith("[VERIFY]"), + ); + + expect(verifyCalls.length).toBe(5); + + // In summary mode, the second argument should be { type: ... } + expect(verifyCalls[0][1]).toEqual({ type: EventType.RUN_STARTED }); + expect(verifyCalls[1][1]).toEqual({ type: EventType.TEXT_MESSAGE_START }); + expect(verifyCalls[2][1]).toEqual({ + type: EventType.TEXT_MESSAGE_CONTENT, + }); + expect(verifyCalls[3][1]).toEqual({ type: EventType.TEXT_MESSAGE_END }); + expect(verifyCalls[4][1]).toEqual({ type: EventType.RUN_FINISHED }); + }); + }); + + describe("prefix format", () => { + it("uses [VERIFY] prefix", async () => { + const logger = createDebugLogger({ + enabled: true, + events: true, + lifecycle: true, + verbose: false, + })!; + + const source$ = new Subject(); + const result$ = verifyEvents(logger)(source$).pipe(toArray()); + const resultPromise = firstValueFrom(result$); + emitCompleteSequence(source$); + await resultPromise; + + const allCalls = debugSpy.mock.calls; + for (const call of allCalls) { + expect(call[0]).toMatch(/^\[VERIFY\]/); + } + }); + }); + + describe("event count verification", () => { + it("each event in the sequence produces exactly one debug log", async () => { + const logger = createDebugLogger({ + enabled: true, + events: true, + lifecycle: true, + verbose: false, + })!; + + const source$ = new Subject(); + const result$ = verifyEvents(logger)(source$).pipe(toArray()); + const resultPromise = firstValueFrom(result$); + emitCompleteSequence(source$); + const events = await resultPromise; + + const verifyCalls = debugSpy.mock.calls.filter( + (call) => typeof call[0] === "string" && call[0].startsWith("[VERIFY]"), + ); + + // Exactly one log per event + expect(verifyCalls.length).toBe(events.length); + }); + }); +}); diff --git a/sdks/typescript/packages/client/src/verify/__tests__/verify.multiple-runs.test.ts b/sdks/typescript/packages/client/src/verify/__tests__/verify.multiple-runs.test.ts index 91ddf1d14a..2add60748e 100644 --- a/sdks/typescript/packages/client/src/verify/__tests__/verify.multiple-runs.test.ts +++ b/sdks/typescript/packages/client/src/verify/__tests__/verify.multiple-runs.test.ts @@ -288,9 +288,7 @@ describe("verifyEvents multiple runs", () => { next: (event) => events.push(event), error: (err) => { expect(err).toBeInstanceOf(AGUIError); - expect(err.message).toContain( - "Cannot send 'RUN_STARTED' while a run is still active", - ); + expect(err.message).toContain("Cannot send 'RUN_STARTED' while a run is still active"); subscription.unsubscribe(); }, }); @@ -380,9 +378,7 @@ describe("verifyEvents multiple runs", () => { next: (event) => events.push(event), error: (err) => { expect(err).toBeInstanceOf(AGUIError); - expect(err.message).toContain( - "The run has already errored with 'RUN_ERROR'", - ); + expect(err.message).toContain("The run has already errored with 'RUN_ERROR'"); subscription.unsubscribe(); }, }); diff --git a/sdks/typescript/packages/client/src/verify/verify.ts b/sdks/typescript/packages/client/src/verify/verify.ts index 217d6e423c..f3b6ba5aab 100644 --- a/sdks/typescript/packages/client/src/verify/verify.ts +++ b/sdks/typescript/packages/client/src/verify/verify.ts @@ -1,10 +1,12 @@ import { BaseEvent, EventType, AGUIError } from "@ag-ui/core"; import { Observable, throwError, of } from "rxjs"; import { mergeMap } from "rxjs/operators"; +import { DebugLogger } from "@/debug-logger"; export const verifyEvents = - (debug: boolean) => + (debugLogger?: DebugLogger | false | null) => (source$: Observable): Observable => { + const log = debugLogger || undefined; // Declare variables in closure to maintain state across events let activeMessages = new Map(); // Map of message ID -> active status let activeToolCalls = new Map(); // Map of tool call ID -> active status @@ -35,9 +37,7 @@ export const verifyEvents = mergeMap((event) => { const eventType = event.type; - if (debug) { - console.debug("[VERIFY]:", JSON.stringify(event)); - } + log?.event("VERIFY", "Event:", event, { type: event.type }); // Check if run has errored if (runError) { @@ -50,7 +50,11 @@ export const verifyEvents = } // Check if run has already finished (but allow new RUN_STARTED to start a new run) - if (runFinished && eventType !== EventType.RUN_ERROR && eventType !== EventType.RUN_STARTED) { + if ( + runFinished && + eventType !== EventType.RUN_ERROR && + eventType !== EventType.RUN_STARTED + ) { return throwError( () => new AGUIError(