From 40c563c4ae45f60e852acc9198cedcf3be486f87 Mon Sep 17 00:00:00 2001 From: li Date: Tue, 7 Jul 2026 13:53:39 +0800 Subject: [PATCH] =?UTF-8?q?fix(gateway):=20=E8=AE=B0=E5=BD=95=E8=AF=B7?= =?UTF-8?q?=E6=B1=82=E4=BD=93=E8=A7=A3=E6=9E=90=E5=A4=B1=E8=B4=A5=E7=9A=84?= =?UTF-8?q?=E7=9C=9F=E5=AE=9E=E5=8E=9F=E5=9B=A0=EF=BC=8C=E4=B8=8D=E5=86=8D?= =?UTF-8?q?=E5=90=9E=E9=94=99?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit 400 "Failed to parse request body" 此前丢弃底层错误，无法区分 JSON 真非法、还是 body 被截断/被中间件提前消费。 - 服务层 invalid json 错误增补 len/offset/非法字符信息 （仅诊断元数据，不含 body 内容，可安全 wrap）； - handler 层新增 logRequestBodyParseFailure，向服务端日志输出 底层错误 + body 长度 + 转义后的 head/tail 片段（各 256B）， 客户端响应文案保持不变； - 接入全部 9 处入站解析点（messages/count_tokens/responses/ chat_completions/embeddings，Anthropic 与 OpenAI 网关）。 Fixes #3715 --- backend/internal/handler/gateway_handler.go | 2 + .../gateway_handler_chat_completions.go | 1 + .../handler/gateway_handler_responses.go | 1 + .../handler/openai_chat_completions.go | 1 + backend/internal/handler/openai_embeddings.go | 1 + .../handler/openai_gateway_count_tokens.go | 1 + .../handler/openai_gateway_handler.go | 2 + .../handler/request_body_parse_log.go | 54 ++++++++++ .../handler/request_body_parse_log_test.go | 100 ++++++++++++++++++ backend/internal/service/gateway_request.go | 23 +++- .../gateway_request_invalid_json_test.go | 52 +++++++++ 11 files changed, 237 insertions(+), 1 deletion(-) create mode 100644 backend/internal/handler/request_body_parse_log.go create mode 100644 backend/internal/handler/request_body_parse_log_test.go create mode 100644 backend/internal/service/gateway_request_invalid_json_test.go diff --git a/backend/internal/handler/gateway_handler.go b/backend/internal/handler/gateway_handler.go index b20d9ef652..0caa7f718b 100644 --- a/backend/internal/handler/gateway_handler.go +++ b/backend/internal/handler/gateway_handler.go @@ -158,6 +158,7 @@ func (h *GatewayHandler) Messages(c *gin.Context) { bodyRef := service.NewRequestBodyRef(body) parsedReq, err := service.ParseGatewayRequest(bodyRef, domain.PlatformAnthropic) if err != nil { + logRequestBodyParseFailure(reqLog, body, err) h.errorResponse(c, http.StatusBadRequest, "invalid_request_error", "Failed to parse request body") return } @@ -1796,6 +1797,7 @@ func (h *GatewayHandler) CountTokens(c *gin.Context) { bodyRef := service.NewRequestBodyRef(body) parsedReq, err := service.ParseGatewayRequest(bodyRef, domain.PlatformAnthropic) if err != nil { + logRequestBodyParseFailure(reqLog, body, err) h.errorResponse(c, http.StatusBadRequest, "invalid_request_error", "Failed to parse request body") return } diff --git a/backend/internal/handler/gateway_handler_chat_completions.go b/backend/internal/handler/gateway_handler_chat_completions.go index d0ecc01e6a..03ceb0d952 100644 --- a/backend/internal/handler/gateway_handler_chat_completions.go +++ b/backend/internal/handler/gateway_handler_chat_completions.go @@ -64,6 +64,7 @@ func (h *GatewayHandler) ChatCompletions(c *gin.Context) { // Validate JSON if !gjson.ValidBytes(body) { + logRequestBodyParseFailure(reqLog, body, nil) h.chatCompletionsErrorResponse(c, http.StatusBadRequest, "invalid_request_error", "Failed to parse request body") return } diff --git a/backend/internal/handler/gateway_handler_responses.go b/backend/internal/handler/gateway_handler_responses.go index 4a8d752193..f5ee18b722 100644 --- a/backend/internal/handler/gateway_handler_responses.go +++ b/backend/internal/handler/gateway_handler_responses.go @@ -64,6 +64,7 @@ func (h *GatewayHandler) Responses(c *gin.Context) { // Validate JSON if !gjson.ValidBytes(body) { + logRequestBodyParseFailure(reqLog, body, nil) h.responsesErrorResponse(c, http.StatusBadRequest, "invalid_request_error", "Failed to parse request body") return } diff --git a/backend/internal/handler/openai_chat_completions.go b/backend/internal/handler/openai_chat_completions.go index baff1dcbd6..847d386cde 100644 --- a/backend/internal/handler/openai_chat_completions.go +++ b/backend/internal/handler/openai_chat_completions.go @@ -64,6 +64,7 @@ func (h *OpenAIGatewayHandler) ChatCompletions(c *gin.Context) { } if !gjson.ValidBytes(body) { + logRequestBodyParseFailure(reqLog, body, nil) h.errorResponse(c, http.StatusBadRequest, "invalid_request_error", "Failed to parse request body") return } diff --git a/backend/internal/handler/openai_embeddings.go b/backend/internal/handler/openai_embeddings.go index 8be533c723..56d775eb7c 100644 --- a/backend/internal/handler/openai_embeddings.go +++ b/backend/internal/handler/openai_embeddings.go @@ -60,6 +60,7 @@ func (h *OpenAIGatewayHandler) Embeddings(c *gin.Context) { return } if !gjson.ValidBytes(body) { + logRequestBodyParseFailure(reqLog, body, nil) h.errorResponse(c, http.StatusBadRequest, "invalid_request_error", "Failed to parse request body") return } diff --git a/backend/internal/handler/openai_gateway_count_tokens.go b/backend/internal/handler/openai_gateway_count_tokens.go index fc9c4d5df7..9a6709cc4f 100644 --- a/backend/internal/handler/openai_gateway_count_tokens.go +++ b/backend/internal/handler/openai_gateway_count_tokens.go @@ -64,6 +64,7 @@ func (h *OpenAIGatewayHandler) CountTokens(c *gin.Context) { bodyRef := service.NewRequestBodyRef(body) parsedReq, err := service.ParseGatewayRequest(bodyRef, domain.PlatformAnthropic) if err != nil { + logRequestBodyParseFailure(reqLog, body, err) h.anthropicErrorResponse(c, http.StatusBadRequest, "invalid_request_error", "Failed to parse request body") return } diff --git a/backend/internal/handler/openai_gateway_handler.go b/backend/internal/handler/openai_gateway_handler.go index 7f097afa4b..551de2dd61 100644 --- a/backend/internal/handler/openai_gateway_handler.go +++ b/backend/internal/handler/openai_gateway_handler.go @@ -218,6 +218,7 @@ func (h *OpenAIGatewayHandler) Responses(c *gin.Context) { // 校验请求体 JSON 合法性 if !gjson.ValidBytes(body) { + logRequestBodyParseFailure(reqLog, body, nil) h.errorResponse(c, http.StatusBadRequest, "invalid_request_error", "Failed to parse request body") return } @@ -697,6 +698,7 @@ func (h *OpenAIGatewayHandler) Messages(c *gin.Context) { } if !gjson.ValidBytes(body) { + logRequestBodyParseFailure(reqLog, body, nil) h.anthropicErrorResponse(c, http.StatusBadRequest, "invalid_request_error", "Failed to parse request body") return } diff --git a/backend/internal/handler/request_body_parse_log.go b/backend/internal/handler/request_body_parse_log.go new file mode 100644 index 0000000000..c38a7f9bd5 --- /dev/null +++ b/backend/internal/handler/request_body_parse_log.go @@ -0,0 +1,54 @@ +package handler + +import ( + "strconv" + + "github.com/Wei-Shaw/sub2api/internal/service" + "go.uber.org/zap" +) + +// parseFailureSnippetLen bounds the head/tail snippets logged on body parse +// failure. 256 bytes is enough to see the structural context (model field, +// first content block / trailing brace) without dumping user payloads. +const parseFailureSnippetLen = 256 + +// logRequestBodyParseFailure records the real reason a request body failed +// JSON parsing/validation. The client keeps receiving the generic +// "Failed to parse request body"; the sanitized diagnostics (underlying +// error with byte offset, body length, escaped head/tail snippets) land in +// the server log only, so operators can distinguish genuinely invalid JSON +// from a truncated or partially consumed body. +// +// err may be nil for call sites that validate with gjson.ValidBytes directly; +// the diagnostic error is derived from the body in that case. +func logRequestBodyParseFailure(reqLog *zap.Logger, body []byte, err error) { + if reqLog == nil { + return + } + if err == nil { + err = service.DescribeInvalidJSON(body) + } + + head := body + var tail []byte + if len(body) > parseFailureSnippetLen { + head = body[:parseFailureSnippetLen] + tail = body[len(body)-parseFailureSnippetLen:] + } + + fields := []zap.Field{ + zap.Error(err), + zap.Int("body_len", len(body)), + zap.String("body_head", sanitizeBodySnippet(head)), + } + if len(tail) > 0 { + fields = append(fields, zap.String("body_tail", sanitizeBodySnippet(tail))) + } + reqLog.Warn("parse request body failed", fields...) +} + +// sanitizeBodySnippet escapes control characters and invalid UTF-8 so the +// snippet is always a single printable log line. +func sanitizeBodySnippet(b []byte) string { + return strconv.Quote(string(b)) +} diff --git a/backend/internal/handler/request_body_parse_log_test.go b/backend/internal/handler/request_body_parse_log_test.go new file mode 100644 index 0000000000..c1477eb4d7 --- /dev/null +++ b/backend/internal/handler/request_body_parse_log_test.go @@ -0,0 +1,100 @@ +//go:build unit + +package handler + +import ( + "strings" + "testing" + + "github.com/stretchr/testify/require" + "go.uber.org/zap" + "go.uber.org/zap/zaptest/observer" +) + +func newObservedLogger(t *testing.T) (*zap.Logger, *observer.ObservedLogs) { + t.Helper() + core, logs := observer.New(zap.WarnLevel) + return zap.New(core), logs +} + +func loggedFields(t *testing.T, logs *observer.ObservedLogs) map[string]any { + t.Helper() + entries := logs.All() + require.Len(t, entries, 1) + fields := map[string]any{} + for _, f := range entries[0].Context { + switch f.Key { + case "body_len": + fields[f.Key] = int(f.Integer) + case "error": + fields[f.Key] = f.Interface.(error).Error() + default: + fields[f.Key] = f.String + } + } + return fields +} + +func TestLogRequestBodyParseFailure_DerivesErrorWhenNil(t *testing.T) { + log, logs := newObservedLogger(t) + body := []byte(`{"model": bad}`) + + logRequestBodyParseFailure(log, body, nil) + + fields := loggedFields(t, logs) + require.Equal(t, len(body), fields["body_len"]) + require.Contains(t, fields["error"], "invalid json") + require.Contains(t, fields["error"], "offset=11") +} + +func TestLogRequestBodyParseFailure_ShortBodyHasNoTail(t *testing.T) { + log, logs := newObservedLogger(t) + body := []byte(`{"broken":`) + + logRequestBodyParseFailure(log, body, nil) + + fields := loggedFields(t, logs) + require.Contains(t, fields, "body_head") + require.NotContains(t, fields, "body_tail") + require.Contains(t, fields["body_head"].(string), `{\"broken\":`) +} + +func TestLogRequestBodyParseFailure_LargeBodyBoundedSnippets(t *testing.T) { + log, logs := newObservedLogger(t) + // ~1MB body: head must show the structural prefix, tail the trailing bytes, + // and neither snippet may exceed the configured bound (plus quoting overhead). + body := []byte(`{"model":"claude-sonnet-4-6","big":"` + strings.Repeat("A", 1<<20) + `"`) + + logRequestBodyParseFailure(log, body, nil) + + fields := loggedFields(t, logs) + require.Equal(t, len(body), fields["body_len"]) + head := fields["body_head"].(string) + tail := fields["body_tail"].(string) + require.Contains(t, head, "claude-sonnet-4-6") + require.Contains(t, tail, "AAA") + require.NotContains(t, tail, "claude-sonnet-4-6") + // strconv.Quote adds surrounding quotes and escapes; 4x is a generous cap. + require.LessOrEqual(t, len(head), parseFailureSnippetLen*4) + require.LessOrEqual(t, len(tail), parseFailureSnippetLen*4) +} + +func TestLogRequestBodyParseFailure_EscapesControlCharacters(t *testing.T) { + log, logs := newObservedLogger(t) + body := []byte("{\"model\":\x01\n\"x\"}") + + logRequestBodyParseFailure(log, body, nil) + + fields := loggedFields(t, logs) + head := fields["body_head"].(string) + require.NotContains(t, head, "\n") + require.NotContains(t, head, "\x01") + require.Contains(t, head, `\n`) + require.Contains(t, head, `\x01`) +} + +func TestLogRequestBodyParseFailure_NilLoggerNoPanic(t *testing.T) { + require.NotPanics(t, func() { + logRequestBodyParseFailure(nil, []byte(`{`), nil) + }) +} diff --git a/backend/internal/service/gateway_request.go b/backend/internal/service/gateway_request.go index a90714ca1d..1665b1fe47 100644 --- a/backend/internal/service/gateway_request.go +++ b/backend/internal/service/gateway_request.go @@ -3,6 +3,7 @@ package service import ( "bytes" "encoding/json" + "errors" "fmt" "math" "regexp" @@ -168,7 +169,7 @@ func parseGatewayRequestCurrentBody(parsed *ParsedRequest, protocol string) erro bodyBytes := parsed.Body.Bytes() if !gjson.ValidBytes(bodyBytes) { - return fmt.Errorf("invalid json") + return DescribeInvalidJSON(bodyBytes) } // 只在当前函数内零拷贝读取 JSON 字段；ReplaceBody 后必须重新进入本函数刷新派生状态。 @@ -216,6 +217,26 @@ func refreshGatewayRequestRanges(parsed *ParsedRequest, protocol string) error { return parseGatewayRequestCurrentBody(parsed, protocol) } +// DescribeInvalidJSON returns a diagnostic error for a request body that +// failed JSON validation. It re-parses with encoding/json (failure path only) +// to pinpoint the first offending byte, so operators can distinguish genuinely +// invalid JSON from a truncated / partially consumed body. The error carries +// only length/offset/character information — never body content — so callers +// may safely wrap or log it. +func DescribeInvalidJSON(body []byte) error { + var raw json.RawMessage + if err := json.Unmarshal(body, &raw); err != nil { + var syntaxErr *json.SyntaxError + if errors.As(err, &syntaxErr) { + return fmt.Errorf("invalid json (len=%d, offset=%d): %s", len(body), syntaxErr.Offset, syntaxErr.Error()) + } + return fmt.Errorf("invalid json (len=%d): %w", len(body), err) + } + // gjson rejected the body but encoding/json accepted it (divergent edge + // cases, e.g. certain malformed UTF-8 sequences); report the basics. + return fmt.Errorf("invalid json (len=%d)", len(body)) +} + // ParsedRequest 保存网关请求的预解析结果 // // 性能优化说明： diff --git a/backend/internal/service/gateway_request_invalid_json_test.go b/backend/internal/service/gateway_request_invalid_json_test.go new file mode 100644 index 0000000000..cc69a41e72 --- /dev/null +++ b/backend/internal/service/gateway_request_invalid_json_test.go @@ -0,0 +1,52 @@ +//go:build unit + +package service + +import ( + "fmt" + "strings" + "testing" + + "github.com/Wei-Shaw/sub2api/internal/domain" + "github.com/stretchr/testify/require" +) + +func TestDescribeInvalidJSON_TruncatedBody(t *testing.T) { + // Simulates a body cut off mid-stream (e.g. partially consumed by middleware). + body := []byte(`{"model":"claude-sonnet-4-6","messages":[{"role":"user","content":"hi`) + + err := DescribeInvalidJSON(body) + + require.Error(t, err) + require.Contains(t, err.Error(), fmt.Sprintf("len=%d", len(body))) + require.Contains(t, err.Error(), "unexpected end of JSON input") +} + +func TestDescribeInvalidJSON_InvalidCharacterWithOffset(t *testing.T) { + body := []byte(`{"model": bad}`) + + err := DescribeInvalidJSON(body) + + require.Error(t, err) + require.Contains(t, err.Error(), "offset=11") + require.Contains(t, err.Error(), "invalid character") +} + +func TestDescribeInvalidJSON_DoesNotLeakBodyContent(t *testing.T) { + secret := "sk-super-secret-value" + body := []byte(`{"api_key":"` + secret + `","broken":`) + + err := DescribeInvalidJSON(body) + + require.Error(t, err) + require.NotContains(t, err.Error(), secret) +} + +func TestParseGatewayRequest_InvalidJSONErrorIsDiagnostic(t *testing.T) { + body := []byte(`{"model":"claude-sonnet-4-6","messages":[`) + + _, err := ParseGatewayRequest(NewRequestBodyRef(body), domain.PlatformAnthropic) + + require.Error(t, err) + require.True(t, strings.HasPrefix(err.Error(), "invalid json (len="), "error should carry diagnostics, got: %s", err.Error()) +}