From 51b301365923468b6684e46b790cf3a5c8889fff Mon Sep 17 00:00:00 2001
From: Rob Colbert <rob@digitaltelepresence.com>
Date: Mon, 18 May 2026 15:20:53 -0400
Subject: [PATCH] feat(ai): add DtpLog logging of all OpenAI API responses

- Fix broken chunkCount reference in generate() usage chunk log
- Add generate() complete log with usage, response/thinking lengths
- Add readStreamingChatCompletion() usage chunk log (full chunk dump)
- Add readStreamingChatCompletion() iteration complete log
- Add readNonStreamingChatCompletion() full response dump
- Add chat() streaming iteration usage log
- Add chat() non-streaming fallback usage log
- Add chat() final response stats log

All logs use info level and 'OpenAI {method}: {event}' naming for
easy grep/filtering. Streaming chunks use JSON.parse(JSON.stringify())
to serialize the full OpenAI SDK response objects.
---
 packages/ai/src/openai.ts | 51 +++++++++++++++++++++++++++++++++++++++
 1 file changed, 51 insertions(+)

diff --git a/packages/ai/src/openai.ts b/packages/ai/src/openai.ts
index 1719ea3..d8034f5 100644
--- a/packages/ai/src/openai.ts
+++ b/packages/ai/src/openai.ts
@@ -242,6 +242,11 @@ export class OpenAiApi extends AiApi {
           promptTokens: chunk.usage.prompt_tokens,
           completionTokens: chunk.usage.completion_tokens,
         };
+        // 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;
@@ -270,6 +275,14 @@ export class OpenAiApi extends AiApi {
     const endTime = Date.now();
     const durationMs = endTime - startTime;
 
+    // LOG: dump final usage and accumulated stats from generate()
+    this.log.info("OpenAI generate: complete", {
+      usage,
+      responseLength: accumulatedResponse.length,
+      thinkingLength: accumulatedThinking.length,
+      durationMs,
+    });
+
     return {
       done: true,
       response: accumulatedResponse,
@@ -320,6 +333,12 @@ export class OpenAiApi extends AiApi {
       finishReason: iteration.finishReason,
     });
 
+    // LOG: dump usage from streaming chat iteration
+    this.log.info("OpenAI chat: streaming iteration usage", {
+      usage: iteration.usage,
+      finishReason: iteration.finishReason,
+    });
+
     if (this.isEmptyIteration(iteration)) {
       iteration = await this.readNonStreamingChatCompletion(model, messages, tools, options.signal);
       if (streamCallback && iteration.response) {
@@ -331,6 +350,11 @@ export class OpenAiApi extends AiApi {
         toolCallCount: iteration.toolCalls.length,
         finishReason: iteration.finishReason,
       });
+      // LOG: dump usage from non-streaming fallback
+      this.log.info("OpenAI chat: non-streaming fallback usage", {
+        usage: iteration.usage,
+        finishReason: iteration.finishReason,
+      });
     }
 
     if (this.isEmptyIteration(iteration)) {
@@ -351,6 +375,12 @@ export class OpenAiApi extends AiApi {
       toolCalls: iteration.toolCalls.length > 0 ? iteration.toolCalls : undefined,
       stats: this.buildStats(startTime, iteration.usage),
     };
+    // LOG: dump final chat response stats
+    this.log.info("OpenAI chat: final response", {
+      usage: iteration.usage,
+      stats: finalResponse.stats,
+      finishReason: iteration.finishReason,
+    });
     this.assertNonEmptyChatResponse(finalResponse);
     return finalResponse;
   }
@@ -455,6 +485,11 @@ export class OpenAiApi extends AiApi {
           promptTokens: chunk.usage.prompt_tokens,
           completionTokens: chunk.usage.completion_tokens,
         };
+        // 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;
@@ -481,6 +516,18 @@ 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,
+      usage,
+      responseLength: content.length,
+      thinkingLength: thinking.length,
+      toolCallCount: toolCallMap.size,
+    });
+
     return {
       response: content,
       thinking: thinking || undefined,
@@ -522,6 +569,10 @@ export class OpenAiApi extends AiApi {
           }
         : {}),
     }, 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 message = choice?.message;
     const content = typeof message?.content === "string" ? message.content : "";