381 lines
11 KiB
Go
381 lines
11 KiB
Go
package loggerx_test
|
||||
|
|
|
|||
|
|
import (
|
|||
|
|
"context"
|
|||
|
|
"encoding/json"
|
|||
|
|
"fmt"
|
|||
|
|
"io"
|
|||
|
|
"log"
|
|||
|
|
"os"
|
|||
|
|
"path/filepath"
|
|||
|
|
"runtime"
|
|||
|
|
"strings"
|
|||
|
|
"sync"
|
|||
|
|
"testing"
|
|||
|
|
"time"
|
|||
|
|
|
|||
|
|
"github.com/yuninks/loggerx"
|
|||
|
|
)
|
|||
|
|
|
|||
|
|
// newTestLogger 统一构造测试实例,测试结束关闭句柄
|
|||
|
|
func newTestLogger(t *testing.T, opts ...loggerx.Option) (*loggerx.Logger, string) {
|
|||
|
|
t.Helper()
|
|||
|
|
dir := t.TempDir()
|
|||
|
|
opts = append([]loggerx.Option{loggerx.SetDir(dir)}, opts...)
|
|||
|
|
l := loggerx.NewLogger(context.Background(), opts...)
|
|||
|
|
t.Cleanup(func() {
|
|||
|
|
if err := l.Close(); err != nil {
|
|||
|
|
t.Errorf("Close 返回错误: %v", err)
|
|||
|
|
}
|
|||
|
|
})
|
|||
|
|
return l, dir
|
|||
|
|
}
|
|||
|
|
|
|||
|
|
// syncAndRead 先刷盘再读取(写入走 bufio,落盘后才能看到)
|
|||
|
|
func syncAndRead(t *testing.T, l *loggerx.Logger, dir, event string) string {
|
|||
|
|
t.Helper()
|
|||
|
|
if err := l.MustSync(); err != nil {
|
|||
|
|
t.Fatalf("MustSync: %v", err)
|
|||
|
|
}
|
|||
|
|
return readLog(t, dir, event)
|
|||
|
|
}
|
|||
|
|
|
|||
|
|
// tailOf 取字符串末尾 n 个字节,用于失败时打印现场
|
|||
|
|
func tailOf(s string, n int) string {
|
|||
|
|
if len(s) <= n {
|
|||
|
|
return s
|
|||
|
|
}
|
|||
|
|
return s[len(s)-n:]
|
|||
|
|
}
|
|||
|
|
|
|||
|
|
// readLog 读取切割后的日志文件(文件名可能带日期前缀)
|
|||
|
|
func readLog(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)
|
|||
|
|
}
|
|||
|
|
if len(files) == 0 {
|
|||
|
|
files, _ = filepath.Glob(filepath.Join(dir, event+".log"))
|
|||
|
|
}
|
|||
|
|
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()
|
|||
|
|
}
|
|||
|
|
|
|||
|
|
// ---------------- 修复1:文件句柄缓存键必须包含 event ----------------
|
|||
|
|
|
|||
|
|
// info/error 交替写入后,各自文件的内容必须完整且不串台
|
|||
|
|
func TestEventHandlerIsolation(t *testing.T) {
|
|||
|
|
l, dir := newTestLogger(t)
|
|||
|
|
|
|||
|
|
const n = 50
|
|||
|
|
for i := 0; i < n; i++ {
|
|||
|
|
l.Infof(context.Background(), "INFO-%d", i)
|
|||
|
|
l.Errorf(context.Background(), "ERR-%d", i)
|
|||
|
|
}
|
|||
|
|
|
|||
|
|
info, errl := syncAndRead(t, l, dir, "info"), syncAndRead(t, l, dir, "error")
|
|||
|
|
if got := strings.Count(info, "INFO-"); got != n {
|
|||
|
|
t.Errorf("info.log 条数 = %d, 期望 %d", got, n)
|
|||
|
|
}
|
|||
|
|
if got := strings.Count(errl, "ERR-"); got != n {
|
|||
|
|
t.Errorf("error.log 条数 = %d, 期望 %d", got, n)
|
|||
|
|
}
|
|||
|
|
if strings.Contains(info, "ERR-") {
|
|||
|
|
t.Error("info.log 中混入了 error 日志")
|
|||
|
|
}
|
|||
|
|
if strings.Contains(errl, "INFO-") {
|
|||
|
|
t.Error("error.log 中混入了 info 日志")
|
|||
|
|
}
|
|||
|
|
}
|
|||
|
|
|
|||
|
|
// 不同 channel 也必须各自独立
|
|||
|
|
func TestChannelIsolation(t *testing.T) {
|
|||
|
|
l, dir := newTestLogger(t)
|
|||
|
|
l.Channel("c1").Info(context.Background(), "IN-C1")
|
|||
|
|
l.Channel("c2").Info(context.Background(), "IN-C2")
|
|||
|
|
|
|||
|
|
if s := syncAndRead(t, l, dir, "info"); strings.Contains(s, "IN-C2") {
|
|||
|
|
t.Error("根 channel 的日志里混入了 c2 的内容")
|
|||
|
|
}
|
|||
|
|
// channel 的日志在子目录里,同样带时间前缀
|
|||
|
|
c1, err := filepath.Glob(filepath.Join(dir, "c1", "*_info.log"))
|
|||
|
|
if err != nil || len(c1) == 0 {
|
|||
|
|
t.Fatalf("没有找到 c1 的日志文件: %v", err)
|
|||
|
|
}
|
|||
|
|
b, err := os.ReadFile(c1[0])
|
|||
|
|
if err != nil {
|
|||
|
|
t.Fatalf("读取 c1 日志: %v", err)
|
|||
|
|
}
|
|||
|
|
if !strings.Contains(string(b), "IN-C1") {
|
|||
|
|
t.Errorf("c1 日志内容不正确: %s", string(b))
|
|||
|
|
}
|
|||
|
|
}
|
|||
|
|
|
|||
|
|
// 事件交替写入的性能:不能因为切换事件而反复重开文件
|
|||
|
|
func BenchmarkInfoOnly(b *testing.B) {
|
|||
|
|
l := loggerx.NewLogger(context.Background(), loggerx.SetDir(b.TempDir()))
|
|||
|
|
defer l.Close()
|
|||
|
|
ctx := context.Background()
|
|||
|
|
b.ReportAllocs()
|
|||
|
|
b.ResetTimer()
|
|||
|
|
for i := 0; i < b.N; i++ {
|
|||
|
|
l.Infof(ctx, "hello %d", i)
|
|||
|
|
}
|
|||
|
|
}
|
|||
|
|
|
|||
|
|
func BenchmarkInfoErrorInterleaved(b *testing.B) {
|
|||
|
|
l := loggerx.NewLogger(context.Background(), loggerx.SetDir(b.TempDir()))
|
|||
|
|
defer l.Close()
|
|||
|
|
ctx := context.Background()
|
|||
|
|
b.ReportAllocs()
|
|||
|
|
b.ResetTimer()
|
|||
|
|
for i := 0; i < b.N; i++ {
|
|||
|
|
l.Infof(ctx, "hello %d", i)
|
|||
|
|
l.Errorf(ctx, "hello %d", i)
|
|||
|
|
}
|
|||
|
|
}
|
|||
|
|
|
|||
|
|
// ---------------- 修复2:io.Writer 契约 ----------------
|
|||
|
|
|
|||
|
|
func TestWriteSatisfiesIOWriterContract(t *testing.T) {
|
|||
|
|
cases := []struct {
|
|||
|
|
name string
|
|||
|
|
opts []loggerx.Option
|
|||
|
|
}{
|
|||
|
|
{"默认(写文件)", nil},
|
|||
|
|
{"只写驱动(不写文件)", []loggerx.Option{loggerx.SetPrintFile(false), loggerx.SetToConsole()}},
|
|||
|
|
{"文件+附加驱动", []loggerx.Option{loggerx.SetExtraDriver(io.Discard)}},
|
|||
|
|
}
|
|||
|
|
|
|||
|
|
for _, c := range cases {
|
|||
|
|
t.Run(c.name, func(t *testing.T) {
|
|||
|
|
l, _ := newTestLogger(t, c.opts...)
|
|||
|
|
b := []byte("hello io.Writer\n")
|
|||
|
|
n, err := l.Write(b)
|
|||
|
|
if err != nil {
|
|||
|
|
t.Fatalf("Write 返回错误: %v", err)
|
|||
|
|
}
|
|||
|
|
if n != len(b) {
|
|||
|
|
t.Fatalf("Write 返回 n=%d, 期望 len(b)=%d(违反 io.Writer 契约)", n, len(b))
|
|||
|
|
}
|
|||
|
|
})
|
|||
|
|
}
|
|||
|
|
}
|
|||
|
|
|
|||
|
|
// 通过标准库 log 写入也必须成功:log 在短写时会报 io.ErrShortWrite
|
|||
|
|
func TestStdLogWriteNoShortWriteError(t *testing.T) {
|
|||
|
|
l, dir := newTestLogger(t)
|
|||
|
|
|
|||
|
|
// log.SetOutput 是全局状态,恢复现场
|
|||
|
|
prev := log.Writer()
|
|||
|
|
defer log.SetOutput(prev)
|
|||
|
|
log.SetOutput(l)
|
|||
|
|
|
|||
|
|
if err := log.Output(2, "via standard log"); err != nil {
|
|||
|
|
t.Fatalf("标准 log 写入失败: %v", err)
|
|||
|
|
}
|
|||
|
|
if s := syncAndRead(t, l, dir, "info"); !strings.Contains(s, "via standard log") {
|
|||
|
|
t.Errorf("日志内容未落盘: %s", s)
|
|||
|
|
}
|
|||
|
|
}
|
|||
|
|
|
|||
|
|
// ---------------- 修复3:句柄释放与刷盘 ----------------
|
|||
|
|
|
|||
|
|
// Close 之后文件必须能被删除(Windows 上句柄没关是删不掉的)
|
|||
|
|
func TestCloseReleasesFileHandles(t *testing.T) {
|
|||
|
|
dir := t.TempDir()
|
|||
|
|
l := loggerx.NewLogger(context.Background(), loggerx.SetDir(dir))
|
|||
|
|
l.Info(context.Background(), "before close")
|
|||
|
|
|
|||
|
|
if err := l.Close(); err != nil {
|
|||
|
|
t.Fatalf("Close: %v", err)
|
|||
|
|
}
|
|||
|
|
|
|||
|
|
files, _ := filepath.Glob(filepath.Join(dir, "*.log"))
|
|||
|
|
if len(files) == 0 {
|
|||
|
|
t.Fatal("没有生成日志文件")
|
|||
|
|
}
|
|||
|
|
for _, f := range files {
|
|||
|
|
if err := os.Remove(f); err != nil {
|
|||
|
|
t.Errorf("Close 后仍无法删除 %s: %v", filepath.Base(f), err)
|
|||
|
|
}
|
|||
|
|
}
|
|||
|
|
}
|
|||
|
|
|
|||
|
|
// Close 必须先把缓存里的内容刷到磁盘
|
|||
|
|
func TestCloseFlushesBufferedData(t *testing.T) {
|
|||
|
|
dir := t.TempDir()
|
|||
|
|
l := loggerx.NewLogger(context.Background(), loggerx.SetDir(dir))
|
|||
|
|
l.Info(context.Background(), "buffered-content")
|
|||
|
|
|
|||
|
|
if err := l.Close(); err != nil {
|
|||
|
|
t.Fatalf("Close: %v", err)
|
|||
|
|
}
|
|||
|
|
files, _ := filepath.Glob(filepath.Join(dir, "*.log"))
|
|||
|
|
if len(files) != 1 {
|
|||
|
|
t.Fatalf("期望 1 个日志文件, 实际 %d", len(files))
|
|||
|
|
}
|
|||
|
|
b, err := os.ReadFile(files[0])
|
|||
|
|
if err != nil {
|
|||
|
|
t.Fatalf("读取: %v", err)
|
|||
|
|
}
|
|||
|
|
if !strings.Contains(string(b), "buffered-content") {
|
|||
|
|
t.Errorf("Close 后内容丢失: %q", string(b))
|
|||
|
|
}
|
|||
|
|
}
|
|||
|
|
|
|||
|
|
// 重复 Close 必须安全
|
|||
|
|
func TestCloseIsIdempotent(t *testing.T) {
|
|||
|
|
l := loggerx.NewLogger(context.Background(), loggerx.SetDir(t.TempDir()))
|
|||
|
|
if err := l.Close(); err != nil {
|
|||
|
|
t.Fatalf("首次 Close: %v", err)
|
|||
|
|
}
|
|||
|
|
if err := l.Close(); err != nil {
|
|||
|
|
t.Fatalf("重复 Close: %v", err)
|
|||
|
|
}
|
|||
|
|
}
|
|||
|
|
|
|||
|
|
// 异步写入 + Close:队列里的内容不能丢
|
|||
|
|
func TestCloseDrainsAsyncQueue(t *testing.T) {
|
|||
|
|
for _, n := range []int{10, 100, 197, 198, 199, 200, 201, 250} {
|
|||
|
|
t.Run(fmt.Sprintf("n=%d", n), func(t *testing.T) {
|
|||
|
|
dir := t.TempDir()
|
|||
|
|
l := loggerx.NewLogger(context.Background(), loggerx.SetDir(dir), loggerx.SetWriteAsync())
|
|||
|
|
|
|||
|
|
al := l.WriteAsync()
|
|||
|
|
for i := 0; i < n; i++ {
|
|||
|
|
al.Infof(context.Background(), "ASYNC-%d", i)
|
|||
|
|
}
|
|||
|
|
if err := l.Close(); err != nil {
|
|||
|
|
t.Fatalf("Close: %v", err)
|
|||
|
|
}
|
|||
|
|
|
|||
|
|
var sb strings.Builder
|
|||
|
|
files, _ := filepath.Glob(filepath.Join(dir, "*.log"))
|
|||
|
|
for _, f := range files {
|
|||
|
|
b, err := os.ReadFile(f)
|
|||
|
|
if err != nil {
|
|||
|
|
t.Fatalf("读取 %s: %v", f, err)
|
|||
|
|
}
|
|||
|
|
sb.Write(b)
|
|||
|
|
}
|
|||
|
|
content := sb.String()
|
|||
|
|
|
|||
|
|
missing := make([]string, 0)
|
|||
|
|
for i := 0; i < n; i++ {
|
|||
|
|
if !strings.Contains(content, fmt.Sprintf(`ASYNC-%d"`, i)) {
|
|||
|
|
missing = append(missing, fmt.Sprint(i))
|
|||
|
|
}
|
|||
|
|
}
|
|||
|
|
if len(missing) > 0 {
|
|||
|
|
cnt := strings.Count(content, "[info]")
|
|||
|
|
t.Errorf("丢 %d 条: %s | 实际日志行数=%d n=%d 结尾=%q", len(missing), strings.Join(missing, ","), cnt, n, tailOf(content, 160))
|
|||
|
|
}
|
|||
|
|
})
|
|||
|
|
}
|
|||
|
|
}
|
|||
|
|
|
|||
|
|
// 用 context.Background 创建实例,Close 后后台 goroutine 必须退出
|
|||
|
|
func TestCloseStopsGoroutines(t *testing.T) {
|
|||
|
|
before := runtime.NumGoroutine()
|
|||
|
|
|
|||
|
|
loggers := make([]*loggerx.Logger, 0, 10)
|
|||
|
|
for i := 0; i < 10; i++ {
|
|||
|
|
loggers = append(loggers, loggerx.NewLogger(context.Background(), loggerx.SetDir(t.TempDir())))
|
|||
|
|
}
|
|||
|
|
for _, l := range loggers {
|
|||
|
|
if err := l.Close(); err != nil {
|
|||
|
|
t.Fatalf("Close: %v", err)
|
|||
|
|
}
|
|||
|
|
}
|
|||
|
|
|
|||
|
|
deadline := time.Now().Add(3 * time.Second)
|
|||
|
|
for time.Now().Before(deadline) {
|
|||
|
|
if runtime.NumGoroutine() <= before {
|
|||
|
|
return
|
|||
|
|
}
|
|||
|
|
time.Sleep(20 * time.Millisecond)
|
|||
|
|
}
|
|||
|
|
t.Errorf("Close 后 goroutine 未回收: before=%d after=%d", before, runtime.NumGoroutine())
|
|||
|
|
}
|
|||
|
|
|
|||
|
|
// ---------------- 修复4:nil ctx / 序列化失败 ----------------
|
|||
|
|
|
|||
|
|
func TestNilContextDoesNotPanic(t *testing.T) {
|
|||
|
|
l, dir := newTestLogger(t)
|
|||
|
|
// nolint:staticcheck // 故意传 nil,验证不 panic
|
|||
|
|
l.Info(nil, "nil ctx")
|
|||
|
|
if s := syncAndRead(t, l, dir, "info"); !strings.Contains(s, "nil ctx") {
|
|||
|
|
t.Errorf("nil ctx 时日志未写入: %q", s)
|
|||
|
|
}
|
|||
|
|
}
|
|||
|
|
|
|||
|
|
// 不可序列化的内容不能产出空行 / 坏 JSON
|
|||
|
|
func TestUnmarshalableContentProducesValidJSON(t *testing.T) {
|
|||
|
|
l, dir := newTestLogger(t)
|
|||
|
|
l.Info(context.Background(), make(chan int), func() {}, map[string]any{"ok": 1})
|
|||
|
|
l.Infof(context.Background(), "后面这条必须还在")
|
|||
|
|
|
|||
|
|
content := syncAndRead(t, l, dir, "info")
|
|||
|
|
lines := strings.Split(strings.TrimSpace(content), "\n")
|
|||
|
|
if len(lines) != 2 {
|
|||
|
|
t.Fatalf("期望 2 行日志, 实际 %d 行: %q", len(lines), content)
|
|||
|
|
}
|
|||
|
|
for i, line := range lines {
|
|||
|
|
body := strings.TrimPrefix(line, "[info]")
|
|||
|
|
if body == "" {
|
|||
|
|
t.Fatalf("第 %d 行是空的 [info] 裸行(序列化失败被静默丢弃)", i+1)
|
|||
|
|
}
|
|||
|
|
var v map[string]any
|
|||
|
|
if err := json.Unmarshal([]byte(body), &v); err != nil {
|
|||
|
|
t.Fatalf("第 %d 行不是合法 JSON: %v\n内容: %s", i+1, err, body)
|
|||
|
|
}
|
|||
|
|
if i == 0 && v["content"] == nil {
|
|||
|
|
t.Error("序列化失败时 content 丢失,无法定位问题")
|
|||
|
|
}
|
|||
|
|
}
|
|||
|
|
}
|
|||
|
|
|
|||
|
|
// 并发写入:数据不能串、不能丢
|
|||
|
|
func TestConcurrentWriteIntegrity(t *testing.T) {
|
|||
|
|
l, dir := newTestLogger(t)
|
|||
|
|
|
|||
|
|
var wg sync.WaitGroup
|
|||
|
|
const perLevel = 300
|
|||
|
|
for i := 0; i < perLevel; i++ {
|
|||
|
|
wg.Add(3)
|
|||
|
|
go func(i int) { defer wg.Done(); l.Infof(context.Background(), "INFO-%d", i) }(i)
|
|||
|
|
go func(i int) { defer wg.Done(); l.Errorf(context.Background(), "ERR-%d", i) }(i)
|
|||
|
|
go func(i int) { defer wg.Done(); l.Channel("cc").Infof(context.Background(), "CC-%d", i) }(i)
|
|||
|
|
}
|
|||
|
|
wg.Wait()
|
|||
|
|
|
|||
|
|
if got := strings.Count(syncAndRead(t, l, dir, "info"), "INFO-"); got != perLevel {
|
|||
|
|
t.Errorf("info 条数 = %d, 期望 %d", got, perLevel)
|
|||
|
|
}
|
|||
|
|
if got := strings.Count(syncAndRead(t, l, dir, "error"), "ERR-"); got != perLevel {
|
|||
|
|
t.Errorf("error 条数 = %d, 期望 %d", got, perLevel)
|
|||
|
|
}
|
|||
|
|
// cc 是子 channel,日志落在 cc/ 子目录
|
|||
|
|
ccFiles, _ := filepath.Glob(filepath.Join(dir, "cc", "*_info.log"))
|
|||
|
|
if len(ccFiles) == 0 {
|
|||
|
|
t.Fatal("没有找到 cc 的日志文件")
|
|||
|
|
}
|
|||
|
|
var ccb strings.Builder
|
|||
|
|
for _, f := range ccFiles {
|
|||
|
|
b, _ := os.ReadFile(f)
|
|||
|
|
ccb.Write(b)
|
|||
|
|
}
|
|||
|
|
if got := strings.Count(ccb.String(), "CC-"); got != perLevel {
|
|||
|
|
t.Errorf("cc 条数 = %d, 期望 %d", got, perLevel)
|
|||
|
|
}
|
|||
|
|
}
|