kra-new/internal/logging/zap_test.go

180 lines
7.0 KiB
Go

package logging
import (
"context"
"log/slog"
"os"
"path/filepath"
"strings"
"testing"
"time"
"go.uber.org/zap"
"go.uber.org/zap/zapcore"
)
func TestZapHandlerHonorsConfiguredLevel(t *testing.T) {
root := t.TempDir()
handler, cleanup := newZapHandler(root, "application.log", Options{Level: "error", Format: "json"}, nil)
defer cleanup()
if handler.Enabled(context.Background(), slog.LevelInfo) {
t.Fatal("info should be disabled when level is error")
}
if !handler.Enabled(context.Background(), slog.LevelError) {
t.Fatal("error should be enabled when level is error")
}
}
func TestZapHandlerUsesDebugFallbackForInvalidLevel(t *testing.T) {
root := t.TempDir()
handler, cleanup := newZapHandler(root, "application.log", Options{Level: "not-a-level", Format: "json"}, nil)
defer cleanup()
if !handler.Enabled(context.Background(), slog.LevelDebug) {
t.Fatal("invalid levels should use the reference debug fallback")
}
}
func TestZapHandlerRoutesHTTPAndErrorLogs(t *testing.T) {
root := t.TempDir()
handler, cleanup := newZapHandler(root, "application.log", Options{Level: "info", Format: "json"}, nil)
logger := slog.New(handler)
logger.Info("request", "mod", "http", "request_id", "req-1")
logger.Error("failed", "mod", "users")
cleanup()
dateEntries, err := os.ReadDir(root)
if err != nil || len(dateEntries) != 1 {
t.Fatalf("expected one daily log directory, entries=%v err=%v", len(dateEntries), err)
}
date := dateEntries[0].Name()
paths := []string{
filepath.Join(root, date, "application.log"),
filepath.Join(root, date, "http", "access.log"),
filepath.Join(root, date, "users", "application.log"),
filepath.Join(root, date, "error", "error.log"),
}
for _, path := range paths {
if info, err := os.Stat(path); err != nil || info.Size() == 0 {
t.Fatalf("expected non-empty routed log %s: info=%v err=%v", path, info, err)
}
}
}
func TestConsoleEncoderDoesNotChangeJSONFileEncoder(t *testing.T) {
config := zap.NewProductionEncoderConfig()
config.EncodeTime = zapcore.RFC3339NanoTimeEncoder
fileEncoder := zapcore.NewJSONEncoder(config)
entry := zapcore.Entry{Level: zapcore.InfoLevel, Time: time.Date(2026, 8, 21, 16, 30, 0, 0, time.Local), Message: "started"}
buffer, err := fileEncoder.EncodeEntry(entry, nil)
if err != nil {
t.Fatal(err)
}
defer buffer.Free()
if !strings.HasPrefix(buffer.String(), "{") || !strings.Contains(buffer.String(), `"msg":"started"`) {
t.Fatalf("file encoder is no longer JSON: %s", buffer.String())
}
}
func TestConsoleSummaryHidesInfrastructureNoise(t *testing.T) {
entry := zapcore.Entry{
Level: zapcore.InfoLevel,
Time: time.Date(2026, 8, 21, 16, 50, 53, 145000000, time.Local),
Message: "register swagger handler",
Caller: zapcore.NewEntryCaller(0, `D:\workspace\kra\internal\server\swagger.go`, 55, true),
}
line := formatConsoleEntry(entry, "system", []zapcore.Field{
zap.String("service.id", "DESKTOP"), zap.String("app_id", "kra"),
zap.String("trace_id", ""), zap.String("path", "/swagger/*any"),
}, "[kra] ")
for _, want := range []string{"[kra] 16:50:53.145", "INFO", "system", "swagger.go:55", "register swagger handler", "path=/swagger/*any"} {
if !strings.Contains(line, want) {
t.Fatalf("console line %q does not contain %q", line, want)
}
}
for _, unwanted := range []string{"service.id", "DESKTOP", "app_id", "trace_id", `D:\workspace`} {
if strings.Contains(line, unwanted) {
t.Fatalf("console line still contains %q: %s", unwanted, line)
}
}
}
func TestZapHandlerRecordsEveryErrorThroughSink(t *testing.T) {
root := t.TempDir()
var entries []ErrorEntry
logger, control := NewReloadableZapLogger(root, "application.log", Options{Level: "info", Format: "json"})
defer control.Close()
control.SetErrorSink(ErrorSinkFunc(func(_ context.Context, entry ErrorEntry) error {
entries = append(entries, entry)
return nil
}))
logger.Error("task execution failed", "mod", "timedTask", "request_id", "request-1", "trace_id", "trace-1", "error", os.ErrPermission)
control.Reload(t.TempDir(), Options{Level: "info", Format: "json"})
logger.Error("reloaded logger failure", "mod", "system")
if len(entries) != 2 {
t.Fatalf("expected two error entries across reload, got %d", len(entries))
}
entry := entries[0]
if entry.Form != "后端" || entry.Level != "error" || entry.RequestID != "request-1" || entry.TraceID != "trace-1" || !strings.Contains(entry.Info, "task execution failed") || !strings.Contains(entry.Info, os.ErrPermission.Error()) {
t.Fatalf("unexpected error entry: %+v", entry)
}
}
func TestErrorEntryIncludesFinalApplicationSource(t *testing.T) {
filename := filepath.Join(t.TempDir(), "worker.go")
content := "package sample\n\nfunc execute() {\n\tprintln(\"failed\")\n}\n"
if err := os.WriteFile(filename, []byte(content), 0o600); err != nil {
t.Fatal(err)
}
entry := errorEntryFromZap(zapcore.Entry{Message: "task failed", Level: zapcore.ErrorLevel, Stack: "kra/internal/worker.execute\n" + filename + ":4"}, nil)
if !strings.Contains(entry.Info, "最终调用方法:"+filename+":4 (execute lines 3-5)") || !strings.Contains(entry.Info, "func execute()") {
t.Fatalf("expected final caller source in error entry: %s", entry.Info)
}
}
func TestSkipStackFileRecognizesServerTransportPackages(t *testing.T) {
tests := []struct {
name string
path string
want bool
}{
{name: "handler", path: `D:\workspace\app\system\internal\server\handler\user.go`, want: true},
{name: "middleware", path: `D:\workspace\app\system\internal\server\middleware\auth.go`, want: true},
{name: "router", path: `/workspace/internal/server/router/user.go`, want: true},
{name: "http helper", path: `/workspace/internal/server/httpx/response.go`, want: true},
{name: "handler remains application boundary", path: `/workspace/internal/server/handler_user.go`, want: false},
}
for _, test := range tests {
t.Run(test.name, func(t *testing.T) {
if got := skipStackFile(test.path); got != test.want {
t.Fatalf("skipStackFile(%q) = %v, want %v", test.path, got, test.want)
}
})
}
}
func TestErrorSinkSkipsGORMBridge(t *testing.T) {
root := t.TempDir()
var entries []ErrorEntry
state := &errorSinkState{sink: ErrorSinkFunc(func(_ context.Context, entry ErrorEntry) error {
entries = append(entries, entry)
return nil
})}
base := zapcore.NewNopCore()
core := &routedFileCore{base: base, encoder: zapcore.NewJSONEncoder(zap.NewProductionEncoderConfig()), level: zapcore.ErrorLevel, root: root, state: &routedFileState{writers: map[string]*DailyWriter{}}, errorSink: state}
defer core.Close()
for _, filename := range []string{"/tmp/gorm_logger_writer.go", "/workspace/pkg/database/gormkit/logger.go"} {
if err := core.Write(zapcore.Entry{Level: zapcore.ErrorLevel, Message: "database failed", Caller: zapcore.EntryCaller{Defined: true, File: filename, Line: 10}}, nil); err != nil {
t.Fatal(err)
}
}
if err := core.Write(zapcore.Entry{Level: zapcore.ErrorLevel, Message: "database failed"}, []zapcore.Field{zap.Bool("gorm_logger", true)}); err != nil {
t.Fatal(err)
}
if len(entries) != 0 {
t.Fatalf("gorm bridge error must not recurse into sys_error: %+v", entries)
}
}