feat(log): Seq 会话追踪、控制台降噪与推送质量增强

请求日志自动带 sid/request_id,支持 LogBind;挂 Seq 后控制台仅 Warn+,Seq 仍全量;并修毫秒时间戳、@m、失败重试与停机 flush。

Co-authored-by: Cursor <cursoragent@cursor.com>
This commit is contained in:
2026-07-23 05:26:44 +08:00
parent b254606003
commit 831a7f017a
6 changed files with 554 additions and 197 deletions
+178 -2
View File
@@ -96,8 +96,8 @@ func TestToClef_PlainText(t *testing.T) {
if err := json.Unmarshal(clef, &m); err != nil {
t.Fatal(err)
}
if m["@mt"] != "plain log line" {
t.Fatalf("@mt=%v", m["@mt"])
if m["@m"] != "plain log line" {
t.Fatalf("@m=%v", m["@m"])
}
if m["source"] != "stdout" {
t.Fatalf("source=%v", m["source"])
@@ -107,6 +107,182 @@ func TestToClef_PlainText(t *testing.T) {
}
}
func TestWithFields_ChildHasFieldsParentClean(t *testing.T) {
parent, buf := newLoggerWithCapture(1)
child := parent.WithFields("sid", "abc123def456", "request_id", "fedcba987654")
child.Info().Msg("child-msg")
m := buf.lastJSON()
if m == nil {
t.Fatal("no output")
}
if m["sid"] != "abc123def456" || m["request_id"] != "fedcba987654" {
t.Fatalf("child fields missing: %v", m)
}
parent.Info().Msg("parent-msg")
m2 := buf.lastJSON()
if m2["sid"] != nil || m2["request_id"] != nil {
t.Fatalf("parent polluted: %v", m2)
}
// 错误历史父子共享
parent2 := NewLogger(1, "", 10)
child2 := parent2.WithFields("sid", "x")
child2.Error("shared-err")
if n := len(parent2.GetRecentErrors()); n != 1 {
t.Fatalf("shared error store want 1 got %d", n)
}
}
func TestToClef_MillisecondAndAtM(t *testing.T) {
sw := &SeqWriter{instance: "test:1"}
in := []byte(`{"level":"info","time":"2026-07-23 04:50:01.123","message":"hello {name}"}`)
clef := sw.toClef(in)
var m map[string]interface{}
if err := json.Unmarshal(clef, &m); err != nil {
t.Fatal(err)
}
if m["@m"] != "hello {name}" {
t.Fatalf("@m=%v", m["@m"])
}
if m["@mt"] != nil {
t.Fatalf("should not have @mt: %v", m["@mt"])
}
at, ok := m["@t"].(string)
if !ok || !strings.Contains(at, ".123") {
t.Fatalf("@t missing ms: %v", m["@t"])
}
}
func TestSeqWriter_RetryOnce(t *testing.T) {
var mu sync.Mutex
calls := 0
var gotBody string
srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
body, _ := io.ReadAll(r.Body)
mu.Lock()
calls++
n := calls
if n == 1 {
mu.Unlock()
w.WriteHeader(http.StatusInternalServerError)
return
}
gotBody = string(body)
mu.Unlock()
w.WriteHeader(http.StatusCreated)
}))
defer srv.Close()
l := NewLogger(1, "", 0)
l.SetSeqWriter(srv.URL, "", "test:retry")
l.Info().Msg("retry-me")
deadline := time.Now().Add(4 * time.Second)
for time.Now().Before(deadline) {
mu.Lock()
ok := calls >= 2 && strings.Contains(gotBody, "retry-me")
mu.Unlock()
if ok {
return
}
time.Sleep(50 * time.Millisecond)
}
mu.Lock()
defer mu.Unlock()
t.Fatalf("retry failed: calls=%d body=%q", calls, gotBody)
}
func TestLevelFilterWriter_WarnOnly(t *testing.T) {
buf := &captureBuf{}
w := newLevelFilterWriter(buf, zerolog.WarnLevel)
mw := &multiWriter{writers: []io.Writer{w}}
zl := zerolog.New(mw).Level(zerolog.DebugLevel)
zl.Info().Msg("info-hidden")
zl.Warn().Msg("warn-shown")
buf.mu.Lock()
n := len(buf.lines)
buf.mu.Unlock()
if n != 1 {
t.Fatalf("want 1 console line got %d: %v", n, buf.lines)
}
if !strings.Contains(buf.lines[0], "warn-shown") {
t.Fatalf("unexpected: %v", buf.lines[0])
}
}
func TestSetSeqWriter_QuietsConsoleKeepsSeqFull(t *testing.T) {
var mu sync.Mutex
var gotBody string
srv := startFakeSeqServer(t, func(body string) {
mu.Lock()
gotBody += body
mu.Unlock()
})
defer srv.Close()
l := NewLogger(1, "", 0)
consoleBuf := &captureBuf{}
l.console.inner = consoleBuf
l.SetSeqWriter(srv.URL, "", "test:quiet")
l.Info().Msg("info-to-seq-only")
l.Warn().Msg("warn-both")
deadline := time.Now().Add(3 * time.Second)
for time.Now().Before(deadline) {
mu.Lock()
ok := strings.Contains(gotBody, "info-to-seq-only") && strings.Contains(gotBody, "warn-both")
mu.Unlock()
if ok {
break
}
time.Sleep(50 * time.Millisecond)
}
mu.Lock()
body := gotBody
mu.Unlock()
if !strings.Contains(body, "info-to-seq-only") || !strings.Contains(body, "warn-both") {
t.Fatalf("Seq incomplete: %q", body)
}
consoleBuf.mu.Lock()
defer consoleBuf.mu.Unlock()
for _, line := range consoleBuf.lines {
if strings.Contains(line, "info-to-seq-only") {
t.Fatalf("Info leaked to console: %v", consoleBuf.lines)
}
}
foundWarn := false
for _, line := range consoleBuf.lines {
if strings.Contains(line, "warn-both") {
foundWarn = true
}
}
if !foundWarn {
t.Fatalf("Warn missing on console: %v", consoleBuf.lines)
}
l.CloseSeq()
}
func TestSeqWriter_CloseFlushes(t *testing.T) {
var mu sync.Mutex
var gotBody string
srv := startFakeSeqServer(t, func(body string) {
mu.Lock()
gotBody += body
mu.Unlock()
})
defer srv.Close()
l := NewLogger(1, "", 0)
l.SetSeqWriter(srv.URL, "", "test:close")
l.Info().Msg("flush-on-close")
l.CloseSeq()
mu.Lock()
defer mu.Unlock()
if !strings.Contains(gotBody, "flush-on-close") {
t.Fatalf("Close did not flush: %q", gotBody)
}
}
func TestStdoutCapture_LongLine(t *testing.T) {
l, buf := newLoggerWithCapture(1)
pr, pw := io.Pipe()