yet another attempt from yet another agent on trying to just capture some simple stats

This commit is contained in:
Rob Colbert 2026-05-18 16:08:12 -04:00
parent 241f3b5b69
commit ef43fa2a00

View File

@ -64,6 +64,12 @@ interface StreamingToolCallAccumulator {
}; };
} }
interface OpenAiUsage {
promptTokens: number;
completionTokens: number;
reasoningTokens: number;
}
interface OpenAiChatIterationResult { interface OpenAiChatIterationResult {
response: string; response: string;
thinking?: string; thinking?: string;
@ -80,13 +86,7 @@ interface OpenAiChatIterationResult {
chunkCount: number; chunkCount: number;
contentDeltaCount: number; contentDeltaCount: number;
toolDeltaCount: number; toolDeltaCount: number;
// Usage data from OpenAI API (prompt_tokens, completion_tokens) usage?: OpenAiUsage;
usage?: {
promptTokens: number;
completionTokens: number;
};
// Raw usage object from OpenAI API response (for logging/observability)
rawUsage?: unknown;
} }
export class OpenAiApi extends AiApi { export class OpenAiApi extends AiApi {
@ -194,11 +194,6 @@ export class OpenAiApi extends AiApi {
options: IAiGenerateOptions, options: IAiGenerateOptions,
streamCallback?: IAiResponseStreamFn, streamCallback?: IAiResponseStreamFn,
): Promise<IAiGenerateResponse> { ): Promise<IAiGenerateResponse> {
await this.log.debug("OpenAiApi.generate called", {
provider: model.provider.name,
modelId: model.modelId,
});
if (options.signal?.aborted) { if (options.signal?.aborted) {
throw new DOMException("The operation was aborted", "AbortError"); throw new DOMException("The operation was aborted", "AbortError");
} }
@ -229,12 +224,9 @@ export class OpenAiApi extends AiApi {
: {}), : {}),
}, options.signal ? { signal: options.signal } : undefined); }, options.signal ? { signal: options.signal } : undefined);
this.log.debug("OpenAI API response", { response: JSON.parse(JSON.stringify(response)) });
let accumulatedResponse = ""; let accumulatedResponse = "";
let accumulatedThinking = ""; let accumulatedThinking = "";
let usage: { promptTokens: number; completionTokens: number } | undefined; let usage: OpenAiUsage | undefined;
let rawUsage: unknown;
for await (const chunk of response) { for await (const chunk of response) {
if (options.signal?.aborted) { if (options.signal?.aborted) {
@ -243,16 +235,7 @@ export class OpenAiApi extends AiApi {
// Capture usage from the final streaming chunk // Capture usage from the final streaming chunk
if (chunk.usage) { if (chunk.usage) {
usage = { usage = this.extractUsage(chunk.usage);
promptTokens: chunk.usage.prompt_tokens,
completionTokens: chunk.usage.completion_tokens,
};
rawUsage = chunk.usage;
// LOG: dump entire usage chunk from OpenAI generate streaming response
this.log.info("OpenAI generate: streaming chunk with usage", {
usage: JSON.parse(JSON.stringify(chunk.usage)),
chunk: JSON.parse(JSON.stringify(chunk)),
});
} }
const delta = chunk.choices[0]?.delta; const delta = chunk.choices[0]?.delta;
@ -281,14 +264,6 @@ export class OpenAiApi extends AiApi {
const endTime = Date.now(); const endTime = Date.now();
const durationMs = endTime - startTime; const durationMs = endTime - startTime;
// LOG: dump final usage and accumulated stats from generate()
this.log.info("OpenAI generate: complete", {
rawUsage: rawUsage ? JSON.parse(JSON.stringify(rawUsage)) : undefined,
responseLength: accumulatedResponse.length,
thinkingLength: accumulatedThinking.length,
durationMs,
});
return { return {
done: true, done: true,
response: accumulatedResponse, response: accumulatedResponse,
@ -301,7 +276,7 @@ export class OpenAiApi extends AiApi {
tokenCounts: { tokenCounts: {
input: usage?.promptTokens ?? 0, input: usage?.promptTokens ?? 0,
response: usage?.completionTokens ?? 0, response: usage?.completionTokens ?? 0,
thinking: 0, thinking: usage?.reasoningTokens ?? 0,
}, },
}, },
}; };
@ -312,11 +287,6 @@ export class OpenAiApi extends AiApi {
options: IAiChatOptions, options: IAiChatOptions,
streamCallback?: IAiResponseStreamFn, streamCallback?: IAiResponseStreamFn,
): Promise<IAiChatResponse> { ): Promise<IAiChatResponse> {
await this.log.debug("OpenAiApi.chat called", {
provider: model.provider.name,
modelId: model.modelId,
});
const startTime = Date.now(); const startTime = Date.now();
const messages = this.buildMessages(options); const messages = this.buildMessages(options);
const tools = this.buildTools(options); const tools = this.buildTools(options);
@ -329,38 +299,11 @@ export class OpenAiApi extends AiApi {
options.signal, options.signal,
); );
await this.log.debug("OpenAI chat stream iteration finished", {
chunkCount: iteration.chunkCount,
contentDeltaCount: iteration.contentDeltaCount,
toolDeltaCount: iteration.toolDeltaCount,
responseLength: iteration.response.length,
thinkingLength: iteration.thinking?.length || 0,
toolCallCount: iteration.toolCalls.length,
finishReason: iteration.finishReason,
});
// LOG: dump usage from streaming chat iteration
this.log.info("OpenAI chat: streaming iteration usage", {
rawUsage: iteration.rawUsage ? JSON.parse(JSON.stringify(iteration.rawUsage)) : undefined,
finishReason: iteration.finishReason,
});
if (this.isEmptyIteration(iteration)) { if (this.isEmptyIteration(iteration)) {
iteration = await this.readNonStreamingChatCompletion(model, messages, tools, options.signal); iteration = await this.readNonStreamingChatCompletion(model, messages, tools, options.signal);
if (streamCallback && iteration.response) { if (streamCallback && iteration.response) {
await streamCallback({ type: "response", data: iteration.response }); await streamCallback({ type: "response", data: iteration.response });
} }
await this.log.warn("OpenAI stream was empty; used non-streaming fallback", {
responseLength: iteration.response.length,
thinkingLength: iteration.thinking?.length || 0,
toolCallCount: iteration.toolCalls.length,
finishReason: iteration.finishReason,
});
// LOG: dump usage from non-streaming fallback
this.log.info("OpenAI chat: non-streaming fallback usage", {
rawUsage: iteration.rawUsage ? JSON.parse(JSON.stringify(iteration.rawUsage)) : undefined,
finishReason: iteration.finishReason,
});
} }
if (this.isEmptyIteration(iteration)) { if (this.isEmptyIteration(iteration)) {
@ -381,16 +324,18 @@ export class OpenAiApi extends AiApi {
toolCalls: iteration.toolCalls.length > 0 ? iteration.toolCalls : undefined, toolCalls: iteration.toolCalls.length > 0 ? iteration.toolCalls : undefined,
stats: this.buildStats(startTime, iteration.usage), stats: this.buildStats(startTime, iteration.usage),
}; };
// LOG: dump final chat response stats
this.log.info("OpenAI chat: final response", {
rawUsage: iteration.rawUsage ? JSON.parse(JSON.stringify(iteration.rawUsage)) : undefined,
stats: finalResponse.stats,
finishReason: iteration.finishReason,
});
this.assertNonEmptyChatResponse(finalResponse); this.assertNonEmptyChatResponse(finalResponse);
return finalResponse; return finalResponse;
} }
private extractUsage(usage: { prompt_tokens: number; completion_tokens: number; completion_tokens_details?: { reasoning_tokens?: number } }): OpenAiUsage {
return {
promptTokens: usage.prompt_tokens,
completionTokens: usage.completion_tokens,
reasoningTokens: usage.completion_tokens_details?.reasoning_tokens ?? 0,
};
}
private buildMessages(options: IAiChatOptions): ChatCompletionMessageParam[] { private buildMessages(options: IAiChatOptions): ChatCompletionMessageParam[] {
const messages: ChatCompletionMessageParam[] = []; const messages: ChatCompletionMessageParam[] = [];
if (options.systemPrompt) { if (options.systemPrompt) {
@ -468,8 +413,6 @@ export class OpenAiApi extends AiApi {
: {}), : {}),
}, signal ? { signal } : undefined); }, signal ? { signal } : undefined);
this.log.debug("OpenAI API response", { response: JSON.parse(JSON.stringify(response)) });
let content = ""; let content = "";
let thinking = ""; let thinking = "";
let chunkCount = 0; let chunkCount = 0;
@ -477,8 +420,7 @@ export class OpenAiApi extends AiApi {
let toolDeltaCount = 0; let toolDeltaCount = 0;
let finishReason: string | null | undefined; let finishReason: string | null | undefined;
const toolCallMap = new Map<number, StreamingToolCallAccumulator>(); const toolCallMap = new Map<number, StreamingToolCallAccumulator>();
let usage: { promptTokens: number; completionTokens: number } | undefined; let usage: OpenAiUsage | undefined;
let rawUsage: unknown;
for await (const chunk of response) { for await (const chunk of response) {
if (signal?.aborted) { if (signal?.aborted) {
@ -490,16 +432,7 @@ export class OpenAiApi extends AiApi {
// Capture usage from the final streaming chunk // Capture usage from the final streaming chunk
if (chunk.usage) { if (chunk.usage) {
usage = { usage = this.extractUsage(chunk.usage);
promptTokens: chunk.usage.prompt_tokens,
completionTokens: chunk.usage.completion_tokens,
};
rawUsage = chunk.usage;
// LOG: dump entire usage chunk from OpenAI chat streaming response
this.log.info("OpenAI chat stream: streaming chunk with usage", {
usage: JSON.parse(JSON.stringify(chunk.usage)),
chunk: JSON.parse(JSON.stringify(chunk)),
});
} }
const delta = chunk.choices[0]?.delta; const delta = chunk.choices[0]?.delta;
@ -526,18 +459,6 @@ export class OpenAiApi extends AiApi {
} }
} }
// LOG: dump final streaming chat completion iteration result
this.log.info("OpenAI chat stream: iteration complete", {
chunkCount,
contentDeltaCount,
toolDeltaCount,
finishReason,
rawUsage: rawUsage ? JSON.parse(JSON.stringify(rawUsage)) : undefined,
responseLength: content.length,
thinkingLength: thinking.length,
toolCallCount: toolCallMap.size,
});
return { return {
response: content, response: content,
thinking: thinking || undefined, thinking: thinking || undefined,
@ -547,7 +468,6 @@ export class OpenAiApi extends AiApi {
contentDeltaCount, contentDeltaCount,
toolDeltaCount, toolDeltaCount,
usage, usage,
rawUsage,
}; };
} }
@ -580,18 +500,11 @@ export class OpenAiApi extends AiApi {
} }
: {}), : {}),
}, signal ? { signal } : undefined); }, signal ? { signal } : undefined);
// LOG: dump entire non-streaming response from OpenAI
this.log.info("OpenAI chat non-streaming: response", {
response: JSON.parse(JSON.stringify(response)),
});
const choice = response.choices[0]; const choice = response.choices[0];
const message = choice?.message; const message = choice?.message;
const content = typeof message?.content === "string" ? message.content : ""; const content = typeof message?.content === "string" ? message.content : "";
const usage = response.usage ? { const usage = response.usage ? this.extractUsage(response.usage) : undefined;
promptTokens: response.usage.prompt_tokens,
completionTokens: response.usage.completion_tokens,
} : undefined;
const rawUsage = response.usage;
const assistantToolCalls = (message?.tool_calls || []) const assistantToolCalls = (message?.tool_calls || [])
.filter((tc) => tc.type === "function") .filter((tc) => tc.type === "function")
.map((tc) => ({ .map((tc) => ({
@ -619,7 +532,6 @@ export class OpenAiApi extends AiApi {
contentDeltaCount: content ? 1 : 0, contentDeltaCount: content ? 1 : 0,
toolDeltaCount: assistantToolCalls.length, toolDeltaCount: assistantToolCalls.length,
usage, usage,
rawUsage,
}; };
} }
@ -690,7 +602,7 @@ export class OpenAiApi extends AiApi {
private buildStats( private buildStats(
startTime: number, startTime: number,
usage?: { promptTokens: number; completionTokens: number }, usage?: OpenAiUsage,
): IAiChatResponse["stats"] { ): IAiChatResponse["stats"] {
const seconds = (Date.now() - startTime) / 1000; const seconds = (Date.now() - startTime) / 1000;
return { return {
@ -701,7 +613,7 @@ export class OpenAiApi extends AiApi {
tokenCounts: { tokenCounts: {
input: usage?.promptTokens ?? 0, input: usage?.promptTokens ?? 0,
response: usage?.completionTokens ?? 0, response: usage?.completionTokens ?? 0,
thinking: 0, thinking: usage?.reasoningTokens ?? 0,
}, },
}; };
} }