feat(llm-client): add configurable logging system

Add a flexible logging system to the llm-client package that can be
enabled/disabled without rebuilding:

- Add Logger class with configurable enable/disable and custom logger support
- Add LogLevel, LoggerFn, LoggingConfig types
- Add `debug` option to LLMStreamRequest for per-request logging override
- Add setLogging() method for runtime enable/disable
- Replace hardcoded console.log in openai-responses provider with logger
- Add ?debug=true query param to flowchart generate endpoint

Usage:
- Per-request: llm.stream({ ..., debug: true })
- Global: llm.setLogging({ enabled: true })
- Custom logger: new LLMClient({ logging: { enabled: true, logger: fn } })

Co-Authored-By: Claude Opus 4.5 <noreply@anthropic.com>
This commit is contained in:
Thomas Hallock 2026-01-22 15:17:31 -06:00
parent 454f93faae
commit cdd53f6602
7 changed files with 428 additions and 140 deletions

View File

@ -12,149 +12,171 @@
* - output_delta: Partial structured output being generated * - output_delta: Partial structured output being generated
* - complete: Generated flowchart result * - complete: Generated flowchart result
* - error: Error occurred * - error: Error occurred
*
* Query params:
* - debug=true: Enable verbose LLM debug logging
*/ */
import { and, eq } from 'drizzle-orm' import { and, eq } from "drizzle-orm";
import type { z } from 'zod' import type { z } from "zod";
import { db, schema } from '@/db' import { db, schema } from "@/db";
import { import {
broadcast, broadcast,
completeGeneration, completeGeneration,
failGeneration, failGeneration,
startGeneration, startGeneration,
} from '@/lib/flowchart-workshop/generation-registry' } from "@/lib/flowchart-workshop/generation-registry";
import { import {
GeneratedFlowchartSchema, GeneratedFlowchartSchema,
getGenerationSystemPrompt, getGenerationSystemPrompt,
getSubtractionExample, getSubtractionExample,
transformLLMDefinitionToInternal, transformLLMDefinitionToInternal,
} from '@/lib/flowchart-workshop/llm-schemas' } from "@/lib/flowchart-workshop/llm-schemas";
import { validateTestCasesWithCoverage } from '@/lib/flowchart-workshop/test-case-validator' import { validateTestCasesWithCoverage } from "@/lib/flowchart-workshop/test-case-validator";
import { llm, type StreamEvent } from '@/lib/llm' import { llm, type StreamEvent } from "@/lib/llm";
import { getDbUserId } from '@/lib/viewer' import { getDbUserId } from "@/lib/viewer";
type GeneratedFlowchart = z.infer<typeof GeneratedFlowchartSchema> type GeneratedFlowchart = z.infer<typeof GeneratedFlowchartSchema>;
interface RouteParams { interface RouteParams {
params: Promise<{ id: string }> params: Promise<{ id: string }>;
} }
export async function POST(request: Request, { params }: RouteParams) { export async function POST(request: Request, { params }: RouteParams) {
const { id } = await params const { id } = await params;
// Check for debug mode via query param
const url = new URL(request.url);
const debug = url.searchParams.get("debug") === "true";
if (debug) {
console.log("[generate] Debug mode enabled");
}
if (!id) { if (!id) {
return new Response(JSON.stringify({ error: 'Session ID required' }), { return new Response(JSON.stringify({ error: "Session ID required" }), {
status: 400, status: 400,
headers: { 'Content-Type': 'application/json' }, headers: { "Content-Type": "application/json" },
}) });
} }
// Authorization check // Authorization check
let userId: string let userId: string;
try { try {
userId = await getDbUserId() userId = await getDbUserId();
} catch { } catch {
return new Response(JSON.stringify({ error: 'Not authenticated' }), { return new Response(JSON.stringify({ error: "Not authenticated" }), {
status: 401, status: 401,
headers: { 'Content-Type': 'application/json' }, headers: { "Content-Type": "application/json" },
}) });
} }
// Get the session // Get the session
const session = await db.query.workshopSessions.findFirst({ const session = await db.query.workshopSessions.findFirst({
where: and(eq(schema.workshopSessions.id, id), eq(schema.workshopSessions.userId, userId)), where: and(
}) eq(schema.workshopSessions.id, id),
eq(schema.workshopSessions.userId, userId),
),
});
if (!session) { if (!session) {
return new Response(JSON.stringify({ error: 'Session not found' }), { return new Response(JSON.stringify({ error: "Session not found" }), {
status: 404, status: 404,
headers: { 'Content-Type': 'application/json' }, headers: { "Content-Type": "application/json" },
}) });
} }
// Parse request body // Parse request body
let topicDescription: string let topicDescription: string;
try { try {
const body = await request.json() const body = await request.json();
topicDescription = body.topicDescription || session.topicDescription topicDescription = body.topicDescription || session.topicDescription;
if (!topicDescription) { if (!topicDescription) {
return new Response(JSON.stringify({ error: 'Topic description required' }), { return new Response(
status: 400, JSON.stringify({ error: "Topic description required" }),
headers: { 'Content-Type': 'application/json' }, {
}) status: 400,
headers: { "Content-Type": "application/json" },
},
);
} }
} catch { } catch {
return new Response(JSON.stringify({ error: 'Invalid request body' }), { return new Response(JSON.stringify({ error: "Invalid request body" }), {
status: 400, status: 400,
headers: { 'Content-Type': 'application/json' }, headers: { "Content-Type": "application/json" },
}) });
} }
// Update session state // Update session state
await db await db
.update(schema.workshopSessions) .update(schema.workshopSessions)
.set({ .set({
state: 'generating', state: "generating",
topicDescription, topicDescription,
updatedAt: new Date(), updatedAt: new Date(),
}) })
.where(eq(schema.workshopSessions.id, id)) .where(eq(schema.workshopSessions.id, id));
// Create SSE stream with resilient event sending // Create SSE stream with resilient event sending
// Key design: LLM processing and DB saves happen regardless of client connection // Key design: LLM processing and DB saves happen regardless of client connection
// Client streaming is best-effort - if they disconnect, we still complete the work // Client streaming is best-effort - if they disconnect, we still complete the work
const encoder = new TextEncoder() const encoder = new TextEncoder();
const stream = new ReadableStream({ const stream = new ReadableStream({
async start(controller) { async start(controller) {
let clientConnected = true let clientConnected = true;
// Resilient event sender - catches errors if client disconnected // Resilient event sender - catches errors if client disconnected
// This ensures LLM processing continues even if client closes browser // This ensures LLM processing continues even if client closes browser
const sendEvent = (event: string, data: unknown) => { const sendEvent = (event: string, data: unknown) => {
if (!clientConnected) return if (!clientConnected) return;
try { try {
controller.enqueue(encoder.encode(`event: ${event}\n`)) controller.enqueue(encoder.encode(`event: ${event}\n`));
controller.enqueue(encoder.encode(`data: ${JSON.stringify(data)}\n\n`)) controller.enqueue(
encoder.encode(`data: ${JSON.stringify(data)}\n\n`),
);
} catch { } catch {
// Client disconnected - mark as disconnected but continue processing // Client disconnected - mark as disconnected but continue processing
clientConnected = false clientConnected = false;
console.log( if (debug) {
`[generate] Client disconnected during ${event} event, continuing LLM processing...` console.log(`[generate] Client disconnected during ${event} event`);
) }
} }
} };
const closeStream = () => { const closeStream = () => {
if (!clientConnected) return if (!clientConnected) return;
try { try {
controller.close() controller.close();
} catch { } catch {
// Already closed // Already closed
} }
} };
// Track LLM errors separately from client errors // Track LLM errors separately from client errors
let llmError: { message: string; code?: string } | null = null let llmError: { message: string; code?: string } | null = null;
let finalResult: GeneratedFlowchart | null = null let finalResult: GeneratedFlowchart | null = null;
let usage: { let usage: {
promptTokens: number promptTokens: number;
completionTokens: number completionTokens: number;
reasoningTokens?: number reasoningTokens?: number;
} | null = null } | null = null;
// Start tracking this generation in the registry (for reconnection support) // Start tracking this generation in the registry (for reconnection support)
const generationState = startGeneration(id) const generationState = startGeneration(id);
// Throttled save of reasoning text to database (for durability) // Throttled save of reasoning text to database (for durability)
let lastReasoningSaveTime = 0 let lastReasoningSaveTime = 0;
const REASONING_SAVE_INTERVAL_MS = 2000 // Save reasoning every 2 seconds const REASONING_SAVE_INTERVAL_MS = 2000; // Save reasoning every 2 seconds
const saveReasoningToDb = async (force = false) => { const saveReasoningToDb = async (force = false) => {
const now = Date.now() const now = Date.now();
if (!force && now - lastReasoningSaveTime < REASONING_SAVE_INTERVAL_MS) { if (
return // Throttle saves !force &&
now - lastReasoningSaveTime < REASONING_SAVE_INTERVAL_MS
) {
return; // Throttle saves
} }
lastReasoningSaveTime = now lastReasoningSaveTime = now;
try { try {
await db await db
.update(schema.workshopSessions) .update(schema.workshopSessions)
@ -162,23 +184,29 @@ export async function POST(request: Request, { params }: RouteParams) {
currentReasoningText: generationState.accumulatedReasoning, currentReasoningText: generationState.accumulatedReasoning,
updatedAt: new Date(), updatedAt: new Date(),
}) })
.where(eq(schema.workshopSessions.id, id)) .where(eq(schema.workshopSessions.id, id));
} catch (err) { } catch (err) {
// Log but don't fail the stream on DB errors // Log but don't fail the stream on DB errors
console.error('[generate] Failed to save reasoning to DB:', err) console.error("[generate] Failed to save reasoning to DB:", err);
} }
} };
try { try {
sendEvent('progress', { stage: 'preparing', message: 'Preparing flowchart generation...' }) sendEvent("progress", {
stage: "preparing",
message: "Preparing flowchart generation...",
});
broadcast(id, { broadcast(id, {
type: 'progress', type: "progress",
data: { stage: 'preparing', message: 'Preparing flowchart generation...' }, data: {
}) stage: "preparing",
message: "Preparing flowchart generation...",
},
});
// Build the prompt // Build the prompt
const systemPrompt = getGenerationSystemPrompt() const systemPrompt = getGenerationSystemPrompt();
const examplePrompt = getSubtractionExample() const examplePrompt = getSubtractionExample();
const userPrompt = `Create an interactive math flowchart for teaching the following topic: const userPrompt = `Create an interactive math flowchart for teaching the following topic:
@ -191,23 +219,25 @@ Create a complete, working flowchart with:
The flowchart should be engaging for students, with clear phases, checkpoints for important calculations, and encouraging visual elements. The flowchart should be engaging for students, with clear phases, checkpoints for important calculations, and encouraging visual elements.
Return the result as a JSON object matching the GeneratedFlowchartSchema.` Return the result as a JSON object matching the GeneratedFlowchartSchema.`;
// Combine system prompt with user prompt // Combine system prompt with user prompt
const fullPrompt = `${systemPrompt}\n\n${examplePrompt}\n\n---\n\n${userPrompt}` const fullPrompt = `${systemPrompt}\n\n${examplePrompt}\n\n---\n\n${userPrompt}`;
// Stream the LLM response with reasoning // Stream the LLM response with reasoning
// Use debug option to enable detailed logging in the LLM client
const llmStream = llm.stream({ const llmStream = llm.stream({
provider: 'openai', provider: "openai",
model: 'gpt-5.2', model: "gpt-5.2",
prompt: fullPrompt, prompt: fullPrompt,
schema: GeneratedFlowchartSchema, schema: GeneratedFlowchartSchema,
reasoning: { reasoning: {
effort: 'medium', effort: "medium",
summary: 'auto', summary: "auto",
}, },
timeoutMs: 300_000, // 5 minutes for complex flowchart generation timeoutMs: 300_000, // 5 minutes for complex flowchart generation
}) debug, // Enable LLM client debug logging if debug=true
});
// Forward all stream events to the client AND broadcast to registry subscribers // Forward all stream events to the client AND broadcast to registry subscribers
// The for-await loop processes all LLM events regardless of client state // The for-await loop processes all LLM events regardless of client state
@ -217,64 +247,65 @@ Return the result as a JSON object matching the GeneratedFlowchartSchema.`
unknown unknown
>) { >) {
switch (event.type) { switch (event.type) {
case 'started': { case "started": {
const startedData = { const startedData = {
responseId: event.responseId, responseId: event.responseId,
message: 'Generating flowchart...', message: "Generating flowchart...",
} };
sendEvent('started', startedData) sendEvent("started", startedData);
// Note: 'started' is not broadcast - subscribers already know generation started // Note: 'started' is not broadcast - subscribers already know generation started
break break;
} }
case 'reasoning': { case "reasoning": {
const reasoningData = { const reasoningData = {
text: event.text, text: event.text,
summaryIndex: event.summaryIndex, summaryIndex: event.summaryIndex,
isDelta: event.isDelta, isDelta: event.isDelta,
} };
// Broadcast to registry (this accumulates reasoning internally) // Broadcast to registry (this accumulates reasoning internally)
broadcast(id, { type: 'reasoning', data: reasoningData }) broadcast(id, { type: "reasoning", data: reasoningData });
// Throttled save to database for durability (don't await - fire and forget) // Throttled save to database for durability (don't await - fire and forget)
saveReasoningToDb() saveReasoningToDb();
// Send to this client's SSE stream // Send to this client's SSE stream
sendEvent('reasoning', reasoningData) sendEvent("reasoning", reasoningData);
break break;
} }
case 'output_delta': { case "output_delta": {
const outputData = { const outputData = {
text: event.text, text: event.text,
outputIndex: event.outputIndex, outputIndex: event.outputIndex,
} };
broadcast(id, { type: 'output_delta', data: outputData }) broadcast(id, { type: "output_delta", data: outputData });
sendEvent('output_delta', outputData) sendEvent("output_delta", outputData);
break break;
} }
case 'error': case "error":
console.error("[generate] LLM error:", event.message, event.code);
// This is an LLM error, not a client error // This is an LLM error, not a client error
llmError = { message: event.message, code: event.code } llmError = { message: event.message, code: event.code };
sendEvent('error', { sendEvent("error", {
message: event.message, message: event.message,
code: event.code, code: event.code,
}) });
// Don't broadcast error here - we'll call failGeneration() below // Don't broadcast error here - we'll call failGeneration() below
break break;
case 'complete': case "complete":
finalResult = event.data finalResult = event.data;
usage = event.usage usage = event.usage;
break break;
} }
} }
} catch (error) { } catch (error) {
// This catch is for unexpected errors (network issues, etc.) // This catch is for unexpected errors (network issues, etc.)
// NOT for client disconnect (those are caught in sendEvent) // NOT for client disconnect (those are caught in sendEvent)
console.error('Flowchart generation error:', error) console.error("[generate] Stream processing error:", error);
llmError = { llmError = {
message: error instanceof Error ? error.message : 'Unknown error', message: error instanceof Error ? error.message : "Unknown error",
} };
} }
// ALWAYS update database based on LLM result, regardless of client connection // ALWAYS update database based on LLM result, regardless of client connection
@ -284,43 +315,51 @@ Return the result as a JSON object matching the GeneratedFlowchartSchema.`
await db await db
.update(schema.workshopSessions) .update(schema.workshopSessions)
.set({ .set({
state: 'initial', state: "initial",
draftNotes: JSON.stringify([`Generation failed: ${llmError.message}`]), draftNotes: JSON.stringify([
`Generation failed: ${llmError.message}`,
]),
currentReasoningText: null, // Clear reasoning on completion/error currentReasoningText: null, // Clear reasoning on completion/error
updatedAt: new Date(), updatedAt: new Date(),
}) })
.where(eq(schema.workshopSessions.id, id)) .where(eq(schema.workshopSessions.id, id));
// Notify registry subscribers of failure // Notify registry subscribers of failure
failGeneration(id, llmError.message) failGeneration(id, llmError.message);
sendEvent('error', { message: llmError.message }) sendEvent("error", { message: llmError.message });
} else if (finalResult) { } else if (finalResult) {
// LLM succeeded - save the result // LLM succeeded - save the result
sendEvent('progress', { stage: 'validating', message: 'Validating result...' }) sendEvent("progress", {
stage: "validating",
message: "Validating result...",
});
// Transform LLM output (array-based) to internal format (record-based) // Transform LLM output (array-based) to internal format (record-based)
const internalDefinition = transformLLMDefinitionToInternal(finalResult.definition) const internalDefinition = transformLLMDefinitionToInternal(
finalResult.definition,
);
// Run test case validation with coverage analysis // Run test case validation with coverage analysis
const validationReport = await validateTestCasesWithCoverage( const validationReport = await validateTestCasesWithCoverage(
internalDefinition, internalDefinition,
finalResult.mermaidContent finalResult.mermaidContent,
) );
// Send validation event (regardless of pass/fail - UI will display results) // Send validation event (regardless of pass/fail - UI will display results)
sendEvent('validation', { sendEvent("validation", {
passed: validationReport.passed, passed: validationReport.passed,
failedCount: validationReport.summary.failed + validationReport.summary.errors, failedCount:
validationReport.summary.failed + validationReport.summary.errors,
totalCount: validationReport.summary.total, totalCount: validationReport.summary.total,
coveragePercent: validationReport.coverage.coveragePercent, coveragePercent: validationReport.coverage.coveragePercent,
}) });
// Update session with the generated content, clear reasoning // Update session with the generated content, clear reasoning
await db await db
.update(schema.workshopSessions) .update(schema.workshopSessions)
.set({ .set({
state: 'refining', state: "refining",
draftDefinitionJson: JSON.stringify(internalDefinition), draftDefinitionJson: JSON.stringify(internalDefinition),
draftMermaidContent: finalResult.mermaidContent, draftMermaidContent: finalResult.mermaidContent,
draftTitle: finalResult.title, draftTitle: finalResult.title,
@ -331,11 +370,11 @@ Return the result as a JSON object matching the GeneratedFlowchartSchema.`
currentReasoningText: null, // Clear reasoning on completion currentReasoningText: null, // Clear reasoning on completion
updatedAt: new Date(), updatedAt: new Date(),
}) })
.where(eq(schema.workshopSessions.id, id)) .where(eq(schema.workshopSessions.id, id));
console.log( if (debug) {
`[generate] Flowchart saved to DB for session ${id}${clientConnected ? '' : ' (client had disconnected)'}` console.log(`[generate] Flowchart saved to DB for session ${id}`);
) }
// Build complete result for broadcasting // Build complete result for broadcasting
const completeResult = { const completeResult = {
@ -347,23 +386,23 @@ Return the result as a JSON object matching the GeneratedFlowchartSchema.`
difficulty: finalResult.difficulty, difficulty: finalResult.difficulty,
notes: finalResult.notes, notes: finalResult.notes,
usage, usage,
} };
// Notify registry subscribers of completion (this also broadcasts 'complete' event) // Notify registry subscribers of completion (this also broadcasts 'complete' event)
completeGeneration(id, completeResult) completeGeneration(id, completeResult);
sendEvent('complete', completeResult) sendEvent("complete", completeResult);
} }
closeStream() closeStream();
}, },
}) });
return new Response(stream, { return new Response(stream, {
headers: { headers: {
'Content-Type': 'text/event-stream', "Content-Type": "text/event-stream",
'Cache-Control': 'no-cache', "Cache-Control": "no-cache",
Connection: 'keep-alive', Connection: "keep-alive",
}, },
}) });
} }

View File

@ -20,7 +20,7 @@
* @see packages/llm-client/README.md for full documentation * @see packages/llm-client/README.md for full documentation
*/ */
import { LLMClient } from '@soroban/llm-client' import { LLMClient } from "@soroban/llm-client";
// Create singleton instance // Create singleton instance
// Configuration is automatically loaded from environment variables: // Configuration is automatically loaded from environment variables:
@ -30,7 +30,7 @@ import { LLMClient } from '@soroban/llm-client'
// - LLM_OPENAI_BASE_URL: OpenAI base URL (optional) // - LLM_OPENAI_BASE_URL: OpenAI base URL (optional)
// - LLM_ANTHROPIC_API_KEY: Anthropic API key // - LLM_ANTHROPIC_API_KEY: Anthropic API key
// - LLM_ANTHROPIC_BASE_URL: Anthropic base URL (optional) // - LLM_ANTHROPIC_BASE_URL: Anthropic base URL (optional)
export const llm = new LLMClient() export const llm = new LLMClient();
// Re-export types and utilities for convenience // Re-export types and utilities for convenience
export type { export type {
@ -53,7 +53,11 @@ export type {
StreamEventOutputDelta, StreamEventOutputDelta,
StreamEventError, StreamEventError,
StreamEventComplete, StreamEventComplete,
} from '@soroban/llm-client' // Logging types
LogLevel,
LoggerFn,
LoggingConfig,
} from "@soroban/llm-client";
export { export {
LLMValidationError, LLMValidationError,
@ -61,4 +65,7 @@ export {
LLMTimeoutError, LLMTimeoutError,
LLMNetworkError, LLMNetworkError,
ProviderNotConfiguredError, ProviderNotConfiguredError,
} from '@soroban/llm-client' // Logging
Logger,
defaultLogger,
} from "@soroban/llm-client";

View File

@ -7,6 +7,7 @@ import type {
LLMRequest, LLMRequest,
LLMResponse, LLMResponse,
LLMStreamRequest, LLMStreamRequest,
LoggingConfig,
ProviderRequest, ProviderRequest,
StreamEvent, StreamEvent,
ValidationFeedback, ValidationFeedback,
@ -19,6 +20,7 @@ import {
isProviderConfigured, isProviderConfigured,
} from "./config"; } from "./config";
import { executeWithRetry } from "./retry"; import { executeWithRetry } from "./retry";
import { Logger } from "./logger";
import { OpenAIProvider } from "./providers/openai"; import { OpenAIProvider } from "./providers/openai";
import { AnthropicProvider } from "./providers/anthropic"; import { AnthropicProvider } from "./providers/anthropic";
import { OpenAIResponsesProvider } from "./providers/openai-responses"; import { OpenAIResponsesProvider } from "./providers/openai-responses";
@ -80,6 +82,7 @@ const providerFactories: Record<string, ProviderFactory> = {
export class LLMClient { export class LLMClient {
private readonly config: LLMClientConfig; private readonly config: LLMClientConfig;
private readonly providers: Map<string, LLMProvider> = new Map(); private readonly providers: Map<string, LLMProvider> = new Map();
private logger: Logger;
/** /**
* Create a new LLM client * Create a new LLM client
@ -99,7 +102,18 @@ export class LLMClient {
...envConfig.providers, ...envConfig.providers,
...configOverrides?.providers, ...configOverrides?.providers,
}, },
logging: configOverrides?.logging ?? envConfig.logging,
}; };
this.logger = new Logger(this.config.logging);
}
/**
* Enable or disable logging at runtime
*/
setLogging(config: Partial<LoggingConfig>): void {
const newConfig = { ...this.config.logging, ...config } as LoggingConfig;
this.config.logging = newConfig;
this.logger = new Logger(newConfig);
} }
/** /**
@ -158,9 +172,19 @@ export class LLMClient {
async *stream<T extends z.ZodType>( async *stream<T extends z.ZodType>(
request: LLMStreamRequest<T>, request: LLMStreamRequest<T>,
): AsyncGenerator<StreamEvent<z.infer<T>>, void, unknown> { ): AsyncGenerator<StreamEvent<z.infer<T>>, void, unknown> {
// Get logger for this request (may be overridden by request.debug)
const requestLogger = this.logger.withEnabled(request.debug);
const providerName = request.provider ?? this.config.defaultProvider; const providerName = request.provider ?? this.config.defaultProvider;
const model = request.model ?? this.getDefaultModel(providerName); const model = request.model ?? this.getDefaultModel(providerName);
requestLogger.debug("Starting stream request", {
provider: providerName,
model,
promptLength: request.prompt.length,
hasImages: !!request.images?.length,
});
// Currently only OpenAI Responses API supports streaming with reasoning // Currently only OpenAI Responses API supports streaming with reasoning
if (providerName.toLowerCase() !== "openai") { if (providerName.toLowerCase() !== "openai") {
throw new Error( throw new Error(
@ -176,7 +200,10 @@ export class LLMClient {
} }
// Create responses provider (separate from chat completions provider) // Create responses provider (separate from chat completions provider)
const responsesProvider = new OpenAIResponsesProvider(providerConfig); const responsesProvider = new OpenAIResponsesProvider(
providerConfig,
requestLogger,
);
// Convert Zod schema to JSON Schema // Convert Zod schema to JSON Schema
const jsonSchema = z.toJSONSchema(request.schema, { const jsonSchema = z.toJSONSchema(request.schema, {
@ -192,6 +219,12 @@ export class LLMClient {
summary: "auto" as const, summary: "auto" as const,
}; };
requestLogger.debug("Streaming with config", {
reasoning,
timeoutMs: request.timeoutMs,
schemaKeys: Object.keys(jsonSchema),
});
// Stream the response // Stream the response
yield* responsesProvider.stream<z.infer<T>>( yield* responsesProvider.stream<z.infer<T>>(
{ {

View File

@ -55,8 +55,16 @@ export type {
// Embedding types // Embedding types
EmbeddingRequest, EmbeddingRequest,
EmbeddingResponse, EmbeddingResponse,
// Logging types
LogLevel,
LoggerFn,
LoggingConfig,
} from "./types"; } from "./types";
// Logging utilities
export { defaultLogger } from "./types";
export { Logger } from "./logger";
// Errors // Errors
export { export {
LLMValidationError, LLMValidationError,

View File

@ -0,0 +1,81 @@
import type { LogLevel, LoggerFn, LoggingConfig } from "./types";
import { defaultLogger } from "./types";
/**
* Log level priority for filtering
*/
const LOG_LEVEL_PRIORITY: Record<LogLevel, number> = {
debug: 0,
info: 1,
warn: 2,
error: 3,
};
/**
* Internal logger that respects configuration
*/
export class Logger {
private readonly config: LoggingConfig;
private readonly logger: LoggerFn;
private readonly minLevelPriority: number;
constructor(config?: LoggingConfig) {
this.config = config ?? { enabled: false };
this.logger = this.config.logger ?? defaultLogger;
this.minLevelPriority = LOG_LEVEL_PRIORITY[this.config.minLevel ?? "debug"];
}
/**
* Check if logging is enabled
*/
get enabled(): boolean {
return this.config.enabled;
}
/**
* Create a child logger with override for enabled state
* Used for per-request debug overrides
*/
withEnabled(enabled: boolean | undefined): Logger {
if (enabled === undefined) {
return this;
}
return new Logger({
...this.config,
enabled,
});
}
/**
* Log a message if logging is enabled and level is at or above minimum
*/
log(level: LogLevel, message: string, data?: Record<string, unknown>): void {
if (!this.config.enabled) {
return;
}
if (LOG_LEVEL_PRIORITY[level] < this.minLevelPriority) {
return;
}
this.logger(level, message, data);
}
/** Log at debug level */
debug(message: string, data?: Record<string, unknown>): void {
this.log("debug", message, data);
}
/** Log at info level */
info(message: string, data?: Record<string, unknown>): void {
this.log("info", message, data);
}
/** Log at warn level */
warn(message: string, data?: Record<string, unknown>): void {
this.log("warn", message, data);
}
/** Log at error level */
error(message: string, data?: Record<string, unknown>): void {
this.log("error", message, data);
}
}

View File

@ -1,6 +1,7 @@
import { z } from "zod"; import { z } from "zod";
import type { ProviderConfig, ReasoningConfig, StreamEvent } from "../types"; import type { ProviderConfig, ReasoningConfig, StreamEvent } from "../types";
import { LLMApiError, LLMTimeoutError, LLMNetworkError } from "../types"; import { LLMApiError, LLMTimeoutError, LLMNetworkError } from "../types";
import { Logger } from "../logger";
/** Default idle timeout for streaming requests (2 minutes without data = abort) */ /** Default idle timeout for streaming requests (2 minutes without data = abort) */
const DEFAULT_IDLE_TIMEOUT_MS = 120_000; const DEFAULT_IDLE_TIMEOUT_MS = 120_000;
@ -83,8 +84,15 @@ type ResponsesStreamEvent =
*/ */
export class OpenAIResponsesProvider { export class OpenAIResponsesProvider {
readonly name = "openai"; readonly name = "openai";
private readonly logger: Logger;
constructor(private readonly config: ProviderConfig) {} constructor(
private readonly config: ProviderConfig,
logger?: Logger,
) {
// Use provided logger or create a disabled one
this.logger = logger ?? new Logger({ enabled: false });
}
/** /**
* Stream a response from the Responses API * Stream a response from the Responses API
@ -192,20 +200,39 @@ export class OpenAIResponsesProvider {
let response: Response; let response: Response;
try { try {
response = await fetch(`${this.config.baseUrl}/responses`, { const fetchUrl = `${this.config.baseUrl}/responses`;
const bodyJson = JSON.stringify(requestBody);
this.logger.debug("Making POST request", {
url: fetchUrl,
bodySize: bodyJson.length,
model: request.model,
reasoning: request.reasoning,
});
const fetchStartTime = Date.now();
response = await fetch(fetchUrl, {
method: "POST", method: "POST",
headers: { headers: {
Authorization: `Bearer ${this.config.apiKey}`, Authorization: `Bearer ${this.config.apiKey}`,
"Content-Type": "application/json", "Content-Type": "application/json",
}, },
body: JSON.stringify(requestBody), body: bodyJson,
signal: controller.signal, signal: controller.signal,
}); });
this.logger.debug("Fetch completed", {
durationMs: Date.now() - fetchStartTime,
status: response.status,
});
} catch (error) { } catch (error) {
clearAllTimeouts(); clearAllTimeouts();
this.logger.error("Fetch error", {
error: error instanceof Error ? error.message : String(error),
});
if (error instanceof Error && error.name === "AbortError") { if (error instanceof Error && error.name === "AbortError") {
const timeoutValue = idleTimedOut ? idleTimeoutMs : totalTimeoutMs; const timeoutValue = idleTimedOut ? idleTimeoutMs : totalTimeoutMs;
this.logger.error("Request aborted due to timeout", {
timeoutMs: timeoutValue,
});
throw new LLMTimeoutError(this.name, timeoutValue); throw new LLMTimeoutError(this.name, timeoutValue);
} }
@ -229,6 +256,7 @@ export class OpenAIResponsesProvider {
} }
// Process the SSE stream // Process the SSE stream
this.logger.debug("Starting to read SSE stream");
const reader = response.body?.getReader(); const reader = response.body?.getReader();
if (!reader) { if (!reader) {
clearAllTimeouts(); clearAllTimeouts();
@ -239,10 +267,20 @@ export class OpenAIResponsesProvider {
let buffer = ""; let buffer = "";
let accumulatedOutput = ""; let accumulatedOutput = "";
let finalResponse: ResponsesStreamEvent | null = null; let finalResponse: ResponsesStreamEvent | null = null;
let chunkCount = 0;
let eventCount = 0;
try { try {
while (true) { while (true) {
const { done, value } = await reader.read(); const { done, value } = await reader.read();
chunkCount++;
if (chunkCount <= 3 || chunkCount % 100 === 0) {
this.logger.debug("Chunk received", {
chunkNum: chunkCount,
size: value?.length ?? 0,
done,
});
}
if (done) break; if (done) break;
@ -266,9 +304,14 @@ export class OpenAIResponsesProvider {
try { try {
const event = JSON.parse(data) as ResponsesStreamEvent; const event = JSON.parse(data) as ResponsesStreamEvent;
eventCount++;
// Handle different event types // Handle different event types
switch (event.type) { switch (event.type) {
case "response.created": case "response.created":
this.logger.info("Stream started", {
responseId: event.response.id,
});
yield { yield {
type: "started", type: "started",
responseId: event.response.id, responseId: event.response.id,
@ -285,6 +328,10 @@ export class OpenAIResponsesProvider {
break; break;
case "response.reasoning_summary_text.done": case "response.reasoning_summary_text.done":
this.logger.debug("Reasoning summary complete", {
summaryIndex: event.summary_index,
textLength: event.text.length,
});
yield { yield {
type: "reasoning", type: "reasoning",
text: event.text, text: event.text,
@ -303,10 +350,21 @@ export class OpenAIResponsesProvider {
break; break;
case "response.completed": case "response.completed":
this.logger.info("Stream completed", {
outputLength: accumulatedOutput.length,
usage:
finalResponse?.type === "response.completed"
? finalResponse.response.usage
: undefined,
});
finalResponse = event; finalResponse = event;
break; break;
case "response.failed": case "response.failed":
this.logger.error("Stream failed", {
message: event.error.message,
code: event.error.code,
});
yield { yield {
type: "error", type: "error",
message: event.error.message, message: event.error.message,
@ -315,6 +373,10 @@ export class OpenAIResponsesProvider {
break; break;
case "error": case "error":
this.logger.error("Stream error", {
message: event.error.message,
code: event.error.code ?? event.error.type,
});
yield { yield {
type: "error", type: "error",
message: event.error.message, message: event.error.message,
@ -332,6 +394,12 @@ export class OpenAIResponsesProvider {
// Clear timeouts on successful completion // Clear timeouts on successful completion
clearAllTimeouts(); clearAllTimeouts();
this.logger.debug("Stream reading finished", {
totalChunks: chunkCount,
totalEvents: eventCount,
hasFinalResponse: !!finalResponse,
});
// Extract and validate the final output // Extract and validate the final output
if (finalResponse && finalResponse.type === "response.completed") { if (finalResponse && finalResponse.type === "response.completed") {
const output = finalResponse.response.output; const output = finalResponse.response.output;

View File

@ -1,5 +1,50 @@
import type { z } from "zod"; import type { z } from "zod";
// ============================================================================
// Logging Types
// ============================================================================
/**
* Log levels for LLM client logging
*/
export type LogLevel = "debug" | "info" | "warn" | "error";
/**
* Logger function signature
* @param level - The log level
* @param message - The log message
* @param data - Optional structured data to include
*/
export type LoggerFn = (
level: LogLevel,
message: string,
data?: Record<string, unknown>,
) => void;
/**
* Logging configuration for the LLM client
*/
export interface LoggingConfig {
/** Enable logging globally (default: false) */
enabled: boolean;
/** Custom logger function (default: console-based logger) */
logger?: LoggerFn;
/** Minimum log level to output (default: 'debug') */
minLevel?: LogLevel;
}
/**
* Default console-based logger
*/
export const defaultLogger: LoggerFn = (level, message, data) => {
const prefix = `[llm-client:${level}]`;
if (data) {
console[level === "debug" ? "log" : level](prefix, message, data);
} else {
console[level === "debug" ? "log" : level](prefix, message);
}
};
/** /**
* Provider configuration loaded from environment variables * Provider configuration loaded from environment variables
*/ */
@ -28,6 +73,8 @@ export interface LLMClientConfig {
providers: Record<string, ProviderConfig>; providers: Record<string, ProviderConfig>;
/** Default maximum retry attempts */ /** Default maximum retry attempts */
defaultMaxRetries: number; defaultMaxRetries: number;
/** Logging configuration */
logging?: LoggingConfig;
} }
/** /**
@ -336,6 +383,11 @@ export interface LLMStreamRequest<T extends z.ZodType> {
* Streaming requests typically take longer, so default is higher * Streaming requests typically take longer, so default is higher
*/ */
timeoutMs?: number; timeoutMs?: number;
/**
* Enable debug logging for this request (overrides global setting)
* Set to true to enable, false to disable, or omit to use global setting
*/
debug?: boolean;
} }
/** /**