fix(gateway): 记录请求体解析失败的真实原因,不再吞错

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
This commit is contained in:
li
2026-07-07 13:53:39 +08:00
parent 9d5f1b73ad
commit 40c563c4ae
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)
})
}