package httpapi_test import ( "bytes" "log/slog" "net/http" "strings" "testing" "time" "git.yeij.top/AskaEth/Scoreboard/server/internal/httpapi" ) // logEnv 把服务端日志抓进内存缓冲:日志分级与拦截点只有真的抓到才能断言。 // 用 DEBUG 级别建 handler,WARN/INFO/ERROR 与默认级别下的可见性差异由用例分别断言。 func logEnv(t *testing.T) (*testEnv, *bytes.Buffer) { t.Helper() buf := &bytes.Buffer{} logger := slog.New(slog.NewJSONHandler(buf, &slog.HandlerOptions{Level: slog.LevelDebug})) env := newTestEnvWith(t, func(o *httpapi.Options) { o.Logger = logger }) return env, buf } // waitLog 等到日志里出现 want 之后返回整段日志。 // 一部分日志(审计 INFO、拦截 WARN)在响应写完之后才落,不能立刻就读缓冲。 func waitLog(t *testing.T, buf *bytes.Buffer, want string) string { t.Helper() for i := 0; i < 200; i++ { if got := buf.String(); strings.Contains(got, want) { return got } time.Sleep(5 * time.Millisecond) } t.Fatalf("等不到日志片段 %q,当前日志:\n%s", want, buf.String()) return "" } // recorderClient 建号并登录,返回 recorder 客户端。 func recorderClient(t *testing.T, env *testEnv) *http.Client { t.Helper() env.createUser("recorder", "recorder-pass", "recorder") client, _ := env.client() env.login(client, "recorder", "recorder-pass") return client } // 拦截点必须指向真正做校验的那段代码,而不是 response.go 里的构造函数。 func TestInterceptLogPointsAtValidator(t *testing.T) { env, buf := logEnv(t) ids := env.seed(t) client := recorderClient(t, env) // avgMode 校验发生在 repo_events.go 的 normalizeAvgMode。 status, env2 := env.do(client, http.MethodPost, "/api/events", map[string]any{ "sportId": ids.sport, "code": "E-BAD", "name": "非法小项", "avgMode": "bogus", }, true) if status != http.StatusBadRequest || env2.Error == nil { t.Fatalf("非法 avgMode 应 400,得到 %d %+v", status, env2.Error) } logs := waitLog(t, buf, "请求被拦截") if !strings.Contains(logs, `"origin":"internal/httpapi/repo_events.go:`) || !strings.Contains(logs, "normalizeAvgMode") { t.Fatalf("WARN 行应指出拦截点是 normalizeAvgMode,得到:\n%s", logs) } for _, forbidden := range []string{"response.go", "badRequest", "newAPIError", "/home/"} { if strings.Contains(logs, forbidden) { t.Fatalf("拦截点不该出现 %q(应指向校验代码、且不带开发机路径),得到:\n%s", forbidden, logs) } } } // 分级:4xx 有 WARN 与 DEBUG、没有 ERROR;5xx 用 ERROR;成功的写操作只有 INFO 放行。 func TestInterceptLogLevels(t *testing.T) { t.Run("4xx", func(t *testing.T) { env, buf := logEnv(t) ids := env.seed(t) client := recorderClient(t, env) env.do(client, http.MethodPost, "/api/events", map[string]any{ "sportId": ids.sport, "code": "E-BAD", "name": "非法小项", "avgMode": "bogus", }, true) logs := waitLog(t, buf, `"level":"WARN"`) // WARN 是默认 info 级别下可见的那行:为什么被拦 + 拦截点都要在里面。 if !strings.Contains(logs, `"reason":"avgMode 只能是 valid / all"`) { t.Fatalf("WARN 行应写明被拦原因,得到:\n%s", logs) } if !strings.Contains(logs, `"origin":"internal/httpapi/repo_events.go:`) { t.Fatalf("WARN 行应带拦截点,得到:\n%s", logs) } logs = waitLog(t, buf, `"level":"DEBUG"`) if !strings.Contains(logs, `"msg":"拦截上下文"`) || !strings.Contains(logs, `"detail":"bogus"`) { t.Fatalf("DEBUG 行应带完整上下文与 detail,得到:\n%s", logs) } if strings.Contains(logs, `"level":"ERROR"`) { t.Fatalf("4xx 不该出现 ERROR,得到:\n%s", logs) } }) t.Run("5xx", func(t *testing.T) { sender := &strictDisplaySender{} buf := &bytes.Buffer{} logger := slog.New(slog.NewJSONHandler(buf, &slog.HandlerOptions{Level: slog.LevelDebug})) env := newTestEnvWith(t, func(o *httpapi.Options) { o.Logger = logger o.Display = sender }) client := recorderClient(t, env) status, _ := env.do(client, http.MethodPost, "/api/display/command", map[string]any{"action": "nope"}, true) if status != http.StatusInternalServerError { t.Fatalf("未知指令应 500,得到 %d", status) } logs := waitLog(t, buf, `"level":"ERROR"`) if !strings.Contains(logs, `"origin":"internal/httpapi/handlers_results.go:`) || !strings.Contains(logs, "displayCommandHandler") { t.Fatalf("ERROR 行应带上拦截点,得到:\n%s", logs) } if strings.Contains(logs, `"level":"WARN"`) { t.Fatalf("5xx 不该同时按 WARN 记,得到:\n%s", logs) } }) t.Run("放行", func(t *testing.T) { env, buf := logEnv(t) client := recorderClient(t, env) status, env2 := env.do(client, http.MethodPost, "/api/teams", map[string]any{ "code": "Z9", "name": "第九分公司", }, true) if status != http.StatusOK || !env2.OK { t.Fatalf("新建单位应 200,得到 %d %+v", status, env2.Error) } logs := waitLog(t, buf, "操作已放行") for _, want := range []string{`"level":"INFO"`, `"action":"team.create"`, `"entity":"team"`, `"actor":"recorder#`} { if !strings.Contains(logs, want) { t.Fatalf("放行日志应含 %s,得到:\n%s", want, logs) } } // 一次审计条目一行 INFO:登录 + 新建单位共 2 行,别在同一次请求里重复刷。 if n := strings.Count(logs, "操作已放行"); n != 2 { t.Fatalf("放行日志应恰好 2 行(登录 + 新建单位),得到 %d 行:\n%s", n, logs) } if strings.Contains(logs, `"level":"WARN"`) || strings.Contains(logs, `"level":"ERROR"`) { t.Fatalf("成功请求不该有 WARN/ERROR,得到:\n%s", logs) } }) } // 日志不能整段记请求体:带证件号的新建人员请求(成功与 409 两条路径)都不该把证件号打出来。 func TestInterceptLogKeepsBodyOut(t *testing.T) { env, buf := logEnv(t) client := recorderClient(t, env) const idCard = "110101199001019999" env.do(client, http.MethodPost, "/api/athletes", map[string]any{ "name": "张三", "gender": "男", "teamId": 1, "idCard": idCard, "active": true, }, true) // 同一个证件号再来一次:409 的 WARN 也不该带出证件号。 env.do(client, http.MethodPost, "/api/athletes", map[string]any{ "name": "张三", "gender": "男", "teamId": 1, "idCard": idCard, "active": true, }, true) logs := waitLog(t, buf, "操作已放行") if !strings.Contains(logs, "请求被拦截") { t.Fatalf("第二次建档应被拦截并记 WARN,得到:\n%s", logs) } if strings.Contains(logs, idCard) { t.Fatalf("日志里出现了证件号原文,说明请求体被打了进去:\n%s", logs) } } // 导入的行级拦截每一条都要有一行 DEBUG,带行号与拦截点。 func TestImportRowInterceptLogs(t *testing.T) { env, buf := logEnv(t) env.seed(t) client := recorderClient(t, env) body := importHeader + "\n" + "M100,男子,A,张三,110101199001011234,男,,,,已报到,\n" + "M100,男子,A,李四,110101199001011235,男,,,,,\n" status, resp := env.postImport(t, client, "/api/entries/import", body, "") if status != http.StatusOK { t.Fatalf("导入应 200,得到 %d %+v", status, resp.Error) } result := decodeData[map[string]any](t, resp) if result["skipped"] != float64(1) { t.Fatalf("非法 status 的那行应被跳过: %+v", result) } logs := waitLog(t, buf, "导入行被拦截") if !strings.Contains(logs, `"row":2`) || !strings.Contains(logs, "无法识别") { t.Fatalf("行级 DEBUG 应带行号与原因,得到:\n%s", logs) } if !strings.Contains(logs, "internal/httpapi/handlers_config.go:") || !strings.Contains(logs, "importEntriesWith") { t.Fatalf("行级 DEBUG 应带拦截点,得到:\n%s", logs) } if n := strings.Count(logs, "导入行被拦截"); n != 1 { t.Fatalf("一条行级错误应只记一行 DEBUG,得到 %d 行:\n%s", n, logs) } }