✨ feat(ai): 记录上游请求入参与会话日志

- 增加 OpenAI、Anthropic、Gemini 上游请求体与响应状态日志 - 为 AIChatSend 和 AIChatStream 补充会话生命周期日志 - 增加请求日志脱敏与 URL 密钥过滤测试
2026-06-14 10:29:52 +08:00 · 2026-06-11 11:07:22 +08:00
parent 74a422a5e2
commit 2d562ccfd6
6 changed files with 391 additions and 6 deletions
--- 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
 }

--- 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
 }
--- 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
 }

--- a/internal/ai/provider/request_log.go
+++ 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
+}
--- a/internal/ai/provider/request_log_test.go
+++ 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)
+	}
+}
--- 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),
+		)
 	}()
 }