Files

484 lines
14 KiB
Go
Raw Permalink Normal View History

2026-10-05 19:30:40 +08:00
package loggerx_test
import (
"bytes"
"context"
"encoding/json"
"fmt"
"os"
"path/filepath"
"strings"
"sync"
"testing"
"github.com/yuninks/loggerx"
)
// levelsOf 解析 JSON 日志的每一行,返回「level -> 出现次数」
func levelsOf(t *testing.T, raw string) map[string]int {
t.Helper()
out := make(map[string]int)
for _, line := range splitLines(raw) {
var fd struct {
Level string `json:"level"`
}
if err := json.Unmarshal([]byte(line), &fd); err != nil {
t.Fatalf("日志行不是合法 JSON: %q: %v", line, err)
}
out[fd.Level]++
}
return out
}
// splitLines 去掉空行,只保留有效日志行
func splitLines(raw string) []string {
var out []string
for _, line := range strings.Split(raw, "\n") {
if strings.TrimSpace(line) != "" {
out = append(out, line)
}
}
return out
}
// 开启 SetAllLevelToInfo 后:debug / warn / error 都要同时进 info.log,
// 各原级别文件仍只写自己那一条;info 本身不重复写
func TestAllLevelToInfoMirrorsEveryLevel(t *testing.T) {
l, dir := newTestLogger(t, loggerx.SetAllLevelToInfo())
ctx := context.Background()
l.Debug(ctx, "M-DEBUG")
l.Info(ctx, "M-INFO")
l.Warn(ctx, "M-WARN")
l.Error(ctx, "M-ERROR")
info := syncAndRead(t, l, dir, "info")
for _, ev := range []string{"debug", "info", "warn", "error"} {
marker := "M-" + strings.ToUpper(ev)
if n := strings.Count(info, marker); n != 1 {
t.Errorf("info.log 中 %s 出现 %d 次,期望 1 次\n%s", marker, n, info)
}
}
// 副本必须保留原始 level,而不是统一改写成 info
want := map[string]int{"debug": 1, "info": 1, "warn": 1, "error": 1}
got := levelsOf(t, info)
for lv, n := range want {
if got[lv] != n {
t.Errorf("info.log 中 level=%s 的行数 = %d,期望 %d(实际 %v)", lv, got[lv], n, got)
}
}
if len(got) != len(want) {
t.Errorf("info.log 出现了预期外的 level: %v", got)
}
// 原级别文件不受影响:各写各的,且只写一条
for _, ev := range []string{"debug", "warn", "error"} {
own := syncAndRead(t, l, dir, ev)
marker := "M-" + strings.ToUpper(ev)
if n := strings.Count(own, marker); n != 1 {
t.Errorf("%s.log 中 %s 出现 %d 次,期望 1 次\n%s", ev, marker, n, own)
}
for _, other := range []string{"M-DEBUG", "M-INFO", "M-WARN", "M-ERROR"} {
if other == marker {
continue
}
if strings.Contains(own, other) {
t.Errorf("%s.log 混入了 %s\n%s", ev, other, own)
}
}
}
}
// 未开启选项时(默认):info.log 只放 info,其它级别不得混入
func TestAllLevelToInfoOffByDefault(t *testing.T) {
l, dir := newTestLogger(t)
ctx := context.Background()
l.Debug(ctx, "N-DEBUG")
l.Info(ctx, "N-INFO")
l.Warn(ctx, "N-WARN")
l.Error(ctx, "N-ERROR")
info := syncAndRead(t, l, dir, "info")
for _, marker := range []string{"N-DEBUG", "N-WARN", "N-ERROR"} {
if strings.Contains(info, marker) {
t.Errorf("未开启 SetAllLevelToInfo 时 info.log 不应包含 %s\n%s", marker, info)
}
}
if n := strings.Count(info, "N-INFO"); n != 1 {
t.Errorf("info.log 中 info 日志出现 %d 次,期望 1 次\n%s", n, info)
}
}
// 副本只落文件:控制台 / 自定义驱动上每条日志只能出现一次(同步与异步都成立)
func TestAllLevelToInfoDoesNotDuplicateDrivers(t *testing.T) {
for _, mode := range []struct {
name string
opts []loggerx.Option
}{
{name: "sync"},
{name: "async", opts: []loggerx.Option{loggerx.SetWriteAsync()}},
} {
t.Run(mode.name, func(t *testing.T) {
var buf bytes.Buffer
opts := append([]loggerx.Option{loggerx.SetAllLevelToInfo(), loggerx.SetExtraDriver(&buf)}, mode.opts...)
l, dir := newTestLogger(t, opts...)
ctx := context.Background()
l.Debug(ctx, "D-DEBUG")
l.Info(ctx, "D-INFO")
l.Warn(ctx, "D-WARN")
l.Error(ctx, "D-ERROR")
// 异步模式下驱动由消费协程写,必须先 Close 再读 buf,否则是数据竞争
if err := l.Close(); err != nil {
t.Fatalf("Close: %v", err)
}
info := syncAndRead(t, l, dir, "info")
out := buf.String()
for _, marker := range []string{"D-DEBUG", "D-INFO", "D-WARN", "D-ERROR"} {
if n := strings.Count(out, marker); n != 1 {
t.Errorf("额外驱动里 %s 出现 %d 次,期望 1 次\n%s", marker, n, out)
}
if !strings.Contains(info, marker) {
t.Errorf("info.log 里缺少 %s\n%s", marker, info)
}
}
})
}
}
// 异步 + channel 组合下镜像同样成立,且不能串 channel
func TestAllLevelToInfoAsyncChannel(t *testing.T) {
dir := t.TempDir()
l := loggerx.NewLogger(context.Background(),
loggerx.SetDir(dir),
loggerx.SetWriteAsync(),
loggerx.SetAllLevelToInfo(),
)
ctx := context.Background()
l.Channel("sub").Error(ctx, "A-SUBERR")
l.Channel("sub").Warn(ctx, "A-SUBWARN")
l.Channel("sub").Info(ctx, "A-SUBINFO")
l.Error(ctx, "A-ROOTERR")
if err := l.Close(); err != nil {
t.Fatalf("Close: %v", err)
}
subInfo := readLog(t, filepath.Join(dir, "sub"), "info")
for _, marker := range []string{"A-SUBERR", "A-SUBWARN", "A-SUBINFO"} {
if n := strings.Count(subInfo, marker); n != 1 {
t.Errorf("sub/info.log 中 %s 出现 %d 次,期望 1 次\n%s", marker, n, subInfo)
}
}
// error 仍然落在自己的文件里
subErr := readLog(t, filepath.Join(dir, "sub"), "error")
if n := strings.Count(subErr, "A-SUBERR"); n != 1 {
t.Errorf("sub/error.log 中 A-SUBERR 出现 %d 次,期望 1 次\n%s", n, subErr)
}
// 根 channel 的 info.log 不能混入 sub 的内容
rootInfo := readLog(t, dir, "info")
if n := strings.Count(rootInfo, "A-ROOTERR"); n != 1 {
t.Errorf("根 info.log 中 A-ROOTERR 出现 %d 次,期望 1 次\n%s", n, rootInfo)
}
if strings.Contains(rootInfo, "A-SUBERR") {
t.Errorf("根 info.log 混入了 sub channel 的日志\n%s", rootInfo)
}
}
// 级别过滤优先:被 SetMinLevel 丢弃的日志不会因为它出现在 info.log 里
func TestAllLevelToInfoRespectsMinLevel(t *testing.T) {
l, dir := newTestLogger(t, loggerx.SetAllLevelToInfo(), loggerx.SetMinLevel(loggerx.LevelWarn))
ctx := context.Background()
l.Debug(ctx, "F-DEBUG")
l.Info(ctx, "F-INFO")
l.Warn(ctx, "F-WARN")
l.Error(ctx, "F-ERROR")
info := syncAndRead(t, l, dir, "info")
for _, marker := range []string{"F-DEBUG", "F-INFO"} {
if strings.Contains(info, marker) {
t.Errorf("低于 MinLevel 的 %s 不应出现在 info.log\n%s", marker, info)
}
}
for _, marker := range []string{"F-WARN", "F-ERROR"} {
if n := strings.Count(info, marker); n != 1 {
t.Errorf("info.log 中 %s 出现 %d 次,期望 1 次\n%s", marker, n, info)
}
}
}
// text 格式下镜像同样是一行一条
func TestAllLevelToInfoTextFormat(t *testing.T) {
l, dir := newTestLogger(t, loggerx.SetAllLevelToInfo(), loggerx.SetFormat(loggerx.FormatText))
ctx := context.Background()
l.Warn(ctx, "T-WARN")
l.Error(ctx, "T-ERROR")
info := syncAndRead(t, l, dir, "info")
lines := splitLines(info)
if len(lines) != 2 {
t.Fatalf("info.log 行数 = %d,期望 2\n%s", len(lines), info)
}
for i, marker := range []string{"T-WARN", "T-ERROR"} {
if !strings.Contains(lines[i], marker) {
t.Errorf("info.log 第 %d 行缺少 %s: %s", i+1, marker, lines[i])
}
}
if !strings.Contains(lines[1], "level=error") {
t.Errorf("text 副本应保留原始 level: %s", lines[1])
}
}
// 并发下镜像不能丢、不能重复:info.log 的条数必须是四个级别之和
func TestAllLevelToInfoConcurrentExactCounts(t *testing.T) {
const (
workers = 8
rounds = 60
)
l, dir := newTestLogger(t, loggerx.SetAllLevelToInfo())
var wg sync.WaitGroup
for w := 0; w < workers; w++ {
wg.Add(1)
go func(w int) {
defer wg.Done()
ctx := context.Background()
for i := 0; i < rounds; i++ {
l.Debugf(ctx, "C-DEBUG-%d-%d", w, i)
l.Infof(ctx, "C-INFO-%d-%d", w, i)
l.Warnf(ctx, "C-WARN-%d-%d", w, i)
l.Errorf(ctx, "C-ERROR-%d-%d", w, i)
}
}(w)
}
wg.Wait()
// 原级别文件:debug/warn/error 各自只放自己那 rounds*workers 条
for _, ev := range []string{"debug", "warn", "error"} {
got := syncAndRead(t, l, dir, ev)
if n := len(splitLines(got)); n != workers*rounds {
t.Errorf("%s.log 行数 = %d,期望 %d", ev, n, workers*rounds)
}
}
// info.log:info 本身 + debug/warn/error 三份副本 = 4 倍
info := syncAndRead(t, l, dir, "info")
if n := len(splitLines(info)); n != 4*workers*rounds {
t.Errorf("info.log 行数 = %d,期望 %d", n, 4*workers*rounds)
}
for _, ev := range []string{"DEBUG", "INFO", "WARN", "ERROR"} {
if n := strings.Count(info, "C-"+ev+"-"); n != workers*rounds {
t.Errorf("info.log 中 %s 出现 %d 次,期望 %d", ev, n, workers*rounds)
}
}
}
// 异步 + 并发:镜像任务不能丢、不能串级别文件
func TestAllLevelToInfoAsyncConcurrentCounts(t *testing.T) {
const (
workers = 4
rounds = 50
)
dir := t.TempDir()
l := loggerx.NewLogger(context.Background(),
loggerx.SetDir(dir),
loggerx.SetWriteAsync(),
loggerx.SetAllLevelToInfo(),
)
var wg sync.WaitGroup
for w := 0; w < workers; w++ {
wg.Add(1)
go func(w int) {
defer wg.Done()
ctx := context.Background()
for i := 0; i < rounds; i++ {
l.Warnf(ctx, "Q-WARN-%d-%d", w, i)
l.Errorf(ctx, "Q-ERROR-%d-%d", w, i)
}
}(w)
}
wg.Wait()
if err := l.Close(); err != nil {
t.Fatalf("Close: %v", err)
}
for _, ev := range []string{"warn", "error"} {
own := readLog(t, dir, ev)
if n := strings.Count(own, "Q-"+strings.ToUpper(ev)+"-"); n != workers*rounds {
t.Errorf("%s.log 中自身日志出现 %d 次,期望 %d", ev, n, workers*rounds)
}
}
info := readLog(t, dir, "info")
for _, ev := range []string{"WARN", "ERROR"} {
if n := strings.Count(info, "Q-"+ev+"-"); n != workers*rounds {
t.Errorf("info.log 中 %s 出现 %d 次,期望 %d", ev, n, workers*rounds)
}
}
if n := len(splitLines(info)); n != 2*workers*rounds {
t.Errorf("info.log 行数 = %d,期望 %d", n, 2*workers*rounds)
}
}
// readLevelAll 读取某级别在目录下的全部文件(含大小切割产生的 _N 归档)
func readLevelAll(t *testing.T, dir, event string) string {
t.Helper()
files, err := filepath.Glob(filepath.Join(dir, "*_"+event+"*.log"))
if err != nil {
t.Fatalf("glob %s: %v", event, err)
}
var sb strings.Builder
for _, f := range files {
b, err := os.ReadFile(f)
if err != nil {
t.Fatalf("读取 %s: %v", f, err)
}
sb.Write(b)
}
return sb.String()
}
// 开启大小切割时镜像同样要正常滚动归档,一条都不能丢、也不能重复
func TestAllLevelToInfoWithSizeSplit(t *testing.T) {
dir := t.TempDir()
l := loggerx.NewLogger(context.Background(),
loggerx.SetDir(dir),
loggerx.SetAllLevelToInfo(),
loggerx.SetSizeSplit(2*1024), // 很小,强制滚动多次
loggerx.SetCompress(false), // 不压缩,便于直接读归档
)
t.Cleanup(func() {
if err := l.Close(); err != nil {
t.Errorf("Close 返回错误: %v", err)
}
})
const n = 200
ctx := context.Background()
for i := 0; i < n; i++ {
l.Warnf(ctx, "S-WARN-%03d", i)
l.Infof(ctx, "S-INFO-%03d", i)
}
if err := l.MustSync(); err != nil {
t.Fatalf("MustSync: %v", err)
}
info := readLevelAll(t, dir, "info")
warn := readLevelAll(t, dir, "warn")
for i := 0; i < n; i++ {
if got := strings.Count(info, fmt.Sprintf("S-WARN-%03d", i)); got != 1 {
t.Fatalf("info.log 中 S-WARN-%03d 出现 %d 次,期望 1 次", i, got)
}
if got := strings.Count(info, fmt.Sprintf("S-INFO-%03d", i)); got != 1 {
t.Fatalf("info.log 中 S-INFO-%03d 出现 %d 次,期望 1 次", i, got)
}
if got := strings.Count(warn, fmt.Sprintf("S-WARN-%03d", i)); got != 1 {
t.Fatalf("warn.log 中 S-WARN-%03d 出现 %d 次,期望 1 次", i, got)
}
}
if got, want := len(splitLines(info)), 2*n; got != want {
t.Errorf("info.log 总行数 = %d,期望 %d", got, want)
}
if got, want := len(splitLines(warn)), n; got != want {
t.Errorf("warn.log 总行数 = %d,期望 %d", got, want)
}
}
// 异步模式下镜像写入失败必须上报(否则 info.log 写不进去是静默的),
// 且不能影响原级别文件落盘
func TestAllLevelToInfoAsyncReportsMirrorFailure(t *testing.T) {
dir := t.TempDir()
// 用一个同名目录占住 info.log:镜像必然打不开,而 warn.log 正常
if err := os.Mkdir(filepath.Join(dir, "info.log"), 0o755); err != nil {
t.Fatalf("mkdir info.log: %v", err)
}
reported := make(chan error, 32)
l := loggerx.NewLogger(context.Background(),
loggerx.SetDir(dir),
loggerx.SetFileSplit(loggerx.FileSplitNone),
loggerx.SetWriteAsync(),
loggerx.SetAllLevelToInfo(),
loggerx.SetErrorHandler(func(err error) {
select {
case reported <- err:
default:
}
}),
)
l.Warn(context.Background(), "R-WARN")
if err := l.Close(); err != nil {
t.Fatalf("Close: %v", err)
}
select {
case err := <-reported:
if !strings.Contains(err.Error(), "info") {
t.Errorf("上报的错误与 info 镜像无关: %v", err)
}
default:
t.Error("异步模式下 info 镜像写入失败没有被上报")
}
if !strings.Contains(readLog(t, dir, "warn"), "R-WARN") {
t.Error("镜像失败不应影响 warn.log 落盘")
}
}
// SetPrintFile(false):没有文件可镜像,选项不能引发重复驱动输出,也不能建出 info.log
func TestAllLevelToInfoWithoutFile(t *testing.T) {
for _, mode := range []struct {
name string
opts []loggerx.Option
}{
{name: "sync"},
{name: "async", opts: []loggerx.Option{loggerx.SetWriteAsync()}},
} {
t.Run(mode.name, func(t *testing.T) {
var buf bytes.Buffer
dir := t.TempDir()
opts := append([]loggerx.Option{
loggerx.SetDir(dir),
loggerx.SetPrintFile(false),
loggerx.SetAllLevelToInfo(),
loggerx.SetExtraDriver(&buf),
}, mode.opts...)
l := loggerx.NewLogger(context.Background(), opts...)
l.Error(context.Background(), "P-ERROR")
l.Warn(context.Background(), "P-WARN")
// 异步模式下驱动由消费协程写,必须先 Close 再读 buf
if err := l.Close(); err != nil {
t.Fatalf("Close: %v", err)
}
out := buf.String()
if n := strings.Count(out, "P-ERROR"); n != 1 {
t.Errorf("驱动里 P-ERROR 出现 %d 次,期望 1 次\n%s", n, out)
}
if n := strings.Count(out, "P-WARN"); n != 1 {
t.Errorf("驱动里 P-WARN 出现 %d 次,期望 1 次\n%s", n, out)
}
files, err := filepath.Glob(filepath.Join(dir, "*_info.log"))
if err != nil {
t.Fatalf("glob: %v", err)
}
if len(files) != 0 {
t.Errorf("SetPrintFile(false) 时不应产生文件,实际有 %v", files)
}
})
}
}