Skip to content

Commit 3dd0844

Browse files
committed
Enhance logging for API requests and responses across executors
- Added detailed logging of upstream request metadata including URL, method, headers, and body for Codex, Gemini, IFlow, OpenAI Compat, and Qwen executors. - Implemented error logging for API response failures to capture errors during HTTP requests. - Introduced structured logging for authentication details (AuthID, AuthLabel, AuthType, AuthValue) to improve traceability. - Updated response logging to include status codes and headers for better debugging. - Ensured that all executors consistently log API interactions to facilitate monitoring and troubleshooting.
1 parent 4477c72 commit 3dd0844

File tree

9 files changed

+698
-46
lines changed

9 files changed

+698
-46
lines changed

internal/logging/request_logger.go

Lines changed: 26 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -328,9 +328,19 @@ func (l *FileRequestLogger) formatLogContent(url, method string, headers map[str
328328
// Request info
329329
content.WriteString(l.formatRequestInfo(url, method, headers, body))
330330

331-
content.WriteString("=== API REQUEST ===\n")
332-
content.Write(apiRequest)
333-
content.WriteString("\n\n")
331+
if len(apiRequest) > 0 {
332+
if bytes.HasPrefix(apiRequest, []byte("=== API REQUEST")) {
333+
content.Write(apiRequest)
334+
if !bytes.HasSuffix(apiRequest, []byte("\n")) {
335+
content.WriteString("\n")
336+
}
337+
} else {
338+
content.WriteString("=== API REQUEST ===\n")
339+
content.Write(apiRequest)
340+
content.WriteString("\n")
341+
}
342+
content.WriteString("\n")
343+
}
334344

335345
for i := 0; i < len(apiResponseErrors); i++ {
336346
content.WriteString("=== API ERROR RESPONSE ===\n")
@@ -339,9 +349,19 @@ func (l *FileRequestLogger) formatLogContent(url, method string, headers map[str
339349
content.WriteString("\n\n")
340350
}
341351

342-
content.WriteString("=== API RESPONSE ===\n")
343-
content.Write(apiResponse)
344-
content.WriteString("\n\n")
352+
if len(apiResponse) > 0 {
353+
if bytes.HasPrefix(apiResponse, []byte("=== API RESPONSE")) {
354+
content.Write(apiResponse)
355+
if !bytes.HasSuffix(apiResponse, []byte("\n")) {
356+
content.WriteString("\n")
357+
}
358+
} else {
359+
content.WriteString("=== API RESPONSE ===\n")
360+
content.Write(apiResponse)
361+
content.WriteString("\n")
362+
}
363+
content.WriteString("\n")
364+
}
345365

346366
// Response section
347367
content.WriteString("=== RESPONSE ===\n")

internal/runtime/executor/claude_executor.go

Lines changed: 63 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -54,23 +54,41 @@ func (e *ClaudeExecutor) Execute(ctx context.Context, auth *cliproxyauth.Auth, r
5454
}
5555

5656
url := fmt.Sprintf("%s/v1/messages?beta=true", baseURL)
57-
recordAPIRequest(ctx, e.cfg, body)
5857
httpReq, err := http.NewRequestWithContext(ctx, http.MethodPost, url, bytes.NewReader(body))
5958
if err != nil {
6059
return cliproxyexecutor.Response{}, err
6160
}
6261
applyClaudeHeaders(httpReq, apiKey, false)
62+
var authID, authLabel, authType, authValue string
63+
if auth != nil {
64+
authID = auth.ID
65+
authLabel = auth.Label
66+
authType, authValue = auth.AccountInfo()
67+
}
68+
recordAPIRequest(ctx, e.cfg, upstreamRequestLog{
69+
URL: url,
70+
Method: http.MethodPost,
71+
Headers: httpReq.Header.Clone(),
72+
Body: body,
73+
Provider: e.Identifier(),
74+
AuthID: authID,
75+
AuthLabel: authLabel,
76+
AuthType: authType,
77+
AuthValue: authValue,
78+
})
6379

6480
httpClient := newProxyAwareHTTPClient(ctx, e.cfg, auth, 0)
6581
resp, err := httpClient.Do(httpReq)
6682
if err != nil {
83+
recordAPIResponseError(ctx, e.cfg, err)
6784
return cliproxyexecutor.Response{}, err
6885
}
6986
defer func() {
7087
if errClose := resp.Body.Close(); errClose != nil {
7188
log.Errorf("response body close error: %v", errClose)
7289
}
7390
}()
91+
recordAPIResponseMetadata(ctx, e.cfg, resp.StatusCode, resp.Header.Clone())
7492
if resp.StatusCode < 200 || resp.StatusCode >= 300 {
7593
b, _ := io.ReadAll(resp.Body)
7694
appendAPIResponseChunk(ctx, e.cfg, b)
@@ -82,13 +100,15 @@ func (e *ClaudeExecutor) Execute(ctx context.Context, auth *cliproxyauth.Auth, r
82100
if hasZSTDEcoding(resp.Header.Get("Content-Encoding")) {
83101
decoder, err = zstd.NewReader(resp.Body)
84102
if err != nil {
103+
recordAPIResponseError(ctx, e.cfg, err)
85104
return cliproxyexecutor.Response{}, fmt.Errorf("failed to initialize zstd decoder: %w", err)
86105
}
87106
reader = decoder
88107
defer decoder.Close()
89108
}
90109
data, err := io.ReadAll(reader)
91110
if err != nil {
111+
recordAPIResponseError(ctx, e.cfg, err)
92112
return cliproxyexecutor.Response{}, err
93113
}
94114
appendAPIResponseChunk(ctx, e.cfg, data)
@@ -120,18 +140,36 @@ func (e *ClaudeExecutor) ExecuteStream(ctx context.Context, auth *cliproxyauth.A
120140
body, _ = sjson.SetRawBytes(body, "system", []byte(misc.ClaudeCodeInstructions))
121141

122142
url := fmt.Sprintf("%s/v1/messages?beta=true", baseURL)
123-
recordAPIRequest(ctx, e.cfg, body)
124143
httpReq, err := http.NewRequestWithContext(ctx, http.MethodPost, url, bytes.NewReader(body))
125144
if err != nil {
126145
return nil, err
127146
}
128147
applyClaudeHeaders(httpReq, apiKey, true)
148+
var authID, authLabel, authType, authValue string
149+
if auth != nil {
150+
authID = auth.ID
151+
authLabel = auth.Label
152+
authType, authValue = auth.AccountInfo()
153+
}
154+
recordAPIRequest(ctx, e.cfg, upstreamRequestLog{
155+
URL: url,
156+
Method: http.MethodPost,
157+
Headers: httpReq.Header.Clone(),
158+
Body: body,
159+
Provider: e.Identifier(),
160+
AuthID: authID,
161+
AuthLabel: authLabel,
162+
AuthType: authType,
163+
AuthValue: authValue,
164+
})
129165

130166
httpClient := newProxyAwareHTTPClient(ctx, e.cfg, auth, 0)
131167
resp, err := httpClient.Do(httpReq)
132168
if err != nil {
169+
recordAPIResponseError(ctx, e.cfg, err)
133170
return nil, err
134171
}
172+
recordAPIResponseMetadata(ctx, e.cfg, resp.StatusCode, resp.Header.Clone())
135173
if resp.StatusCode < 200 || resp.StatusCode >= 300 {
136174
defer func() { _ = resp.Body.Close() }()
137175
b, _ := io.ReadAll(resp.Body)
@@ -162,6 +200,7 @@ func (e *ClaudeExecutor) ExecuteStream(ctx context.Context, auth *cliproxyauth.A
162200
out <- cliproxyexecutor.StreamChunk{Payload: cloned}
163201
}
164202
if err = scanner.Err(); err != nil {
203+
recordAPIResponseError(ctx, e.cfg, err)
165204
out <- cliproxyexecutor.StreamChunk{Err: err}
166205
}
167206
return
@@ -184,6 +223,7 @@ func (e *ClaudeExecutor) ExecuteStream(ctx context.Context, auth *cliproxyauth.A
184223
}
185224
}
186225
if err = scanner.Err(); err != nil {
226+
recordAPIResponseError(ctx, e.cfg, err)
187227
out <- cliproxyexecutor.StreamChunk{Err: err}
188228
}
189229
}()
@@ -208,23 +248,41 @@ func (e *ClaudeExecutor) CountTokens(ctx context.Context, auth *cliproxyauth.Aut
208248
}
209249

210250
url := fmt.Sprintf("%s/v1/messages/count_tokens?beta=true", baseURL)
211-
recordAPIRequest(ctx, e.cfg, body)
212251
httpReq, err := http.NewRequestWithContext(ctx, http.MethodPost, url, bytes.NewReader(body))
213252
if err != nil {
214253
return cliproxyexecutor.Response{}, err
215254
}
216255
applyClaudeHeaders(httpReq, apiKey, false)
256+
var authID, authLabel, authType, authValue string
257+
if auth != nil {
258+
authID = auth.ID
259+
authLabel = auth.Label
260+
authType, authValue = auth.AccountInfo()
261+
}
262+
recordAPIRequest(ctx, e.cfg, upstreamRequestLog{
263+
URL: url,
264+
Method: http.MethodPost,
265+
Headers: httpReq.Header.Clone(),
266+
Body: body,
267+
Provider: e.Identifier(),
268+
AuthID: authID,
269+
AuthLabel: authLabel,
270+
AuthType: authType,
271+
AuthValue: authValue,
272+
})
217273

218274
httpClient := newProxyAwareHTTPClient(ctx, e.cfg, auth, 0)
219275
resp, err := httpClient.Do(httpReq)
220276
if err != nil {
277+
recordAPIResponseError(ctx, e.cfg, err)
221278
return cliproxyexecutor.Response{}, err
222279
}
223280
defer func() {
224281
if errClose := resp.Body.Close(); errClose != nil {
225282
log.Errorf("response body close error: %v", errClose)
226283
}
227284
}()
285+
recordAPIResponseMetadata(ctx, e.cfg, resp.StatusCode, resp.Header.Clone())
228286
if resp.StatusCode < 200 || resp.StatusCode >= 300 {
229287
b, _ := io.ReadAll(resp.Body)
230288
appendAPIResponseChunk(ctx, e.cfg, b)
@@ -235,13 +293,15 @@ func (e *ClaudeExecutor) CountTokens(ctx context.Context, auth *cliproxyauth.Aut
235293
if hasZSTDEcoding(resp.Header.Get("Content-Encoding")) {
236294
decoder, err = zstd.NewReader(resp.Body)
237295
if err != nil {
296+
recordAPIResponseError(ctx, e.cfg, err)
238297
return cliproxyexecutor.Response{}, fmt.Errorf("failed to initialize zstd decoder: %w", err)
239298
}
240299
reader = decoder
241300
defer decoder.Close()
242301
}
243302
data, err := io.ReadAll(reader)
244303
if err != nil {
304+
recordAPIResponseError(ctx, e.cfg, err)
245305
return cliproxyexecutor.Response{}, err
246306
}
247307
appendAPIResponseChunk(ctx, e.cfg, data)

internal/runtime/executor/codex_executor.go

Lines changed: 45 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -79,19 +79,37 @@ func (e *CodexExecutor) Execute(ctx context.Context, auth *cliproxyauth.Auth, re
7979
body, _ = sjson.DeleteBytes(body, "previous_response_id")
8080

8181
url := strings.TrimSuffix(baseURL, "/") + "/responses"
82-
recordAPIRequest(ctx, e.cfg, body)
8382
httpReq, err := http.NewRequestWithContext(ctx, http.MethodPost, url, bytes.NewReader(body))
8483
if err != nil {
8584
return cliproxyexecutor.Response{}, err
8685
}
8786
applyCodexHeaders(httpReq, auth, apiKey)
87+
var authID, authLabel, authType, authValue string
88+
if auth != nil {
89+
authID = auth.ID
90+
authLabel = auth.Label
91+
authType, authValue = auth.AccountInfo()
92+
}
93+
recordAPIRequest(ctx, e.cfg, upstreamRequestLog{
94+
URL: url,
95+
Method: http.MethodPost,
96+
Headers: httpReq.Header.Clone(),
97+
Body: body,
98+
Provider: e.Identifier(),
99+
AuthID: authID,
100+
AuthLabel: authLabel,
101+
AuthType: authType,
102+
AuthValue: authValue,
103+
})
88104

89105
httpClient := newProxyAwareHTTPClient(ctx, e.cfg, auth, 0)
90106
resp, err := httpClient.Do(httpReq)
91107
if err != nil {
108+
recordAPIResponseError(ctx, e.cfg, err)
92109
return cliproxyexecutor.Response{}, err
93110
}
94111
defer func() { _ = resp.Body.Close() }()
112+
recordAPIResponseMetadata(ctx, e.cfg, resp.StatusCode, resp.Header.Clone())
95113
if resp.StatusCode < 200 || resp.StatusCode >= 300 {
96114
b, _ := io.ReadAll(resp.Body)
97115
appendAPIResponseChunk(ctx, e.cfg, b)
@@ -100,6 +118,7 @@ func (e *CodexExecutor) Execute(ctx context.Context, auth *cliproxyauth.Auth, re
100118
}
101119
data, err := io.ReadAll(resp.Body)
102120
if err != nil {
121+
recordAPIResponseError(ctx, e.cfg, err)
103122
return cliproxyexecutor.Response{}, err
104123
}
105124
appendAPIResponseChunk(ctx, e.cfg, data)
@@ -165,21 +184,43 @@ func (e *CodexExecutor) ExecuteStream(ctx context.Context, auth *cliproxyauth.Au
165184
body, _ = sjson.DeleteBytes(body, "previous_response_id")
166185

167186
url := strings.TrimSuffix(baseURL, "/") + "/responses"
168-
recordAPIRequest(ctx, e.cfg, body)
169187
httpReq, err := http.NewRequestWithContext(ctx, http.MethodPost, url, bytes.NewReader(body))
170188
if err != nil {
171189
return nil, err
172190
}
173191
applyCodexHeaders(httpReq, auth, apiKey)
192+
var authID, authLabel, authType, authValue string
193+
if auth != nil {
194+
authID = auth.ID
195+
authLabel = auth.Label
196+
authType, authValue = auth.AccountInfo()
197+
}
198+
recordAPIRequest(ctx, e.cfg, upstreamRequestLog{
199+
URL: url,
200+
Method: http.MethodPost,
201+
Headers: httpReq.Header.Clone(),
202+
Body: body,
203+
Provider: e.Identifier(),
204+
AuthID: authID,
205+
AuthLabel: authLabel,
206+
AuthType: authType,
207+
AuthValue: authValue,
208+
})
174209

175210
httpClient := newProxyAwareHTTPClient(ctx, e.cfg, auth, 0)
176211
resp, err := httpClient.Do(httpReq)
177212
if err != nil {
213+
recordAPIResponseError(ctx, e.cfg, err)
178214
return nil, err
179215
}
216+
recordAPIResponseMetadata(ctx, e.cfg, resp.StatusCode, resp.Header.Clone())
180217
if resp.StatusCode < 200 || resp.StatusCode >= 300 {
181218
defer func() { _ = resp.Body.Close() }()
182-
b, _ := io.ReadAll(resp.Body)
219+
b, readErr := io.ReadAll(resp.Body)
220+
if readErr != nil {
221+
recordAPIResponseError(ctx, e.cfg, readErr)
222+
return nil, readErr
223+
}
183224
appendAPIResponseChunk(ctx, e.cfg, b)
184225
log.Debugf("request error, error status: %d, error body: %s", resp.StatusCode, string(b))
185226
return nil, statusErr{code: resp.StatusCode, msg: string(b)}
@@ -211,6 +252,7 @@ func (e *CodexExecutor) ExecuteStream(ctx context.Context, auth *cliproxyauth.Au
211252
}
212253
}
213254
if err = scanner.Err(); err != nil {
255+
recordAPIResponseError(ctx, e.cfg, err)
214256
out <- cliproxyexecutor.StreamChunk{Err: err}
215257
}
216258
}()

0 commit comments

Comments
 (0)