From d3e71decf41f8cdc1f5ea40ee52b1241d8d38524 Mon Sep 17 00:00:00 2001 From: hoteas <925970985@qq.com> Date: Mon, 27 Jul 2026 07:46:38 +0800 Subject: [PATCH] =?UTF-8?q?feat(log):=20=E5=89=8D=E5=90=8E=E7=AB=AF?= =?UTF-8?q?=E5=85=B1=E7=94=A8=20request=5Fid=20=E4=B8=8E=E5=9B=9B=E6=97=B6?= =?UTF-8?q?=E9=97=B4=E7=82=B9=E6=97=B6=E9=92=9F=E6=A0=A1=E5=87=86?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit - X-Request-Id 请求头带合法 UUID 则沿用为 request_id（严格格式白名单防注入），否则自生成 12 位 hex - 响应头新增 X-Server-Received-Ms / X-Server-Sent-Ms 供前端时钟校准 - CORS Allow-Headers 增加 X-Request-Id，Expose-Headers 显式列出（credentials 下不认 *） Co-authored-by: Cursor --- application.go | 45 ++++++++++++++++++--- context.go | 4 ++ docs/Seq_日志集成.md | 24 +++++++++-- request_trace_test.go | 93 +++++++++++++++++++++++++++++++++++++++++++ 4 files changed, 157 insertions(+), 9 deletions(-) create mode 100644 request_trace_test.go diff --git a/application.go b/application.go index d709c93..9afbc96 100644 --- a/application.go +++ b/application.go @@ -208,6 +208,30 @@ func truncateUA(s string, max int) string { return string(r[:max]) } +// normalizeRequestId 校验前端传入的 X-Request-Id。 +// 仅接受标准 UUID 形态（36 位，8-4-4-4-12，hex+连字符），统一转小写； +// 其余（超长、控制符、任意注入串）一律丢弃返回空，保证日志字段安全且低基数可控。 +func normalizeRequestId(v string) string { + if len(v) != 36 { + return "" + } + for i := 0; i < 36; i++ { + c := v[i] + switch i { + case 8, 13, 18, 23: + if c != '-' { + return "" + } + default: + isHex := (c >= '0' && c <= '9') || (c >= 'a' && c <= 'f') || (c >= 'A' && c <= 'F') + if !isHex { + return "" + } + } + } + return strings.ToLower(v) +} + // shortID 生成 n 字节随机 hex（n=6 → 12 位） func shortID(n int) string { b := make([]byte, n) @@ -557,13 +581,20 @@ func (that *Application) handler(w http.ResponseWriter, req *http.Request) { unescapeUrl = req.RequestURI } - // 请求级追踪：sid=sessionId 前 12 位（脱敏），request_id 回写响应头 - requestId := shortID(6) + // 请求级追踪：sid=sessionId 前 12 位（脱敏），request_id 回写响应头。 + // 前后端共用一个 request_id：前端带合法 X-Request-Id（UUID）则沿用，非法/缺失才服务端自生成， + // 严格格式校验杜绝日志注入。 + requestId := normalizeRequestId(req.Header.Get("X-Request-Id")) + if requestId == "" { + requestId = shortID(6) + } sid := sessionId if len(sid) > 12 { sid = sid[:12] } w.Header().Set("X-Request-Id", requestId) + // 服务端接收时间（ms），与 View() 写出的 X-Server-Sent-Ms 组成四时间点时钟校准 + w.Header().Set("X-Server-Received-Ms", strconv.FormatInt(nowUnixTime.UnixMilli(), 10)) reqLog := that.Log.WithFields("sid", sid, "request_id", requestId) dbCopy := that.Db dbCopy.Log = reqLog @@ -716,8 +747,9 @@ func (that *Application) crossDomain(context *Context, sessionId string) { //header.Set("Access-Control-Allow-Origin", "*") header.Set("Access-Control-Allow-Methods", "GET,POST,OPTIONS,PUT,DELETE") header.Set("Access-Control-Allow-Credentials", "true") - header.Set("Access-Control-Expose-Headers", "*") - header.Set("Access-Control-Allow-Headers", "X-Requested-With,Content-Type,Access-Token,Authorization,Cookie,Set-Cookie") + // credentials 模式下浏览器不认 "*"，必须显式列出可读响应头 + header.Set("Access-Control-Expose-Headers", "X-Request-Id,X-Server-Received-Ms,X-Server-Sent-Ms") + header.Set("Access-Control-Allow-Headers", "X-Requested-With,Content-Type,Access-Token,Authorization,Cookie,Set-Cookie,X-Request-Id") if sessionId != "" { //跨域允许需要设置cookie的允许跨域https才有效果 @@ -763,8 +795,9 @@ func (that *Application) crossDomain(context *Context, sessionId string) { header.Set("Access-Control-Allow-Methods", "GET,POST,OPTIONS,PUT,DELETE") header.Set("Access-Control-Allow-Credentials", "true") - header.Set("Access-Control-Expose-Headers", "*") - header.Set("Access-Control-Allow-Headers", "X-Requested-With,Content-Type,Access-Token,Authorization,Cookie,Set-Cookie") + // credentials 模式下浏览器不认 "*"，必须显式列出可读响应头 + header.Set("Access-Control-Expose-Headers", "X-Request-Id,X-Server-Received-Ms,X-Server-Sent-Ms") + header.Set("Access-Control-Allow-Headers", "X-Requested-With,Content-Type,Access-Token,Authorization,Cookie,Set-Cookie,X-Request-Id") if sessionId != "" { //跨域允许需要设置cookie的允许跨域https才有效果 diff --git a/context.go b/context.go index 69c3630..3fa1cc5 100644 --- a/context.go +++ b/context.go @@ -6,6 +6,7 @@ import ( "io" "mime/multipart" "net/http" + "strconv" "sync" "time" @@ -127,6 +128,9 @@ func (that *Context) View() { } that.DataSize = len(d) that.RespData = nil + // 服务端发送时间（ms）：与 X-Server-Received-Ms 组成四时间点，供前端时钟校准； + // 必须在首次 Write 之前设置，否则 header 已锁定 + that.Resp.Header().Set("X-Server-Sent-Ms", strconv.FormatInt(time.Now().UnixMilli(), 10)) that.Resp.Write(d) } diff --git a/docs/Seq_日志集成.md b/docs/Seq_日志集成.md index 3cc1777..cd0e59a 100644 --- a/docs/Seq_日志集成.md +++ b/docs/Seq_日志集成.md @@ -23,13 +23,31 @@ HoTime 框架内置 Seq 日志推送支持。通过在 `config.json` 填写 `seq 激活后每个 HTTP 请求会自动： -- 生成 `request_id`（12 位 hex），回写响应头 `X-Request-Id` +- 确定 `request_id`（前端带合法 UUID 则沿用，否则自生成 12 位 hex），回写响应头 `X-Request-Id` - 将 `sessionId` 前 12 位作为 `sid` 写入请求级日志（脱敏，避免把登录凭据写进 Seq） - 业务日志、SQL 日志、访问日志均携带 `sid` / `request_id` - **控制台自动降噪**（零额外配置）：业务日志（`that.Log`）控制台放宽到 **Info+**（Debug/SQL 不上控制台），访问日志（`that.WebConnectLog`）控制台保持 **Warn+**（量大不上控制台）；Debug/SQL/访问日志（Info 级）仍全量进 Seq 与文件 --- +## 请求追踪与前端串联（共用 request_id） + +前后端**共用一个 `request_id`**：前端为每次请求生成 UUID 并经 `X-Request-Id` 请求头带上，服务端严格校验（36 位 8-4-4-4-12 hex+连字符，统一小写）通过则直接沿用为本请求 `request_id`；非法或缺失（含浏览器直接访问、老前端）则服务端自生成 12 位 hex。最终值回写响应头 `X-Request-Id`，业务/SQL/访问日志统一携带——Seq 里一条 `request_id = ''` 即可同时串出前端事件与后端全链路日志。 + +- 严格格式白名单杜绝日志注入（换行/引号/超长一律丢弃走自生成分支） +- 前端伪造/重复 UUID 只污染其自身请求的串联，不影响其他请求；接受该风险换取单字段简洁 + +同时每个请求回写**服务端收发时间**响应头，供前端做四时间点时钟校准（前端日志的 `@t` 对齐服务器时间轴）： + +- `X-Server-Received-Ms`：handler 入口时间（ms） +- `X-Server-Sent-Ms`：响应体写出前时间（ms，`context.View()` 设置；静态文件不带） + +CORS 已相应放行/暴露：`Access-Control-Allow-Headers` 增加 `X-Request-Id`；`Access-Control-Expose-Headers` 由 `*` 改为显式 `X-Request-Id,X-Server-Received-Ms,X-Server-Sent-Ms`（credentials 模式下浏览器不认 `*`）。 + +**怎么测**：`request_trace_test.go` — `go test . -count=1 -run 'TestNormalizeRequestId|TestRequestIdSharing|TestViewSetsServerSentMsHeader'`。 + +--- + ## 会话追踪与 LogBind 框架在 `handler` 入口派生请求级 Logger，并浅拷贝 `Db` 将其 `Log` 指向同一 Logger，因此 **SQL 日志自动带会话字段**。字段会出现在同条日志的控制台/文件/Seq 出口上。 @@ -122,7 +140,7 @@ multiWriter（hotimev1.5/log/logger.go） | `message` / `msg` | `@m` | 消息正文（不用 `@mt`，避免 `{xxx}` 被当模板） | | `caller` | `caller` | 调用位置 | | `sid` | `sid` | sessionId 前 12 位 | -| `request_id` | `request_id` | 单次请求 id | +| `request_id` | `request_id` | 单次请求 id（前端合法 UUID 沿用，否则服务端 12 位 hex） | | `ip` | `ip` | 客户端最佳 IP | | `ip_chain` | `ip_chain` | 多源去重链路（与 `ip` 不同时才有） | | `ip_country` | `ip_country` | 有 `EO-Client-IPCountry` 时 | @@ -138,7 +156,7 @@ multiWriter（hotimev1.5/log/logger.go） | 目标 | 查询语句 | |---|---| | 按会话追踪 | `sid = 'abc123def456'` | -| 按单次请求 | `request_id = 'fedcba987654'` | +| 按单次请求（前后端同 id 串联） | `request_id = '6f0a1b2c-3d4e-4f5a-8b6c-7d8e9f0a1b2c'`（服务端自生成时为 12 位 hex） | | 关键词 | 直接输入，如 `支付失败` | | 日志级别 | `@l = 'Error'` | | 特定实例 | `instance = '192.168.1.10:8085'` | diff --git a/request_trace_test.go b/request_trace_test.go new file mode 100644 index 0000000..f9a0009 --- /dev/null +++ b/request_trace_test.go @@ -0,0 +1,93 @@ +package hotime + +import ( + "net/http/httptest" + "strconv" + "strings" + "testing" + "time" + + . "code.hoteas.com/golang/hotime/common" +) + +func TestNormalizeRequestId_Valid(t *testing.T) { + cases := []struct{ in, want string }{ + {"6f0a1b2c-3d4e-4f5a-8b6c-7d8e9f0a1b2c", "6f0a1b2c-3d4e-4f5a-8b6c-7d8e9f0a1b2c"}, + // 大写归一为小写 + {"6F0A1B2C-3D4E-4F5A-8B6C-7D8E9F0A1B2C", "6f0a1b2c-3d4e-4f5a-8b6c-7d8e9f0a1b2c"}, + } + for _, c := range cases { + if got := normalizeRequestId(c.in); got != c.want { + t.Fatalf("normalizeRequestId(%q)=%q want %q", c.in, got, c.want) + } + } +} + +func TestNormalizeRequestId_Invalid(t *testing.T) { + cases := []string{ + "", + "abc", + // 12 位短 hex（服务端自生成格式，不接受为前端传入 id） + "a1b2c3d4e5f6", + // 长度对但连字符位置错 + "6f0a1b2c3-d4e-4f5a-8b6c-7d8e9f0a1b2c", + // 非 hex 字符 + "6f0a1b2c-3d4e-4f5a-8b6c-7d8e9f0a1bzz", + // 注入尝试：换行/引号 + "6f0a1b2c-3d4e-4f5a-8b6c-7d8e9f0a1\n2c", + "\"};alert(1);//-4f5a-8b6c-7d8e9f0a1b2c", + // 超长 + "6f0a1b2c-3d4e-4f5a-8b6c-7d8e9f0a1b2c0", + } + for _, c := range cases { + if got := normalizeRequestId(c); got != "" { + t.Fatalf("normalizeRequestId(%q)=%q want empty", c, got) + } + } +} + +// 共用 request_id 行为：前端带合法 UUID 沿用，非法/缺失服务端自生成 12 位 hex +func TestRequestIdSharing(t *testing.T) { + // 合法 UUID → 沿用（归一小写） + if got := normalizeRequestId("6F0A1B2C-3D4E-4F5A-8B6C-7D8E9F0A1B2C"); got != "6f0a1b2c-3d4e-4f5a-8b6c-7d8e9f0a1b2c" { + t.Fatalf("合法 UUID 应沿用为 request_id，got %q", got) + } + // 非法 → 走服务端自生成分支 + if normalizeRequestId("evil\ninjection") != "" { + t.Fatal("非法值应被丢弃并触发服务端自生成") + } + id := shortID(6) + if len(id) != 12 { + t.Fatalf("服务端自生成 request_id 应为 12 位 hex，got %q", id) + } + for i := 0; i < len(id); i++ { + c := id[i] + if !((c >= '0' && c <= '9') || (c >= 'a' && c <= 'f')) { + t.Fatalf("服务端自生成 request_id 含非 hex 字符: %q", id) + } + } +} + +func TestViewSetsServerSentMsHeader(t *testing.T) { + rec := httptest.NewRecorder() + ctx := &Context{Resp: rec, RespData: Map{"status": 0}} + + before := time.Now().UnixMilli() + ctx.View() + after := time.Now().UnixMilli() + + h := rec.Header().Get("X-Server-Sent-Ms") + if h == "" { + t.Fatal("X-Server-Sent-Ms 未设置") + } + ms, err := strconv.ParseInt(h, 10, 64) + if err != nil { + t.Fatalf("X-Server-Sent-Ms=%q 非毫秒时间戳: %v", h, err) + } + if ms < before || ms > after { + t.Fatalf("X-Server-Sent-Ms=%d 不在 [%d,%d] 区间", ms, before, after) + } + if !strings.Contains(rec.Body.String(), "\"status\":0") { + t.Fatalf("响应体异常: %s", rec.Body.String()) + } +}