66 "paperdebugger/internal/models"
77 "paperdebugger/internal/services/toolkit/handler"
88 chatv2 "paperdebugger/pkg/gen/api/chat/v2"
9+ "time"
910
1011 "github.com/openai/openai-go/v3"
1112)
@@ -70,18 +71,26 @@ func (a *AIClientV2) ChatCompletionStreamV2(ctx context.Context, callbackStream
7071 for {
7172 params .Messages = openaiChatHistory
7273 // var openaiOutput OpenAIChatHistory
74+ a .logger .Info ("[Stream Debug] Starting new streaming request" , "model" , modelSlug )
75+ streamStartTime := time .Now ()
7376 stream := oaiClient .Chat .Completions .NewStreaming (context .Background (), params )
7477
7578 reasoning_content := ""
7679 answer_content := ""
7780 answer_content_id := ""
7881 has_sent_part_begin := false
82+ firstChunkReceived := false
7983 tool_info := map [int ]map [string ]string {}
8084 toolCalls := []openai.FinishedChatCompletionToolCall {}
8185 for stream .Next () {
8286 // time.Sleep(5000 * time.Millisecond) // DEBUG POINT: change this to test in a slow mode
8387 chunk := stream .Current ()
8488
89+ if ! firstChunkReceived {
90+ firstChunkReceived = true
91+ a .logger .Info ("[Stream Debug] First chunk received" , "elapsed_ms" , time .Since (streamStartTime ).Milliseconds ())
92+ }
93+
8594 if len (chunk .Choices ) == 0 {
8695 // Handle usage information
8796 // fmt.Printf("Usage: %+v\n", chunk.Usage)
@@ -99,25 +108,35 @@ func (a *AIClientV2) ChatCompletionStreamV2(ctx context.Context, callbackStream
99108 _ , hasReasoning := delta .JSON .ExtraFields ["reasoning" ]
100109 if ! has_sent_part_begin && (delta .Role == "assistant" || delta .Content != "" || hasReasoningContent || hasReasoning ) {
101110 has_sent_part_begin = true
111+ a .logger .Info ("[Stream Debug] Sending StreamPartBegin" , "elapsed_ms" , time .Since (streamStartTime ).Milliseconds (), "role" , delta .Role , "hasReasoningContent" , hasReasoningContent , "hasReasoning" , hasReasoning )
102112 streamHandler .HandleAssistantPartBegin (chunk .ID )
103113 }
104114
105115 if field , ok := delta .JSON .ExtraFields ["reasoning_content" ]; ok && field .Raw () != "null" {
106116 var s string
107117 err := json .Unmarshal ([]byte (field .Raw ()), & s )
108118 if err == nil {
119+ if reasoning_content == "" {
120+ a .logger .Info ("[Stream Debug] First reasoning chunk" , "elapsed_ms" , time .Since (streamStartTime ).Milliseconds (), "length" , len (s ))
121+ }
109122 reasoning_content += s
110123 streamHandler .HandleReasoningDelta (chunk .ID , s )
111124 }
112125 } else if field , ok := delta .JSON .ExtraFields ["reasoning" ]; ok && field .Raw () != "null" {
113126 var s string
114127 err := json .Unmarshal ([]byte (field .Raw ()), & s )
115128 if err == nil {
129+ if reasoning_content == "" {
130+ a .logger .Info ("[Stream Debug] First reasoning chunk" , "elapsed_ms" , time .Since (streamStartTime ).Milliseconds (), "length" , len (s ))
131+ }
116132 reasoning_content += s
117133 streamHandler .HandleReasoningDelta (chunk .ID , s )
118134 }
119135 } else {
120136 if delta .Content != "" {
137+ if answer_content == "" {
138+ a .logger .Info ("[Stream Debug] First content chunk" , "elapsed_ms" , time .Since (streamStartTime ).Milliseconds (), "length" , len (delta .Content ))
139+ }
121140 answer_content += delta .Content
122141 answer_content_id = chunk .ID
123142 streamHandler .HandleTextDelta (chunk )
0 commit comments