Files
sub2api/backend/internal/handler/request_body_parse_log_test.go
T
li 40c563c4ae 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
2026-07-07 13:53:39 +08:00

101 lines
2.9 KiB
Go

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