Merge pull request #3780 from fengshao1227/fix/gateway-parse-error-observability

fix(gateway): 记录请求体解析失败的真实原因,不再吞错
This commit is contained in:
Wesley Liddick
2026-07-07 14:37:46 +08:00
committed by GitHub
11 changed files with 237 additions and 1 deletions
@@ -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
}
@@ -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
}
@@ -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
}
@@ -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
}
@@ -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
}
@@ -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
}
@@ -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
}
@@ -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))
}
@@ -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)
})
}
+22 -1
View File
@@ -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 保存网关请求的预解析结果
//
// 性能优化说明:
@@ -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())
}