diff --git a/internal/ai/provider/anthropic.go b/internal/ai/provider/anthropic.go index 8f3c03d..1a7b238 100644 --- a/internal/ai/provider/anthropic.go +++ b/internal/ai/provider/anthropic.go @@ -469,9 +469,11 @@ func (p *AnthropicProvider) doRequest(ctx context.Context, body interface{}) (io } url := normalizeAnthropicMessagesURL(p.baseURL) + requestLog := logAIUpstreamRequestStart(p.Name(), http.MethodPost, url, body) httpReq, err := http.NewRequestWithContext(ctx, http.MethodPost, url, bytes.NewReader(jsonBody)) if err != nil { + logAIUpstreamRequestFinish(requestLog, 0, err) return nil, fmt.Errorf("创建 HTTP 请求失败: %w", err) } @@ -497,15 +499,19 @@ func (p *AnthropicProvider) doRequest(ctx context.Context, body interface{}) (io resp, err := p.client.Do(httpReq) if err != nil { + logAIUpstreamRequestFinish(requestLog, 0, err) return nil, fmt.Errorf("发送请求到 %s 失败: %w", url, err) } if resp.StatusCode != http.StatusOK { defer resp.Body.Close() bodyBytes, _ := io.ReadAll(resp.Body) - return nil, fmt.Errorf("Anthropic API 返回错误 (HTTP %d): %s", resp.StatusCode, string(bodyBytes)) + statusErr := fmt.Errorf("Anthropic API 返回错误 (HTTP %d): %s", resp.StatusCode, string(bodyBytes)) + logAIUpstreamRequestFinish(requestLog, resp.StatusCode, statusErr) + return nil, statusErr } + logAIUpstreamRequestFinish(requestLog, resp.StatusCode, nil) return resp.Body, nil } diff --git a/internal/ai/provider/gemini.go b/internal/ai/provider/gemini.go index ebadde9..4330bbf 100644 --- a/internal/ai/provider/gemini.go +++ b/internal/ai/provider/gemini.go @@ -71,9 +71,9 @@ func (p *GeminiProvider) Validate() error { } type geminiRequest struct { - Contents []geminiContent `json:"contents"` + Contents []geminiContent `json:"contents"` SystemInstruction *geminiContent `json:"systemInstruction,omitempty"` - GenerationConfig geminiGenConfig `json:"generationConfig,omitempty"` + GenerationConfig geminiGenConfig `json:"generationConfig,omitempty"` } type geminiContent struct { @@ -255,7 +255,7 @@ func (p *GeminiProvider) buildRequest(req ai.ChatRequest) geminiRequest { Contents: contents, SystemInstruction: systemInstruction, GenerationConfig: geminiGenConfig{ - Temperature: temperature, + Temperature: temperature, }, } } @@ -266,8 +266,10 @@ func (p *GeminiProvider) doRequest(ctx context.Context, url string, body interfa return nil, fmt.Errorf("序列化请求失败: %w", err) } + requestLog := logAIUpstreamRequestStart(p.Name(), http.MethodPost, url, body) httpReq, err := http.NewRequestWithContext(ctx, http.MethodPost, url, bytes.NewReader(jsonBody)) if err != nil { + logAIUpstreamRequestFinish(requestLog, 0, err) return nil, fmt.Errorf("创建 HTTP 请求失败: %w", err) } httpReq.Header.Set("Content-Type", "application/json") @@ -280,14 +282,18 @@ func (p *GeminiProvider) doRequest(ctx context.Context, url string, body interfa resp, err := p.client.Do(httpReq) if err != nil { + logAIUpstreamRequestFinish(requestLog, 0, err) return nil, fmt.Errorf("发送请求到 Gemini 失败: %w", err) } if resp.StatusCode != http.StatusOK { defer resp.Body.Close() bodyBytes, _ := io.ReadAll(resp.Body) - return nil, fmt.Errorf("Gemini API 返回错误 (HTTP %d): %s", resp.StatusCode, string(bodyBytes)) + statusErr := fmt.Errorf("Gemini API 返回错误 (HTTP %d): %s", resp.StatusCode, string(bodyBytes)) + logAIUpstreamRequestFinish(requestLog, resp.StatusCode, statusErr) + return nil, statusErr } + logAIUpstreamRequestFinish(requestLog, resp.StatusCode, nil) return resp.Body, nil } diff --git a/internal/ai/provider/openai.go b/internal/ai/provider/openai.go index 83a82c5..9fcf912 100644 --- a/internal/ai/provider/openai.go +++ b/internal/ai/provider/openai.go @@ -402,8 +402,10 @@ func (p *OpenAIProvider) doRequest(ctx context.Context, body interface{}) (io.Re } url := ResolveOpenAICompatibleEndpoint(p.baseURL, "chat/completions") + requestLog := logAIUpstreamRequestStart(p.Name(), http.MethodPost, url, body) httpReq, err := http.NewRequestWithContext(ctx, http.MethodPost, url, bytes.NewReader(jsonBody)) if err != nil { + logAIUpstreamRequestFinish(requestLog, 0, err) return nil, fmt.Errorf("创建 HTTP 请求失败: %w", err) } @@ -424,15 +426,19 @@ func (p *OpenAIProvider) doRequest(ctx context.Context, body interface{}) (io.Re resp, err := p.client.Do(httpReq) if err != nil { + logAIUpstreamRequestFinish(requestLog, 0, err) return nil, fmt.Errorf("发送请求到 %s 失败: %w", url, err) } if resp.StatusCode != http.StatusOK { defer resp.Body.Close() bodyBytes, _ := io.ReadAll(resp.Body) - return nil, fmt.Errorf("OpenAI API 返回错误 (HTTP %d): %s", resp.StatusCode, string(bodyBytes)) + statusErr := fmt.Errorf("OpenAI API 返回错误 (HTTP %d): %s", resp.StatusCode, string(bodyBytes)) + logAIUpstreamRequestFinish(requestLog, resp.StatusCode, statusErr) + return nil, statusErr } + logAIUpstreamRequestFinish(requestLog, resp.StatusCode, nil) return resp.Body, nil } diff --git a/internal/ai/provider/request_log.go b/internal/ai/provider/request_log.go new file mode 100644 index 0000000..2a6de9b --- /dev/null +++ b/internal/ai/provider/request_log.go @@ -0,0 +1,217 @@ +package provider + +import ( + "encoding/json" + "fmt" + "net/url" + "regexp" + "sort" + "strings" + "time" + + "GoNavi-Wails/internal/logger" +) + +const ( + aiUpstreamStringPreviewLimit = 4096 + aiUpstreamBodyPreviewLimit = 24000 +) + +var ( + secretLikeValuePatterns = []*regexp.Regexp{ + regexp.MustCompile(`(?i)bearer\s+[a-z0-9._~+/=-]{8,}`), + regexp.MustCompile(`(?i)\bsk-[a-z0-9._-]{8,}`), + regexp.MustCompile(`(?i)\bgh[pousr]_[a-z0-9_]{8,}`), + regexp.MustCompile(`(?i)\b(xox[baprs]-[a-z0-9-]{8,})`), + } + dataURIValuePattern = regexp.MustCompile(`^data:([^;,]+);base64,`) +) + +type aiUpstreamRequestLogHandle struct { + id string + provider string + started time.Time + endpoint string +} + +func newAIUpstreamRequestLogID(providerName string) string { + normalized := strings.ToLower(strings.TrimSpace(providerName)) + normalized = regexp.MustCompile(`[^a-z0-9]+`).ReplaceAllString(normalized, "-") + normalized = strings.Trim(normalized, "-") + if normalized == "" { + normalized = "provider" + } + return fmt.Sprintf("%s-%d", normalized, time.Now().UnixNano()) +} + +func logAIUpstreamRequestStart(providerName string, method string, endpoint string, body any) aiUpstreamRequestLogHandle { + handle := aiUpstreamRequestLogHandle{ + id: newAIUpstreamRequestLogID(providerName), + provider: strings.TrimSpace(providerName), + started: time.Now(), + endpoint: sanitizeAIUpstreamURL(endpoint), + } + logger.Infof( + "AI 上游请求开始：requestId=%s provider=%s method=%s endpoint=%s body=%s", + handle.id, + handle.provider, + strings.TrimSpace(method), + handle.endpoint, + formatAIUpstreamRequestLogBody(body), + ) + return handle +} + +func logAIUpstreamRequestFinish(handle aiUpstreamRequestLogHandle, statusCode int, err error) { + duration := time.Since(handle.started).Round(time.Millisecond) + if err != nil { + logger.Warnf( + "AI 上游请求失败：requestId=%s provider=%s endpoint=%s duration=%s err=%v", + handle.id, + handle.provider, + handle.endpoint, + duration, + RedactAIUpstreamLogText(err.Error()), + ) + return + } + logger.Infof( + "AI 上游请求完成：requestId=%s provider=%s endpoint=%s status=%d duration=%s", + handle.id, + handle.provider, + handle.endpoint, + statusCode, + duration, + ) +} + +func formatAIUpstreamRequestLogBody(body any) string { + sanitized := sanitizeAIUpstreamLogValue(body) + bytes, err := json.Marshal(sanitized) + if err != nil { + return fmt.Sprintf(`{"marshalError":%q}`, err.Error()) + } + text := string(bytes) + if len(text) <= aiUpstreamBodyPreviewLimit { + return text + } + return fmt.Sprintf("%s...[truncated %d chars]", text[:aiUpstreamBodyPreviewLimit], len(text)-aiUpstreamBodyPreviewLimit) +} + +func RedactAIUpstreamLogText(value string) string { + return sanitizeAIUpstreamString(value) +} + +func sanitizeAIUpstreamURL(rawURL string) string { + text := strings.TrimSpace(rawURL) + if text == "" { + return "" + } + parsed, err := url.Parse(text) + if err != nil { + return redactSecretLikeString(text) + } + query := parsed.Query() + for key := range query { + if isSensitiveFieldName(key) { + query.Set(key, "[REDACTED]") + } + } + parsed.RawQuery = query.Encode() + return redactSecretLikeString(parsed.String()) +} + +func sanitizeAIUpstreamLogValue(value any) any { + switch typed := value.(type) { + case nil: + return nil + case bool, float32, float64, + int, int8, int16, int32, int64, + uint, uint8, uint16, uint32, uint64: + return typed + case json.Number: + return typed + case json.RawMessage: + var decoded any + if err := json.Unmarshal(typed, &decoded); err == nil { + return sanitizeAIUpstreamLogValue(decoded) + } + return sanitizeAIUpstreamString(string(typed)) + case []byte: + return sanitizeAIUpstreamString(string(typed)) + case string: + return sanitizeAIUpstreamString(typed) + case map[string]any: + return sanitizeAIUpstreamMap(typed) + case []any: + result := make([]any, 0, len(typed)) + for _, item := range typed { + result = append(result, sanitizeAIUpstreamLogValue(item)) + } + return result + } + + bytes, err := json.Marshal(value) + if err != nil { + return sanitizeAIUpstreamString(fmt.Sprint(value)) + } + var decoded any + if err := json.Unmarshal(bytes, &decoded); err != nil { + return sanitizeAIUpstreamString(string(bytes)) + } + return sanitizeAIUpstreamLogValue(decoded) +} + +func sanitizeAIUpstreamMap(input map[string]any) map[string]any { + result := make(map[string]any, len(input)) + keys := make([]string, 0, len(input)) + for key := range input { + keys = append(keys, key) + } + sort.Strings(keys) + for _, key := range keys { + if isSensitiveFieldName(key) { + result[key] = "[REDACTED]" + continue + } + result[key] = sanitizeAIUpstreamLogValue(input[key]) + } + return result +} + +func isSensitiveFieldName(key string) bool { + normalized := strings.ToLower(strings.TrimSpace(key)) + normalized = strings.NewReplacer("-", "", "_", "", ".", "").Replace(normalized) + if normalized == "" { + return false + } + if normalized == "key" || normalized == "apikey" || normalized == "xapikey" { + return true + } + return strings.Contains(normalized, "authorization") || + strings.Contains(normalized, "token") || + strings.Contains(normalized, "secret") || + strings.Contains(normalized, "password") || + strings.Contains(normalized, "passwd") || + strings.Contains(normalized, "credential") || + strings.Contains(normalized, "cookie") +} + +func sanitizeAIUpstreamString(value string) string { + text := redactSecretLikeString(value) + if matches := dataURIValuePattern.FindStringSubmatch(text); len(matches) == 2 { + return fmt.Sprintf("data:%s;base64,[REDACTED %d chars]", matches[1], len(text)) + } + if len(text) <= aiUpstreamStringPreviewLimit { + return text + } + return fmt.Sprintf("%s...[truncated %d chars]", text[:aiUpstreamStringPreviewLimit], len(text)-aiUpstreamStringPreviewLimit) +} + +func redactSecretLikeString(value string) string { + result := value + for _, pattern := range secretLikeValuePatterns { + result = pattern.ReplaceAllString(result, "[REDACTED]") + } + return result +} diff --git a/internal/ai/provider/request_log_test.go b/internal/ai/provider/request_log_test.go new file mode 100644 index 0000000..344273a --- /dev/null +++ b/internal/ai/provider/request_log_test.go @@ -0,0 +1,96 @@ +package provider + +import ( + "strings" + "testing" +) + +func TestFormatAIUpstreamRequestLogBodyRedactsSecretsAndKeepsUsefulRequestShape(t *testing.T) { + body := map[string]any{ + "model": "gpt-test", + "api_key": "sk-body-secret-1234567890", + "password": "plain-password", + "temperature": 0.2, + "messages": []any{ + map[string]any{ + "role": "user", + "content": "请分析 orders 表，临时 token 是 Bearer abcdefghijklmnopqrstuvwxyz，另一个 key 是 sk-live-abcdefghijklmnopqrstuvwxyz", + }, + map[string]any{ + "role": "user", + "content": []any{ + map[string]any{"type": "text", "text": "带图片的问题"}, + map[string]any{ + "type": "image_url", + "image_url": map[string]any{ + "url": "data:image/png;base64," + strings.Repeat("a", 128), + }, + }, + }, + }, + }, + "tools": []any{ + map[string]any{ + "type": "function", + "function": map[string]any{ + "name": "inspect_table_bundle", + "description": "读取表结构", + }, + }, + }, + } + + got := formatAIUpstreamRequestLogBody(body) + + for _, want := range []string{ + `"model":"gpt-test"`, + `"temperature":0.2`, + `"messages"`, + `orders`, + `"tools"`, + `inspect_table_bundle`, + `data:image/png;base64,[REDACTED`, + `"[REDACTED]"`, + } { + if !strings.Contains(got, want) { + t.Fatalf("expected sanitized log body to contain %q, got %s", want, got) + } + } + + for _, leaked := range []string{ + "sk-body-secret", + "plain-password", + "Bearer abcdefghijklmnopqrstuvwxyz", + "sk-live-abcdefghijklmnopqrstuvwxyz", + strings.Repeat("a", 64), + } { + if strings.Contains(got, leaked) { + t.Fatalf("sanitized log body leaked %q: %s", leaked, got) + } + } +} + +func TestSanitizeAIUpstreamURLRedactsQuerySecrets(t *testing.T) { + got := sanitizeAIUpstreamURL("https://generativelanguage.googleapis.com/v1beta/models/gemini:generateContent?key=secret-key&token=secret-token&alt=sse") + + if strings.Contains(got, "secret-key") || strings.Contains(got, "secret-token") { + t.Fatalf("expected URL secrets to be redacted, got %s", got) + } + if !strings.Contains(got, "alt=sse") { + t.Fatalf("expected non-sensitive query to remain, got %s", got) + } + if !strings.Contains(got, "key=%5BREDACTED%5D") || !strings.Contains(got, "token=%5BREDACTED%5D") { + t.Fatalf("expected redacted key and token placeholders, got %s", got) + } +} + +func TestRedactAIUpstreamLogTextSanitizesErrorMessages(t *testing.T) { + got := RedactAIUpstreamLogText("upstream error: Authorization Bearer abcdefghijklmnopqrstuvwxyz and key sk-live-abcdefghijklmnopqrstuvwxyz") + + if strings.Contains(got, "Bearer abcdefghijklmnopqrstuvwxyz") || strings.Contains(got, "sk-live-abcdefghijklmnopqrstuvwxyz") { + t.Fatalf("expected upstream error text to be redacted, got %s", got) + } + if !strings.Contains(got, "[REDACTED]") { + t.Fatalf("expected redacted placeholder, got %s", got) + } +} diff --git a/internal/ai/service/service.go b/internal/ai/service/service.go index 558888d..183c65e 100644 --- a/internal/ai/service/service.go +++ b/internal/ai/service/service.go @@ -893,13 +893,29 @@ func (s *Service) AISetContextLevel(level string) { func (s *Service) AIChatSend(messages []ai.Message, tools []ai.Tool) map[string]interface{} { p, err := s.getActiveProvider() if err != nil { + logger.Error(err, "AIChatSend 获取 Provider 失败：messages=%d tools=%d", len(messages), len(tools)) return map[string]interface{}{"success": false, "error": err.Error()} } + started := time.Now() + providerName := p.Name() + logger.Infof("AIChatSend 开始：provider=%s messages=%d tools=%d", providerName, len(messages), len(tools)) resp, err := p.Chat(context.Background(), ai.ChatRequest{Messages: messages, Tools: tools}) if err != nil { + logger.Warnf("AIChatSend 失败：provider=%s messages=%d tools=%d duration=%s err=%s", providerName, len(messages), len(tools), time.Since(started).Round(time.Millisecond), provider.RedactAIUpstreamLogText(err.Error())) return map[string]interface{}{"success": false, "error": err.Error()} } + logger.Infof( + "AIChatSend 完成：provider=%s messages=%d tools=%d toolCalls=%d promptTokens=%d completionTokens=%d totalTokens=%d duration=%s", + providerName, + len(messages), + len(tools), + len(resp.ToolCalls), + resp.TokensUsed.PromptTokens, + resp.TokensUsed.CompletionTokens, + resp.TokensUsed.TotalTokens, + time.Since(started).Round(time.Millisecond), + ) return map[string]interface{}{ "success": true, @@ -931,6 +947,7 @@ func (s *Service) AIChatStream(sessionID string, messages []ai.Message, tools [] p, err := s.getActiveProvider() if err != nil { + logger.Error(err, "AIChatStream 获取 Provider 失败：sessionID=%s messages=%d tools=%d", sessionID, len(messages), len(tools)) wailsRuntime.EventsEmit(s.ctx, "ai:stream:"+sessionID, map[string]interface{}{ "error": err.Error(), "done": true, @@ -938,7 +955,26 @@ func (s *Service) AIChatStream(sessionID string, messages []ai.Message, tools [] return } + started := time.Now() + providerName := p.Name() + contentChunks := 0 + thinkingChunks := 0 + toolCallChunks := 0 + errorChunks := 0 + logger.Infof("AIChatStream 开始：sessionID=%s provider=%s messages=%d tools=%d", sessionID, providerName, len(messages), len(tools)) err = p.ChatStream(streamCtx, ai.ChatRequest{Messages: messages, Tools: tools}, func(chunk ai.StreamChunk) { + if chunk.Content != "" { + contentChunks++ + } + if chunk.Thinking != "" || chunk.ReasoningContent != "" { + thinkingChunks++ + } + if len(chunk.ToolCalls) > 0 { + toolCallChunks++ + } + if chunk.Error != "" { + errorChunks++ + } wailsRuntime.EventsEmit(s.ctx, "ai:stream:"+sessionID, map[string]interface{}{ "content": chunk.Content, "thinking": chunk.Thinking, @@ -951,11 +987,29 @@ func (s *Service) AIChatStream(sessionID string, messages []ai.Message, tools [] // 当 context 被主动 cancel 的时候，不把这个视为向外抛的 error if err != nil && err != context.Canceled { + logger.Warnf("AIChatStream 失败：sessionID=%s provider=%s messages=%d tools=%d duration=%s err=%s", sessionID, providerName, len(messages), len(tools), time.Since(started).Round(time.Millisecond), provider.RedactAIUpstreamLogText(err.Error())) wailsRuntime.EventsEmit(s.ctx, "ai:stream:"+sessionID, map[string]interface{}{ "error": err.Error(), "done": true, }) + return } + if err == context.Canceled { + logger.Infof("AIChatStream 已取消：sessionID=%s provider=%s duration=%s", sessionID, providerName, time.Since(started).Round(time.Millisecond)) + return + } + logger.Infof( + "AIChatStream 完成：sessionID=%s provider=%s messages=%d tools=%d contentChunks=%d thinkingChunks=%d toolCallChunks=%d errorChunks=%d duration=%s", + sessionID, + providerName, + len(messages), + len(tools), + contentChunks, + thinkingChunks, + toolCallChunks, + errorChunks, + time.Since(started).Round(time.Millisecond), + ) }() }